logging hibernate parameter values using logback and slf4j

Question

I use hibernate, spring mvc, and eclipse. In my eclipse console, the hibernate sql displays in the form of:

Hibernate: insert into some_table (fieldname1, fieldname2, fieldname3, fieldname4)  
values (?, ?, ?, ?)

How can I get the console to print out the values that are being inserted in the place of the question marks? I am committed to using slf4j and logback for the logging in my app.

Here is my logback.xml:

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="30 seconds">

    <contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator">
        <resetJUL>true</resetJUL>
    </contextListener>

    <!-- To enable JMX Management -->
    <jmxConfigurator/>

    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%-5level %logger{0} - %msg%n</pattern>
        </encoder>
    </appender>

    <!--<logger name="org.hibernate" level="debug"/> -->
    <logger name="mypackagename.myappname" level="debug"/>
    <logger name="org.hibernate.SQL" additivity="false" level="DEBUG" />
    <logger name="org.hibernate.type" additivity="false" level="TRACE" />

    <root level="info">
        <appender-ref ref="console"/>
    </root>
</configuration>

Answer 1

The correct working answer turned out to be:

<?xml version="1.0" encoding="UTF-8"?>
<configuration scan="true" scanPeriod="30 seconds">

    <contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator">
        <resetJUL>true</resetJUL>
    </contextListener>

    <!-- To enable JMX Management -->
    <jmxConfigurator/>

    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%-5level %logger{0} - %msg%n</pattern>
        </encoder>
    </appender>

    <logger name="mypackagename.myappname" level="TRACE"/>
    <logger name="org.hibernate.SQL" level="DEBUG" />
    <logger name="org.hibernate.type" level="TRACE" />

    <root level="info">
        <appender-ref ref="console"/>
    </root>
</configuration>

Answer 2

Configure org.hibernate.type.descriptor.sql.BasicBinder package to log TRACE level:

 <logger name="org.hibernate.type.descriptor.sql.BasicBinder" additivity="false" level="TRACE" />

Answer 3

This is some info about the the 2 offered answers. Both worked for me.

For printing the query you want:

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

To print it "pretty" you can use the jpaProperties.put("hibernate.format_sql", true|false); More info in [https://docs.jboss.org/hibernate/stable/core.old/reference/en/html/configuration-optional.html]

Now regarding the values. The accepted:

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

The output would be:

2017-02-12 14:16:57 DEBUG org.hibernate.SQL - 
    select
        producttyp0_.idProductType as idProduc1_25_1_,
        producttyp0_.deleted as deleted2_25_1_,
        producttyp0_.description as descript3_25_1_,
        producttyp0_.name as name4_25_1_,
        products1_.idProductType as idProduc6_25_3_,
        products1_.idProduct as idProduc1_24_3_,
        products1_.idProduct as idProduc1_24_0_,
        products1_.deleted as deleted2_24_0_,
        products1_.maxQty as maxQty3_24_0_,
        products1_.name as name4_24_0_,
        products1_.price as price5_24_0_,
        products1_.idProductType as idProduc6_24_0_ 
    from
        ProductType producttyp0_ 
    left outer join
        Product products1_ 
            on producttyp0_.idProductType=products1_.idProductType 
    where
        producttyp0_.idProductType=?
2017-02-12 14:16:57 TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [INTEGER] - [35]
2017-02-12 14:16:57 TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([idProduc1_24_0_] : [INTEGER]) - [null]
2017-02-12 14:16:57 TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([deleted2_25_1_] : [INTEGER]) - [0]
2017-02-12 14:16:57 TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([descript3_25_1_] : [VARCHAR]) - [desc]
2017-02-12 14:16:57 TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([name4_25_1_] : [VARCHAR]) - [c0my6zko[test]]
2017-02-12 14:16:57 TRACE o.h.t.descriptor.sql.BasicExtractor - extracted value ([idProduc6_25_3_] : [INTEGER]) - [null]

---

And the other offered solution

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

The output would be:

2017-02-12 14:18:55 DEBUG org.hibernate.SQL - 
    select
        producttyp0_.idProductType as idProduc1_25_1_,
        producttyp0_.deleted as deleted2_25_1_,
        producttyp0_.description as descript3_25_1_,
        producttyp0_.name as name4_25_1_,
        products1_.idProductType as idProduc6_25_3_,
        products1_.idProduct as idProduc1_24_3_,
        products1_.idProduct as idProduc1_24_0_,
        products1_.deleted as deleted2_24_0_,
        products1_.maxQty as maxQty3_24_0_,
        products1_.name as name4_24_0_,
        products1_.price as price5_24_0_,
        products1_.idProductType as idProduc6_24_0_ 
    from
        ProductType producttyp0_ 
    left outer join
        Product products1_ 
            on producttyp0_.idProductType=products1_.idProductType 
    where
        producttyp0_.idProductType=?
2017-02-12 14:18:55 TRACE o.h.type.descriptor.sql.BasicBinder - binding parameter [1] as [INTEGER] - [36]

Personally I like the 2nd one because is less info (avoiding the o.h.t.descriptor.sql.BasicExtractor), but its up to the project.

Hope it gives a little more info about what to include.