Archive

Archive for the ‘Hibernate’ Category

I use connection pooling to fix a hibernate problem

Friday, 31. July 2009 Andreas Höhmann Leave a comment

Yesterday i had a problem with hibernate envers and a sql-server database and the solution was to switch from a “non pooled” to a “pooled” datasource with JPA/hibernate/spring.

The problem

I got this wonderfull stacktrace:

Caused by: org.hibernate.exception.JDBCConnectionException: Cannot open connection
 at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:97)
 at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:66)
 at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:52)
 at org.hibernate.jdbc.ConnectionManager.openConnection(ConnectionManager.java:449)
 at org.hibernate.jdbc.ConnectionManager.getConnection(ConnectionManager.java:167)
 at org.hibernate.jdbc.AbstractBatcher.prepareQueryStatement(AbstractBatcher.java:161)
 at org.hibernate.loader.Loader.prepareQueryStatement(Loader.java:1573)
 at org.hibernate.loader.Loader.doQuery(Loader.java:696)
 at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:259)
 at org.hibernate.loader.Loader.doList(Loader.java:2228)
 at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2125)
 at org.hibernate.loader.Loader.list(Loader.java:2120)
 at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:401)
 at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:361)
 at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:196)
 at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1148)
 at org.hibernate.impl.QueryImpl.list(QueryImpl.java:102)
 at org.hibernate.envers.entities.mapper.relation.lazy.initializor.AbstractCollectionInitializor.initialize(AbstractCollectionInitializor.java:62)
 at org.hibernate.envers.entities.mapper.relation.lazy.proxy.CollectionProxy.checkInit(CollectionProxy.java:47)
 at org.hibernate.envers.entities.mapper.relation.lazy.proxy.CollectionProxy.toString(CollectionProxy.java:118)
 at org.apache.commons.beanutils.converters.StringConverter.convert(StringConverter.java:57)
 at org.apache.commons.beanutils.ConvertUtilsBean.convert(ConvertUtilsBean.java:400)
 at org.apache.commons.beanutils.BeanUtilsBean.getNestedProperty(BeanUtilsBean.java:699)
 at org.apache.commons.beanutils.BeanUtilsBean.getProperty(BeanUtilsBean.java:723)
 at org.apache.commons.beanutils.BeanUtilsBean.describe(BeanUtilsBean.java:504)
 at org.apache.commons.beanutils.BeanUtils.describe(BeanUtils.java:145)
 at com.siemens.spice.common.persistence.revision.BeanDiff.getAllProperties(BeanDiff.java:170)

The background story

We use envers for revision-management of persisted objects. Our application have a “changelog-view” for change-statistics (which object changed from version A to version B, differences between these versions for each object etc.):

changelog_table

During the creation of the table data our code find out the changed objects (with a envers query). We use our RevisionsDaoImpl for that, i.e. the getRevisions method:


@Repository
@Transactional
class RevisionsDaoImpl<T,KEY, REVINFO> {

 protected final Class<T> classOfT;
 protected EntityManager entityManager;

 public RevisionsDaoImpl(final Class<T> clazz) {
 super(clazz);
 }

 public List<Revision<T, REVINFO>> getRevisions(final int theRevisionFrom, final int theRevisionTo) {
 final AuditReader reader = ExtendedAuditReaderFactory.get(entityManager);
 AuditQuery query = reader.createQuery().forRevisionsOfEntity(classOfT, false, true);
 query = query.addOrder(AuditEntity.revisionNumber().asc());
 // all items newer or equal than theRevisionFrom
 query = query.add(AuditEntity.revisionNumber().ge(Integer.valueOf(theRevisionFrom)));
 // all items older or equal than theRevisionTo
 query = query.add(AuditEntity.revisionNumber().le(Integer.valueOf(theRevisionTo)));
 return fetchRevisions(query, reader);
 }

 protected List<Revision<T, REVINFO>> fetchRevisions(final AuditQuery query, final AuditReader reader) {
 try {
 final Object resultList = query.getResultList();
 final List<Object[]> queryResult = (List<Object[]>) resultList;
 final List<Revision<T, REVINFO>> result = new ArrayList<Revision<T, REVINFO>>(queryResult.size());
 for (final Object[] array : queryResult) {
 result.add(new RevisionImpl<T, REVINFO>((T) array[0], (REVINFO) array[1], (RevisionType) array[2]));
 }
 return result;
 } catch (final RevisionDoesNotExistException ex) {
 return null;
 } catch (final NoResultException ex) {
 return null;
 }
 }
 ...
}

In the datatable bean we are loading all revisions (from version A to version B) . Then we use org.apache.commons.beanutils.BeanUtils to get all properties from version A and B and then we compare these properties for each object. The result is the list of changed objects and all differences for each object (diffRevision(T versionA, T version B)):


