Estamos recebendo a seguinte exceção em um aplicativo:
Tempo limite de execução expirado. O período de tempo limite decorrido antes da conclusão da operação ou o servidor não está respondendo.
Então, eu olhei para a consulta e com certeza estava demorando muito. Então eu ajustei para levar menos de um segundo.
Mas ainda estou recebendo timeouts.
Então eu configurei uma sessão Extended Events para o evento Attention para pegar os tempos limite e ver o que está acontecendo (usando esta página como um guia).
Os resultados foram confusos. Vejo minhas consultas na lista, mas a duração registrada no rastreamento é inferior a um segundo!
Aqui estão alguns valores de exemplo que estou obtendo na coluna de duração para o tempo limite:
| tempo esgotado |
|---|
| 539 |
| 539 |
| 474 |
| 423 |
| 505 |
| 904 |
Estou confuso. Por que estou recebendo um erro de tempo limite do SQL Server, quando a duração mostra uma média de meio segundo?
NOTA: A saída do evento estendido mostra algumas linhas com mais de 30 segundos. Estes são timeouts legítimos para minha visão e estou trabalhando neles. (Apenas indico isso para mostrar que o evento estendido Attention parece estar funcionando para essas consultas.)
Achei que poderia estar bloqueando, então configurei um evento estendido do Relatório de Processos Bloqueados para ver (seguindo este guia ). Embora haja bloqueios acontecendo no servidor, eles não estão nos bancos de dados em que minha consulta está sendo executada.
O aplicativo está usando uma API chamada Dapper (um Micro ORM bastante popular que ouvi dizer que é usado para executar o Stack Exchange). Imagino que tenha um gerenciamento de conexão decente. Mas mesmo que eles tenham usado mal suas conexões, pelo que entendi, isso leva a vazamentos de recursos, não a tempos limite do SQL.
O tempo limite da consulta no aplicativo é definido como 120 segundos. Isso deve ser bastante tempo para obter a maioria das consultas que estou vendo relatadas como tempos limite.
Percebi que seja qual for a duração, não é o tempo em que a consulta de tempo limite foi executada. Eu corri
waitfor delay '00:00:30'em uma janela de consulta definida para tempo limite em 10 segundos. Os resultados deveriam ter sido de 10 segundos para todos os tempos limite. Mas eu obtive esses valores para meus 6 testes: 70707, 311, 269, 264, 3442, 272. Meu palpite é que a duração é a quantidade de tempo que levou para lidar com o evento Attention (ou seja, parar a consulta).Apenas para ter certeza de que a duração não funcionaria corretamente com uma consulta em execução real, executei uma de longa duração, novamente definida para tempo limite em 10 segundos. As durações foram: 64246, 58002, 52828, 68061, 48153, 49084. Demorou mais, mas nenhum desses tempos chega perto de 10 segundos. Mais uma vez, confirma que a duração não é o que parece ser.
A documentação diz que a duração está em microssegundos (não em milissegundos). Isso também pode funcionar se for a hora de manipular o evento Attention, mas nunca corresponderia ao tempo que levou para a execução da consulta expirada.
Executei a consulta de longa duração sem tempo limite e tive que pará-la após 120 segundos. Demorou muito mais para parar e a duração do evento Attention foi 6400055. 6,4 segundos é aproximadamente quanto tempo levou para parar. Novamente confirmando que a duração é a quantidade de tempo que leva para lidar com o evento "Atenção".