Quem nunca quis 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?

Neste 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.

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 em que ele 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:

Após selecionarmos os eventos, devemos escolher as colunas que
desejamos visualizar. As colunas que utilizo no meu ambiente são as
seguintes:

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.

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

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.

exec dbo.stpCreate_Trace

Para conferir o trace criado, basta executar a query abaixo.

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.

waitfor delay '00:00:04'
GO
create procedure stpTeste_Trace1
AS
BEGIN
waitfor delay '00:00:04'
END
GO
exec stpTeste_Trace1

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.

Agora que o trace já foi testado e vimos que ele realmente
funciona, criaremos um job para enviar o trace para a
tabela de log e automatizar todo o processo.

Você deve criar um Job no Management Studio com
o nome “DBA – Trace Querys Demoradas” e esse job deve
possuir 3 steps.

Step 1

No primeiro Step
devemos parar o trace momentaneamente para enviar todo o seu resultado
para a tabela de log. Nesse step, você deve selecionar a database
em que você criou a tabela que armazenará o trace e incluir a query
abaixo no step.

Declare @Trace_Id int

Segue abaixo a figura de como fica esse step:

Step 2

Agora que os dados do trace
já foram armazenados na tabela, deve-se excluir o arquivo de trace
para que um novo seja criado. Isso pode ser realizado executando o
comando “del C:\Trace\Querys_Demoradas.trc /Q”
como pode ser visto na figura abaixo:

Step 3

Esse passo deve apenas recriar o trace.
Similar ao step 1, você deve selecionar a database em
que vc criou a procedure e rodar a query abaixo:

exec dbo.stpCreate_Trace

No meu ambiente, esse job roda de hora em hora no meu
principal servidor de produção, mas isso depende da sua necessidade. Eu
também excluo os registros com mais de 60 dias, para que a tabela de log
não fique muito grande, ja que não analiso esses registros mais
antigos.

Agora que nosso procedimento ja está em produção, é possivel atacar
as querys mais demoradas.

No meu ambiente, identifico as procedures que mais
retornam no trace e realizo um agrupamento, como feito abaixo,
para facilitar minha visualização diária. Para um exemplo, vou criar
mais uma procedure de teste e executá-las algumas vezes.

CREATE PROCEDURE stpTeste_Trace2
AS
BEGIN
waitfor delay '00:00:04'
END

Depois de executadas, rodarei o Job para importar o arquivo
de trace para a tabela de log.

EXEC msdb..sp_start_job @job_name = 'DBA - Trace Querys Demoradas'

Com a query abaixo, podemos visualizar os dados armazenados
no trace agrupados por procedure.

declare @Dt_Inicial datetime, @Dt_Final datetime
select @Dt_Inicial = cast(floor(cast(getdate() as float)) as datetime), @Dt_Final = cast(floor(cast(getdate()+1 as float)) as datetime)

Essa query retorna o seguinte resultado:

Onde QTD é a quantidade de vezes que a procedure demorou
mais de 3 segundos, Total é o tempo total dessas execuções, Media
é o tempo médio dessas execuções, Menor e Maior são
os menores e maiores tempos, respectivamente, e Reads, Writes
e CPU é a soma dos recursos que as execuções dessas procedures
gastaram.

Para quem viu o outro artigo que escrevi,  Criando
um CheckList Automático do Banco de Dados, eu recebo essa
informação em minha planilha de CheckList diário com um filtro
para pegar o trace de 08:00am as 18:00pm do dia anterior. Desta
forma, analiso quais são as procedures que mais demoram no meu
ambiente para melhorá-las.

Como já disse anteriormente, tenho esse procedimento implantado
no meu principal servidor de produção e ele não consome muitos recursos
do servidor. Logo vale apena implementá-lo levando em conta que a
informação que você tem é muito valiosa. É possível identificar por
exemplo, a partir de qual horário os procedimentos do seu ambiente
começaram a apresentar uma lentidão ou que tem alguém da sua equipe de
desenvolvimento rodando alguma query pesada no seu servidor de
produção no meio do dia ou ainda que no momento que executam a
procedure A, ela faz com que muitas outras procedures
fiquem lentas. Dentre outros benefícios.

Sugiro fortemente que, se você não possui uma rotina parecida com
essa, tente implementá-la assim que possível.

Abraços.