Leitura Obrigatória: SQL Magazine 7, artigo Indexed Views; SQL Magazine 9, artigo Estatísticas de Distribuição; SQL Magazine 11, artigo Profiler Parte I.

Como vimos na primeira parte dessa matéria na edição anterior, o Profiler é uma ferramenta de apoio ao gerenciamento e tuning de servidores SQL Server 2000. Iniciar uma trace é uma tarefa simples: basta executar o Profiler, conectar-se a um servidor, clicar em RUN e pronto! Mas, e agora? Os eventos selecionados servem para identificar a causa do problema de má performance em meu servidor?

O objetivo dessa matéria será criar um guia, passo-a-passo, de como deve ser conduzido um processo para diagnóstico de performance utilizando o Profiler como ferramenta de apoio.

Análise preliminar: identificando stored procedures e batchs com baixa performance

Demora excessiva para conclusão de consultas, deadlocks em demasia e problemas com timeout nas aplicações - esse é o quadro de um servidor com sérios problemas de performance. Nosso objetivo inicial será efetuar um levantamento para determinar quais são os processos mais demorados, cronometrando a execução de batchs e stored procedures (sp´s) nesse servidor.

A denominação “batch” é utilizada para especificar um grupo de um ou mais comandos T-SQL enviados de uma só vez para o servidor SQL Server.

Iniciaremos o Profiler no menu do Microsoft SQL Server, escolhendo New Trace na opção File da barra de ferramentas. Na tela de propriedades da trace, confirme a seleção do template SQLProfilerStandard na guia General. Esse template captura a execução de batchs (TSQL\SQL: Batch Completed) e sp´s (Stored Procedures\ RPC: Completed). Os eventos Security Audit e Sessions não são necessários para essa análise, podendo ser removidos (selecione o evento e clique em <<Remove). A Figura 1 apresenta a relação final de eventos que devem estar selecionados.

Imagem
Figura 1. Eventos que devem ser selecionados para monitorar execução de batchs e sp´s.

As colunas e ordem de apresentação dos eventos do template SQLProfilerStandard sofrerão duas alterações: na guia Data Columns ordenaremos as linhas capturadas segundo seu tempo de execução e eliminaremos algumas colunas desnecessárias nesse momento. Para ordenar as linhas do Profiler segundo a duração do comando executado, selecione Duration e clique em Up até que essa coluna fique logo abaixo de Groups. As colunas removidas foram: NTUserName, LoginName, CPU, Reads, Writes e ClientProcessId. O resultado final pode ser visualizado na Figura 2.

Imagem
Figura 2. Colunas selecionadas para visualização no Profiler.

Até esse momento, a trace irá capturar todos os batchs e sp´s executados nesse servidor. Seria interessante ligar um filtro de tempo de modo que só fossem captutados os processos com tempo de execução acima de um determinado limite. Para conseguir esse efeito, vamos ligar o filtro Duration na guia Filters, trabalhando com um limite de 2000 milisegundos (ver Figura 3).

Imagem
Figura 3. Filtrando comandos T-SQL cujo tempo de execução for superior a 2000 milisegundos (=2 segundos).

Agora inicie a trace clicando em . Para simular uma atividade no SGBD, abra uma sessão no Query Analyzer, digite as linhas da Listagem 1 e confirme o resultado na tela do Profiler (ver Figura 4).

Listagem 1

            use NorthWind

            go
            
            create proc stp_teste

            as

            select top 1 * from orders

            select top 1 * from [order details]

            waitfor delay '00:00:03'

            select top 1 * from customers

            go

            exec stp_teste

            go

            select count(*) from [order details] 

            go

            select top 10 * from orders

            go
        
Impressão de cheques pelo sistema
Figura 4. Executando trace com o filtro Duration ativo.

