[FIXED] Call getNextException to see the cause : How to make Hibernate / JPA show the DB server message for an exception

Issue

I am using Postgresql, Hibernate and JPA. Whenever there is an exception in the database, I get something like this which is not very helpful as it does not show what really went wrong on the DB server.

Caused by: java.sql.BatchUpdateException: Batch entry 0 update foo set ALERT_FLAG='3' was aborted.  Call getNextException to see the cause.
    at org.postgresql.jdbc2.AbstractJdbc2Statement$BatchResultHandler.handleError(AbstractJdbc2Statement.java:2621)
    at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1837)
    at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:407)
    at org.postgresql.jdbc2.AbstractJdbc2Statement.executeBatch(AbstractJdbc2Statement.java:2754)
    at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeBatch(NewProxyPreparedStatement.java:1723)
    at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:70)
    at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:268)
    ... 82 more

I want the exception message from the database to appear in the application's log.

I came across this article which uses an Aspect to populate the exception chain which is otherwise not populated properly in case of SQLExceptions.

Is there a way to fix this without using Aspects or any custom code. Ideal solution would involve only config file changes.

Solution

There is no need to write any custom code to achieve this - Hibernate will log the exception cause by default. If you can't see this, Hibernate logging must not be set up correctly. Here's an example with slf4j+log4j, and using Maven for dependency management.

src/main/java/pgextest/PGExceptionTest.java

public class PGExceptionTest {

    public static void main(String[] args) throws Exception {

        EntityManagerFactory entityManagerFactory = Persistence.createEntityManagerFactory(
                "pgextest");
        EntityManager entityManager = entityManagerFactory.createEntityManager();
        entityManager.getTransaction().begin();
        // here I attempt to persist an object with an ID that is already in use
        entityManager.persist(new PGExceptionTestBean(1));
        entityManager.getTransaction().commit();
        entityManager.close();
    }
}

src/main/resources/log4j.properties

log4j.rootLogger=ERROR, stdout

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%5p [%t] - %m%n

src/main/resources/META-INF/persistence.xml

<persistence 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_2_0.xsd"
        version="2.0">
    <persistence-unit name="pgextest">
        <properties>
            <property name="javax.persistence.jdbc.driver" value="org.postgresql.Driver"/>
            <property name="javax.persistence.jdbc.url" value="jdbc:postgresql://localhost/pgextest"/>
            <property name="javax.persistence.jdbc.user" value="postgres"/>
            <property name="javax.persistence.jdbc.password" value="postgres"/>
            <property name="hibernate.dialect" value="org.hibernate.dialect.PostgreSQLDialect"/>
            <property name="hibernate.jdbc.batch_size" value="5"/>
        </properties>
    </persistence-unit>
</persistence>

pom.xml

<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">

    <modelVersion>4.0.0</modelVersion>

    <groupId>pgextest</groupId>
    <artifactId>pgextest</artifactId>
    <version>0.0.1-SNAPSHOT</version>

    <build>
        <plugins>
            <plugin>
                <artifactId>maven-compiler-plugin</artifactId>
                <configuration>
                    <source>1.6</source>
                    <target>1.6</target>
                </configuration>
            </plugin>
        </plugins>
    </build>

    <dependencies>
        <dependency>
            <groupId>org.hibernate</groupId>
            <artifactId>hibernate-entitymanager</artifactId>
            <version>3.6.9.Final</version>
        </dependency>   

        <dependency>
            <groupId>postgresql</groupId>
            <artifactId>postgresql</artifactId>
            <version>9.1-901.jdbc4</version>
            <scope>runtime</scope>
        </dependency>

        <dependency>
            <groupId>org.slf4j</groupId>
            <artifactId>slf4j-log4j12</artifactId>
            <version>1.6.1</version>
            <scope>runtime</scope>
        </dependency>

        <dependency>
            <groupId>log4j</groupId>
            <artifactId>log4j</artifactId>
            <version>1.2.15</version>
            <scope>runtime</scope>
        </dependency>
    </dependencies>
</project>

Executing the main method will then log the following:

ERROR [main] - Batch entry 0 insert into PGExceptionTestBean (label, id) values (NULL, '1') was aborted.  Call getNextException to see the cause.
ERROR [main] - ERROR: duplicate key value violates unique constraint "pgexceptiontestbean_pkey"

It's probably worth mentioning that you can disable the JDBC batching that wraps the original exception by setting the property hibernate.jdbc.batch_size to 0 (needless to say you probably don't want to do this in production.)

Answered By - ryanp