How to print a query string with parameter values when using Hibernate

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?

See also http://stackoverflow.com/questions/2536829/hibernate-show-real-sql — Petr Gladkikh, Aug 16 '12 at 05:23

score 555 · Accepted Answer · edited Apr 25 '17 at 13:53

555

You need to enable logging for the the following categories:

org.hibernate.SQL - set to debug to log all SQL DML statements as they are executed
org.hibernate.type - set to trace to log all JDBC parameters

So a log4j configuration could look like:

# logs the SQL statements
log4j.logger.org.hibernate.SQL=debug 

# Logs the JDBC parameters passed to a query
log4j.logger.org.hibernate.type=trace

The first is equivalent to hibernate.show_sql=true legacy property, the second prints the bound parameters among other things.

Another solution (non hibernate based) would be to use a JDBC proxy driver like P6Spy.

edited Apr 25 '17 at 13:53

Abdull

26,371
26
130
172

answered Nov 11 '09 at 06:40

Pascal Thivent

562,542
136
1,062
1,124

31

This is useful. But this does not show me the real SQL queries. – Nicolas Barbulesco Sep 03 '13 at 08:26
7

@Nicolas that's true, however inmediately after the query it dispays the binded parameters. – Aritz Sep 19 '13 at 06:47
4

I am using grails 2.4.4 and hibernate 4. Changing log4j configuration did not work for me but p6spy worked! – Champ Jan 13 '15 at 07:03
Adding the `org.hibernate.type` category to my appender didn't work for me, but adding the `org.hibernate.loader.hql` category instead did work. – Emil Lundberg Feb 13 '15 at 16:04
the logging of JDBC params doesn't work in hibernate 4 – Gordon Jun 25 '15 at 22:59
You may need to tell Hibernate what logging manager you use (log4j, slf4j), see [how](http://stackoverflow.com/questions/11639997/how-do-you-configure-logging-in-hibernate-4-to-use-slf4j). – Vlastimil Ovčáčík Aug 09 '15 at 18:31
19

In Hibernate 5 we can use `org.hibernate.type.descriptor.sql.BasicBinder` logger. Enabling logging on `org.hibernate.type` printed too much useless info for me... – csharpfolk Aug 08 '16 at 18:15
6

`org.hibernate.type` and `org.hibernate.loader.hql` not work for me to show the parameters – Dherik Oct 06 '16 at 15:54
1

Where should I put those configurations? – Gavin Haynes Nov 19 '16 at 00:15
So, if you already have `hibernate.show_sql=true`, you can skip the first part and just add the `log4j.logger.org.hibernate.type=trace`. Works for me – Nestor Milyaev Mar 22 '18 at 13:31
"Enabling logging on org.hibernate.type printed too much useless info for me..." Me too. TRACE [,] [org.hibernate.type.descriptor.sql.BasicExtractor] found [...] as column [...] System crashed when a varchar(max) column containing a very large text was logged. – Géza Dec 20 '18 at 17:25
it works for me with: logging.level.org.hibernate.SQL= DEBUG \n logging.level.org.hibernate.type=trace – tiennv Aug 20 '20 at 12:39
try it: https://www.programmersought.com/article/9068221566/ – oitathi Jul 15 '21 at 13:01
Bound parameters aren't being printed with `log4j.logger.org.hibernate.type=trace` – Code Jockey Sep 24 '21 at 13:36
For sl4j using logging.level.org.hibernate.type=true worked for me – Shubhasish Bhunia Jan 03 '23 at 10:42
Can you show the output of what it looks like in the log files? people answering this question have been scared to show what it actually looks like in the log. – Collin Jan 26 '23 at 22:30

score 107 · Answer 2 · edited Nov 14 '21 at 20:15

107

If you are using Spring Boot, just config this:

application.yml

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

application.properties

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

and nothing more.

Your log will be something like this:

2020-12-07 | DEBUG | o.h.SQL:127 - insert into Employee (id, name, title, id) values (?, ?, ?, ?)
2020-12-07 | TRACE | o.h.t.d.s.BasicBinder:64 - binding parameter [1] as [VARCHAR] - [001]
2020-12-07 | TRACE | o.h.t.d.s.BasicBinder:64 - binding parameter [2] as [VARCHAR] - [John Smith]
2020-12-07 | TRACE | o.h.t.d.s.BasicBinder:52 - binding parameter [3] as [VARCHAR] - [null]
2020-12-07 | TRACE | o.h.t.d.s.BasicBinder:64 - binding parameter [4] as [BIGINT] - [1]

edited Nov 14 '21 at 20:15

answered Nov 04 '16 at 21:17

JRichardsz

14,356
6
59
94

1

Small addition: With this setup I also get all the results in my log file. `logging.level.org.hibernate.type.descriptor.sql.BasicBinder=TRACE` only shows the parameters. – FLUXparticle Sep 08 '22 at 12:14
2

is there any way to get it to just show the binding values in the same line as "insert"??? – Collin Jan 26 '23 at 22:24
Complicated. That log is inside of library :/ – JRichardsz May 07 '23 at 21:50

score 87 · Answer 3 · answered Aug 31 '13 at 22:33

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] - MatchingStep@com.mypackage.foo
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