protected List<T> getChangeLog() {
 final List<T> result = new ArrayList<T>();
 final VersionedDao<T, Integer, RevisionInfo> dao = getRevisionsDao();
 // get all revisions from A to B for objects T
 final List<Revision<T, RevisionInfo>> revs = dao.getRevisions(fromRevision.intValue(), toRevision.intValue());
 // get A revision and B revision for each object T with revisions
 final Map<Integer, List<Revision<T, RevisionInfo>>> oldNewRevisions = dao.getOldNewRevisions(revs, fromRevision, toRevision);
 // build diff for each object
 for (final Revision rev : revs) {
 final T entity = rev.getEntity();
 final Revision<T, RevisionInfo> oldestRevision = oldNewRevisions.get(entity.getId()).get(0);
 final Revision<T, RevisionInfo> newestRevision = oldNewRevisions.get(entity.getId()).get(1);
 result.add(diffRevision(newestRevision, oldestRevision));
 }

In the ui layer we are using rich:dataTable which have sortable columns. The above exception occured if a column-sort was triggered.

Maybe inside hibernate or envers too many transactions or connections created and not fast enough released during the table data creation or the table rendering (lazy loaded properties may play a role in this game). Or the jdbc driver we are using is the bad guy (net.sourceforge.jtds:jtds:1.2).

The solution

Anyway! A workaround was to use a pooled datasource instead of a standard datasource. I found a list of pooling frameworks for hibernate here. The Hibernate  documentation contains some information too. I decide to try the 3CPO framework. Its very easy to add  a new dependency:


<dependency>
 <groupId>org.hibernate</groupId>
 <artifactId>hibernate-c3p0</artifactId>
 <version>3.3.1.GA</version>
 <scope>runtime</scope>
 </dependency>

And change the datasource:


<bean id="dataSource" class="org.springframework.jdbc.datasource.DriverManagerDataSource">
<property name="driverClassName" value="${jpa.driver}" />
<property name="url" value="${jpa.url}" />
<property name="username" value="${jpa.username}" />
<property name="password" value="${jpa.password}" />
</bean>

<bean id="pooledDataSource" class="com.mchange.v2.c3p0.ComboPooledDataSource" destroy-method="close">
<property name="jdbcUrl" value="${jpa.url}" />
<property name="user" value="${jpa.username}" />
<property name="password" value="${jpa.password}" />
<property name="initialPoolSize" value="1" />
<property name="minPoolSize" value="1" />
<property name="maxPoolSize" value="3" />
<property name="idleConnectionTestPeriod" value="500" />
<property name="acquireIncrement" value="1" />
<property name="maxStatements" value="50" />
<property name="numHelperThreads" value="1" />
</bean>

<bean id="entityManagerFactory" class="org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean">
<property name="loadTimeWeaver">
 <bean class="org.springframework.instrument.classloading.InstrumentationLoadTimeWeaver" />
 </property>
<property name="dataSource" ref="pooledDataSource" />
<property name="persistenceUnitName" value="sid-admin-web-persistence" />
<property name="jpaVendorAdapter">
 <bean class="org.springframework.orm.jpa.vendor.HibernateJpaVendorAdapter">
<property name="showSql" value="false" />
<property name="generateDdl" value="true" />
<property name="databasePlatform" value="${jpa.hibernate.dialect}" />
 </bean>
 </property>
</bean>
<bean id=”dataSource” class=”org.springframework.jdbc.datasource.DriverManagerDataSource”>
<property name=”driverClassName” value=”${jpa.driver}” />
<property name=”url” value=”${jpa.url}” />
<property name=”username” value=”${jpa.username}” />
<property name=”password” value=”${jpa.password}” />
</bean>

<bean id=”pooledDataSource” class=”com.mchange.v2.c3p0.ComboPooledDataSource” destroy-method=”close”>
<description>
Wir muessen eine “pooled data source” benutzen weil im changelog massiv transaktionen/connections
erzeugt werden, dies fuehrt in verbindung mit dem sql-server zu einem knappwerden der sockets und
zu einem jdbc-error
</description>
<property name=”driverClass” value=”${jpa.driver}” />
<property name=”jdbcUrl” value=”${jpa.url}” />
<property name=”user” value=”${jpa.username}” />
<property name=”password” value=”${jpa.password}” />
<property name=”initialPoolSize” value=”1″ />
<property name=”minPoolSize” value=”1″ />
<property name=”maxPoolSize” value=”3″ />
<property name=”idleConnectionTestPeriod” value=”500″ />
<property name=”acquireIncrement” value=”1″ />
<property name=”maxStatements” value=”50″ />
<property name=”numHelperThreads” value=”1″ />
</bean>

<bean id=”entityManagerFactory” class=”org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean”>
<property name=”loadTimeWeaver”>
<bean class=”org.springframework.instrument.classloading.InstrumentationLoadTimeWeaver” />
</property>
<property name=”dataSource” ref=”dataSource” />
<property name=”persistenceUnitName” value=”sid-admin-web-persistence” />
<property name=”jpaVendorAdapter”>
<bean class=”org.springframework.orm.jpa.vendor.HibernateJpaVendorAdapter”>
<property name=”showSql” value=”false” />
<property name=”generateDdl” value=”true” />
<property name=”databasePlatform” value=”${jpa.hibernate.dialect}” />
</bean>
</property>
</bean>

Hibernate sql logging with values

Wednesday, 3. June 2009 Andreas Höhmann Leave a comment

As you might know already, Hibernate supports logging for sql-statements. Your Spring-configuration (e.g. spring-database.xml) must contain this:


<bean id="entityManagerFactory"
 class="org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean">
<property name="dataSource" ref="dataSource" />
<property name="persistenceUnitName" value="logging-test" />
<property name="jpaVendorAdapter">
 <bean>
<property name="showSql" value="true" />
<property name="generateDdl" value="true" />
<property name="databasePlatform" value="${jpa.hibernate.dialect}" />
 </bean>
 </property>
<property name="jpaProperties" value="hibernate.dialect=${jpa.hibernate.dialect}" />
 </bean>

With showSql=true hibernate will show you logmessages like this:

Hibernate:
   delete
   from
      SoftwareCategory_SoftwareCategory
   where
      SoftwareCategory_id=?
Hibernate:
   update
      SoftwareCategory
   set
      concurrentVersion=?,
      CATEGORY_NAME=?,
      PARENT_ID=?
   where
      id=?
      and concurrentVersion=?
Hibernate:
   insert
   into
      SoftwareCategory_SoftwareCategory
      (SoftwareCategory_id, POSITION, children_id)
   values
      (?, ?, ?)

To see the values and not the placeholders (?) you must define the loglevel trace for hibernate-types in the log4j.xml:


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

Then you will see logmessages like this:

Hibernate:
   insert
   into
      SoftwareCategory_SoftwareCategory
      (SoftwareCategory_id, POSITION, children_id)
   values
      (?, ?, ?)
NullableType:151 - binding '68' to parameter: 1
NullableType:151 - binding '0' to parameter: 2
NullableType:151 - binding '69' to parameter: 3

Not bad but there is a better way for this :-)

