Por que um loop simples resulta em esperas ASYNC_NETWORK_IO?

O seguinte T-SQL leva cerca de 25 segundos na minha máquina com o 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;

Ele acumula 532 ms de ASYNC_NETWORK_IOespera de acordo com ambos sys.dm_exec_session_wait_statse sys.dm_os_wait_stats. O tempo total de espera aumenta à medida que o número de iterações de loop aumenta. Usando o wait_completedevento estendido, vejo que a espera ocorre aproximadamente a cada 43 ms, com algumas exceções:

Além disso, posso receber as pilhas de chamadas que ocorrem imediatamente antes da ASYNC_NETWORK_IOespera:

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

Finalmente, notei que o SSMS usa uma quantidade surpreendente de CPU durante o loop (cerca de meio núcleo em média). Não consigo descobrir o que o SSMS está fazendo durante esse período.

Por que um loop simples causa ASYNC_NETWORK_IOesperas quando executado através do SSMS? A única saída que eu pareço obter do cliente nessa execução de consulta é os "Comandos concluídos com sucesso". mensagem.

A documentação para SET NOCOUNTdiz:

SET NOCOUNT ONimpede o envio de DONE_IN_PROCmensagens para o cliente para cada instrução em um procedimento armazenado. Para procedimentos armazenados que contêm várias instruções que não retornam muitos dados reais ou para procedimentos que contêm loops Transact-SQL, a configuração SET NOCOUNTde ONpode fornecer um aumento significativo no desempenho, porque o tráfego de rede é bastante reduzido.

Você não está executando as instruções em um procedimento armazenado; portanto, o SQL Server envia DONEtokens (código 0xFD) para indicar o status de conclusão de cada instrução SQL. Essas mensagens são adiadas e enviadas de forma assíncrona quando o pacote de rede está cheio. Quando o cliente não consome pacotes de rede com rapidez suficiente, eventualmente os buffers são preenchidos e a operação fica bloqueada para o SQL Server, gerando as ASYNC_NETWORK_IOesperas.

Observe que os DONEtokens são diferentes de DONEINPROC(código 0xFF), conforme observa a documentação:

• Um DONEtoken é retornado para cada instrução SQL no lote SQL, exceto declarações de variáveis.

• Para execução de instruções SQL em procedimentos armazenados, DONEPROCe DONEINPROCtokens são usados ​​no lugar de DONEtokens.

Você verá uma redução drástica nas ASYNC_NETWORK_IOesperas usando:

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;

Você também pode usar sys.sp_executesqlpara obter o mesmo resultado.

Exemplo de rastreamento de pilha capturado assim que uma ASYNC_NETWORK_IOespera começa:

Um pacote TDS de exemplo, como visto na função embutida, sqllang!srv_completioncode_ex<1>tinha os seguintes 13 bytes:

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

Que decodifica para:

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

Por fim, o número de ASYNC_NETWORK_IOesperas depende do cliente e do driver e o que ele faz, se houver, com todas as DONEmensagens. Testando com um loop 1/10 do tamanho indicado na pergunta (5.000.000 de iterações de loop), encontrei o SSMS executado por cerca de 4 segundos com 200-300 ms de espera. sqlcmdfuncionou por 2-3 segundos com um dígito ms espera; osqlno mesmo tempo de execução, com cerca de 10 ms de espera.

O pior cliente de longe para este teste foi o Azure Data Studio. Funcionou por quase 6 horas: