Spring + JPA not committing data

[frankb]

I have a very simple annotated POJO. I'm using toplink-essentials. Unit tests succeed in inserting/deleting/updating. The problem I have is when I use the code from the web tier. Reading data is fine. Inserting or updating does nothing. No errors. From the log, I can see the EntityManager being created then immediately closed. The same behaviour occurs with MySQL 5.0.24 and PostgreSQL 8.14.

Is it something stupid that I'm missing?

Here's my applicationContext.xml:

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xmlns:tx="http://www.springframework.org/schema/tx"
    xsi:schemaLocation="http://www.springframework.org/schema/beans
      http://www.springframework.org/schema/beans/spring-beans.xsd
      http://www.springframework.org/schema/tx
      http://www.springframework.org/schema/tx/spring-tx.xsd">
	
	<bean id="cdDao" class="frankb.model.dao.CdDao">
		<property name="entityManagerFactory" ref="entityManagerFactory"/>
	</bean>
	
	
	
	<bean id="cdService" class="frankb.web.xfire.CdService">
		<property name="cdDao"><ref bean="cdDao"/></property>
	</bean>



	<bean id="entityManagerFactory" class="org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean">
		<property name="dataSource" ref="dataSource"/>
		<property name="jpaVendorAdapter">
			<bean class="org.springframework.orm.jpa.vendor.TopLinkJpaVendorAdapter">
				<property name="showSql" value="true"/>
				<property name="generateDdl" value="false"/>
				<property name="databasePlatform" value="oracle.toplink.essentials.platform.database.PostgreSQLPlatform"/>
			</bean>
		</property>
		
		<property name="loadTimeWeaver">
			<bean class="org.springframework.instrument.classloading.SimpleLoadTimeWeaver"/>
		</property>
	</bean>

	<bean id="dataSource" class="org.springframework.jndi.JndiObjectFactoryBean">
		<property name="jndiName" value="java:comp/env/jdbc/cdcatalog" />
	</bean>

	<bean id="transactionManager" class="org.springframework.orm.jpa.JpaTransactionManager">
		<property name="entityManagerFactory" ref="entityManagerFactory"/>
		<property name="dataSource" ref="dataSource"/>
	</bean>
	
</beans>

[Andreas Senft]

I am missing the place, where you create a transactional proxy around your service. Without using a transactional proxy no commit will be performed. Have a look at the reference manual for more information.

Regards,
Andreas

[frankb]

Thanks Andreas,
I have insert/update working now.

Here's my working applicationContext.xml:

<?xml version="1.0" encoding="UTF-8"?>
<beans xmlns="http://www.springframework.org/schema/beans"
    xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xmlns:tx="http://www.springframework.org/schema/tx"
    xsi:schemaLocation="http://www.springframework.org/schema/beans
      http://www.springframework.org/schema/beans/spring-beans.xsd
      http://www.springframework.org/schema/tx
      http://www.springframework.org/schema/tx/spring-tx.xsd">
	

	<bean id="entityManagerFactory" class="org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean">
		<property name="dataSource" ref="dataSource"/>
		<property name="jpaVendorAdapter">
			<bean class="org.springframework.orm.jpa.vendor.TopLinkJpaVendorAdapter">
				<property name="showSql" value="true"/>
				<property name="generateDdl" value="false"/>
				<property name="databasePlatform" value="oracle.toplink.essentials.platform.database.MySQL4Platform"/>
			</bean>
		</property>
		
		<property name="loadTimeWeaver">
			<bean class="org.springframework.instrument.classloading.SimpleLoadTimeWeaver"/>
		</property>
	</bean>

	<bean id="dataSource" class="org.springframework.jndi.JndiObjectFactoryBean">
		<property name="jndiName" value="java:comp/env/jdbc/cdcatalog" />
	</bean>
	
	<bean id="transactionManager" class="org.springframework.orm.jpa.JpaTransactionManager">
		<property name="entityManagerFactory" ref="entityManagerFactory"/>
		<property name="dataSource" ref="dataSource"/>
	</bean>
	
	
	<bean id="baseTransactionProxy" class="org.springframework.transaction.interceptor.TransactionProxyFactoryBean" abstract="true">
		<property name="transactionManager" ref="transactionManager"/>
		<property name="transactionAttributes">
			<props>
				<prop key="save*">PROPAGATION_REQUIRED</prop>
				<prop key="update*">PROPAGATION_REQUIRED</prop>
				<prop key="delete*">PROPAGATION_REQUIRED</prop>
			</props>
		</property>
	</bean>
	
	
	
	<bean id="cdService" parent="baseTransactionProxy">
		<property name="target">
			<bean class="frankb.model.dao.CdDao">
				<property name="entityManagerFactory" ref="entityManagerFactory"/>
			</bean>
		</property>
	</bean>
	
