SQL Server - Analizzare un problema di timeout utilizzando Sqlnexus

Artikel
01/04/2009

Una delle richieste più frequenti che riceviamo nel team di supporto di Sql Server è quella di capire la causa determinante timeout applicativi durante l’esecuzione di query.

In questo post spiegherò come utilizzare Sqlnexus per effettuare velocemente l'analisi di un problema relativo alla lentezza di una query e determinante un timeout applicativo.

Problema

Errori di timeout, che si verificano in modalità casuale, durante una complessa attività applicativa.

Dati da raccogliere

Per capire la causa di problemi di timeout è necessario individuare l'attività su cui il timeout si verifica e se tale attività è stata affetta da blocchi o da problemi di performance sul server.

Dal punto di vista di Sql server, l’analisi di un timeout verificatosi durante l’esecuzione di una query, può essere inizialmente affrontata come un generico problema di performance volto ad identificare la causa per cui una determinata query viene eseguita in un tempo superiore a quello impostato dal timeout applicativo.

A tale scopo, durante il riprodursi del problema, si chiede generalmente di raccogliere dati di performance quali trace di Sql server profiler, System monitor counters e trace di Blocker script.

Il tool in grado di raccogliere contemporaneamente tali informazioni è Pssdiag:

Sql server 2000 è disponibile pubblicamente con interfaccia grafica al seguente indirizzo http://support.microsoft.com/kb/830232
Sql server 2005 è possibile utilizzare il tool Sqldiag compreso nell'installazione e non avente interfaccia grafica

Per avere un esempio degli eventi e counters da catturare è possibile far riferimento al seguente articolo HOW TO: Troubleshoot Application Performance with SQL Server.

In questa situazione specifica sono stati raccolti i seguenti eventi:

Database: tutti gli eventi
Errors and warning: tutti gli eventi
Locks: Lock:Deadlock, Lock:Escalation, Lock:Timeout
Objects: Auto Update Stats
Performance: Show Plan Statistics
Security Audit: Login, Login Failed, Logout
Sessions: ExistingConnestion
StoredProcedure: RPC:Completed, RPC:Starting, SP:CacheInsert, SP:CacheRemove, SP:Recompile, SP:StmtCompleted, SP:StmtStarting
Tsql:SQL:BatchCompleted, SQL:BatchStarting, SQL:StmtCompleted, SQL:StmtStarting

Analisi dei dati

In questa sezione vedremo come Sqlnexus possa essere utilizzato per analizzare i dati raccolti tramite le trace di Sql server profiler.

Installazione di Sqlnexus

Scaricare il tool Sqlnexus e verificare le informazioni sul suo utilizzo

Installare RML utilities

Caricamento dati in Sqlnexus

Avviare Sqlnexus.exe e connettersi a un Sql server in ambiente di test per effettuare l’analisi dei dati.
Una volta aperta l’interfaccia di Sqlnexus, cliccando su import, verrà visualizzata la finestra in cui impostare la cartella contenente i file di Sql server profiler raccolti con Pssdiag:

Visualizzazione dei dati di performance

Terminato l'import dei dati , potremo selezionare Readtrace_main, nella sezione Reports, per visualizzare l'analisi:

Selezionando i link presenti nella schermata di Performance Overview, potremo visualizzare i report indicanti le query eseguite durante l’intervallo di tempo di cattura dei dati e il rispettivo consumo di risorse. Tali report costituiscono un aiuto essenziale nell’individuare le query aventi maggiore impatto in termini di tempo di esecuzione , letture , scritture o consumo di CPU.

Individuazione dei timeout

Siccome l’obiettivo di questo blog e quello di analizzare le query su cui è avvenuto un timeout applicativo, dovremo individuare gli eventi di Attention avvenuti durante la cattura dei dati.
Per visualizzare tali eventi, selezioniamo Interesting events e sarà visualizzato un grafico simile a quello sotto riportato:

Come è possibile verificare dalla schermata sopra riportata, supponendo di aver impostato gli eventi necessari in Sql server profiler, potremo visualizzare tramite un grafico facilmente leggibile, altri tipi di eventi quali la crescita dei datafile o i sort warning e associare o meno tali eventi al verificarsi del problema.
Selezionando il link Attention, potremo visualizzare la query su cui è avvenuto il timeout e lo spid che stava eseguendo in quel momento la query.

Selezionando la query, potremo visualizzare tutti i dettagli sul tempo di esecuzione, le letture eseguite, il consumo di CPU e il nome del file di Sql server profiler contenente l’esecuzione della query durante l’avvenuto timeout.

Dalla schermata sopra riportata è evidente che il tempo di esecuzione della query ha superato i 30 sec di timeout impostato dall’applicazione.

Una volta individuata la query su cui si manifesta il problema, lo spid avente in esecuzione la query e l’intervallo di tempo in cui è avvenuto il timeout, potremo aprire la trace di Sql server profiler, filtrare per lo spid indicato da Sqlnexus, cercare la query affetta dal problema e analizzare in dettaglio i vari passi di esecuzione.

Nell’esempio qui riportato, analizzando la trace di Sql server profiler in corrispondenza della query e dell’intervallo di tempo in cui si è verificato il problema è stato possibile verificare che il timeout applicativo era dovuto ad un tempo di esecuzione superiori ai 30 sec e che la maggior parte del tempo di esecuzione, circa 25 sec, era utilizzato nella ricompilazione e inserimento in cache.

Se la trace di Sql server profiler non dovesse bastare ad individuare la causa del problema, sarà necessario effettuare altre verifiche quali l’analisi del Blocker script e dei Performance counters in corrispondenza dell’intervallo di tempo in cui si è verificato il problema oppure la verifica dettagliata del piano di esecuzione della query per effettuare un adeguato tuning.

Anche per analisi più approfondite Sqlnexus potrà aiutare, dandoci velocemente una panoramica delle attività presenti sul server durante il verificarsi del problema.

Raffaella Canobbio
Support Escalation Engineer
Microsoft Enterprise SQL Support

Freigeben über