Wpływ planu wykonania na oczekiwania ASYNC_NETWORK_IO – część 1

Kilka tygodni temu pod tagiem hash #SQLHelp na Twitterze zadano interesujące pytanie dotyczące wpływu planów wykonania na typ oczekiwania ASYNC_NETWORK_IO, które wywołało różne opinie i wiele dobrych dyskusji.

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

Moją natychmiastową odpowiedzią na to byłoby to, że ktoś błędnie interpretuje przyczynę i skutek tego, ponieważ typ oczekiwania ASYNC_NETWORK_IO jest napotykany, gdy silnik ma wyniki do wysłania przez TDS do klienta, ale nie ma dostępnych buforów TDS w połączeniu, aby je wysłać na. Ogólnie rzecz biorąc, oznacza to, że strona klienta nie zużywa wyników efektywnie, ale w oparciu o następującą dyskusję, zaintrygował mnie na tyle, aby przetestować, czy plan wykonania rzeczywiście wpłynie na oczekiwania ASYNC_NETWORK_IO.

Podsumowując:skupienie się na ASYNC_NETWORK_IO czeka samotnie, ponieważ metryka dostrajania jest błędem. Im szybciej wykonuje się zapytanie, tym wyższy jest prawdopodobnie skumulowany ten typ oczekiwania, nawet jeśli klient zużywa wyniki tak szybko, jak to możliwe. (Zapoznaj się również z niedawnym postem Grega o skoncentrowaniu się na samym oczekiwaniu w ogóle.)

Konfiguracja testowa

Aby przeprowadzić testy w tym celu, wygenerowano bardzo prostą tabelę na podstawie przykładu otrzymanego przez e-mail od innego członka społeczności, który wykazał zmianę typu oczekiwania, ale miał również zupełnie inne zapytanie między tymi dwoma testy z dodatkową tabelą używaną w drugim teście i zawierał komentarz, aby wyłączyć wyniki, co usuwa znaczną część tego typu oczekiwania na początek, więc nie jest to tylko zmiana planu.

Uwaga:chciałbym zaznaczyć, że nie jest to w ogóle negatywne stwierdzenie wobec nikogo; późniejsza dyskusja i dalsze testy, które pochodziły z dostarczonej oryginalnej reprodukcji, były bardzo pouczające i doprowadziły do ​​dalszych badań nad ogólnym zrozumieniem tego typu oczekiwania. Oryginalna reprodukcja DID wykazała różnicę, ale z dodatkowymi zmianami, które nie były częścią oryginalnego pytania, jak postawiono.

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

Używając tej tabeli jako podstawowego zestawu danych do testowania różnych kształtów planu za pomocą podpowiedzi, użyto następujących zapytań:

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;

Ponieważ uruchamiałem te zapytania na SQL Server 2019 CU1, plany wykonania zawierały informacje o rzeczywistych statystykach oczekiwania związane z wykonaniem zapytania.

Uwaga: Optymalizator użyłby łączenia scalającego bez stosowania wskazówek dla tego konkretnego zestawu danych i zapytania.

Wstępne wyniki testu

Na potrzeby wstępnych testów po prostu użyłem programu SSMS do uruchomienia zapytań i zebrałem plan Actual Execution, aby porównać informacje o oczekiwaniu związane z każdym zapytaniem, które pokazano poniżej. Zwróć uwagę, że dla tego rozmiaru danych czasy, które upłynęły, nie różnią się znacząco, podobnie jak czasy oczekiwania lub liczniki oczekiwania dla ASYNC_NETWORK_IO.

HASZOWANIE DOŁĄCZ

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

POŁĄCZ DOŁĄCZ

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

POŁĄCZENIE W PĘTLI

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

Jednak nie na tym miejscu chciałem przerwać testowanie, ponieważ moje własne doświadczenie wielokrotnie wskazywało, że Management Studio jest bardzo nieefektywnym konsumentem wyników z SQL Server i może samo powodować ASYNC_NETWORK_IO czeka na wystąpienie. Postanowiłem więc zmienić sposób testowania i przeszedłem do wykonywania zapytań SQLCMD.