Analisando a trace, verificamos que:

  • A única linha capturada foi a da execução de stp_Teste, pois o filtro com Duration=2000 está ativo, inibindo a visualização dos dois últimos select´s ;
  • A execução da sp aparece sob o evento TSQL\SQL:BatchCompleted e não em Stored Procedures\RPC: Completed por dois motivos:
  • O Profiler considera quaisquer sequência de comandos executados no Query Analyzer como um batch;
  • O evento RPC:Completed irá aparecer somente quando a sp for executada numa aplicação que faça uso do mecanismo de RPC (Remote Procedure Call), e não pelo comando T-SQL execute.

Após deixar a trace ativa por um período, teremos capturado os processos com maior tempo de execução. O próximo passo será analisar os comandos T-SQL presentes nas sp´s e/ou batchs responsáveis pelos gargalos.

Análise específica: identificando comandos T-SQL com baixa performance

A trace gerada anteriormente forneceu a relação de batchs e sp´s que estão apresentando tempo de execução superior a 2 segundos. No caso da stored procedure stp_Teste, temos que identificar qual comando T-SQL está sendo responsável pela lentidão. Para conseguir esse efeito, criaremos uma trace para analisar somente a sp stp_Teste. Isto permitirá que visualizemos os tempos dos comandos T-SQL à medida em que são executados.

O ponto de partida é identificar o id do objeto que queremos selecionar. No Query Analyzer, digite:


            select object_id (‘stp_Teste’)

            ----------------------------------------------------------------------------------------------------

            743673697

            (1 row(s) affected)
        

Crie agora uma nova trace no Profiler, selecionando os eventos presentes na Figura 5. SP:Completed irá gerar uma linha contendo a chamada para a procedure e SP:StmtCompleted irá gerar uma linha para cada comando T-SQL executado dentro da sp.

Imagem
Figura 5. Eventos que devem ser selecionados para visualizar a execução dos comandos T-SQL dentro das sp´s.

Na guia Data Columns, selecione os mesmos eventos assinalados na Figura 6.

Imagem
Figura 6. Selecionando colunas para analisar execução de sp.

Na guia Filters, siga até ObjectId e informe o id da procedure stp_Teste obtida anteriormete (Figura 7).

Imagem
Figura 7. Ligando o filtro ObjectId para filtrar os comandos T-SQL executados na procedure stp_Teste

Clique em , execute a procedure stp_Teste no Query Analyzer e em seguida pare a trace. O resultado encontra-se na Figura 8.

Imagem
Figura 8. Visualização dos comandos executados na procedure stp_Teste.

Analisando a trace na Figura 8, nota-se que o comando ... waitfor delay ’00:00:03’ é o responsável pela lentidão na procedure stp_Teste. Perceba que a duração dele equivale a 3 segundos enquanto a duração dos outros é nula. A idéia agora é colar esses comandos individuais no Query Analyzer (1) e digitar + para avaliar o plano de execução gráfico. O comando ... waitfor delay ’00:00:03’ não necessita de maiores análises, pois denuncia explicitamente o gargalo. Na vida real, provavelmente seríamos apresentados a processos que denunciariam varreduras seqüenciais (=Table Scan ou Index Scan) em tabelas com milhares de linhas.

(1) Clique sobre a linha cujo comando deseja colar e, na parte inferior da tela do Profiler, execute + para capturar o comando, seguido de um + na tela do Query Analyzer.

Esse procedimento de análise deverá se repetir para todas as sp´s capturadas na trace inicial. Os batchs não necessitam da filtragem adicional por ObjectId; basta recortar o comando na trace e avaliar seu plano de execução no Query Analyzer.

Análise de outros objetos relacionados à performance

Como o leitor já deve ter percebido, o Profiler deixa à nossa disposição uma infinidade de combinações entre eventos, colunas e filtros. Os eventos que devemos selecionar na trace dependem do que exatamente estamos querendo analisar; os filtros informados também devem estar de acordo com a informação obtida em cada evento.

Um erro bastante comum ao criarmos traces advém do fato de ligarmos filtros em eventos que não tratam essa informação. Por exemplo, a filtragem da coluna DBUserName para o evento Locks/Lock:DeadLock não produziria o resultado esperado pois Locks/Lock:DeadLock não trabalha essa informação (ver Figura 9). Para saber as colunas retornadas por cada evento, procure o Event Classes no BOL.

Imagem
Figura 9. Colunas atualizadas para cada evento na classe Locks.

A seguir será apresentado um resumo dos principais eventos que devem ser analisados para solucionar problemas relacionados à performance.

Identificando cursores criados no servidor

Cursores oneram performance pois não conseguem desfrutar da grande vantagem dos SGBDs: trabalhar o dado orientado a bloco. A linguagem SQL foi criada com comandos que efetuam manipulações em lote: podemos selecionar, inserir e deletar vários registros com um único comando. Quando utilizamos cursores, estamos fazendo uma inversão nessa regra: selecionamos uma série de linhas para serem trabalhadas individualmente.

Existem situações onde a utilização de cursores se torna inevitável, quer pela complexidade do negócio ou mesmo quando a aplicação precisa apresentar um RecordSet para navegação na tela do cliente. Em ambos os casos, entretanto, existem algumas regras de boa conduta na utilização de cursores que devem ser observadas:

  • Procure transformar atualizações realizadas com cursores em processos que utilizem somente os comandos select, insert, update e delete. Trabalhar com cursores é uma opção tentadora que deve ser evitada. Vale a pena gastar alguns minutos a mais numa solução que utilize alguns select´s, crie uma tabela temporária e depois faça uma atualização.
  • Utilize somente cursores do lado cliente nas aplicações. Manter cursores ativos no servidor é uma prática que deve ser evitada: cursores devem ser mantidos na aplicação cliente para não sobrecarregar a memória do servidor. Existem dois eventos que controlam a abertura e fechamento de cursores no servidor: Cursors:Cursor Open e Cursors:Cursors Close. Se você se deparar com esses eventos, peça para o desenvolvedor mudar a localização do cursor para o cliente.

Na trace da Figura 10 podemos visualizar um cursor de servidor.

Imagem
Figura 10. Trace capturando um cursor de servidor.

Com uma pequena alteração em CursorLocation no código escrito em Visual Basic (ver Listagem 2)...

Listagem 2

            Dim con As New ADODB.Connection

                con.Open "Provider=SQLOLEDB.1;Integrated Security=SSPI;Persist Security Info=False;Initial Catalog=northwind;Data Source=srvteste"
 
                Dim rs As New ADODB.Recordset

                rs.CursorLocation = adUseServer … substituir por ... adUseClient

                rs.Open "select * from northwind.dbo.employees", con, adOpenStatic, adLockOptimistic

            End Sub
        

... obtemos o resultado apresentado na Figura 11. Perceba que os eventos CursorOpen e CursorClose não existem mais!

Imagem
Figura 11

Rastreando processos envolvidos em Deadlocks

Deadlock é uma causa freqüente de má performance, pois requer que a conexão escolhida como vítima - e cuja execução de comandos foi abortada - envie novamente o comando para execução. O Profiler possui dois eventos que nos ajudam a rastrear deadlocks: Lock:DeadLock informa a ocorrência do erro #1205 associado ao deadlock e Lock:DeadLockChain irá apontar o spid das conexões envolvidas no deadlock. A Figura 12 ilustra a ocorrência de um deadlock: note que as conexões envolvidas são as 62 e 66 (=Lock:DeadLock Chain); os comandos responsáveis pelo conflito de recursos que originou o deadlock são os dois últimos updates. A ação corretiva nesse caso seria eliminar a cláusula holdlock existente nos dois select´s iniciais da trace.

Imagem
Figura 12

Evitando CacheMiss

