Impact van uitvoeringsplan op ASYNC_NETWORK_IO Wachten - Deel 1

Een paar weken geleden werd een interessante vraag gesteld op de #SQLHelp-hashtag op Twitter over de impact van uitvoeringsplannen op het ASYNC_NETWORK_IO-wachttype, en het genereerde een aantal verschillende meningen en veel goede discussie.

https://twitter.com/shawndube/status/1225476846537650176

Mijn onmiddellijke antwoord hierop zou zijn dat iemand de oorzaak en het gevolg hiervan verkeerd interpreteert, aangezien het wachttype ASYNC_NETWORK_IO wordt aangetroffen wanneer de engine resultaten heeft om via TDS naar de client te verzenden, maar er geen beschikbare TDS-buffers op de verbinding zijn om ze te verzenden Aan. Over het algemeen betekent dit dat de klant de resultaten niet efficiënt gebruikt, maar op basis van de daaropvolgende discussie raakte ik geïntrigeerd genoeg om wat te testen of een uitvoeringsplan daadwerkelijk van invloed zou zijn op de ASYNC_NETWORK_IO-wachten.

Om samen te vatten:focussen op ASYNC_NETWORK_IO wacht alleen, aangezien een afstemmingsstatistiek een vergissing is. Hoe sneller een query wordt uitgevoerd, hoe hoger dit type wacht waarschijnlijk zal oplopen, zelfs als de client de resultaten zo snel mogelijk consumeert. (Zie ook het recente bericht van Greg over het focussen op alleen wachten in het algemeen.)

Testconfiguratie

Om de tests hiervoor uit te voeren, werd een zeer eenvoudige tabel gegenereerd op basis van een voorbeeld dat mij per e-mail werd verstrekt door een ander lid van de community, dat een verandering in het wachttype aantoonde, maar ook een geheel andere vraag tussen de twee had tests met een extra tabel die werd gebruikt in de tweede test, en het had een opmerking om de resultaten uit te schakelen, waardoor het significante deel van dit wachttype om te beginnen wordt verwijderd, dus het is niet alleen een planwijziging alleen.

Opmerking:ik wil erop wijzen dat dit helemaal niet een negatieve uitspraak is tegenover wie dan ook; de daaropvolgende discussie en verdere tests die voortkwamen uit de originele reproductie die werd verstrekt, waren zeer leerzaam en leidden tot verder onderzoek naar het begrijpen van dit type wachttijd in het algemeen. De originele reproductie demonstreerde een verschil, maar met aanvullende wijzigingen die geen deel uitmaakten van de oorspronkelijke vraag zoals gesteld.

DROP TABLE IF EXISTS [DemoTable];
 
CREATE TABLE [DemoTable] (
  ID INT PRIMARY KEY,
  FILLER VARCHAR(100)
);
 
INSERT INTO [DemoTable] WITH (TABLOCK)
SELECT TOP (250000) ROW_NUMBER() OVER (ORDER BY (SELECT NULL)), REPLICATE('Z', 50)
  FROM master..spt_values t1
  CROSS JOIN master..spt_values t2
  CROSS JOIN master..spt_values t3
  OPTION (MAXDOP 1);
GO

Met behulp van deze tabel als basisgegevensset voor het testen van verschillende plattegrondvormen met behulp van hints, werden de volgende query's gebruikt:

SELECT t1.ID, t2.FILLER, t2.FILLER
  FROM [DemoTable] t1
  INNER HASH JOIN [DemoTable] t2 ON t1.ID = t2.ID;
 
  SELECT t1.ID, t2.FILLER, t2.FILLER
  FROM [DemoTable] t1
  INNER MERGE JOIN [DemoTable] t2 ON t1.ID = t2.ID;
 
  SELECT t1.ID, t2.FILLER, t2.FILLER
  FROM [DemoTable] t1
  INNER LOOP JOIN [DemoTable] t2 ON t1.ID = t2.ID;

Aangezien ik deze query's op SQL Server 2019 CU1 uitvoerde, bevatten de uitvoeringsplannen de feitelijke wachtstatistieken met betrekking tot de uitvoering van de query.

Opmerking: De optimizer zou een Merge Join gebruiken zonder dat de hints worden toegepast voor deze specifieke dataset en query.

Eerste testresultaten