This is not answering the OPs question. – ShadowGames Oct 15 '19 at 08:52 — ShadowGames, Oct 15 '19 at 08:52
How do we get it in the same line instead of the "?" – Collin Jan 26 '23 at 22:30 — Collin, Jan 26 '23 at 22:30

score 41 · Answer 4 · edited May 11 '17 at 17:47

41

Change hibernate.cfg.xml to:

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

Include log4j and below entries in "log4j.properties":

log4j.logger.org.hibernate=INFO, hb
log4j.logger.org.hibernate.SQL=DEBUG
log4j.logger.org.hibernate.type=TRACE

log4j.appender.hb=org.apache.log4j.ConsoleAppender
log4j.appender.hb.layout=org.apache.log4j.PatternLayout

edited May 11 '17 at 17:47

Dave Jarvis

30,436
41
178
315

answered Jan 25 '13 at 10:16

Hari

411
4
2

Thanks, has worked for me really well. Those settings will add under the sql query a parameter like `binding parameter [1] as [VARCHAR] - [1]`. – G. Ciardini May 07 '19 at 08:34

Erik Pragt · Answer 5 · 2023-07-03T22:09:17.133

30

If you're using Spring Boot 3 and/or Hibernate 6, the following configuration will display the parameter values:

# basic log level for all messages
logging.level.org.hibernate=info
# SQL statements and parameters
logging.level.org.hibernate.SQL=debug
logging.level.org.hibernate.orm.jdbc.bind=trace
# Statistics and slow queries
logging.level.org.hibernate.stat=debug
logging.level.org.hibernate.SQL_SLOW=info
# 2nd Level Cache
logging.level.org.hibernate.cache=debug

edited Jul 03 '23 at 22:09

answered Nov 27 '22 at 05:46

Erik Pragt

13,513
11
58
64

2

Why is this only on the second page :D Looked for the Spring boot 3 / Hibernate 6 solution for hours and only found the old entries and didn't understand why it wasn't working. Thank you sir :) – lynxSven May 31 '23 at 13:55
1

Yeah, sorry! I'm afraid this answer go up in the next year or so, and will most likely be the top answer Spring 4 and Hibernate 7 are out :-) – Erik Pragt Jun 01 '23 at 00:49

score 27 · Answer 6 · edited Nov 14 '21 at 20:21

Log4JDBC is a nice solution which prints the exact SQL going to the database with parameters in place, rather than the most popular answer here which does not do this. One major convenience of this is that you can copy the SQL straight to your DB front-end and execute it as-is.

The latter also outputs a tabular representation of query results.

Sample Output showing generated SQL with params in place together with result set table from query:

5. insert into ENQUIRY_APPLICANT_DETAILS (ID, INCLUDED_IN_QUOTE, APPLICANT_ID, TERRITORY_ID, ENQUIRY_ID, ELIGIBLE_FOR_COVER) values (7, 1, 11, 1, 2, 0) 

10 Oct 2013 16:21:22 4953 [main] INFO  jdbc.resultsettable  - |---|--------|--------|-----------|----------|---------|-------|
10 Oct 2013 16:21:22 4953 [main] INFO  jdbc.resultsettable  - |ID |CREATED |DELETED |CODESET_ID |NAME      |POSITION |PREFIX |
10 Oct 2013 16:21:22 4953 [main] INFO  jdbc.resultsettable  - |---|--------|--------|-----------|----------|---------|-------|
10 Oct 2013 16:21:22 4953 [main] INFO  jdbc.resultsettable  - |2  |null    |null    |1          |Country 2 |1        |60     |
10 Oct 2013 16:21:22 4953 [main] INFO  jdbc.resultsettable  - |---|--------|--------|-----------|----------|---------|-------|

Update 2016

Most recently I have now been using log4jdbc-log4j2 (https://code.google.com/archive/p/log4jdbc-log4j2/ ) with SLF4j and logback. Maven dependencies required for my setup are as below:

<dependency>
    <groupId>org.bgee.log4jdbc-log4j2</groupId>
    <artifactId>log4jdbc-log4j2-jdbc4.1</artifactId>
    <version>1.16</version>
</dependency>
<dependency>
    <groupId>org.slf4j</groupId>
    <artifactId>slf4j-api</artifactId>
    <version>${slf4j.version}</version>
</dependency>
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-core</artifactId>
    <version>${logback.version}</version>
</dependency>
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
    <version>$logback.version}</version>