</beans>

[Vita Rara]

I'm have the same issue. I'm new to Spring and JPA. I'm running on JBoss-4.0.4.GA.

My EntityManager is being found because I can look up entities, but I can't persist them.

I have the following in my applicationContext.xml file:

    <!-- Jpa Transaction Manager -->
    <!--
    <bean id="myTxManager"
             class="org.springframework.orm.jpa.JpaTransactionManager">
        <property name="entityManagerFactory" ref="entityManagerFactory" />
    </bean>
    --> 

    <bean id="myTxManager"
             class="org.springframework.transaction.jta.JtaTransactionManager" />

    <tx:advice id="txAdvice" transaction-manager="myTxManager">
        <tx:attributes>
            <tx:method name="creteEntity" propagation="REQUIRED"/>
            <tx:method name="updateEntity" propagation="REQUIRED"/>
            <tx:method name="deleteEntity" propagation="REQUIRED"/>
            <tx:method name="cancelEntity" propagation="REQUIRED"/>
            <tx:method name="uncancelEntity" propagation="REQUIRED"/>
            <tx:method name="deactivateEntity" propagation="REQUIRED"/>
            <tx:method name="reactivateEntity" propagation="REQUIRED"/>
            <tx:method name="execute" propagation="REQUIRED"/>
            <tx:method name="*" propagation="SUPPORTS" />
        </tx:attributes>
    </tx:advice>

   <aop:config>
        <aop:pointcut id="partyPackageMethods" 
                expression="execution(* net.vitarara.quadran.core.business.impl.party.*.* (..))"/>
        <aop:advisor advice-ref="txAdvice" pointcut-ref="partyPackageMethods"/>
    </aop:config>

I'm calling net.vitarara.quadran.core.business.impl.party.Part yManagerImpl.createEntity (), which I believe should be wrapped in a transaction. The PartyManager.createEntity() method is delegating the actual work to a processor object in the same package that is being done in it's execute() method, which I also believe should be wrapped in the transaction. The execute() method then calls the Dao object's persist method using getJpaTemplate().

What am I missing here?

Note I have tried this with both the Jpa and Jta transaction managers.

Thanks,

Mark

[Arno Werr]

Enable logging on org.springframework.transaction.interceptor and see what it's doing. It will provide you with a wealth of info basically wether your ideas fit with Spring/JPA config
sample

01:24:39,800 DEBUG [NameMatchTransactionAttributeSource] Adding transactional method [delete*] with attribute [PROPAGATION_REQUIRED,ISOLATION_DEFAULT]
01:24:39,800 DEBUG [NameMatchTransactionAttributeSource] Adding transactional method [update*] with attribute [PROPAGATION_REQUIRED,ISOLATION_DEFAULT]
01:24:39,801 DEBUG [NameMatchTransactionAttributeSource] Adding transactional method [create*] with attribute [PROPAGATION_REQUIRED,ISOLATION_DEFAULT,+ArrayIndexOutOfBoundsException]
...
01:25:04,894 DEBUG [TransactionInterceptor] Getting transaction for com.arno.spring.Service.createCat
... 
 
01:25:05,004 DEBUG [TransactionInterceptor] Invoking commit for transaction on com.arno.spring.Service.createCat

Then act accordingly

[Vita Rara]

Enable logging on org.springframework.transaction.interceptor and see what it's doing. It will provide you with a wealth of info basically wether your ideas fit with Spring/JPA config
sample

OK, did that and this what I get in the log:

12:09:59,623 DEBUG [AopUtils] Candidate advisor [PointcutAdvisor: pointcut [AspectJExpressionPointcut: () execution(* net.vitarara.quadran.core.business.impl.party.Part yManagerImpl.* (..))], advice [org.springframework.transaction.interceptor.Transa ctionInterceptor@43a4e9]] rejected for class [net.vitarara.quadran.core.business.impl.party.Part yTypeManagerImpl]

Any ideas?

Thanks,

Mark

[Arno Werr]