Yesterday i found the project JDBCLogger.  They have implemented a “JDBC-Proxy” with logging support. Its Maven-ready and comes with a easy Spring-integration. So how can we use this cool stuff … it is so easy:

1. Define the JDBCLogger dependencies in the pom.xml:


<dependencies>
<dependency>
 <groupId>net.sourceforge.jdbclogger</groupId>
 <artifactId>jdbclogger-core</artifactId>
 <version>0.7-SNAPSHOT</version>
 </dependency>
 <dependency>
 <groupId>net.sourceforge.jdbclogger</groupId>
 <artifactId>jdbclogger-spring</artifactId>
 <version>0.7-SNAPSHOT</version>
 </dependency>
 </dependencies>

The informations from the installation-guide on the project-site is a little too old, so the maven-repository http://jdbclogger.sourceforge.net/m2-repo/ doesn’t exists. No problem we can build jdbclogger-core and jdbclogger-spring by ourself (read more). The simplest way to build the two artifacts is:

  • checkout from  svn
  • edit master-pom, comment out all modules, leave only core and spring active
  • run mvn clean install from root-dir

2. Change your Spring-configuration, switch showSql off and add the following bean:


<bean id="jdbcLoggerConfig"
 class="net.sourceforge.jdbclogger.spring.JdbcLoggerBeanPostProcessor">
<property name="enabled" value="true" />
<property name="dataSourceConfigurations">
	<list>
 <bean class="net.sourceforge.jdbclogger.spring.JdbcLoggerDataSourceConfiguration">
<property name="dataSourceBeanName" value="dataSource" />
<property name="driverClassNamePropertyName" value="driverClassName" />
 </bean>
 </list>
 </property>
<property name="targetDriverClassNames">
	<list>
 <value>${jpa.driver}</value>
 </list>
 </property>
 </bean>

3.  Activate logging in the log4j.xml:


<category name="net.sourceforge.jdbclogger">
<priority value="debug" />
 </category>
<category name="net.sourceforge.jdbclogger.spring">
<priority value="error" />
 </category>

Thats it :-) Now you will see logmessages like this:

JdbcLoggerDriver:65 – Wrapper ‘net.sourceforge.jdbclogger.JdbcLoggerDriver’ successfully registed for driver ‘com.mysql.jdbc.Driver’
PreparedStatementWrapper:156 – Prepared Statement : select softwareca0_.id as id0_, softwareca0_.concurrentVersion as concurre2_0_, softwareca0_.CATEGORY_NAME as CATEGORY3_0_, softwareca0_.PARENT_ID as PARENT4_0_ from SoftwareCategory softwareca0_ where softwareca0_.PARENT_ID is null
StatementWrapper:45 – Statement : delete from softwarecategory_softwareobject
PreparedStatementWrapper:156 – Prepared Statement : insert into SoftwareCategory_SoftwareCategory (SoftwareCategory_id, POSITION, children_id) values (‘92′, ‘3′, ‘96′)