How to print the sql statements with values to log.

jsimas · **Joined:** Tue Feb 19, 2008 6:48 am **Posts:** 17

Hi.

I'm having some problems with a insert statement that is generating a constraint violation exception in database. I already turned on the debug level in hibernate classes but the only sql that i can see is this:

insert into TABLEXPTO (COLUMN1, COLUMN2 COLUMN3) values (?, ?, ?)

How can i see the exact values used in this sql query (instead of the ???)?

Thanks!

sjhyam · **Joined:** Fri Jun 01, 2007 12:41 pm **Posts:** 121

Add the following to your log4j configuration.

# Log JDBC bind parameter runtime arguments
log4j.logger.org.hibernate.type=INFO

jsimas · **Joined:** Tue Feb 19, 2008 6:48 am **Posts:** 17

Hi.

Thanks for you reploy, but i still can't see anything.

I have my log configured like this:

log4j.logger.org.hibernate.SQL=debug
log4j.logger.org.hibernate.engine.QueryParameters=debug
log4j.logger.org.hibernate.persister.entity=debug
log4j.logger.org.hibernate.type=debug

But the only thing that shows is:

[2008-02-19 15:25:01] DEBUG (AbstractBatcher.java:401) select xpto_.column1 as column1_0_ from Xpto xpto_ where xpto_.column2=?

Does anyone has another alternative?

Thanks.

farzad · **Posted:** Tue Feb 19, 2008 11:43 am

jsimas wrote:

Does anyone has another alternative?

Thanks.

I prefer to use a jdbc logger such as p6spy.

Farzad-

jsimas · **Joined:** Tue Feb 19, 2008 6:48 am **Posts:** 17

Hello again.

I'm still fighting to get de prepared statements values i think i have found the explation for not having the values in log.

org.hibernate.loader.Loader

Code:

protected int bindParameterValues(
         PreparedStatement statement,
         QueryParameters queryParameters,
         int startIndex,
         SessionImplementor session) throws SQLException {
      int span = 0;
      span += bindPositionalParameters( statement, queryParameters, startIndex, session );
      span += bindNamedParameters( statement, queryParameters.getNamedParameters(), startIndex + span, session );
      return span;
   }

you can see that he is going to bind parameters by position and by name. When executing the bindNamedParameters a log.debug is made with the values, but executing bindPositionalParameters, no log is made:

Code:

protected int bindPositionalParameters(
           final PreparedStatement statement,
           final QueryParameters queryParameters,
           final int startIndex,
           final SessionImplementor session) throws SQLException, HibernateException {
      final Object[] values = queryParameters.getFilteredPositionalParameterValues();
      final Type[] types = queryParameters.getFilteredPositionalParameterTypes();
      int span = 0;
      for ( int i = 0; i < values.length; i++ ) {
         types[i].nullSafeSet( statement, values[i], startIndex + span, session );
         span += types[i].getColumnSpan( getFactory() );
      }
      return span;
   }

When you have only positional parameters to bind to the prepared statement, how can you debug the values? Can anyone help me please?

Thanks.

tellary · **Joined:** Wed Jan 23, 2008 6:15 am **Posts:** 6

<b>sjhyam</b> have showed a right direction, except that hibernate 3.2.x logs parameters binding with TRACE level.

This must help:

Code:

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

And you'll see output like this:

Code:

20-02-2008 11:45:00 - [DEBUG,             org.hibernate.SQL] "select associatio0_.f_associationid as f1_0_0_, associatio0_.f_insertaction as f2_0_0_, associatio0_.f_firstclassid as f3_0_0_, associatio0_.f_deleteaction as f4_0_0_, associatio0_.f_updateaction as f5_0_0_, associatio0_.f_childinsertaction as f6_0_0_, associatio0_.f_secondclassid as f7_0_0_, associatio0_.f_childdeleteaction as f8_0_0_, associatio0_.f_childupdateaction as f9_0_0_ from t_association associatio0_ where associatio0_.f_associationid=?"
20-02-2008 11:45:00 - [TRACE,   org.hibernate.type.LongType] "binding '302197493' to parameter: 1"

jsimas · **Joined:** Tue Feb 19, 2008 6:48 am **Posts:** 17

Still not working for me.

Hibernate Version: 3.2.6
Commons-loggin: 1.1
Log4j: 1.2.15

If set my log.properties like this:

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

the only thing i get the prepared statment sql :(

I don't understand what i'm doing wrong....

jsimas · **Joined:** Tue Feb 19, 2008 6:48 am **Posts:** 17

I'm now realizing that the problem is in log level configuration... and i don't know why!!!!!

In NullableType for example you have:

Code:

private static final boolean IS_TRACE_ENABLED;
   static {
      //cache this, because it was a significant performance cost; is
      // trace logging enabled on the type package...
      IS_TRACE_ENABLED = LogFactory.getLog( StringHelper.qualifier( Type.class.getName() ) ).isTraceEnabled();
   }

The problem is that IS_TRACE_ENABLED value is false, even if you set in log4j.properties:

Code:

log4j.logger.org.hibernate.type = TRACE

....

jsimas · **Joined:** Tue Feb 19, 2008 6:48 am **Posts:** 17

I'm a very idiot, very idiot man!

The problem of logging was the order of the Listeners in my web.xml file. SpringContext (where i define Hibernate Connection) was first than my Log listener....

Problem solved.