</dependency>

The driver and DB URLs then look like:

database.driver.class=net.sf.log4jdbc.sql.jdbcapi.DriverSpy
database.url=jdbc:log4jdbc:hsqldb:mem:db_name #Hsql
#database.url=jdbc:log4jdbc:mysql://localhost:3306/db_name

My logback.xml configuration file looks like the below: this outputs all SQL statements with parameters plus the resultset tables for all queries.

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n
            </pattern>
        </encoder>
    </appender>

    <logger name="jdbc.audit" level="ERROR" />
    <logger name="jdbc.connection" level="ERROR" />
    <logger name="jdbc.sqltiming" level="ERROR" />
    <logger name="jdbc.resultset" level="ERROR" />
    
    <!-- UNCOMMENT THE BELOW TO HIDE THE RESULT SET TABLE OUTPUT -->
    <!--<logger name="jdbc.resultsettable" level="ERROR" /> -->

    <root level="debug">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

Finally, I had to create a file named log4jdbc.log4j2.properties at the root of the classpath e.g. src/test/resources or src/main/resources in a Maven project. This file has one line:

log4jdbc.spylogdelegator.name=net.sf.log4jdbc.log.slf4j.Slf4jSpyLogDelegator

The above will depend on your logging library. See the docs at https://code.google.com/archive/p/log4jdbc-log4j2 for more info.

Sample Output:

10:44:29.400 [main] DEBUG jdbc.sqlonly -  org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.extract(ResultSetReturnImpl.java:70)
5. select memberrole0_.member_id as member_i2_12_0_, memberrole0_.id as id1_12_0_, memberrole0_.id 
as id1_12_1_, memberrole0_.member_id as member_i2_12_1_, memberrole0_.role_id as role_id3_12_1_, 
role1_.id as id1_17_2_, role1_.name as name2_17_2_ from member_roles memberrole0_ left outer 
join roles role1_ on memberrole0_.role_id=role1_.id where memberrole0_.member_id=104 

10:44:29.402 [main] INFO  jdbc.resultsettable - 
|----------|---|---|----------|--------|---|-----|
|member_id |id |id |member_id |role_id |id |name |
|----------|---|---|----------|--------|---|-----|
|----------|---|---|----------|--------|---|-----|

