Udførelsesplanens indvirkning på ASYNC_NETWORK_IO Venter – Del 1

For et par uger siden blev der stillet et interessant spørgsmål på #SQLHelp hash-tagget på Twitter om virkningen af ​​eksekveringsplaner på ventetypen ASYNC_NETWORK_IO, og det genererede nogle forskellige meninger og en masse god diskussion.

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

Mit umiddelbare svar på dette ville være, at nogen misfortolker årsagen og virkningen af ​​dette, da ventetypen ASYNC_NETWORK_IO stødes på, når motoren har resultater til at sende over TDS til klienten, men der er ingen tilgængelige TDS-buffere på forbindelsen til at sende dem på. Generelt betyder dette, at klientsiden ikke forbruger resultaterne effektivt, men baseret på den efterfølgende diskussion blev jeg fascineret nok til at lave nogle test af, om en eksekveringsplan faktisk ville påvirke ASYNC_NETWORK_IO-venterne betydeligt.

For at opsummere:At fokusere på ASYNC_NETWORK_IO venter alene som en tuning-metrik er en fejl. Jo hurtigere en forespørgsel udføres, jo højere vil denne ventetype sandsynligvis akkumulere, selvom klienten forbruger resultater så hurtigt som muligt. (Se også Gregs seneste indlæg om at fokusere på ventetider alene generelt.)

Test konfiguration

For at køre testene for dette, blev der genereret en meget enkel tabel baseret på et eksempel, som blev givet til mig via e-mail fra et andet medlem af fællesskabet, som viste en ændring i ventetypen, men som også havde en helt anden forespørgsel mellem de to test med en ekstra tabel, der blev brugt i den anden test, og den havde en kommentar til at slå resultaterne fra, hvilket fjerner den betydelige del af denne ventetype til at begynde med, så det er ikke kun en planændring alene.

Bemærk:Jeg vil gerne påpege, at dette ikke er en negativ udtalelse over for nogen overhovedet; den efterfølgende diskussion og yderligere test, der kom fra den originale reproduktion, der blev leveret, var meget lærerig, og det førte til yderligere forskning for at forstå denne ventetype generelt. Den originale gengivelse viste en forskel, men med yderligere ændringer, der ikke var en del af det oprindelige spørgsmål som stillet.

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

Ved at bruge denne tabel som et basisdatasæt til at teste forskellige planformer ved hjælp af tip, blev følgende forespørgsler brugt:

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;

Da jeg kørte disse forespørgsler på SQL Server 2019 CU1, inkluderede udførelsesplanerne de faktiske ventestatistikoplysninger relateret til forespørgselsudførelsen.

Bemærk: Optimizeren ville bruge en Merge Join, uden at hints blev anvendt for dette specifikke datasæt og forespørgsel.

Indledende testresultater

Til de indledende tests brugte jeg simpelthen SSMS til at køre forespørgslerne og indsamlede den faktiske udførelsesplan for at sammenligne venteoplysningerne forbundet med hver forespørgsel, som er vist nedenfor. Bemærk, at for denne størrelse af data er de forløbne tider ikke væsentligt forskellige, og det er heller ikke ventetiderne eller ventetallet for 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" />

FLET JOIN

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

LOOP JOIN

<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" />

Det var dog ikke her, jeg ville stoppe med at teste, for min egen erfaring har gentagne gange vist, at Management Studio er en meget ineffektiv forbruger af resultater fra SQL Server og selv kan forårsage ASYNC_NETWORK_IO venter på at opstå. Så jeg besluttede at ændre, hvordan jeg testede ting, og gik til en SQLCMD-udførelse af forespørgslerne.

Test med SQLCMD

Da jeg bruger SQLCMD meget til demoer, mens jeg præsenterer, har jeg oprettet en testscript.sql-fil med følgende indhold:

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

Dette blev udført fra kommandolinjen som følger, og i løbet af de 5 sekunders forsinkelse blev vinduet minimeret for at tillade udførelsen ikke at gengive og rulle resultater under behandlingen:

For at fange de faktiske eksekveringsplaner gik jeg med en Extended Events-session, hvor jeg indsamlede query_post_execution_showplan-begivenheden, som jeg i bakspejlet på SQL Server 2019 troede, at jeg skulle have brugt query_post_execution_plan_profile i stedet for at bruge den lette forespørgselsudførelsesstatistik, der profilerer infrastruktur v3-implementering, men denne hændelse returnerer ikke WaitStats- eller QueryTimeStats-oplysningerne, medmindre query_post_execution_showplan også er aktiveret på samme tid. Da dette er en isoleret testmaskine uden anden arbejdsbyrde, er indvirkningen af ​​standardprofileringen i virkeligheden ikke så stor bekymring her.

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" />

FLET JOIN

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

LOOP JOIN

<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" />

Dette fungerede faktisk ikke som en hurtigere måde at udføre forespørgslen på, og ydeevnen blev faktisk reduceret ved at bruge kommandolinjeværktøjet til at udføre forespørgslen, selv når vinduet er minimeret og ikke synligt ruller resultaterne. Med vinduet åbent var HASH-udførelsestiden 15708ms og ASYNC_NETWORK_IO ventetiden 15126ms. Dette viser dog, at for de samme nøjagtige resultater påvirker klientens ydeevne, der bruger resultaterne, både ventetiden og udførelsestiden for forespørgslen.

Parallelismevirkning?

En af de ting, jeg lagde mærke til, var, at kun to af planerne var udført med parallelitet, baseret på eksistensen af ​​CXPACKET og LATCH_EX venter i udførelsesplanen XML. Så jeg spekulerede på, hvilken slags indvirkning det ville have på udførelsen af ​​de samme forespørgsler ved at tvinge en seriel eksekveringsplan ved hjælp af OPTION (MAXDOP 1).

HASH JOIN

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

FLET JOIN

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

LOOP JOIN

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

Bemærk her, at det samlede ventetal ikke er faldet væsentligt. Kun den serielle sløjfetilslutningsplan har en større ændring i antallet af ventetider eller den samlede mængde ventetid forbundet med sig, og isoleret set betyder dette ikke, at det er en positiv fordel, udførelsestiden for forespørgslen blev ikke væsentligt forbedret og der kan være andre faktorer, der har påvirket resultaterne af den specifikke test.

Tabellen nedenfor opsummerer ASYNC_NETWORK_IO ventetiden og tæller for hver af testene.

Oversigt

Selvom dette indlægs undersøgelse ikke dækker hvert enkelt aspekt af planændringer eller ventetypen ASYNC_NETWORK_IO, viser den, at denne ventetid ikke er væsentligt påvirket af den eksekveringsplan, der bruges til udførelse af en forespørgsel. Jeg vil klassificere denne ventetype næsten som CXPACKET ventetypen, når jeg udfører analyse af en server som helhed; normalt at se for de fleste arbejdsbelastninger, og medmindre det er utroligt skævt, og der er andre præstationsproblemer, der peger på langsom forbrug af resultater hos klienter som at blokere med lead-blockeren, der venter på ASYNC_NETWORK_IO, så er noget, der skal ignoreres som blot 'en del af den normale vente-signatur for arbejdsbyrden'.