Mengapa loop sederhana menghasilkan ASYNC_NETWORK_IO menunggu?

T-SQL berikut ini memakan waktu sekitar 25 detik pada mesin saya dengan SSMS v17.9:

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;

Ini mengakumulasi 532 ms ASYNC_NETWORK_IOmenunggu sesuai dengan keduanya sys.dm_exec_session_wait_statsdan sys.dm_os_wait_stats. Total waktu tunggu meningkat karena jumlah iterasi loop meningkat. Menggunakan wait_completedacara yang diperluas saya dapat melihat bahwa menunggu terjadi kira-kira setiap 43 ms dengan beberapa pengecualian:

Selain itu, saya bisa mendapatkan tumpukan panggilan yang terjadi tepat sebelum ASYNC_NETWORK_IOmenunggu:

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

Akhirnya, saya perhatikan bahwa SSMS menggunakan jumlah CPU yang mengejutkan selama loop (rata-rata sekitar setengah inti). Saya tidak dapat mengetahui apa yang SSMS lakukan selama waktu itu.

Mengapa loop sederhana menyebabkan ASYNC_NETWORK_IOmenunggu ketika dijalankan melalui SSMS? Satu-satunya hasil yang saya dapatkan dari klien dari eksekusi query ini adalah "Perintah berhasil diselesaikan." pesan.

The dokumentasi untuk SET NOCOUNTmengatakan:

SET NOCOUNT ONmencegah pengiriman DONE_IN_PROCpesan ke klien untuk setiap pernyataan dalam prosedur tersimpan. Untuk prosedur tersimpan yang berisi beberapa pernyataan yang tidak mengembalikan banyak data aktual, atau untuk prosedur yang mengandung loop Transact-SQL, pengaturan SET NOCOUNTuntuk ONdapat memberikan peningkatan kinerja yang signifikan, karena lalu lintas jaringan sangat berkurang.

Anda tidak menjalankan pernyataan dalam prosedur tersimpan, jadi SQL Server mengirim DONEtoken (kode 0xFD) untuk menunjukkan status penyelesaian setiap pernyataan SQL. Pesan-pesan ini ditangguhkan, dan dikirim secara tidak sinkron ketika paket jaringan penuh. Ketika klien tidak mengkonsumsi paket jaringan dengan cukup cepat, akhirnya buffer terisi, dan operasi menjadi pemblokiran untuk SQL Server, menghasilkanASYNC_NETWORK_IO menunggu.

Perhatikan DONEtoken berbeda dari DONEINPROC(kode 0xFF) sebagai catatan dokumentasi:

• Sebuah DONEtanda dikembalikan untuk setiap pernyataan SQL di SQL bets kecuali deklarasi variabel.

• Untuk eksekusi pernyataan SQL dalam prosedur tersimpan, DONEPROCdan DONEINPROCtoken digunakan sebagai pengganti DONEtoken.

Anda akan melihat pengurangan dramatis dalam ASYNC_NETWORK_IOmenunggu menggunakan:

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;

Anda juga bisa menggunakan sys.sp_executesqluntuk mencapai hasil yang sama.

Contoh jejak tumpukan ditangkap hanya saat ASYNC_NETWORK_IOmenunggu dimulai:

Contoh paket TDS seperti yang terlihat pada fungsi inline sqllang!srv_completioncode_ex<1>memiliki 13 byte berikut:

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

Yang diterjemahkan ke:

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

Pada akhirnya, jumlah ASYNC_NETWORK_IOmenunggu tergantung pada klien dan driver, dan apa yang dilakukannya, jika ada, dengan semua DONEpesan. Pengujian dengan loop 1/10 dari ukuran yang diberikan dalam pertanyaan (5.000.000 loop iterasi) Saya menemukan SSMS berjalan selama sekitar 4 detik dengan menunggu 200-300 ms. sqlcmdberlari selama 2-3 detik dengan satu digit ms menunggu;osqlsekitar run time yang sama dengan sekitar 10 ms menunggu.

Klien terburuk sejauh ini untuk tes ini adalah Azure Data Studio. Itu berjalan selama hampir 6 jam: