Web Service com Lentidão gerando Timeout
O cliente estava recebendo erro de timeout em algumas páginas da sua aplicação web. Coletamos um dump do processo w3wp.exe correspondente ao webservice utilizado pela aplicação web, pois o cliente garantiu que as páginas do site apenas realizavam chamadas para esse webservice.
O primeiro passo é carregar a extensão de depuração de código gerenciado Psscor2 que é utilizada para ajudar no diagnóstico de problemas em aplicações do Framework .Net, para as versões 2.0, 3.0 e 3.5 através do commando .load psscor2.
A extensão Psscor2 contém um comando muito útil chamado !aspxpages que mostra informações sobre várias requisições ASP.NET, o tempo de execução e as threads associadas com o System.Web.HttpContext que estavam sendo executadas no momento em que o dump foi coletado.
A figura a seguir exibe o resultado da execução do comando !aspxpages. Através do resultado podemos observar que o tempo médio de execução das requisições, no momento em que o dump foi tirado, era de aproximadamente 5 minutos. É possível observar também que essa tempo ultrapassa, na maioria dos casos, o tempo
estipulado de timeout.
Vamos analisar a thread 41, referente ao web service consultas.asmx, cujo tempo de execução no momento do dump era de 472 segundos (7 minutos).
O comando !clrstack permite verificar a pilha de chamadas da thread para verificar o que está sendo executado.
Através desse comando é possível verificar que a thread está executando o método ExecuteReader para popular um objeto SqlDataReader. Para obter maiores detalhes do que está sendo executado nós podemos executar o commando !dso (!dumpstackobjects) na thread 41 e analisar as informações do objeto SqlDataReader.
Agora que temos o endereço do objeto SqlDataReader (070dac1c) nós podemos obter maiores detalhes deste objeto através do comando !do (!dumpobject).
Observe na figura que o timeout (_timeoutSeconds) dessa conexão é de 600 segundos. O comando SQL que está sendo executado pode ser obtido executando o dump do objeto para o endereço 070daa34 correspondente ao objeto SqlCommand (_command).
Finalmente para obtermos maiores detalhes deste objeto é necessário executar o comando !do (!dumpobject) para o endereço 070da99c correspondente ao comando SQL.
Por se tratar de informação de cliente, não pude mostrar o nome da comando SQL, mas é possível verificar que se trata de uma procedure. Para esse caso, a procedure era a responsável pela lentidão do serviço.