How to print a query string with parameter values

Question

Is it possible in Hibernate to print generated SQL queries with real values instead of question marks?

How would you suggest to print queries with real values if it is not possible with Hibernate API?

Answer 1

Using Hibernate 4 and slf4j/log4j2 , I tried adding the following in my log4j2.xml configuration :

<Logger name="org.hibernate.type.descriptor.sql.BasicBinder" level="trace" additivity="false"> 
    <AppenderRef ref="Console"/> 
</Logger> 
<Logger name="org.hibernate.type.EnumType" level="trace" additivity="false"> 
    <AppenderRef ref="Console"/>
</Logger>

But without success.

I found out through this thread that the jboss-logging framework used by hibernate needed to be configured in order to log through slf4j. I added the following argument to the VM arguments of the application:

-Dorg.jboss.logging.provider=slf4j

And it worked like a charm.

Answer 2

In case of spring boot is being used , just config this :

aplication.yml

logging:
  level:
    org.hibernate.SQL: DEBUG
    org.hibernate.type: TRACE

aplication.properties

logging.level.org.hibernate.SQL=DEBUG
logging.level.org.hibernate.type=TRACE

and nothing more.

HTH

Answer 3

<appender name="console" class="org.apache.log4j.ConsoleAppender">
    <layout class="org.apache.log4j.PatternLayout">
    <param name="ConversionPattern" 
      value="%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n" />
    </layout>
</appender>

<logger name="org.hibernate" additivity="false">
    <level value="INFO" />
    <appender-ref ref="console" />
</logger>

<logger name="org.hibernate.type" additivity="false">
    <level value="TRACE" />
    <appender-ref ref="console" />
</logger>

Answer 4

Hibernate shows query and their parameter values in different lines.

If you are using application.properties in spring boot and you can use below highlighted parameter in application.properties.

1. org.hibernate.SQL will show queries

   logging.level.org.hibernate.SQL=DEBUG

2. org.hibernate.type will show all parameter values, which will map with select , insert and update queries. logging.level.org.hibernate.type=TRACE

   • org.hibernate.type.EnumType will show enum type parameter value

     logging.level.org.hibernate.type.EnumType=TRACE

     example ::

     2018-06-14 11:06:28,217 TRACE [main] [EnumType.java : 321] Binding [active] to parameter: [1]
     

   • sql.BasicBinder will show integer, varchar, boolean type parameter value

     logging.level.org.hibernate.type.descriptor.sql.BasicBinder=TRACE

     example ::

     • 2018-06-14 11:28:29,750 TRACE [http-nio-9891-exec-2] [BasicBinder.java : 65] binding parameter [1] as [BOOLEAN] - [true]
     • 2018-06-14 11:28:29,751 TRACE [http-nio-9891-exec-2] [BasicBinder.java : 65] binding parameter [2] as [INTEGER] - [1]
     • 2018-06-14 11:28:29,752 TRACE [http-nio-9891-exec-2] [BasicBinder.java : 65] binding parameter [3] as [VARCHAR] - [public]

Answer 5

mysql jdbc driver has already provide a convenient to meet this requirement, you must at least the have the jar version >= mysql-connect-jar-5.1.6.jar

step 1: [configure your jdbc.url to add logger and custom logging]

    jdbc.url=jdbc:mysql://host:port/your_db?logger=com.mysql.jdbc.log.Slf4JLogger&profileSQL=true&profilerEventHandler=com.xxx.CustomLoggingProfilerEventHandler

now, it is using slf4j logging, if your default logging is log4j, you must add slf4j-api, slf4j-log4j12 dependencies to use slf4j logging

step 2: [write your custom logging]

package com.xxx;
import java.sql.SQLException;
import java.util.Properties;

import com.mysql.jdbc.Connection;
import com.mysql.jdbc.log.Log;

public class CustomLoggingProfilerEventHandler implements ProfilerEventHandler {
    private Log log;

    public LoggingProfilerEventHandler() {
    }

    public void consumeEvent(ProfilerEvent evt) {
            /**
             * you can only print the sql as        this.log.logInfo(evt.getMessage())
             * you can adjust your sql print log level with: DEBUG,INFO
             * you can also handle the message to meet your requirement
             */ 
            this.log.logInfo(evt);
    }

    public void destroy() {
        this.log = null;
    }

    public void init(Connection conn, Properties props) throws SQLException {
        this.log = conn.getLog();
    }

}

Answer 6

Just for convenience, here is the same configuration example for Logback (SLF4J)

<appender name="SQLROLLINGFILE">
 <File>/tmp/sql.log</File>
 <rollingPolicy>
  <FileNamePattern>logFile.%d{yyyy-MM-dd}.log</FileNamePattern>
 </rollingPolicy>
 <layout>
  <Pattern>%-4date | %msg %n</Pattern>
 </layout>
</appender>

<logger name="org.hibernate.SQL" additivity="false" >   
 <level value="DEBUG" />    
 <appender-ref ref="SQLROLLINGFILE" />
</logger>

<logger name="org.hibernate.type" additivity="false" >
 <level value="TRACE" />
 <appender-ref ref="SQLROLLINGFILE" />
</logger>

The output in your sql.log (example) then looks like this:

2013-08-30 18:01:15,083 | update stepprovider set created_at=?, lastupdated_at=?, version=?, bundlelocation=?, category_id=?, customer_id=?, description=?, icon_file_id=?, name=?, shareStatus=?, spversion=?, status=?, title=?, type=?, num_used=? where id=?
2013-08-30 18:01:15,084 | binding parameter [1] as [TIMESTAMP] - 2012-07-11 09:57:32.0
2013-08-30 18:01:15,085 | binding parameter [2] as [TIMESTAMP] - Fri Aug 30 18:01:15 CEST 2013
2013-08-30 18:01:15,086 | binding parameter [3] as [INTEGER] -
2013-08-30 18:01:15,086 | binding parameter [4] as [VARCHAR] - com.mypackage.foo
2013-08-30 18:01:15,087 | binding parameter [5] as [VARCHAR] -
2013-08-30 18:01:15,087 | binding parameter [6] as [VARCHAR] -
2013-08-30 18:01:15,087 | binding parameter [7] as [VARCHAR] - TODO
2013-08-30 18:01:15,087 | binding parameter [8] as [VARCHAR] -
2013-08-30 18:01:15,088 | binding parameter [9] as [VARCHAR] - [e-mail]
2013-08-30 18:01:15,088 | binding parameter [10] as [VARCHAR] - PRIVATE
2013-08-30 18:01:15,088 | binding parameter [11] as [VARCHAR] - 1.0
2013-08-30 18:01:15,088 | binding parameter [12] as [VARCHAR] - 32
2013-08-30 18:01:15,088 | binding parameter [13] as [VARCHAR] - MatchingStep
2013-08-30 18:01:15,089 | binding parameter [14] as [VARCHAR] -
2013-08-30 18:01:15,089 | binding parameter [15] as [INTEGER] - 0
2013-08-30 18:01:15,089 | binding parameter [16] as [VARCHAR] - 053c2e65-5d51-4c09-85f3-2281a1024f64