Actually, the *latter* outputs a tabluar representation of query results ... i.e. one needs log4jdbc-remix for that nice feature. — meriton, Jun 02 '16 at 16:56
This is very cool and also works for spring boot. Also much easier to integrate there. See [this other stackoverflow question](https://stackoverflow.com/questions/52376778/can-log4jdbc-be-used-with-spring-boot/59771403#59771403) — judos, Jan 16 '20 at 14:08
To avoid adding a library, generally what I do is to put a conditional breakpoint on BasicExtractor#extract method (in hibernate core lib) , example if I am interested in a query on table table_A I do this conditional break point (rs.getStatement().toString().contains("table_A")) and my real SQL query is rs.getStatement().toString() — Saad Achemlal, Aug 14 '23 at 17:02

Michal Zmuda · Answer 7 · 2013-03-19T18:52:17.397

10

You can add category lines to log4j.xml:

<category name="org.hibernate.type">
    <priority value="TRACE"/>
</category>

and add hibernate properties:

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

edited Mar 19 '13 at 18:52

answered Mar 19 '13 at 18:34

Michal Zmuda

5,381
3
43
39

score 9 · Answer 8 · edited Nov 14 '21 at 20:23

9

Add the following to your log4j or logback configuration:

org.hibernate.sql=DEBUG
org.hibernate.type.descriptor.sql.BasicBinder=TRACE

edited Nov 14 '21 at 20:23

answered Dec 14 '13 at 12:34

ravshansbox

748
11
21

6

The `org.hibernate.type.descriptor.sql.BasicBinder` category doesn't include all parameters, eg enum types. So if you want everything, you really need `TRACE` for the entire `org.hibernate.type` group. – seanf Apr 23 '14 at 05:32
Note that org.hibernate.type.descriptor.sql.BasicExtractor logs the result sets. So having large size entry can even crash the apllication when logging to console in Eclipse, and I suppose it is also not ideal for logging into file. That is why I prefer this solution, it works also in Hibernate 3. For those who are interested in enum types, please try out the exact class that logs them when org.hibernate.type=TRACE. Then set org.hibernate.type.xyz.TheClassThatLogsEnumParams=TRACE. – Géza Dec 21 '18 at 09:29

score 9 · Answer 9 · edited Nov 14 '21 at 20:23

You can do it using the datasource-proxy, as I described in this post.

Assuming your application expects a dataSource bean (e.g. via @Resource), this is how you can configure datasource-proxy:

<bean id="actualDataSource" class="bitronix.tm.resource.jdbc.PoolingDataSource" init-method="init"
  destroy-method="close">
    <property name="className" value="bitronix.tm.resource.jdbc.lrc.LrcXADataSource"/>
    <property name="uniqueName" value="actualDataSource"/>
    <property name="minPoolSize" value="0"/>
    <property name="maxPoolSize" value="5"/>
    <property name="allowLocalTransactions" value="false" />
    <property name="driverProperties">
        <props>
            <prop key="user">${jdbc.username}</prop>
            <prop key="password">${jdbc.password}</prop>
            <prop key="url">${jdbc.url}</prop>
            <prop key="driverClassName">${jdbc.driverClassName}</prop>
        </props>
    </property>
</bean>

<bean id="proxyDataSource" class="net.ttddyy.dsproxy.support.ProxyDataSource">
    <property name="dataSource" ref="testDataSource"/>
    <property name="listener">
        <bean class="net.ttddyy.dsproxy.listener.ChainListener">
            <property name="listeners">
                <list>
                    <bean class="net.ttddyy.dsproxy.listener.CommonsQueryLoggingListener">
                        <property name="logLevel" value="INFO"/>
                    </bean>
                    <bean class="net.ttddyy.dsproxy.listener.DataSourceQueryCountListener"/>
                </list>
            </property>
        </bean>
    </property>
</bean>

<alias name="proxyDataSource" alias="dataSource"/>

Now the Hibernate output vs. datasource-proxy:

INFO  [main]: n.t.d.l.CommonsQueryLoggingListener - Name:, Time:1, Num:1, Query:{[select company0_.id as id1_6_, company0_.name as name2_6_ from Company company0_][]}
INFO  [main]: n.t.d.l.CommonsQueryLoggingListener - Name:, Time:0, Num:1, Query:{[insert into WarehouseProductInfo (id, quantity) values (default, ?)][19]}
INFO  [main]: n.t.d.l.CommonsQueryLoggingListener - Name:, Time:0, Num:1, Query:{[insert into Product (id, code, company_id, importer_id, name, version) values (default, ?, ?, ?, ?, ?)][phoneCode,1,-5,Phone,0]}

The datasource-proxy queries contain parameter values and you can even add custom JDBC statement interceptors so that you can catch N+1 query issues right from your integration tests.

score 5 · Answer 10 · edited Nov 14 '21 at 20:25

5

Turn on the org.hibernate.type logger to see how the actual parameters are bind to the question marks.

edited Nov 14 '21 at 20:25

answered Nov 10 '09 at 19:21

flybywire

261,858
191
397
503

score 5 · Answer 11 · edited Nov 14 '21 at 20:26

5

For development with Wildfly (standalone.xml), add these loggers:

<logger category="org.hibernate.SQL">
   <level name="DEBUG"/>
</logger>
<logger category="org.hibernate.type.descriptor.sql">
   <level name="TRACE"/>
</logger>

edited Nov 14 '21 at 20:26

answered Apr 30 '19 at 11:43

womd

3,077
26
20

score 4 · Answer 12 · edited Nov 14 '21 at 20:38

Logging works but not exactly what you want and I wanted some time ago, but P6Spy does work perfectly.

Here is simple tutorial to implement as well. For me it worked like charm.

Download the P6Spy library: Get p6spy-install.jar
Extract it: Extract the p6spy-install.jar file, look for p6spy.jar and spy.properties
Add library dependency: Add p6spy.jar into your project library dependency
Modify P6Spy properties file: Modify your database configuration file. You need to replace your existing JDBC driver with the P6Spy JDBC driver (com.p6spy.engine.spy.P6SpyDriver)

Original is MySQL JDBC driver –(com.mysql.jdbc.Driver)

<session-factory>
  <property name="hibernate.bytecode.use_reflection_optimizer">false</property>
  <property name="hibernate.connection.driver_class">com.mysql.jdbc.Driver</property>  <!-- note the difference -->
  <property name="hibernate.connection.password">password</property>
  <property name="hibernate.connection.url">jdbc:mysql://localhost:3306/myuser</property>
  <property name="hibernate.connection.username">root</property>
  <property name="hibernate.dialect">org.hibernate.dialect.MySQLDialect</property>
  <property name="show_sql">true</property>
</session-factory>

Changed it to P6Spy JDBC driver (com.p6spy.engine.spy.P6SpyDriver)

<session-factory>
  <property name="hibernate.bytecode.use_reflection_optimizer">false</property>
  <property name="hibernate.connection.driver_class">com.p6spy.engine.spy.P6SpyDriver</property>  <!-- note the difference -->
  <property name="hibernate.connection.password">password</property>
  <property name="hibernate.connection.url">jdbc:mysql://localhost:3306/myuser</property>
  <property name="hibernate.connection.username">root</property>
  <property name="hibernate.dialect">org.hibernate.dialect.MySQLDialect</property>
  <property name="show_sql">true</property>
</session-factory>

Modify P6Spy properties file: spy.properties

Replace the realdriver with your existing MySQL JDBC driver

realdriver=com.mysql.jdbc.Driver

# specifies another driver to use
realdriver2=
# specifies a third driver to use
realdriver3=

Change the logfile location in the logfile property. All SQL statements will be logged into this file.

Windows:

logfile=c:/spy.log

UNIX:

logfile=/srv/log/spy.log

Copy spy.properties to project classpath: Copy spy.properties to your project root folder. Make sure your project can locate spy.properties, or else a spy.properties file not found exception will be thrown.

This was the easiest path forward for me in my Spring Boot application, where I was trying to log SQL generated from a unit test. I added a test dependency to Gradle (testCompile 'p6spy:p6spy:3.8.5'), adjusted application.yml to set spring.datasource.url=jdbc:p6spy:h2:mem:testdb and spring.datasource.driver-class-name=com.p6spy.engine.spy.P6SpyDriver, and then added spy.properties with realdriver=org.h2.Driver and logfile set to my preferred path. It was easy to extract the complete SQL from the resulting log file. The only hiccup was that H2 didn't like the generated timestamp format. — Ken Pronovici, Sep 08 '19 at 15:15

score 4 · Answer 13 · answered Mar 25 '16 at 04:54

<!-- A time/date based rolling appender -->
<appender name="FILE" class="org.apache.log4j.RollingFileAppender">
    <param name="File" value="logs/system.log" />
    <param name="Append" value="true" />
    <param name="ImmediateFlush" value="true" />
    <param name="MaxFileSize" value="200MB" />
    <param name="MaxBackupIndex" value="100" />

    <layout class="org.apache.log4j.PatternLayout">
        <param name="ConversionPattern" value="%d %d{Z} [%t] %-5p (%F:%L) - %m%n" />
    </layout>
</appender>

<appender name="journaldev-hibernate" class="org.apache.log4j.RollingFileAppender">
    <param name="File" value="logs/project.log" />
    <param name="Append" value="true" />
    <param name="ImmediateFlush" value="true" />
    <param name="MaxFileSize" value="200MB" />
    <param name="MaxBackupIndex" value="50" />

    <layout class="org.apache.log4j.PatternLayout">
        <param name="ConversionPattern" value="%d %d{Z} [%t] %-5p (%F:%L) - %m%n" />
    </layout>
</appender>

<logger name="com.journaldev.hibernate" additivity="false">
    <level value="DEBUG" />
    <appender-ref ref="journaldev-hibernate" />
</logger>

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

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

<root>
    <priority value="INFO"></priority>
    <appender-ref ref="FILE" />
</root>

S'chn T'gai Spock · Answer 14 · 2017-08-13T04:53:02.377

4

Here is what worked for me, set below property in the log4j.file:

log4j.logger.org.hibernate.type.descriptor.sql.BasicBinder=TRACE

Hibernate properties settings :

hibernate.show_sql=true

edited Aug 13 '17 at 04:53

answered Aug 01 '17 at 14:18

S'chn T'gai Spock

1,203
18
16

score 4 · Answer 15 · edited Nov 14 '21 at 20:48

4

Using a YAML property:

logging.level.org.hibernate:
    SQL: DEBUG
    type.descriptor.sql.BasicBinder: TRACE

edited Nov 14 '21 at 20:48

answered Mar 03 '21 at 01:55

Zoren Konte

306
4
12

I already have logging: level: ${env.LOG_LVL:'INFO'} in application.yaml file how to add for hibernate [TRACE] with the existing one. – Praveen D Mar 23 '22 at 07:54

score 3 · Answer 16 · edited Nov 14 '21 at 20:27

This answer is a little variance for the question. Sometimes, we only need the sql only for debug purposes in runtime. In that case, there are a more easy way, using debug on editors.

Put a breakpoint on org.hibernate.loader.Loader.loadEntityBatch (or navigate on the stack until there);
When execution is suspended, look the value of variable this.sql

This is for Hibernate 3. I'm not sure that this work on other versions.

score 3 · Answer 17 · edited Nov 14 '21 at 20:31

The MySQL JDBC driver already provides a convenient feature to meet this requirement. You must at least the have the JAR version greater than or equal to 5.1.6 (e.g. mysql-connect-jar-5.1.6.jar)

Configure jdbc.url to add logger your logger and custom logging:

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

It is using slf4j logging, if your default logging is log4j, you must add slf4j-api and slf4j-log4j12 as dependencies to use slf4j logging:

Write your custom logging code:

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 his.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();
    }
}