Quando acionamos uma sp, seu plano de execução fica em memória. Nesse plano são armazenadas instruções de como a query deverá ser executada: que índices utilizar, o tipo de join selecionado, etc. Antes de criar um plano de execução novo, o otimizador faz uma busca na área de cache destinada a procedures procurando por um plano pré-existente. Se a busca for bem sucedida, o plano será aproveitado e a sp será executada de acordo com ele.

Existem algumas situações onde o otimizador é obrigado a fazer várias tentativas até encontrar o código pré-compilado. Cada uma dessas tentativas mal sucedidas dispara um evento conhecido por SP:CacheMiss, que pode ser evitado seguindo-se as dicas abaixo:

  • Não utilize o prefixo “sp_” para nomear suas sp´s. Quando o otimizador encontra uma stored-procedure com o prefixo sp, sua execução é desencadeada no banco de dados master. Como a sp não existe nesse banco de dados, seu plano de execução não é encontrado na primeira tentativa, disparando um evento SP:CacheMiss. O processo de execução prossegue procurando a sp no banco de dados local, onde o código compilado é encontrado e a sp executada.
  • Execute stored-procedures qualificando seu dono (owner). Lembre-se que você pode possuir objetos com o mesmo nome mas com owners diferentes. Portanto se você possui usuários que não possuem privilégio de dbo – e isso deve ser a regra –, especifique o owner da sp no momento da chamada. Troque exec stp_Teste por exec dbo.stp_Teste.

Agora um teste: abra o Profiler, mantendo o template padrão SQLServerProfilerStandard. Na guia Events, adicione o evento StoredProcedures/SP:CacheMiss. Crie uma nova sp de nome sp_Teste com o mesmo código de stp_Teste criada no início desse artigo; abra uma sessão no Query Analyzer com um usuário que não possua privilégios de db_owner(1) no banco – por exemplo UserSQLMag (ver Nota) – e execute o batch de comandos da Listagem 4. Confira o resultado na tela do Profiler na Figura 13.

Listagem 4

            set nocount ON

            select system_user

            go

            select user_name() --não pode retornar dbo !!!

            go

            exec dbo.stp_Teste

            go

            exec stp_Teste

            go

            exec sp_teste

            go
        

Usuários pertencentes ao role db_owner possuem permissão para executar qualquer tipo de operação em um banco de dados. Para verificar quais papéis estão atrelados a um usuário, execute o cmd sp_HelpUser . O usuário UserSQLMag – que possui apenas permissão de leitura e escrita no database NorthWind - foi criado com a seqüência de comandos T-SQL abaixo:


            use master

            go

            exec sp_addlogin  'UserSQLMag','UserSQLMag'

            use NorthWind

            go

            exec sp_grantdbaccess 'UserSQLMag'

            exec sp_addrolemember 'db_datareader', 'UserSQLMag'

            exec sp_addrolemember 'db_datawriter', 'UserSQLMag'
        
Imagem
Figura 13. Constatando a ocorrência do evento CacheMiss na execução de sp´s.

A Tabela 1 faz um breve comentário sobre as três modalidades de execução de stored procedures.

Tabela 1
Comando executado CacheMiss? Motivo
Exec dbo.stp_Teste Não A sp foi executada qualificando-se o owner dbo.
exec stp_Teste Sim Como o usuário não pertence ao grupo dbo, a sp é executada sem sucesso em exec UserSQLMag.stp_Teste, gerando um CacheMiss. Na segunda tentativa – com usuário dbo – ocorre o acerto (= exec dbo.stp_Teste)
exec sp_Teste Sim A sp foi procurada sem sucesso no banco de dados master para dbo (primeiro CacheMiss) e depois no banco NorthWind para UserSQLMag (segundo CacheMiss). Na última execução - no banco NorthWind para dbo - ocorre o acerto.

Evitando recompilações