Voor de eerste tests gebruikte ik gewoon SSMS om de query's uit te voeren en verzamelde ik het werkelijke uitvoeringsplan om de wachtinformatie te vergelijken die aan elke query is gekoppeld, die hieronder wordt weergegeven. Houd er rekening mee dat voor deze gegevensomvang de verstreken tijden niet significant verschillen, en evenmin de wachttijden of wachttijden voor ASYNC_NETWORK_IO.

HASH JOIN

<WaitStats>
  <Wait WaitType="CXPACKET"         WaitTimeMs="18393" WaitCount="8415" />
  <Wait WaitType="ASYNC_NETWORK_IO" WaitTimeMs="4394"  WaitCount="6635" />
  <Wait WaitType="HTDELETE"         WaitTimeMs="957"   WaitCount="6"    />
  <Wait WaitType="HTBUILD"          WaitTimeMs="4"     WaitCount="6"    />
  <Wait WaitType="HTREPARTITION"    WaitTimeMs="3"     WaitCount="6"    />
  <Wait WaitType="CMEMTHREAD"       WaitTimeMs="3"     WaitCount="14"   />
  <Wait WaitType="LATCH_EX"         WaitTimeMs="2"     WaitCount="8"    />
</WaitStats>
<QueryTimeStats CpuTime="1068" ElapsedTime="4961" />

MEER AANMELDEN

<WaitStats>
  <Wait WaitType="ASYNC_NETWORK_IO" WaitTimeMs="3169" WaitCount="6592" />
</WaitStats>
<QueryTimeStats CpuTime="792" ElapsedTime="3933" />

LOOP DOE MEE

<WaitStats>
  <Wait WaitType="CXPACKET"         WaitTimeMs="13690" WaitCount="8286" />
  <Wait WaitType="ASYNC_NETWORK_IO" WaitTimeMs="3576"  WaitCount="6631" />
  <Wait WaitType="LATCH_EX"         WaitTimeMs="1"     WaitCount="3"    />
</WaitStats>
<QueryTimeStats CpuTime="2172" ElapsedTime="4084" />

Dit was echter niet waar ik wilde stoppen met testen, omdat mijn eigen ervaring herhaaldelijk heeft aangetoond dat Management Studio een zeer inefficiënte gebruiker is van resultaten van SQL Server en zelf kan veroorzaken ASYNC_NETWORK_IO wacht op optreden. Dus besloot ik de manier waarop ik dingen testte te veranderen en ging ik naar een SQLCMD-uitvoering van de query's.

Testen met SQLCMD

Omdat ik SQLCMD veel gebruik voor demo's tijdens het presenteren, heb ik een testscript.sql-bestand gemaakt met de volgende inhoud:

PRINT 'Minimize Screen';
GO
 
WAITFOR DELAY '00:00:05';
GO
 
SELECT t1.ID, t2.FILLER, t2.FILLER
  FROM [DemoTable] t1
  INNER HASH JOIN [DemoTable] t2 ON t1.ID = t2.ID;
GO
 
SELECT t1.ID, t2.FILLER, t2.FILLER
  FROM [DemoTable] t1
  INNER MERGE JOIN [DemoTable] t2 ON t1.ID = t2.ID;
GO
 
SELECT t1.ID, t2.FILLER, t2.FILLER
  FROM [DemoTable] t1
  INNER LOOP JOIN [DemoTable] t2 ON t1.ID = t2.ID;
GO

Dit werd als volgt uitgevoerd vanaf de opdrachtregel en tijdens de vertraging van 5 seconden werd het venster geminimaliseerd om de uitvoering niet te laten renderen en resultaten te laten scrollen tijdens de verwerking:

Om de daadwerkelijke uitvoeringsplannen vast te leggen, ging ik met een Extended Events-sessie die de query_post_execution_showplan-gebeurtenis verzamelde. retourneert de WaitStats- of QueryTimeStats-informatie niet tenzij tegelijkertijd query_post_execution_showplan ook is ingeschakeld. Bovendien, aangezien dit een geïsoleerde testmachine is zonder andere werklast, zijn de effecten van de standaardprofilering hier niet zo'n groot probleem.

CREATE EVENT SESSION [Actual Plan] ON SERVER 
  ADD EVENT sqlserver.query_post_execution_showplan
  (ACTION(sqlserver.session_id));

HASH JOIN