score 3 · Answer 18 · edited Nov 14 '21 at 20:45

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.

org.hibernate.SQL will show queries:
```
logging.level.org.hibernate.SQL=DEBUG
```
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 output:

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 output:

* 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]

Even this doesn't show the values for _limit_ and _offset_ in queries. — T3rm1, Jan 04 '19 at 13:10

score 3 · Answer 19 · edited Nov 14 '21 at 20:27

The solution is correct but logs also all bindings for the result objects. To prevent this it's possible to create a separate appender and enable filtering. For example:

<!-- A time/date based rolling appender -->
<appender name="FILE_HIBERNATE" class="org.jboss.logging.appender.DailyRollingFileAppender">
    <errorHandler class="org.jboss.logging.util.OnlyOnceErrorHandler"/>
    <param name="File" value="${jboss.server.log.dir}/hiber.log"/>
    <param name="Append" value="false"/>
    <param name="Threshold" value="TRACE"/>
    <!-- Rollover at midnight each day -->
    <param name="DatePattern" value="'.'yyyy-MM-dd"/>

    <layout class="org.apache.log4j.PatternLayout">
        <!-- The default pattern: Date Priority [Category] Message\n -->
        <param name="ConversionPattern" value="%d %-5p [%c] %m%n"/>
    </layout>
  
    <filter class="org.apache.log4j.varia.StringMatchFilter">
        <param name="StringToMatch" value="bind" />
        <param name="AcceptOnMatch" value="true" />
    </filter>
    <filter class="org.apache.log4j.varia.StringMatchFilter">
        <param name="StringToMatch" value="select" />
        <param name="AcceptOnMatch" value="true" />
    </filter>  
    <filter class="org.apache.log4j.varia.DenyAllFilter"/>
