12 Replies Latest reply on Aug 30, 2011 2:55 PM by smarlow

    Hibernate' query logging doesn't work any more

    juergen.zimmermann

      In the past I could set the log category "org.hibernate.SQL" to DEBUG and the generated SQL statements were logged in e.g. the log file. However, in the new JBoss builds (I tried build 1460) nothing is logged. I also tried org.hibernate.sql without success. Is this feature gone?

        • 1. Re: Hibernate' query logging doesn't work any more
          jaikiran

          Someone in the Hibernate forums might know https://forum.hibernate.org/viewforum.php?f=1

          • 2. Re: Hibernate' query logging doesn't work any more
            are.tysnes

            Seting the log level to TRACE (to get everything) gave me this:

             

            14:51:17,571 DEBUG [org.hibernate.engine.jdbc.spi.SqlStatementLogger] (http--127.0.0.1-8080-6)

                select

            <snip.. our sql prettyprinted>

             

            14:51:17,571 TRACE [org.hibernate.type.descriptor.sql.BasicBinder] (http--127.0.0.1-8080-6) binding parameter [1] as [INTEGER] - 10000000

            14:51:17,571 TRACE [org.hibernate.engine.jdbc.internal.proxy.AbstractStatementProxyHandler] (http--127.0.0.1-8080-6) Handling invocation of statement method [setInt]

            14:51:17,571 TRACE [org.hibernate.engine.jdbc.internal.proxy.PreparedStatementProxyHandler] (http--127.0.0.1-8080-6) Binding via setInt: [1, 10000000]

             

            We use JPA 2 generated queries

            • 3. Re: Hibernate' query logging doesn't work any more
              juergen.zimmermann

              Are, for which package resp. category are you setting the log level to TRACE?

              • 4. Re: Hibernate' query logging doesn't work any more
                are.tysnes

                Sorry.. I should have mentioned that.. I was just playing with the root-logger to debug some strange as 7 behaviour when I noticed the hibernate trace/debug:

                 

                JBoss Console

                - Core

                -- Logging

                 

                root-logger -> Log level TRACE

                 

                Click on the Handler tab

                 

                File and/or Console handler -> Log level TRACE

                 

                Just curious.. why don't you use the hibernate properties hibernate.show_sql and hibernate.format_sql in your persistence.xml ?

                 

                <property name="hibernate.show_sql" value="true"/>

                <property name="hibernate.format_sql" value="true"/>

                • 5. Re: Hibernate' query logging doesn't work any more
                  juergen.zimmermann

                  The property hibernate.show_sql just logs to the console, but not to server.log.

                  • 6. Re: Hibernate' query logging doesn't work any more
                    are.tysnes

                    Sounds strange.. the sql is showing up in both console and server.log in our JPA 2 project. Nothing fancy in the log4j.properties as I can tell which should force this. This was also default behaviour in AS 6 as far as I know.

                     

                    Let me know if you need to investigate any of the properties files in our project.

                    • 7. Re: Hibernate' query logging doesn't work any more
                      juergen.zimmermann

                      Could you post the section <subsystem xmlns="urn:jboss:domain:logging:1.0"> inside standalone/configuration/standalone.xml , please?

                      • 8. Re: Hibernate' query logging doesn't work any more
                        are.tysnes
                        standalone.xml

                                <subsystem xmlns="urn:jboss:domain:logging:1.0">

                                    <console-handler name="CONSOLE" autoflush="true">

                                        <level name="INFO"/>

                                        <formatter>

                                            <pattern-formatter pattern="%d{HH:mm:ss,SSS} %-5p [%c] (%t) %s%E%n"/>

                                        </formatter>

                                    </console-handler>

                                    <periodic-rotating-file-handler name="FILE" autoflush="true">

                                        <level name="INFO"/>

                                        <formatter>

                                            <pattern-formatter pattern="%d{HH:mm:ss,SSS} %-5p [%c] (%t) %s%E%n"/>

                                        </formatter>

                                        <file relative-to="jboss.server.log.dir" path="server.log"/>

                                        <suffix value=".yyyy-MM-dd"/>

                                    </periodic-rotating-file-handler>

                                    <logger category="com.arjuna">

                                        <level name="WARN"/>

                                    </logger>

                                    <logger category="org.apache.tomcat.util.modeler">

                                        <level name="WARN"/>

                                    </logger>

                                    <logger category="sun.rmi">

                                        <level name="WARN"/>

                                    </logger>

                                    <root-logger>

                                        <level name="INFO"/>

                                        <handlers>

                                            <handler name="CONSOLE"/>

                                            <handler name="FILE"/>

                                        </handlers>

                                    </root-logger>

                                </subsystem>

                         

                        persistence.xml

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

                        <persistence version="1.0"

                            xmlns="http://java.sun.com/xml/ns/persistence

                            xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"

                            xsi:schemaLocation="http://java.sun.com/xml/ns/persistence

                                http://java.sun.com/xml/ns/persistence/persistence_1_0.xsd">

                            <persistence-unit name="MyAppEntityPU">

                                <provider>org.hibernate.ejb.HibernatePersistence</provider>

                                <jta-data-source>java:jboss/datasources/MySqlMyAppDS</jta-data-source>

                         

                                <class>my-app.entity.CategoryEntity</class>

                                <class>my-app.entity.ChannelEntity</class>

                         

                                <properties>

                                    <property name="openjpa.jdbc.DBDictionary" value="org.apache.openjpa.jdbc.sql.MySQLDictionary" />

                                    <property name="jboss.entity.manager.jndi.name" value="java:/MyAppEntity"/>

                                    <property name="jboss.entity.manager.factory.jndi.name" value="java:/MyAppFactory"/>

                                    <property name="hibernate.show_sql" value="true"/>

                                    <property name="hibernate.format_sql" value="true"/>

                                    <property name="hibernate.max_fetch_depth" value="4"/>

                                    <property name="hibernate.default_batch_fetch_size" value="365"/>

                                </properties>

                            </persistence-unit>

                        </persistence>

                         

                        log4j.properties

                        log4j.rootCategory=TRACE, FILE

                         

                        log4j.logger.com.dappit.Dapper.parser=ERROR

                        log4j.logger.org.w3c.tidy=FATAL

                         

                        log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender

                        log4j.appender.CONSOLE.layout=org.apache.log4j.PatternLayout

                        log4j.appender.CONSOLE.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %-5p %c - %m%n

                         

                        log4j.appender.FILE=org.apache.log4j.DailyRollingFileAppender

                        log4j.appender.FILE.File=${jboss.server.log.dir}/myapp.log

                        log4j.appender.FILE.Append=true

                        log4j.appender.FILE.DatePattern='.'yyyy-MM-dd

                        log4j.appender.FILE.layout=org.apache.log4j.PatternLayout

                        log4j.appender.FILE.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %40.40C.%-20.20M(%3.3L) %-6.6p:%m%n

                         

                        log4j.logger.myapp=TRACE, FILE, CONSOLE

                        log4j.additivity.myapp=false

                         

                        log4j.logger.org.hibernate=WARN, FILE

                        log4j.additivity.org.hibernate=false

                         

                        # The PERF loggers logs to a separate performance log-file to avoid polluting and to ease future

                        # parsing and interpretation of performance.

                        log4j.appender.PERF=org.apache.log4j.DailyRollingFileAppender

                        log4j.appender.PERF.File=${jboss.server.log.dir}/myapp.perf.log

                        log4j.appender.PERF.Append=true

                        log4j.appender.PERF.DatePattern='.'yyyy-MM-dd

                        log4j.appender.PERF.layout=org.apache.log4j.PatternLayout

                        log4j.appender.PERF.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %m%n

                        log4j.logger.performance=TRACE, PERF

                         

                        console output

                        08:11:16,406 INFO  [stdout] (http--127.0.0.1-8080-1) Hibernate:

                        08:11:16,407 INFO  [stdout] (http--127.0.0.1-8080-1)     SELECT

                        08:11:16,407 INFO  [stdout] (http--127.0.0.1-8080-1)         gp.*

                        08:11:16,408 INFO  [stdout] (http--127.0.0.1-8080-1)     FROM

                        ...

                        ...

                         

                        server.log

                        08:11:16,013 INFO  [stdout] (http--127.0.0.1-8080-1) Hibernate:

                        08:11:16,014 INFO  [stdout] (http--127.0.0.1-8080-1)     SELECT

                        08:11:16,014 INFO  [stdout] (http--127.0.0.1-8080-1)         gp.*

                        08:11:16,015 INFO  [stdout] (http--127.0.0.1-8080-1)     FROM

                        ...

                        ...

                        • 9. Re: Hibernate' query logging doesn't work any more
                          juergen.zimmermann

                          The only significant difference I see is that you're having a log4j.properties file. In which directory do you have log4j.properties?

                          • 10. Re: Hibernate' query logging doesn't work any more
                            are.tysnes

                            /src/main/resources in the webapp project

                             

                            and it's located in WEB-INF\classes in the war file

                             

                            I doubt the log4j file has impact on the server.log .. the sql is not logged in my application log declared in log4j.properties.

                            • 11. Re: Hibernate' query logging doesn't work any more
                              juergen.zimmermann

                              org.hibernate.engine.jdbc.spi.SqlStatementLogger is the replacment for org.hibernate.SQL. See  https://issues.jboss.org/browse/AS7-1522

                              • 12. Re: Hibernate' query logging doesn't work any more
                                smarlow

                                As per the below linked code change, "org.hibernate.SQL" will soon work again for logging SQL statements.  When that happens, "org.hibernate.engine.jdbc.spi.SqlStatementLogger" will no longer work.

                                 

                                https://github.com/hibernate/hibernate-core/commit/75e0ba4ce353629beee937a447d8252069fddcb0