<WaitStats>
  <Wait WaitType="CXPACKET"         WaitTimeMs="45722" WaitCount="8674" />
  <Wait WaitType="ASYNC_NETWORK_IO" WaitTimeMs="11321" WaitCount="6610" />
  <Wait WaitType="HTDELETE"         WaitTimeMs="1174"  WaitCount="6"    />
  <Wait WaitType="HTREPARTITION"    WaitTimeMs="4"     WaitCount="6"    />
  <Wait WaitType="HTBUILD"          WaitTimeMs="3"     WaitCount="5"    />
  <Wait WaitType="LATCH_EX"         WaitTimeMs="2"     WaitCount="7"    />
</WaitStats>
<QueryTimeStats ElapsedTime="11874" CpuTime="1070" />

MEER AANMELDEN

<WaitStats>
  <Wait WaitType="ASYNC_NETWORK_IO" WaitTimeMs="10837" WaitCount="6602" />
</WaitStats>
<QueryTimeStats ElapsedTime="11597" CpuTime="789" />

LOOP DOE MEE

<WaitStats>
  <Wait WaitType="CXPACKET"         WaitTimeMs="43587" WaitCount="8620" />
  <Wait WaitType="ASYNC_NETWORK_IO" WaitTimeMs="11177" WaitCount="6612" />
  <Wait WaitType="LATCH_EX"         WaitTimeMs="1"     WaitCount="3"    />
</WaitStats>
<QueryTimeStats ElapsedTime="11696" CpuTime="2221" />

Dit bleek eigenlijk geen snellere manier te zijn om de query uit te voeren, en de prestaties werden zelfs verminderd door het opdrachtregelhulpprogramma te gebruiken om de query uit te voeren, zelfs wanneer het venster geminimaliseerd is en niet zichtbaar door de resultaten wordt geschoven. Met het venster open was de HASH-uitvoeringstijd 15708 ms en de ASYNC_NETWORK_IO wachttijd was 15126 ms. Dit toont echter aan dat voor dezelfde exacte resultaten de prestaties van de client die de resultaten consumeert, van invloed zijn op zowel de wachttijd als de uitvoeringstijd van de query.

Impact parallellisme?

Een van de dingen die me opvielen was dat slechts twee van de plannen parallel waren uitgevoerd, gebaseerd op het bestaan ​​van de CXPACKET- en LATCH_EX-wachten in de XML van het uitvoeringsplan. Dus ik vroeg me af wat voor impact het forceren van een serieel uitvoeringsplan zou hebben op de uitvoering van dezelfde query's met OPTION (MAXDOP 1).

HASH JOIN

<WaitStats>
  <Wait WaitType="ASYNC_NETWORK_IO" WaitTimeMs="4047" WaitCount="6379" />
</WaitStats>
<QueryTimeStats CpuTime="602" ElapsedTime="4619" />

SEMMEN SAMENVOEGEN

<WaitStats>
  <Wait WaitType="ASYNC_NETWORK_IO" WaitTimeMs="3699" WaitCount="6608" />
</WaitStats>
<QueryTimeStats CpuTime="810" ElapsedTime="4478" />

LOOP DOE MEE

<WaitStats>
  <Wait WaitType="ASYNC_NETWORK_IO" WaitTimeMs="2083" WaitCount="5385" />
</WaitStats>
<QueryTimeStats CpuTime="1859" ElapsedTime="3918" />

Merk hier op dat het totale aantal wachttijden niet significant is afgenomen. Alleen het seriële lusverbindingsplan heeft een grote verandering in het aantal wachttijden of de totale hoeveelheid wachttijd die ermee gepaard gaat, en op zichzelf betekent dit niet dat het een positief voordeel is, de uitvoeringstijd voor de query was niet significant verbeterd en er kunnen andere factoren zijn die de resultaten van die specifieke test beïnvloedden.

De onderstaande tabel geeft een overzicht van de ASYNC_NETWORK_IO wachttijd en telling voor elk van de tests.

Samenvatting

Hoewel het onderzoek van dit bericht niet elk aspect van planwijzigingen of het ASYNC_NETWORK_IO-wachttype dekt, toont het wel aan dat dit wachten niet significant wordt beïnvloed door het uitvoeringsplan dat wordt gebruikt voor de uitvoering van een query. Ik zou dit wachttype bijna als het CXPACKET-wachttype classificeren bij het uitvoeren van analyse van een server als geheel; normaal om te zien voor de meeste workloads en tenzij het ongelooflijk scheef is en er andere prestatieproblemen zijn die wijzen op langzame consumptie van resultaten door clients, zoals blokkeren met de leadblocker die wacht op ASYNC_NETWORK_IO, dan iets dat moet worden genegeerd als slechts 'onderdeel van de normale wachthandtekening voor de werkdruk'.