Warum führt eine einfache Schleife dazu, dass ASYNC_NETWORK_IO wartet?

Das folgende T-SQL dauert auf meinem Computer mit SSMS v17.9 ungefähr 25 Sekunden:

DECLARE @outer_loop INT = 0,
@big_string_for_u VARCHAR(8000);

SET NOCOUNT ON;

WHILE @outer_loop < 50000000
BEGIN
    SET @big_string_for_u = 'ZZZZZZZZZZ';
    SET @outer_loop = @outer_loop + 1;
END;

Es kumuliert 532 ms ASYNC_NETWORK_IOWartezeit nach beiden sys.dm_exec_session_wait_statsund sys.dm_os_wait_stats. Die Gesamtwartezeit erhöht sich mit zunehmender Anzahl von Schleifeniterationen. Anhand des wait_completederweiterten Ereignisses kann ich feststellen, dass das Warten mit wenigen Ausnahmen ungefähr alle 43 ms erfolgt:

Außerdem kann ich die Anrufstapel abrufen, die unmittelbar vor dem ASYNC_NETWORK_IOWarten auftreten:

sqldk.dll!SOS_DispatcherBase::GetTrack+0x7f6c
sqldk.dll!SOS_Scheduler::PromotePendingTask+0x204
sqldk.dll!SOS_Task::PostWait+0x5f
sqldk.dll!SOS_Scheduler::Suspend+0xb15
sqllang.dll!CSECCNGProvider::GetBCryptHandleFromAlgID+0xf6af
sqllang.dll!CSECCNGProvider::GetBCryptHandleFromAlgID+0xf44c
sqllang.dll!SNIPacketRelease+0xd63
sqllang.dll!SNIPacketRelease+0x2097
sqllang.dll!SNIPacketRelease+0x1f99
sqllang.dll!SNIPacketRelease+0x18fe
sqllang.dll!CAutoExecuteAsContext::Restore+0x52d
sqllang.dll!CSQLSource::Execute+0x151b
sqllang.dll!CSQLSource::Execute+0xe13
sqllang.dll!CSQLSource::Execute+0x474
sqllang.dll!SNIPacketRelease+0x165d
sqllang.dll!CValOdsRow::CValOdsRow+0xa92
sqllang.dll!CValOdsRow::CValOdsRow+0x883
sqldk.dll!ClockHand::Statistic::RecordClockHandStats+0x15d
sqldk.dll!ClockHand::Statistic::RecordClockHandStats+0x638
sqldk.dll!ClockHand::Statistic::RecordClockHandStats+0x2ad
sqldk.dll!SystemThread::MakeMiniSOSThread+0xdf8
sqldk.dll!SystemThread::MakeMiniSOSThread+0xf00
sqldk.dll!SystemThread::MakeMiniSOSThread+0x667
sqldk.dll!SystemThread::MakeMiniSOSThread+0xbb9

Schließlich ist mir aufgefallen, dass SSMS während der Schleife überraschend viel CPU verbraucht (durchschnittlich etwa einen halben Kern). Ich kann nicht herausfinden, was SSMS während dieser Zeit tut.

Warum wartet eine einfache Schleife, ASYNC_NETWORK_IOwenn sie über SSMS ausgeführt wird? Die einzige Ausgabe, die ich bei dieser Abfrageausführung vom Client zu erhalten scheine, sind die "Befehle erfolgreich ausgeführt". Botschaft.

Die Dokumentation für SET NOCOUNTsagt:

SET NOCOUNT ONverhindert das Senden von DONE_IN_PROCNachrichten an den Client für jede Anweisung in einer gespeicherten Prozedur. Bei gespeicherten Prozeduren, die mehrere Anweisungen enthalten, die nicht viele tatsächliche Daten zurückgeben, oder bei Prozeduren, die Transact-SQL-Schleifen enthalten, kann die Einstellung SET NOCOUNTauf ONeine erhebliche Leistungssteigerung bewirken, da der Netzwerkverkehr stark reduziert wird.

Sie führen die Anweisungen nicht in einer gespeicherten Prozedur aus, daher sendet SQL Server DONEToken (Code 0xFD), um den Abschlussstatus jeder SQL-Anweisung anzuzeigen. Diese Nachrichten werden zurückgestellt und asynchron gesendet, wenn das Netzwerkpaket voll ist. Wenn der Client Netzwerkpakete nicht schnell genug verbraucht, füllen sich die Puffer schließlich und der Vorgang wird für SQL Server blockiert, wodurch die ASYNC_NETWORK_IOWartezeiten generiert werden .

Beachten Sie, dass sich die DONEToken von DONEINPROC(Code 0xFF) unterscheiden, wie in der Dokumentation angegeben:

• DONEFür jede SQL-Anweisung im SQL-Batch wird ein Token zurückgegeben, mit Ausnahme von Variablendeklarationen.

• Für die Ausführung von SQL - Anweisungen in gespeicherten Prozeduren DONEPROCund DONEINPROCToken werden anstelle von DONEToken.

Sie werden eine dramatische Reduzierung der ASYNC_NETWORK_IOWartezeiten feststellen, wenn Sie Folgendes verwenden:

CREATE PROCEDURE #P AS
SET NOCOUNT ON;

DECLARE
    @outer_loop integer = 0,
    @big_string_for_u varchar(8000);


WHILE @outer_loop < 5000000
BEGIN
    SET @big_string_for_u = 'ZZZZZZZZZZ';
    SET @outer_loop = @outer_loop + 1;
END;
GO
EXECUTE dbo.#P;

Sie könnten auch verwenden sys.sp_executesql, um das gleiche Ergebnis zu erzielen.

Beispiel für einen Stack-Trace, der erfasst wird, während ein ASYNC_NETWORK_IOWartevorgang beginnt:

Ein Beispiel für ein TDS-Paket in der Inline-Funktion sqllang!srv_completioncode_ex<1>hatte die folgenden 13 Bytes:

fd 01 00 c1 00 01 00 00 00 00 00 00 00          

Welche dekodiert zu:

• TokenType = 0xfd DONE_TOKEN
• Status = 0x0001 DONE_MORE
• CurCmd = 0x00c1 (193)
• DoneRowCount = 0x00000001 (1)

Letztendlich ASYNC_NETWORK_IOhängt die Anzahl der Wartezeiten vom Client und vom Treiber ab und davon, was er mit allen DONENachrichten , wenn überhaupt, macht . Beim Testen mit einer Schleife von 1/10 der in der Frage angegebenen Größe (5.000.000 Schleifeniterationen) stellte ich fest, dass SSMS etwa 4 Sekunden lang mit 200-300 ms Wartezeit lief. sqlcmdlief für 2-3 Sekunden mit einstelligen ms wartet; osqlungefähr die gleiche Laufzeit mit ungefähr 10 ms Wartezeit.

Der mit Abstand schlechteste Client für diesen Test war Azure Data Studio. Es lief fast 6 Stunden: