Passo a passo para encontrar as querys mais demoradas do Banco de Dados – Parte 1
Fala Pessoal,
Quem não quer saber quais são as querys mais demoradas do seu ambiente de Banco de Dados? Em quais horários essas querys rodam? Quem está executando? De onde está sendo rodada? Quais os recursos que essas querys consomem?
Nesse artigo, demonstrarei como eu faço esse acompanhamento no meu ambiente de trabalho. Ele é válido para as versões 2005 e 2008 do SQL Server. Para a versão do SQL Server 2000, algumas colunas do trace devem ser alteradas pois não existem no SQL 2000.
Primeiramente, deve ser criada uma tabela para armazenar o log das querys mais demoradas que rodam no nosso banco de dados. Deve-se escolher a database adequada do seu ambiente para armazenar essa tabela. Também criei um índice nessa tabela para efetuar as buscas pela data em que a query rodou.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 |
CREATE TABLE dbo.Traces ( [TextData] VARCHAR(MAX) NULL, [NTUserName] VARCHAR(128) NULL, [HostName] VARCHAR(128) NULL, [ApplicationName] VARCHAR(128) NULL, [LoginName] VARCHAR(128) NULL, [SPID] INT NULL, [Duration] NUMERIC(15, 2) NULL, [StartTime] DATETIME NULL, [EndTime] DATETIME NULL, [Reads] INT, [Writes] INT, [CPU] INT, [ServerName] VARCHAR(128) NULL, [DataBaseName] VARCHAR(128), [RowCounts] INT, [SessionLoginName] VARCHAR(128) ) -- Para realizar as querys de busca pela data que a query rodou. CREATE CLUSTERED INDEX [SK01_Traces] ON [Traces]([StartTime]) WITH(FILLFACTOR = 95) |
Em seguida, criaremos uma procedure para criar o arquivo de trace que ficará rodando em backgroud no servidor.
Nessa procedure é criado um trace com a procedure sp_trace_create, onde especificamos o caminho que esse trace será armazenado. No meu caso criei uma pasta chamada Trace no C: do meu servidor. Você deve criar esse diretório antes de rodar o procedimento. Caso queria armazenar em um caminho diferente basta mudar o caminho na procedure.
Com a procedure sp_trace_setevent, nós definimos quais os eventos que nosso trace pegará. Neste caso, armazenaremos os eventos:
| Event Number | Event Name | Description |
| 10 | RPC:Completed | Occurs when a remote procedure call (RPC) has completed. |
| 12 | SQL:BatchCompleted | Occurs when a Transact-SQL batch has completed. |
Após selecionarmos os eventos, devemos escolher as colunas que desejamos visualizar. As colunas que utilizo no meu ambiente são as seguintes:
| Column Number | Column Name | Description |
| 1 | TextData | Text value dependent on the event class that is captured in the trace. |
| 6 | NTUserName | Microsoft Windows user name. |
| 8 | HostName | Name of the client computer that originated the request. |
| 10 | ApplicationName | Name of the client application that created the connection to an instance of SQL Server. This column is populated with the values passed by the application rather than the displayed name of the program. |
| 11 | LoginName | SQL Server login name of the client. |
| 12 | SPID | Server Process ID assigned by SQL Server to the process associated with the client. |
| 13 | Duration | Amount of elapsed time (in milliseconds) taken by the event. This data column is not populated by the Hash Warning event. |
| 14 | StartTime | Time at which the event started, when available. |
| 15 | EndTime | Time at which the event ended. This column is not populated for starting event classes, such as SQL:BatchStarting or SP:Starting. It is also not populated by the Hash Warning event. |
| 16 | Reads | Number of logical disk reads performed by the server on behalf of the event. This column is not populated by the Lock:Released event. |
| 17 | Writes | Number of physical disk writes performed by the server on behalf of the event. |
| 18 | CPU | Amount of CPU time (in milliseconds) used by the event. |
| 26 | ServerName | Name of the instance of SQL Server (either servername or servername\instancename) being traced. |
| 35 | DatabaseName | Name of the database specified in the USE database statement. |
| 40 | DBUserName | SQL Server database username of the client. |
| 48 | RowCounts | Number of rows in the batch. |
| 64 | SessionLoginName | The login name of the user who originated the session. For example, if you connect to SQL Server using Login1 and execute a statement as Login2, SessionLoginName displays Login1, while LoginName displays Login2. This data column displays both SQL Server and Windows logins. |
A lista completa com todos os eventos pode ser encontrada no books online pesquisando pela procedure sp_trace_setevent.
Em seguida é realizado o filtro na coluna 13(Duration) para retornar apenas os valores maiores ou iguais a 3 segundos. Segue abaixo o script dessa procedure.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 |
CREATE PROCEDURE [dbo].[stpCreate_Trace] AS BEGIN DECLARE @rc INT, @TraceID INT, @maxfilesize BIGINT, @on BIT, @intfilter INT, @bigintfilter BIGINT SELECT @on = 1, @maxfilesize = 50 -- Criação do trace EXEC @rc = [dbo].[sp_trace_create] @TraceID OUTPUT, 0, N'C:\Trace\Querys_Demoradas', @maxfilesize, NULL IF (@rc != 0) GOTO error EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 1, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 6, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 8, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 10, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 11, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 12, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 13, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 14, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 15, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 16, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 17, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 18, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 26, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 35, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 40, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 48, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 10, 64, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 1, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 6, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 8, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 10, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 11, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 12, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 13, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 14, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 15, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 16, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 17, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 18, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 26, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 35, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 40, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 48, @on EXEC [dbo].[sp_trace_setevent] @TraceID, 12, 64, @on SET @bigintfilter = 3000000 -- 3 segundos EXEC [dbo].[sp_trace_setfilter] @TraceID, 13, 0, 4, @bigintfilter -- Set the trace status to start EXEC [dbo].[sp_trace_setstatus] @TraceID, 1 GOTO finish error: SELECT ErrorCode = @rc finish: END |
No meu principal servidor de produção, utilizo 3 segundos para realizar o filtro, mas isso depende da realidade de cada ambiente. Por exemplo, antigamente eram logadas as querys que demoravam mais de 10 segundos no meu ambiente, depois da migração para o SQL Server 2005 e da aquisição de um storage baixamos para 5 segundos. Há pouco tempo, depois de melhorar as querys mais demoradas e as que mais consumiam recursos, após a alteração, criação e exclusão de muitos indices (tudo isso com a ajuda das salvadoras dmvs presentes a partir do SQL Server 2005), como só estavam sendo retornadas 30 querys por hora em média, baixei o trace para 3 segundos para melhor identificar possíveis gargalos. O tuning continua, para que eu tenha cada vez menos registros demorando mais de 3 segundos.
Agora vamos rodar nossa procedure para criar o trace.
|
1 |
EXEC [dbo].[stpCreate_Trace] |
Para conferir o trace criado, basta executar a query abaixo.
|
1 2 3 |
SELECT * FROM :: fn_trace_getinfo(default) WHERE CAST([value] AS VARCHAR(50)) = 'C:\Trace\Querys_Demoradas.trc' |
Depois de criado, vamos rodar algumas querys para testar o nosso trace.
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 |
WAITFOR DELAY '00:00:04' GO CREATE PROCEDURE [dbo].[stpTeste_Trace1] AS BEGIN WAITFOR DELAY '00:00:04' END GO EXEC [dbo].[stpTeste_Trace1] -- Conferindo todos os dados que foram armazenados no trace. SELECT [Textdata], [NTUserName], [HostName], [ApplicationName], [LoginName], [SPID], CAST([Duration] / 1000/ 1000.00 AS NUMERIC(15, 2)) [Duration], [Starttime], [EndTime], [Reads],[writes], [CPU], [Servername], [DatabaseName], [rowcounts], [SessionLoginName] FROM :: fn_trace_gettable('C:\Trace\Querys_Demoradas.trc', default) WHERE [Duration] IS NOT NULL ORDER BY [Starttime] |
Segue abaixo o resultado da query com os dados armazenados no trace.
A coluna TextData retorna exatamente a query que você rodou e demorou mais de 3 segundos. Esse tempo pode ser conferido na coluna Duration, Starttime e Endtime. Outras 3 colunas que me ajudam muito são as colunas Reads, Writes e CPU que mostram os recursos que uma determinada query está consumindo.
Este artigo continua em Passo a passo para encontrar as querys mais demoradas do Banco de Dados – Parte 2.
Gostou dessa dica?
Cadastre seu e-mail para receber novos Posts e curta minha Página no Facebook para receber Dicas de Leituras e Eventos sobre SQL Server.
Aprenda a criar essa e outras rotinas para administrar melhor seu SQL Server no meu Treinamento de Tarefas do Dia a Dia de um DBA.
Abraços,
Fabrício Lima
MCITP – Database Administrator
Consultor e Instrutor SQL Server
Trabalha com SQL Server desde 2006
Olá Fabrício, tudo bem?Uma dúvida. Qual a vantagem de utilizarmos esse método de análise ao invés do SQL Server Profiler?Abraços,Leandro Daniel
Fala Leandro.Na verdade, esse método faz exatamente o que o profile faz, entretanto ele fica rodando em backgroud no seu servidor 24 horas por dia.Você não precisa abrir o profile toda vez para colher os resultados, é tudo automatizado.
Olá Fabrício!Mas o SQL Server Profiler também roda em background, e você pode customizá-lo com os filtros que desejar, além de poder guardar tudo no banco.Pelo que entendi, é uma opção ao Profiler, mas que não deve ser utilizado indiscriminadamente, pois o monitoramento tem um custo para o banco de dados, certo? Se isso for verdade, não vi vantagem em fazer dessa forma, pois estaríamos reinventando o Profiler.Abraços,Leandro Daniel
Fala Leandro. Não estou reinventando o profile. Estou usando o profile.Vamos lá, o que eu fiz foi apenas abrir o profile, colocar os filtros que eu queria (no meu caso só o de duração) com as colunas que eu queria e salvar a criação do profile em um arquivo, que chamei de stpCreate_Trace.Eu utilizo esse profile no meu ambiente de produção 24 horas por dia, o custo do mesmo não causa problema algum no meu ambiente e o benefício é que ajuda a resolver muitos outros problemas de performance(de consumo de recursos desnecessários).Com a sp abaixo você também consegue colocar o filtro que quiser (utilizo ela dentro da criação do trace).exec sp_trace_setfilter @TraceID, 13, 0, 4, @bigintfilterLogo se quiser inserir outros filtros no código da minha SP, é bem simples.Se você já usa o profile e já obtem essas informações, OK! Não estou dizendo no artigo para deixar de usar o profile e usar minha rotina. Apenas mostrei como criar esse trace via linha de código(sem sequer abrir a ferramenta gráfica do profile) e automatizar sua importação para o banco de dados, como faço no meu ambiente. Abraços
Olá Fabrício,Acredito que o seu equívoco foi em especificar erroneamente a utilidade de uso de procedures em detrimento do SQL Server Profiler. O único ganho que vejo é o de poder realizar customizações específicas para a necessidade de um sistema, que não seria coberta (de uma maneira simples) pelo SQL Server Profiler. Isso não ficou claro, tanto no texto quanto nos comentários. Essa seria a minha última contribuição ao post, encerrando por aqui a minha participação.Abraços,Leandro Daniel
Fala Leandro,Não concordo, mas respeito sua opinião. Obrigado pelo feedback.Esse trace é muito útil para mim no meu dia a dia de trabalho. Espero que possa ajudar a outros.Abraços
Fabricio,Legal o artigo. Gostei bastante, principalmente por seu esforço em demonstrar uma alternativa ao SQL Profiler. Não podemos simplesmente nos prender em uma determinada solução, precisamos testar todas as alternativas existentes.Foi bom que voce deixou claro que em seu ambiente de produção esses processos não estão pesando em nada; mas que em outros ambientes talvez mais criticos e/ou pesados podem causar algum tipo de problema.Abraços,Alexandre Lopes
Valeu Alexandre.
Fabricio, gostaria de saber se usa esse método eu podeira Criar um Job para executar o TRACE em um determinado horário, uma vez que queria analiza uma PROCEDURE??
Eu Patricia,
Não sei se entendi direito, mas você pode sim agendar um horário para criar o trace.
Entretanto, se você deixar ele habilitado, também conseguiria pegar uma procedure nele.
Fabricio, O que acontece é que tenho que otimizar um Processo. Preciso analizar uma PROCEDURE que é GIGANTESCA e nessa PROCEDURE tem várias outras PROCEDURE que uma chama a outra e assim vai…
Sendo que achei melhor rodar um trace e executar a PROCEDURE GIGANTESCA no mesmo momento .Para verificar os gargalos, depois do trace rodado fária um TUNING. Sendo que estou conseguindo gerar um arquivo *.trc. Mas ele se apagar a cada momento e ele renova queria que gerasse um arquivo *.trc. E diante do arquivo gerado eu pudesse fazer o TUNING.
OBS.: Isso é so porque não posso fazer na hora do expediente e os DBAS não querem fazer uma VPN e fazer do modo gráfico. Pensei no seu procedimento que achei bom, e ja fiz em outra empresa. Uma vez que não sou DBA da empresa.
Desde já obrigada pela atenção
Esse DBA é o cara ! Só tem vc msm Fabrício.
Grande Fabricio, perfeito meu amigo. Só adicionado as perguntas do Leandro, quando voce abre um profiler mesmo estando no servidor você está usando traces Client-Side e não Server-Side como o Fabricio está muito bem apresentando aqui.
Em ambientes com alta carga transacional, você pode derrubar o servidor caso abra um profiler pela IDE. Tudo existe um custo e diminuir este custo em ambientes pesados é o que tentamos. Mesmo voce filtrando, trirando eventos, diminuindo tempo do trace no Client-Side, o Server-Side tem um plus. Eu vejo o maior ganho em não ter o peso da IDE e consumo de banda de rede.
Eu li em um case do Linchi Shea, que o Server-Side teve ganho de 35% de consumo de banda em relação ao Client-Side (profiler pela IDE) e em alguns casos chegou até 70%.
Claro ta rodando no servidor 🙂
Eu sempre aconselho a não usar o Cliente-Side, salvo que você tenha completo domínio do ambiente.
Parabens meu amigo..ótimo artigo
Show de bola Laerte.
Obrigado por agregar essas informações ao Post. Eu sabia que era bem mais leve, mas não sabia desses percentuais de diferença.
Veleu!!
Fabrício, estou obtendo uma certa dificuldade a qual erro pode ser ao executar a procedure, onde é apresentado o seguinte erro:
Procedure: sp_trace_create, Msg 19062, Level 16, State 1:
Could not create a trace file.
Cara muito legal essa matéria, parabéns !
Obrigado Thiago.
Abraços.
@Everton
Opa, blz?
da uma olhada pra ver se o diretório que você esta apontado no trace existe no seu servidor SQL, você pode utilizar uma pasta compartilhada na sua rede também.. Valeu espero ajudar !
Sobre as vantagens de se usar este método, é que na versão EXPRESS não tem PROFILER. Ou seja, uso o express para desenvolvimento e não tinha (até agora) como fazer um trace para consultas mais lentas. Ótimo post.
Uma dúvida, não entendi o objetivo da tabela criada no inicio do post (Traces) , visto que as consultas aos traces se faz diretamente no arquivo de trace.
ops, a tabela Trace é usada na continuação do post. Abraço a todos.
Obrigado pelo feedback Wilker.
Abraços
Fabricio,
implementei os procedimentos 1 e 2 do artigo pra encontrar as querys mais demoradas no meu ambiente de produção. Coloquei pra executar o job a cada 1 hora iniciando as 08:00 da manhã (iínicio do expediente) e se encerrando as 18:00 (final do expediente), pois definir apenas pra o horário administrativo. Observei hoje pela manhã que às 08:00 a execução do job ocorreu com sucesso, mas as execuções posteriores deram faild no momento que solicitar parar a trace pra guardar os arquivos de log. Deu a seguinte mensagem: Executed as user: NT AUTHORITY\SYSTEM. Procedure expects parameter ‘@traceid’ of type ‘int’. [SQLSTATE 42000] (Error 214). The step failed.
Como resolver isso???
Parabéns Fabricio, seus artigos ajudam em muito, e quanto ao Leandro, só lamento….
Obrigado Beto.
Olá Fabrício, primeiramente parabéns pelo artigo, muito útil!
Uma dúvida, é possível pular a etapa de gravar o trace em um arquivo e depois importar o resultado em um job para uma tabela, existe a possibilidade de já gravar o trace direto em uma tabela ao invés do arquivo N’C:\Trace\Querys_Demoradas’ ?
Obrigado e abraço!
fabricio, como calculo esse tempo da procedure, por exemplo voce colocou 3000000 segundos, se eu quiser colocar 10 minutos como calculo?
Bom Dia renata,
3000000 = 3 segundos
600000000 = 600 segundos = 10 minutos
Fabricio,
Sabe me dizer o que pode ser, quando tento apagar o arquivo gerado para gerar o novo, da erro de que o arquivo esta em uso pelo SQL?
Bom Dia…
Não entendi a pergunta.. Bases em uso não podem ter os arquivos excluídos.
Bom dia Fabrício,
Excelente matéria. Eu tenho que criar a tabela e procedure em todas as bases que eu desejo monitorar, certo? Obrigado.
Oi Fabricio muito bom o post!! Sou nova no sql e estou ralando aqui…usamos o rm e o modo de autenticação do SQL é SQL Sever and windows authentication mode e temos relatórios gerados pelo report service em um servidor acessado por vários usuários com autenticação do domínio da rede. Ao listar as querys lentas não tem nenhum campo que me mostra o nome da estação que está rodando a consulta…para todos os usuários rodando um relatório ele mostra o nome da máquina do servidor de relatórios…Os logins do rm são do usuário rm…tem alguma forma de mostrar o usuário ou maquina do domínio da rede que está executando o relatório? obs: em NTUserName está apresentando: NULL…
Fabricio, irei começar a fazer seus cursos. (maratona de sql) kkk. existe algum canal que eu possa falar com vc ou alguem de sua equipe, para tirar algumas dúvidas?.. meu nome é Sidney Mendes
te mandei um email.