</appender> 

<category name="org.hibernate.type">
  <priority value="TRACE"/>
</category>

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

<logger name="org.hibernate.SQL">
   <level value="TRACE"/> 
   <appender-ref ref="FILE_HIBERNATE"/>
</logger>

score 2 · Answer 20 · answered Oct 26 '13 at 11:35

I like this for log4j:

log4j.logger.org.hibernate.SQL=trace
log4j.logger.org.hibernate.engine.query=trace
log4j.logger.org.hibernate.type=trace
log4j.logger.org.hibernate.jdbc=trace
log4j.logger.org.hibernate.type.descriptor.sql.BasicExtractor=error 
log4j.logger.org.hibernate.type.CollectionType=error

score 2 · Answer 21 · answered Sep 05 '14 at 15:55

Log4Jdbc plugin would be best for your requirement. It shows following-

1. Complete SQL query being hit to the db
2. Parameter values being passed to the query
3. Execution time taken by each query

Refer below link to configure Log4Jdbc-

https://code.google.com/p/log4jdbc/

score 2 · Answer 22 · edited Nov 14 '21 at 20:33

2

If you want Hibernate to print generated SQL queries with real values instead of question marks, add following entries to hibernate.cfg.xml/hibernate.properties:

show_sql=true
format_sql=true
use_sql_comments=true

And add following entries to log4j.properties:

log4j.logger.org.hibernate=INFO, hb
log4j.logger.org.hibernate.SQL=DEBUG
log4j.logger.org.hibernate.type=TRACE
log4j.appender.hb=org.apache.log4j.ConsoleAppender
log4j.appender.hb.layout=org.apache.log4j.PatternLayout

edited Nov 14 '21 at 20:33

answered Mar 04 '15 at 07:16

Vijay Bhatt

1,351
13
13

Hey single31 above lines has to be added in your hibernate configuration file then it will definitely work. I always post thing which I have done practically. – Vijay Bhatt Jul 02 '15 at 10:04

score 2 · Answer 23 · answered Mar 25 '16 at 05:12

<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>

How does this relate to the question? – hotzst Mar 25 '16 at 12:01 — hotzst, Mar 25 '16 at 12:01

score 2 · Answer 24 · edited Nov 14 '21 at 20:39

Using Hibernate 4 and slf4j/log4j2, I tried adding the following to 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.

score 1 · Answer 25 · edited Nov 14 '21 at 20:40

1

If you are using hibernate 3.2.X use this:

log4j.logger.org.hibernate.SQL=trace

instead of this:

log4j.logger.org.hibernate.SQL=debug

edited Nov 14 '21 at 20:40

answered Nov 11 '09 at 12:41