Testowanie z SQLCMD

Ponieważ często używam SQLCMD do dem podczas prezentacji, stworzyłem plik testscript.sql o następującej zawartości:

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

Zostało to wykonane z wiersza poleceń w następujący sposób, a podczas 5-sekundowego opóźnienia okno zostało zminimalizowane, aby umożliwić wykonanie nie renderowania i przewijania wyników podczas przetwarzania:

Aby uchwycić rzeczywiste plany wykonania, wybrałem sesję Extended Events, zbierając zdarzenie query_post_execution_showplan, które z perspektywy czasu w SQL Server 2019 pomyślałem, że powinienem zamiast tego użyć query_post_execution_plan_profile, aby użyć lekkiej implementacji infrastruktury profilowania statystyk wykonywania zapytań v3, ale to zdarzenie nie zwraca informacji WaitStats lub QueryTimeStats, chyba że w tym samym czasie włączona jest również funkcja query_post_execution_showplan. Dodatkowo, ponieważ jest to odizolowana maszyna testująca bez innych obciążeń, wpływ standardowego profilowania nie jest tutaj tak duży.

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

HASZOWANIE DOŁĄCZ

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

POŁĄCZ DOŁĄCZ

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

POŁĄCZENIE W PĘTLI

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

W rzeczywistości nie okazało się to szybszym sposobem wykonywania zapytania, a wydajność została faktycznie zmniejszona przez użycie narzędzia wiersza poleceń do wykonania zapytania, nawet gdy okno jest zminimalizowane i nie przewija wyników w widoczny sposób. Przy otwartym oknie czas wykonania HASH wynosił 15708 ms, a czas oczekiwania ASYNC_NETWORK_IO wynosił 15126 ms. Pokazuje to jednak, że dla tych samych dokładnych wyników wydajność klienta zużywającego wyniki wpływa zarówno na czas oczekiwania, jak i czas wykonania zapytania.

Wpływ równoległości?

Jedną z rzeczy, które zauważyłem, było to, że tylko dwa plany zostały wykonane z paralelizmem, w oparciu o istnienie CXPACKET i LATCH_EX waitów w XML planu wykonania. Zastanawiałem się więc, jaki wpływ wymuszenie planu wykonania szeregowego będzie miało na wykonanie tych samych zapytań przy użyciu OPCJI (MAXDOP 1).

HASZOWANIE DOŁĄCZ

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

POŁĄCZ DOŁĄCZ

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

POŁĄCZENIE W PĘTLI

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

Zwróć uwagę, że ogólna liczba oczekiwania nie zmniejszyła się znacząco. Tylko plan łączenia pętli szeregowej ma poważną zmianę liczby oczekiwania lub łącznego czasu oczekiwania z nim związanego i w izolacji nie oznacza to, że jest to pozytywna korzyść, czas wykonania zapytania nie uległ znacznej poprawie i mogą istnieć inne czynniki, które wpłynęły na wyniki tego konkretnego testu.

Poniższa tabela podsumowuje czas oczekiwania ASYNC_NETWORK_IO i liczbę dla każdego z testów.

Podsumowanie

Chociaż badanie tego posta nie obejmuje każdego aspektu zmian planu lub typu oczekiwania ASYNC_NETWORK_IO, pokazuje, że na to oczekiwanie nie ma znaczącego wpływu plan wykonania używany do wykonania zapytania. Sklasyfikowałbym ten typ oczekiwania prawie jak typ oczekiwania CXPACKET podczas przeprowadzania analizy serwera jako całości; normalne dla większości obciążeń i o ile nie jest to niewiarygodnie przekrzywione i występują inne problemy z wydajnością wskazujące na powolne zużycie wyników przez klientów, takie jak blokowanie za pomocą głównego blokera czekającego na ASYNC_NETWORK_IO, wtedy coś należy zignorować jako „część normalnego podpisu czeka na obciążenie pracą”.