Impatto del piano di esecuzione sulle attese di ASYNC_NETWORK_IO - Parte 1

Qualche settimana fa è stata posta un'interessante domanda sull'hashtag #SQLHelp su Twitter sull'impatto dei piani di esecuzione sul tipo di attesa ASYNC_NETWORK_IO, che ha generato alcune opinioni divergenti e molte buone discussioni.

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

La mia risposta immediata a questo sarebbe che qualcuno sta interpretando erroneamente la causa e l'effetto di ciò, poiché il tipo di attesa ASYNC_NETWORK_IO viene rilevato quando il motore ha risultati da inviare tramite TDS al client ma non ci sono buffer TDS disponibili sulla connessione per inviarli su. In generale, ciò significa che il lato client non sta consumando i risultati in modo efficiente, ma sulla base della discussione che ne è seguita sono diventato abbastanza incuriosito da fare alcuni test per verificare se un piano di esecuzione avrebbe effettivamente un impatto significativo sulle attese di ASYNC_NETWORK_IO.

Per riassumere:concentrarsi su ASYNC_NETWORK_IO attende da solo poiché una metrica di ottimizzazione è un errore. Più velocemente viene eseguita una query, più è probabile che si accumulerà questo tipo di attesa, anche se il client sta consumando i risultati il ​​più velocemente possibile. (Vedi anche il recente post di Greg sul concentrarsi solo sulle attese in generale.)

Configurazione di prova

Per eseguire i test per questo, è stata generata una tabella molto semplice basata su un esempio che mi è stato fornito tramite e-mail da un altro membro della comunità, che ha mostrato un cambiamento nel tipo di attesa, ma aveva anche una query completamente diversa tra i due test con una tabella aggiuntiva utilizzata nel secondo test e aveva un commento per disattivare i risultati, che rimuove la parte significativa di questo tipo di attesa per cominciare, quindi non è solo una modifica del piano da sola.

Nota:vorrei sottolineare che questa non è affatto una dichiarazione negativa nei confronti di nessuno; la discussione che ne è seguita e gli ulteriori test che sono scaturiti dalla riproduzione originale fornita sono stati molto educativi e hanno portato a ulteriori ricerche per comprendere questo tipo di attesa in generale. La riproduzione originale ha dimostrato una differenza, ma con modifiche aggiuntive che non facevano parte della domanda originale come posta.

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

Utilizzando questa tabella come set di dati di base per testare diverse forme del piano utilizzando i suggerimenti, sono state utilizzate le seguenti query:

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;

Poiché stavo eseguendo queste query su SQL Server 2019 CU1, i piani di esecuzione includevano le informazioni sulle statistiche di attesa effettive relative all'esecuzione della query.

Nota: L'ottimizzatore utilizzerà un Merge Join senza che i suggerimenti vengano applicati per questo specifico set di dati e query.

Risultati del test iniziale

Per i test iniziali ho semplicemente utilizzato SSMS per eseguire le query e raccolto il piano di esecuzione effettiva per confrontare le informazioni di attesa associate a ciascuna query mostrate di seguito. Nota che per questa dimensione di dati, i tempi trascorsi non sono significativamente diversi, e nemmeno i tempi di attesa o i conteggi di attesa per ASYNC_NETWORK_IO.

UNISCI CON HASH

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

UNISCI UNISCI

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

UNISCI LOOP

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

Tuttavia, non era qui che volevo interrompere i test, perché la mia esperienza ha dimostrato ripetutamente che Management Studio è un consumatore molto inefficiente dei risultati di SQL Server e può esso stesso causare ASYNC_NETWORK_IO attende che si verifichi. Quindi, ho deciso di cambiare il modo in cui stavo testando le cose e sono passato a un'esecuzione SQLCMD delle query.

Test con SQLCMD

Poiché uso molto SQLCMD per le demo durante la presentazione, ho creato un file testscript.sql con i seguenti contenuti:

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

Questo è stato eseguito dalla riga di comando come segue e durante il ritardo di 5 secondi la finestra è stata ridotta a icona per consentire all'esecuzione di non eseguire il rendering e scorrere i risultati durante l'elaborazione:

Per acquisire i piani di esecuzione effettivi, sono andato con una sessione di eventi estesi raccogliendo l'evento query_post_execution_showplan che, con il senno di poi, su SQL Server 2019 ho pensato che avrei dovuto usare query_post_execution_plan_profile invece di utilizzare l'implementazione leggera dell'infrastruttura di profilazione delle statistiche di esecuzione delle query v3, ma questo evento non restituisce le informazioni WaitStats o QueryTimeStats a meno che anche query_post_execution_showplan non sia abilitato contemporaneamente. Inoltre, poiché si tratta di una macchina di prova isolata senza altri carichi di lavoro, l'impatto della profilatura standard non è un grosso problema qui.

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

UNISCI CON HASH

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

UNISCI UNISCI

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

UNISCI LOOP

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

Questo in realtà non si è rivelato un modo più veloce per eseguire la query e le prestazioni sono state effettivamente ridotte utilizzando l'utilità della riga di comando per eseguire la query, anche quando la finestra è ridotta a icona e non scorre visibilmente i risultati. Con la finestra aperta il tempo di esecuzione HASH era 15708 ms e il tempo di attesa ASYNC_NETWORK_IO era 15126 ms. Tuttavia, ciò dimostra che per gli stessi risultati esatti le prestazioni del client che consumano i risultati influiscono sia sul tempo di attesa che sul tempo di esecuzione della query.

Impatto sul parallelismo?

Una delle cose che ho notato è che solo due dei piani sono stati eseguiti con parallelismo, in base all'esistenza delle attese CXPACKET e LATCH_EX nell'XML del piano di esecuzione. Quindi mi sono chiesto che tipo di impatto avrebbe forzare un piano di esecuzione seriale sull'esecuzione di queste stesse query utilizzando OPTION (MAXDOP 1).

UNISCI CON HASH

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

UNISCI UNISCI

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

UNISCI LOOP

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

Nota qui che i conteggi complessivi delle attese non sono diminuiti in modo significativo. Solo il piano di join del ciclo seriale ha un cambiamento importante nel numero di attese o nella quantità totale di tempo di attesa ad esso associato, e da solo ciò non significa che sia un vantaggio positivo, il tempo di esecuzione della query non è stato significativamente migliorato e potrebbero esserci altri fattori che hanno influenzato i risultati di quel test specifico.

La tabella seguente riassume il tempo di attesa e il conteggio di ASYNC_NETWORK_IO per ciascuno dei test.

Riepilogo

Sebbene l'indagine di questo post non copra ogni singolo aspetto delle modifiche al piano o il tipo di attesa ASYNC_NETWORK_IO, dimostra che questa attesa non è influenzata in modo significativo dal piano di esecuzione utilizzato per l'esecuzione di una query. Classificherei questo tipo di attesa quasi come il tipo di attesa CXPACKET quando si esegue l'analisi di un server nel suo insieme; normale da vedere per la maggior parte dei carichi di lavoro e a meno che non sia incredibilmente distorto e ci siano altri problemi di prestazioni che indicano un consumo lento dei risultati da parte dei client come il blocco con il blocco dei lead in attesa di ASYNC_NETWORK_IO, quindi qualcosa da ignorare come 'parte della normale firma di attesa per il carico di lavoro'.