diy

3,590
3
19
16

score 1 · Answer 26 · edited Nov 14 '21 at 20:40

You can log this: net.sf.hibernate.hql.QueryTranslator

Output example:

2013-10-31 14:56:19,029 DEBUG [net.sf.hibernate.hql.QueryTranslator] HQL: select noti.id, noti.idmicrosite, noti.fcaducidad, noti.fpublicacion, noti.tipo, noti.imagen, noti.visible, trad.titulo, trad.subtitulo, trad.laurl, trad.urlnom, trad.fuente, trad.texto  from org.ibit.rol.sac.micromodel.Noticia noti join noti.traducciones trad where index(trad)='ca' and noti.visible='S' and noti.idmicrosite=985 and noti.tipo=3446       
2013-10-31 14:56:19,029 DEBUG [net.sf.hibernate.hql.QueryTranslator] SQL: select noticia0_.NOT_CODI as x0_0_, noticia0_.NOT_MICCOD as x1_0_, noticia0_.NOT_CADUCA as x2_0_, noticia0_.NOT_PUBLIC as x3_0_, noticia0_.NOT_TIPO as x4_0_, noticia0_.NOT_IMAGEN as x5_0_, noticia0_.NOT_VISIB as x6_0_, traduccion1_.NID_TITULO as x7_0_, traduccion1_.NID_SUBTIT as x8_0_, traduccion1_.NID_URL as x9_0_, traduccion1_.NID_URLNOM as x10_0_, traduccion1_.NID_FUENTE as x11_0_, traduccion1_.NID_TEXTO as x12_0_ from GUS_NOTICS noticia0_ inner join GUS_NOTIDI traduccion1_ on noticia0_.NOT_CODI=traduccion1_.NID_NOTCOD where (traduccion1_.NID_CODIDI='ca' )and(noticia0_.NOT_VISIB='S' )and(noticia0_.NOT_MICCOD=985 )and(noticia0_.NOT_TIPO=3446 )

Hey ... I cant find any examples of this approach. Could you provide any reference/examples/tutorials. And is it still same with the latest versions or hibernate/log4j or has it become some org.hibernate.QueryTranslator or something. Thanks — dev ray, Aug 27 '14 at 11:23
Hey ... I tried this, but this does not seem to work with save or update. I guess it only works for select queries, where translation from hql to sql comes into play — dev ray, Aug 28 '14 at 11:01

score 1 · Answer 27 · answered Aug 03 '16 at 17:51

All of the answers here are helpful, but if you're using a Spring application context XML to setup your session factory, setting the log4j SQL level variable only gets you part of the way there, you also have to set the hibernate.show_sql variable in the app context itself to get Hibernate to start actually showing the values.

ApplicationContext.xml has:

<property name="hibernateProperties">
            <value>
            hibernate.jdbc.batch_size=25
            ... <!-- Other parameter values here -->
            hibernate.show_sql=true
            </value>
 </property>

And your log4j file needs

log4j.logger.org.hibernate.SQL=DEBUG

score 1 · Answer 28 · answered May 29 '18 at 10:02

1

In Java:

Transform your query in TypedQuery if it's a CriteriaQuery (javax.persistence).

Then:

query.unwrap(org.hibernate.Query.class).getQueryString();

answered May 29 '18 at 10:02

Frédéric Nell

131
1
1
14

1

Thanks, It prints the query, but not the parameters that it used, there is a way to print the parameters too? – Liz Lamperouge Jun 04 '19 at 10:55
I'm sorry I don't think its possible to map them like this. I would log them and do the work manually as a workaround ;) – Frédéric Nell Nov 27 '20 at 14:00

score 0 · Answer 29 · edited Nov 14 '21 at 20:41

0

Use Wireshark or something similar:

None of the above mentioned answers will print SQL with parameters properly, or it is a pain to get it working with them. I achieved this by using WireShark, which captures all SQL/commands being send from the application to Oracle/MySQL etc. with the queries.

edited Nov 14 '21 at 20:41

answered Oct 10 '13 at 11:09

avijendr

3,958
2
31
46

3

Log4JDBC will. See above. – Alan Hay Oct 10 '13 at 15:18

score 0 · Answer 30 · edited Nov 14 '21 at 20:47

The simplest solution for me is implementing a regular string replacement to replace parameter inputs with parameter values (treating all parameters as string, for simplicity):

String debuggedSql = sql;
// then, for each named parameter
debuggedSql = debuggedSql.replaceAll(":"+key, "'"+value.toString()+"'");
// and finally
System.out.println(debuggedSql);

Or something similar for positional parameters (?).

Take care of null values and specific value types like date, if you want a run ready SQL to be logged.

