I am using Hibernate with Spring and JPA. My problem is that log4j does not log the query parameters. Here is my log4j.xml:
Code:
<?xml version="1.0" encoding="UTF-8" ?>
<!DOCTYPE log4j:configuration SYSTEM "log4j.dtd">
<log4j:configuration debug="true" xmlns:log4j="http://jakarta.apache.org/log4j/">
<appender name="STDOUT" class="org.apache.log4j.ConsoleAppender">
<param name="threshold" value="DEBUG"/>
<layout class="org.apache.log4j.PatternLayout">
<param name="ConversionPattern" value="%d %p [%c] - %m%n"/>
</layout>
</appender>
<!-- spring -->
<logger name="org.springframework">
<level value="info"/>
</logger>
<!-- hibernate -->
<!--
<logger name="org.hibernate">
<level value="info"/>
</logger>
-->
<!-- log SQL statements (same as show_sql=true) -->
<logger name="org.hibernate.SQL">
<level value="debug"/>
</logger>
<!-- log HQL parse trees -->
<logger name="org.hibernate.hql">
<level value="debug"/>
</logger>
<!-- log JDBC resource acquisition -->
<logger name="org.hibernate.jdbc">
<level value="debug"/>
</logger>
<!-- log cache activity -->
<logger name="org.hibernate.cache">
<level value="debug"/>
</logger>
<!-- log JDBC bind parameters -->
<logger name="org.hibernate.type">
<level value="debug"/>
</logger>
<!-- log ddl statements -->
<logger name="org.hibernate.tool.hbm2ddl">
<level value="debug"/>
</logger>
<!-- log transaction activity -->
<logger name="org.hibernate.transaction">
<level value="debug"/>
</logger>
<logger name="org.apache">
<level value="warn"/>
</logger>
<!--
Alle Logmeldungen werden an den Appender STDOUT geschickt.
Es gibt ein zusaetzliches Threshold im Appender STDOUT
-->
<root>
<appender-ref ref="STDOUT"/>
</root>
</log4j:configuration>
I think org.hibernate.type should log the parameters - but they are missing. Here a sample log output:
Code:
[...]
2007-02-08 11:14:03,964 DEBUG [org.hibernate.transaction.JDBCTransaction] - begin
2007-02-08 11:14:03,964 DEBUG [org.hibernate.jdbc.ConnectionManager] - opening JDBC connection
2007-02-08 11:14:03,964 DEBUG [org.hibernate.transaction.JDBCTransaction] - current autocommit status: true
2007-02-08 11:14:03,964 DEBUG [org.hibernate.transaction.JDBCTransaction] - disabling autocommit
2007-02-08 11:14:03,980 INFO [myblog.tests.jpa.UserJPATest] - Began transaction (1): transaction manager [org.springframework.orm.jpa.JpaTransactionManager@bd09e8]; default rollback = true
2007-02-08 11:14:04,042 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] - executing identity-insert immediately
2007-02-08 11:14:04,042 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2007-02-08 11:14:04,042 DEBUG [org.hibernate.SQL] - insert into User (id, name) values (null, ?)
2007-02-08 11:14:04,058 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2007-02-08 11:14:04,058 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2007-02-08 11:14:04,058 DEBUG [org.hibernate.SQL] - call identity()
2007-02-08 11:14:04,058 DEBUG [org.hibernate.id.IdentifierGeneratorFactory] - Natively generated identity: 1
2007-02-08 11:14:04,058 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2007-02-08 11:14:04,058 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] - executing identity-insert immediately
2007-02-08 11:14:04,058 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2007-02-08 11:14:04,058 DEBUG [org.hibernate.SQL] - insert into Email (id, value, index) values (null, ?, ?)
2007-02-08 11:14:04,058 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2007-02-08 11:14:04,058 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2007-02-08 11:14:04,058 DEBUG [org.hibernate.SQL] - call identity()
2007-02-08 11:14:04,058 DEBUG [org.hibernate.id.IdentifierGeneratorFactory] - Natively generated identity: 1
2007-02-08 11:14:04,058 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2007-02-08 11:14:04,058 DEBUG [org.hibernate.event.def.AbstractSaveEventListener] - executing identity-insert immediately
2007-02-08 11:14:04,058 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2007-02-08 11:14:04,058 DEBUG [org.hibernate.SQL] - insert into Email (id, value, index) values (null, ?, ?)
2007-02-08 11:14:04,058 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2007-02-08 11:14:04,058 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
2007-02-08 11:14:04,058 DEBUG [org.hibernate.SQL] - call identity()
2007-02-08 11:14:04,058 DEBUG [org.hibernate.id.IdentifierGeneratorFactory] - Natively generated identity: 2
2007-02-08 11:14:04,058 DEBUG [org.hibernate.jdbc.AbstractBatcher] - about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
2007-02-08 11:14:04,074 DEBUG [org.hibernate.transaction.JDBCTransaction] - rollback
2007-02-08 11:14:04,074 DEBUG [org.hibernate.transaction.JDBCTransaction] - re-enabling autocommit
2007-02-08 11:14:04,074 DEBUG [org.hibernate.transaction.JDBCTransaction] - rolled back JDBC Connection
2007-02-08 11:14:04,074 DEBUG [org.hibernate.jdbc.ConnectionManager] - aggressively releasing JDBC connection
2007-02-08 11:14:04,074 DEBUG [org.hibernate.jdbc.ConnectionManager] - releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
2007-02-08 11:14:04,074 INFO [myblog.tests.jpa.UserJPATest] - Rolled back transaction after test execution