Denomina-se compilação o processo utilizado pelo otimizador para gerar o plano de execução de uma sp. A compilação ocorre:

  • Quando a sp é executada pela primeira vez;
  • Quando o servidor SQL Server 2000 é reinicializado (stop/start no serviço);
  • Se utilizarmos a cláusula with recompile na criação da sp;
  • Quando intercalamos comandos de criação de objetos (=Data Definition Language ou DDL) com comandos de manipulação (=Data Manipulation Language ou DML). Como sabemos, um plano de execução é gerado ANTES de uma seqüência de comandos ser executada (no caso de uma procedure, o plano de execução é gerado antes da procedure ser disparada). Nesse plano, são determinados os meios de acesso às tabelas, baseados nos índices EXISTENTES. Ora, se no código de uma stored procedure ou batch criamos um índice na linha 10 e efetuamos um select nessa mesma tabela na linha 11, o índice criado não será considerado no processo de otimização, pois ele passará a existir somente quando a procedure for executada (o plano é gerado antes da execução da procedure). Pois bem, numa situação dessas o otimizador força uma compilação adicional da query APÓS a criação do indice, de modo que o select contido na linha 11 possa se beneficiar do índice recém-criado.
  • Quando alteramos o estado dos comandos ANSI_DEFAULTS, ANSI_NULLS, ANSI_WARNINGS e CONCAT_NULL_YIELDS_NULL, deixando-os em desacordo com a sessão responsável pela criação da sp. Executar uma mesma query com ANSI_NULLS ligado (=ON) e desligado (=OFF) pode acarretar em resultados diferentes (veja SQL Magazine 7). Quando o otimizador se depara com alteração dessas variáveis no decorrer da execução da sp, ele entente que o plano de execução deve ser reavaliado, solicitando uma nova compilação.

A compilação ocupa um tempo precioso quando realizada no momento da execução da sp. A Tabela 2 ilustra algumas sp´s que foram modificadas para inibir compilações.

Imagem
Tabela 2. Alterações no código das sp´s que evitam recompilações

O evento disparado quando acontece uma recompilação é SP:Recompile. A Figura 14 lista as execuções no Profiler antes e depois das alterações sugeridas na Tabela 2.

Imagem
Figura 14. Visualizando recompilações com o evento SP:Recompile.

Quando um índice é criado externamente a uma SP, para melhorar o desempenho de uma query contida na procedure, a geração de um novo plano não acontece de maneira automática – devemos “forçar” a recompilação com o comando sp_recompile.

Confirmando TCP/IP como protocolo de conexão

Utilize Security Audit:Audit Login para confirmar se o TCP/IP é o protocolo padrão das conexões (ver Figura 15). Até a versão 2.6 do MDAC 2 , o protocolo default de conexão era o Named Pipes, que não possui performance tão boa quanto o TCP/IP. Portanto, se você localizar alguma sessão com protocolo Named Pipes, siga até a estação cliente e verifique o SQL Server Client Network Utility.

2 MDAC é o acrônimo de Microsoft Data Access Components; é o componente responsável pela conexão do cliente com o servidor SQL Server.

Imagem
Figura 15. Selecionando o evento Audit Login para confirmar o protocolo TCP/IP como padrão.

Identificando erros

O Profiler possui uma classe chamada Errors and Warnings que possui dois eventos bastante interessantes: o primeiro – Exception – é indicado para capturar mensagens que aparecem nas aplicações cliente tais como violação de FK, violação de PK, divisão por zero, etc. O segundo – Missing Column Statistics – irá sinalizar colunas sem estatísticas de distribuição, que poderiam ser úteis para o otimizador no processamento da consulta que estiver sendo executada (Figura 16).

Imagem
Figura 16. Identificando erros e falta de estatísticas.

Estatísticas desatualizadas acarretam em planos de execução ineficientes, portanto devemos proceder à sua atualização. Apenas recordando o que foi visto na edição 9, o comando para criação de estatísticas para a coluna Freight na tabela Orders é o seguinte:


            CREATE STATISTICS st_Orders_Freight on Orders (Freight) with FullScan
        