score 0 · Answer 31 · edited Nov 14 '21 at 20:49

I had problems with all of the answers here. None of them actually gave me parameters for the Spring Data JPA query that was being passed an enum as the PK.

For Hibernate 5.3:

    <!-- silence the noise -->
    <Logger name="org.hibernate.search.engine.metadata.impl" additivity="false"/>
    <Logger name="org.hibernate.boot.internal" additivity="false"/>
    <Logger name="org.hibernate.engine.internal" additivity="false"/>
    <Logger name="org.hibernate.engine.jdbc" additivity="false"/>
    <Logger name="org.hibernate.engine.transaction" additivity="false"/>
    <Logger name="org.hibernate.engine.loading.internal" additivity="false"/>
    <Logger name="org.hibernate.engine.spi.CollectionEntry" additivity="false"/>
    <Logger name="org.hibernate.engine.query.spi.HQLQueryPlan" additivity="false"/>
    <Logger name="org.hibernate.engine.query.spi.QueryPlanCache" additivity="false"/>
    <Logger name="org.hibernate.engine.spi.IdentifierValue" additivity="false"/>
    <Logger name="org.hibernate.engine.spi.CascadingActions" additivity="false"/>
    <Logger name="org.hibernate.engine.spi.ActionQueue" additivity="false"/>
    <Logger name="org.jboss.logging"/>
    
    <Logger name="org.hibernate.SQL" level="debug" additivity="false">
      <AppenderRef ref="Console"/>
    </Logger>
    <Logger name="org.hibernate.type.descriptor.sql.BasicBinder" level="trace" additivity="false">
      <AppenderRef ref="Console"/>
    </Logger>
    <Logger name="org.hibernate.engine" level="trace" additivity="false">
      <AppenderRef ref="Console"/>
    </Logger>

With hibernate.format_sql set to true for pretty print, this is a sample of my output:

17:00:00,664 [TRACE] Named parameters: {1=DE} [main] org.hibernate.engine.spi.QueryParameters.traceParameters(QueryParameters.java:325) 
17:00:00,671 [DEBUG] 
    select
        countrysub0_.code as code1_23_,
        countrysub0_1_.country_subdivision as country_1_61_ 
    from
        country_subdivision countrysub0_ 
    left outer join
        jurisdiction_country_subdivision countrysub0_1_ 
            on countrysub0_.code=countrysub0_1_.jurisdiction 
    where
        countrysub0_.code=? [main] org.hibernate.engine.jdbc.spi.SqlStatementLogger.logStatement(SqlStatementLogger.java:103)

I tried simply setting org.hibernate.engine.spi.QueryParameters to trace, but for some reason the named parameters kept getting silenced, so I silenced everything else that was logging instead. It doesn't seem to log all parameters though, so I still needed the BasicBinding log as well.

score 0 · Answer 32 · edited Sep 06 '21 at 13:30

0

you have to configure as below:

# Hibernate logging options (INFO only shows startup messages)
log4j.logger.org.hibernate=INFO

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

edited Sep 06 '21 at 13:30

Paul Roub

36,322
27
84
93

answered Sep 06 '21 at 13:27

ayman.mostafa

451
6
5

score 0 · Answer 33 · edited Dec 08 '21 at 18:18

If you are using spring-boot you can use log4jdbc-spring-boot-starter dependency, which is a fork of org.bgee.log4jdbc-log4j2 .

In pom.xml I used the following dependency:

   <dependency>
        <groupId>com.integralblue</groupId>
        <artifactId>log4jdbc-spring-boot-starter</artifactId>
        <version>2.0.0</version>
    </dependency>

In documentation it's mentioned that if you just include this dependency SQL logging will not work, we have to specify following property in application.properties

logging.level.jdbc.sqlonly=INFO

but with

2.0.0 version, All the logging properties are set to info by default . at time of writing this answer the usage count for 2.0.0 is less compared to 1.0.2

So with 2.0.0 even if you don't specify any properties for logging sql following properties are set by default

logging.level.jdbc.sqlonly=INFO
logging.level.jdbc.resultset=INFO
logging.level.jdbc.connection=INFO
logging.level.jdbc.resultsettable=INFO
logging.level.jdbc.audit=INFO
logging.level.jdbc.sqltiming=INFO

So if you want only SQL queries printed with ? replaced with actual values and avoid unnecessary log from result set these properties explicitly to

logging.level.jdbc.sqlonly=INFO
logging.level.jdbc.resultset=OFF
logging.level.jdbc.connection=OFF
logging.level.jdbc.resultsettable=OFF
logging.level.jdbc.audit=OFF
logging.level.jdbc.sqltiming=OFF

How to print a query string with parameter values when using Hibernate

33 Answers33

Update 2016

Linked

Related