Guess what... rejected means precisely that - no transaction management for this call
I would try playing with pointcut definition 'execute bla-bla' string till I'd get 'accepted' in log. That means you're onboard.

Try to catch not Impl class but her interface per se. I am catching interface * *..Service.*(*..Cat)

You should look for something like this.

2006-08-30 01:24:43,363 DEBUG [org.springframework.aop.support.AopUtils] Candidate advisor [PointcutAdvisor: pointcut [AspectJExpressionPointcut: () execution(* *..Service.*(*..Cat))], advice [org.springframework.transaction.interceptor.TransactionInterceptor@1bdfcdb]] accepted for class [com.arno.spring.impl.ServiceImpl]

[Vita Rara]

Guess what... rejected means precisely that - no transaction management for this call
I would try playing with pointcut definition 'execute bla-bla' string till I'd get 'accepted' in log. That means you're onboard.

Try to catch not Impl class but her interface per se. I am catching interface * *..Service.*(*..Cat)

OK, I cast the net wider like you said to do.

Now I see the aspect being accepted for my interface. I have the following in the logs after turning on logging for org.springframework.

14:00:32,326 DEBUG [JpaTransactionManager] Using transaction object [org.springframework.orm.jpa.JpaTransactionManager$JpaTransactionObject@f12eb4]
14:00:32,326 DEBUG [JpaTransactionManager] Creating new transaction with name [net.vitarara.quadran.core.business.QEntityLifeCycleManager.createEntity]
14:00:32,326 DEBUG [JpaTransactionManager] Opened new EntityManager [org.hibernate.ejb.EntityManagerImpl@315b17] for JPA transaction
14:00:32,327 DEBUG [TransactionSynchronizationManager] Bound value [org.springframework.orm.jpa.EntityManagerHolder@b7c7ed] for key [org.springframework.orm.jpa.LocalEntityManagerFactoryBean@27ea7f] to thread [http-0.0.0.0-8080-1]
14:00:32,327 DEBUG [TransactionSynchronizationManager] Initializing transaction synchronization
14:00:32,327 INFO  [STDOUT] [Quadran] In: net.vitarara.quadran.core.business.impl.party.PartyManagerImpl.createEntity ()
14:00:32,327 INFO  [STDOUT] [Quadran] In net.vitarara.quadran.core.business.impl.party.DefaultCreatePartyProcessor.execute () 
14:00:32,328 INFO  [STDOUT] [Quadran] In net.vitarara.quadran.core.data.jpa.PartyDaoJpaImpl.persist ()
14:00:32,379 DEBUG [TransactionInterceptor] Getting transaction for net.vitarara.quadran.core.business.QEntityLifeCycleManager.createEntity
14:00:32,379 DEBUG [TransactionSynchronizationManager] Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@b7c7ed] for key [org.springframework.orm.jpa.LocalEntityManagerFactoryBean@27ea7f] bound to thread [http-0.0.0.0-8080-1]
14:00:32,379 DEBUG [JpaTransactionManager] Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@315b17] for JPA transaction
14:00:32,379 DEBUG [JpaTransactionManager] Using transaction object [org.springframework.orm.jpa.JpaTransactionManager$JpaTransactionObject@22ee91]
14:00:32,379 DEBUG [JpaTransactionManager] Participating in existing transaction
14:00:32,379 INFO  [STDOUT] [Quadran] In net.vitarara.quadran.core.data.jpa.ContactMechanismDaoJpaImpl.persist ()
14:00:32,381 DEBUG [JpaTemplate] Creating new EntityManager for JPA template execution
14:00:32,382 INFO  [STDOUT] Hibernate: select partyjpaim_.id, partyjpaim_.firstName as firstName134_, partyjpaim_.lastName as lastName134_ from party partyjpaim_ where partyjpaim_.id=?
14:00:32,383 DEBUG [JpaTemplate] Closing new EntityManager after JPA template execution
14:00:32,383 DEBUG [TransactionInterceptor] Invoking commit for transaction on net.vitarara.quadran.core.business.QEntityLifeCycleManager.createEntity
14:00:32,383 DEBUG [TransactionInterceptor] Invoking commit for transaction on net.vitarara.quadran.core.business.QEntityLifeCycleManager.createEntity
14:00:32,383 DEBUG [JpaTransactionManager] Triggering beforeCommit synchronization
14:00:32,384 DEBUG [JpaTransactionManager] Triggering beforeCompletion synchronization
14:00:32,384 DEBUG [JpaTransactionManager] Initiating transaction commit
14:00:32,384 DEBUG [JpaTransactionManager] Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@315b17]
14:00:32,385 DEBUG [JpaTransactionManager] Triggering afterCompletion synchronization
14:00:32,385 DEBUG [TransactionSynchronizationManager] Clearing transaction synchronization
14:00:32,385 DEBUG [TransactionSynchronizationManager] Removed value [org.springframework.orm.jpa.EntityManagerHolder@b7c7ed] for key [org.springframework.orm.jpa.LocalEntityManagerFactoryBean@27ea7f] from thread [http-0.0.0.0-8080-1]
14:00:32,385 DEBUG [JpaTransactionManager] Closing JPA EntityManager [org.hibernate.ejb.EntityManagerImpl@315b17] after transaction

