Categorias
Java Linux Oracle

Descobrindo o SQL gerado pela sua aplicação

Quando trabalhamos com frameworks como Hibernate que geram o comando SQL pra gente, temos uma idéia do que ele faz. Entretanto, quando se usa muitas composições com o o FetchType EAGER, a coisa começa a complicar.

Durante o desenvolvimento, temos ferramentas como o Hibernate Tools que podemos ver o SQL gerado, mas o verdadeiro problema é em ambiente de produção.


Vamos analisar o seguinte método abaixo e seus SQLs gerados:

public List<Evento> listaMeusEventos() {

  Criteria crit = this.session.createCriteria(Evento.class);
  crit.add(Restrictions.gt("data", new GregorianCalendar()));
  crit.addOrder(Order.asc("data"));
  return crit.list();

}

Se você usa Hibernate e log4j, a solução é muito fácil, basta configurar duas opções:

log4j.logger.org.hibernate.SQL=DEBUG
log4j.logger.org.hibernate.type=TRACE

E na configuração do hibernate.cfg.xml adicionar essas opções:

<property name="show_sql">true</property>
<property name="format_sql">true</property>

Você terá no seu log um resultado parecido com esse:

Hibernate:                                                                                                                                                                                                                             

select  this_.id as id5_0_, 
        this_.data as data5_0_,
        this_.lugar_id as lugar6_5_0_,  
        this_.nome as nome5_0_,
        this_.obs as obs5_0_,
        this_.pessoa_id as pessoa7_5_0_,
        this_.tipo as tipo5_0_
from    EVENTOS  this_
where   this_.data
order by
        this_.data asc         
                                                                                                                                                                                                                    
2009-08-06 22:56:13,504 DEBUG hibernate.jdbc.AbstractBatcher  -> preparing statement                                                                                                                                                        
2009-08-06 22:56:13,504 DEBUG hibernate.type.CalendarDateType  -> binding '06 Agosto 2009' to parameter: 1   

Mas se você não usa Hibernate, uma opção bem interessante é o P6Spy.

A idéia é que sua aplicação se conecte com ele, e depois ele se conecta ao seu banco de dados. Com isso, ele tem precisamente todos os SQLs que chegam lá.


[ Sua aplicação manda um SQL ]
=>
[ P6Spy escreve seu SQL em um log ]
=>
[ manda o SQL para o seu banco de Dados ]

A instalação dele é bem simples, ele tem uma biblioteca e um arquivo de propriedades.

O seu uso é bem simples, conforme exemplificado nesse blog:

1 – Baixe o arquivo p6spy-install.jar

2 – Edite o arquivo de propriedades apontando para o seu banco de dados e outras opções, como o caminho do arquivo spy.log

3 – Copie o arquivo de propriedades e a biblioteca para o CLASSPATH de sua aplicação

Se você usar Maven2 nos seus projetos, ao invés de copiar a biblioteca, basta adicionar a dependência:

<dependency>
   <groupId>p6spy</groupId>
   <artifactId>p6spy</artifactId>
   <version>1.3</version>
</dependency>

4 – Faça a sua aplicação apontar para o Spy. No caso do Hibernate, mude o driver JDBC para o driver do Spy:

<property name="connection.driver_class">com.p6spy.engine.spy.P6SpyDriver</property>

A mesma query que o Hibernate exibiu anteriormente é exibida dessa maneira:

1249687673908|-1||resultset|select this_.id as id5_0_, this_.data as data5_0_, this_.lugar_id as lugar6_5_0_, this_.nome as nome5_0_, this_.obs as obs5_0_, this_.pessoa_id as pessoa7_5_0_, this_.tipo as tipo5_0_ from EVENTOS this_ where this_.data>'2009-08-07' order by this_.data asc limit 10|nome5_0_ = Retorno para consulta, obs5_0_ = 16:30h
1249687673910|0|4|rollback||

No caso de você usar o MySQL , existe uma maneira bem mais fácil e prática de monitorar os seus SQLs, basta apenas acessar o arquivo de configuração do MySQL (my.ini em Windows / my.cnf em Linux) e tirar o comentário da linha:

log = /tmp/mysqld.sql

Reinicie o banco de dados e acesse o arquivo mysqld.sql para acompanhar os SQLs gerados.
O mesmo comando anteriormente exibido no log do Spy é exibido aqui dessa maneira:

090807 20:39:20   16839 Query       SET autocommit=0
                  16839 Query       select this_.id as id5_0_, this_.data as data5_0_, this_.lugar_id as lugar6_5_0_, this_.nome as nome5_0_, this_.obs as obs5_0_, this_.pessoa_id as pessoa7_5_0_, this_.tipo as tipo5_0_ from EVENTOS this_ where this_.data&gt;'2009-08-07' order by this_.data asc limit 10                                                                                                                                                                           
                  16839 Query       rollback                                                                                                                                                                                                
                  16839 Query       SET autocommit=1

Pronto, agora ficou mais fácil de identificar os SQLs problemáticos da aplicação.

Boa sorte nos seus logs!

Fernando Boaglio, para a comunidade. =)