Como agendar uma trace

Como você faria para gerar a trace de um processo com problemas de performance que roda somente nas madrugadas de domingo? Gere um script da trace, agende sua utilização no SQL Server 2000 e fim!

Agendamentos de processos no SQL Server 2000 são efetuados através da criação de jobs. Para criar um job no Enterprise Manager, siga o procedimento definido na figura 16B. A criação e manipulação de jobs serão abordados em matéria específica.

Imagem
Figura 16B. Criando um job a partir do Enterprise Manager

Para gerar o script de uma trace siga até a opção File do Profiler, selecione Script Trace ... For SQL Server 2000 (ver Figura 17).

Imagem
Figura 17. Gerando o script dos comandos T-SQL necessários para gerar uma trace.

O código gerado pode ser visualizado na Listagem 5.

Listagem 5. Script gerado pelo Profiler para criação de uma trace.

            /*****************************/

            ''/* Created by: SQL Profiler            */


            /* Date: 28/01/2004  13:45:07         */

            /*****************************/

            -- Create a Queue

            declare @rc int

            declare @TraceID int

            declare @maxfilesize bigint

            declare @DateTime datetime

            set @DateTime = '2004-01-28 14:15:00.000'  horário previsto para término da trace 

            set @maxfilesize = 5  tamanho máximo do arquivo-texto da trace
            
            exec @rc = sp_trace_create @TraceID output, 0, N'c:\temp\Trace_SQLMAG', @maxfilesize, @Datetime


            if (@rc != 0) goto error                                                     

            nome do arquivo-texto que irá armazenar a trace   

            declare @on bit


            set @on = 1

            exec sp_trace_setevent @TraceID, 10, 1, @on

            .

            ...seleção  dos eventos e colunas que aparecem na trace

            ……                                                                              

            exec sp_trace_setevent @TraceID, 17, 18, @on

            declare @intfilter int


            declare @bigintfilter bigint      

            exec sp_trace_setfilter @TraceID, 10, 0, 7, N'SQL Profiler' os filtros que você definiu aparecem aqui

            exec sp_trace_setstatus @TraceID, 1  esse comando irá iniciar a trace

            select TraceID=@TraceID  o id gerado para essa trace é mostrado no final do processo

            goto finish    

            error: 

            select ErrorCode=@rc

            finish: 

            go''
        

A Tabela 3 faz um resumo dos principais comandos utilizados na manipulação de traces.

Impressão de cheques pelo sistema
Tabela 3

Funções internas no SQL Server 2000 que possuem o prefixo “fn_” precisam ser chamadas com a adição de “::” (duas vezes o sinal de pontuação dois pontos) . Um exemplo de execução da função fn_trace_getinfo encontra-se abaixo:


            Select * from ::fn_trace_getinfo(default)
        
TraceId Property Value
1 1 0
1 2 c:\temp\Trace_SQLMag
1 3 5
1 4 2004-01-28 14:15:00.000
1 5 1

O resultado da query pode ser assim interpretado:

TraceId Identificação da trace
Property 1 - Interno;
Property 2 - Nome do arquivo de saída;
Property 3 - Tamanho máximo do arquivo de saída;
Property 4 - Horário para término da execução;
Property 5 - Status atual da trace, a saber:
  • 1 - Trace está ativa;
  • 0 - Trace foi encerrada.

Conclusão

O Profiler é uma ferramenta pouco explorada nos livros sobre SQL Server 2000, mas sua utilização é indispensável no dia-a-dia de um DBA. O objetivo dessa matéria foi introduzir os principais eventos relacionados à performance que podem ser monitorados com a ajuda do Profiler. Agora é com vocês, até a próxima!

Artigo SQL Magazine 12
Clique aqui para ler todos os artigos desta edição