I still don't have any records being created in the database.

It looks to me like the EntityManager (org.hibernate.ejb.EntityManagerImpl@315b17) is being created, and that after all of my code has run commit is being called on it.

I'm kind of stumped at this point.

Mark

[Vita Rara]

I added logging for org.hibernate to see if it would shed further light on the situation.

14:56:13,532 DEBUG [TransactionInterceptor] Getting transaction for net.vitarara.quadran.core.business.QEntityLifeCycleManager.createEntity
14:56:13,532 DEBUG [JpaTransactionManager] Using transaction object [org.springframework.orm.jpa.JpaTransactionManager$JpaTransactionObject@fac173]
14:56:13,532 DEBUG [JpaTransactionManager] Creating new transaction with name [net.vitarara.quadran.core.business.QEntityLifeCycleManager.createEntity]
14:56:13,532 DEBUG [JpaTransactionManager] Opened new EntityManager [org.hibernate.ejb.EntityManagerImpl@b2a51f] for JPA transaction
14:56:13,532 DEBUG [SessionImpl] opened session at timestamp: 4739279149187072
14:56:13,532 DEBUG [JDBCTransaction] begin
14:56:13,532 DEBUG [ConnectionManager] opening JDBC connection
14:56:13,533 DEBUG [JDBCTransaction] current autocommit status: true
14:56:13,533 DEBUG [JDBCTransaction] disabling autocommit
14:56:13,533 DEBUG [TransactionSynchronizationManager] Bound value [org.springframework.orm.jpa.EntityManagerHolder@2ba6d7] for key [org.springframework.orm.jpa.LocalEntityManagerFactoryBean@4f7301] to thread [http-0.0.0.0-8080-1]
14:56:13,533 DEBUG [TransactionSynchronizationManager] Initializing transaction synchronization
14:56:13,533 INFO  [STDOUT] [Quadran] In: net.vitarara.quadran.core.business.impl.party.PartyManagerImpl.createEntity ()
14:56:13,533 INFO  [STDOUT] [Quadran] In net.vitarara.quadran.core.business.impl.party.DefaultCreatePartyProcessor.execute () 
14:56:13,535 INFO  [STDOUT] [Quadran] In net.vitarara.quadran.core.data.jpa.PartyDaoJpaImpl.persist ()
14:56:13,537 DEBUG [SessionImpl] opened session at timestamp: 4739279149203456
14:56:13,557 DEBUG [AbstractSaveEventListener] generated identifier: 6596a2e0cc61af8300c2a9231e2c1123, using strategy: org.hibernate.id.Assigned
14:56:13,579 DEBUG [TransactionInterceptor] Getting transaction for net.vitarara.quadran.core.business.QEntityLifeCycleManager.createEntity
14:56:13,579 DEBUG [TransactionSynchronizationManager] Retrieved value [org.springframework.orm.jpa.EntityManagerHolder@2ba6d7] for key [org.springframework.orm.jpa.LocalEntityManagerFactoryBean@4f7301] bound to thread [http-0.0.0.0-8080-1]
14:56:13,579 DEBUG [JpaTransactionManager] Found thread-bound EntityManager [org.hibernate.ejb.EntityManagerImpl@b2a51f] for JPA transaction
14:56:13,579 DEBUG [JpaTransactionManager] Using transaction object [org.springframework.orm.jpa.JpaTransactionManager$JpaTransactionObject@17999e]
14:56:13,579 DEBUG [JpaTransactionManager] Participating in existing transaction
14:56:13,579 INFO  [STDOUT] [Quadran] In net.vitarara.quadran.core.data.jpa.ContactMechanismDaoJpaImpl.persist ()
14:56:13,581 DEBUG [JpaTemplate] Creating new EntityManager for JPA template execution
14:56:13,581 DEBUG [SessionImpl] opened session at timestamp: 4739279149387776
14:56:13,581 DEBUG [AbstractSaveEventListener] generated identifier: 6596a30bcc61af830066876803749672, using strategy: org.hibernate.id.Assigned
14:56:13,582 DEBUG [AbstractBatcher] about to open PreparedStatement (open PreparedStatements: 0, globally: 0)
14:56:13,582 DEBUG [ConnectionManager] opening JDBC connection
14:56:13,582 DEBUG [SQL] select partyjpaim_.id, partyjpaim_.firstName as firstName134_, partyjpaim_.lastName as lastName134_ from party partyjpaim_ where partyjpaim_.id=?
14:56:13,582 INFO  [STDOUT] Hibernate: select partyjpaim_.id, partyjpaim_.firstName as firstName134_, partyjpaim_.lastName as lastName134_ from party partyjpaim_ where partyjpaim_.id=?
14:56:13,583 DEBUG [AbstractBatcher] about to close PreparedStatement (open PreparedStatements: 1, globally: 1)
14:56:13,583 DEBUG [ConnectionManager] aggressively releasing JDBC connection
14:56:13,583 DEBUG [ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
14:56:13,584 DEBUG [JpaTemplate] Closing new EntityManager after JPA template execution
14:56:13,584 DEBUG [TransactionInterceptor] Invoking commit for transaction on net.vitarara.quadran.core.business.QEntityLifeCycleManager.createEntity
14:56:13,584 DEBUG [TransactionInterceptor] Invoking commit for transaction on net.vitarara.quadran.core.business.QEntityLifeCycleManager.createEntity
14:56:13,584 DEBUG [JpaTransactionManager] Triggering beforeCommit synchronization
14:56:13,584 DEBUG [JpaTransactionManager] Triggering beforeCompletion synchronization
14:56:13,584 DEBUG [JpaTransactionManager] Initiating transaction commit
14:56:13,584 DEBUG [JpaTransactionManager] Committing JPA transaction on EntityManager [org.hibernate.ejb.EntityManagerImpl@b2a51f]
14:56:13,584 DEBUG [JDBCTransaction] commit
14:56:13,585 DEBUG [JDBCTransaction] re-enabling autocommit
14:56:13,585 DEBUG [JDBCTransaction] committed JDBC Connection
14:56:13,585 DEBUG [ConnectionManager] aggressively releasing JDBC connection
14:56:13,585 DEBUG [ConnectionManager] releasing JDBC connection [ (open PreparedStatements: 0, globally: 0) (open ResultSets: 0, globally: 0)]
14:56:13,585 DEBUG [JpaTransactionManager] Triggering afterCompletion synchronization
14:56:13,585 DEBUG [TransactionSynchronizationManager] Clearing transaction synchronization
14:56:13,586 DEBUG [TransactionSynchronizationManager] Removed value [org.springframework.orm.jpa.EntityManagerHolder@2ba6d7] for key [org.springframework.orm.jpa.LocalEntityManagerFactoryBean@4f7301] from thread [http-0.0.0.0-8080-1]
14:56:13,586 DEBUG [JpaTransactionManager] Closing JPA EntityManager [org.hibernate.ejb.EntityManagerImpl@b2a51f] after transaction

It looks to me that when getJpaTemplate is being called a new Hibernate Session in being created that doesn't seem to be part of the transaction. Am I right?

Mark

[Arno Werr]

14:00:32,326 DEBUG [JpaTransactionManager] Opened new EntityManager [org.hibernate.ejb.EntityManagerImpl@315b17] for JPA transaction
...
14:00:32,381 DEBUG [JpaTemplate] Creating new EntityManager for JPA template execution
...
14:00:32,383 DEBUG [JpaTemplate] Closing new EntityManager after JPA template execution
...
14:00:32,385 DEBUG [JpaTransactionManager] Closing JPA EntityManager [org.hibernate.ejb.EntityManagerImpl@315b17] after transaction

One too many. Sorry,cannot help you with this one. With JBoss I do JBoss and JPA part or the application is made using JBoss facilites, i.e.no Spring JPA template. I might try this template (though do not feel much practicality in doing this in JBoss environment) but definitely it is not my my plate right now.