10 October 2016  ·  javaprogrammazionehibernate

Hibernate Logging Tips


Chiunque usi Hibernate prima o poi ha la necessità di capire, per debug o per ottimizzazione, come la query scritta utilizzando i Criteria oppure JPQL venga tradotta in SQL nativo.

Il modo più comune, ma che vi sconsiglio, di ottenere questo risultato è quello di impostare a true la property hibernate.show_sql. Ad esempio se stiamo utilizzando Hibernate tramite Spring e JPA dovremo configurare l'entity manager con qualcosa del genere:

<bean id="em" class="org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean">
        <property name="dataSource" ref="ds"/>
        <property name="jpaVendorAdapter">
            <bean class="org.springframework.orm.jpa.vendor.HibernateJpaVendorAdapter">
                <property name="database" value="MYSQL" />
                <property name="showSql" value="true" />
            </bean>
        </property>
        <property name="persistenceUnitName" value="vlt" >
    </bean>

Così facendo vedrete in output qualcosa del genere (ovviamente la query cambierà in base a come sono stati mappati i vostri DAO)

Hibernate: select subject0_.id as id1_1_, subject0_.name as name1_2_ from subject subject0_ inner join node subject0_1_ on subject0_.id=subject0_1_.id where subject0_.name like ? limit ?

Il problema di questa soluzione è che vi mostra la query, ma non vi mostra i parametri che vengono passati alla query (vedete infatti solo i punti interrogativi).

La soluzione che vi consiglio invece è la seguente:

lasciate a false la variabile hibernate.show_sql
impostare il logger "org.hibernate.SQL" a "debug" (questo vi permetterà di visualizzare la query)
impostare il logger "org.hibernate.type.descriptor.sql" a "trace" (questo vi permetterà di visualizzare i parametri passati in input alla query ed anche i risultati ottenuti)

L'output, adesso completo di tutto, sarà qualcosa del genere

2016-10-10 21:00:17,929 DEBUG - select subject0_.id as id1_1_, subject0_.name as name1_2_ from subject subject0_ inner join node subject0_1_ on subject0_.id=subject0_1_.id where subject0_.name like ? limit ?
2016-10-10 21:00:18,006 TRACE - binding parameter [1] as [VARCHAR] - [%prova%]
2016-10-10 21:00:18,054 TRACE - extracted value ([id1_1_] : [BIGINT]) - [4]
2016-10-10 21:00:18,071 TRACE - extracted value ([name1_2_] : [VARCHAR]) - [prova]

Se utilizzate Log4j2 questa configurazione è possibile ottenerla così:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
  <Appenders>
    <Console name="STDOUT" target="SYSTEM_OUT">
      <PatternLayout pattern="%d %-5p - %m%n"/>
    </Console>
  </Appenders>
  <Loggers>
      <Logger name="org.hibernate.SQL" level="debug"/>
      <Logger name="org.hibernate.type.descriptor.sql" level="trace"/>
    <Root level="info">
      <AppenderRef ref="STDOUT"/>
    </Root>
  </Loggers>
</Configuration>

← Tutti gli articoli