This post is part 2 in a 9-part series on Envers, Spring, and JTA. The next post is The versioning isn’t happening, part 3: it’s in UserTransaction?, and the previous post is The versioning isn’t happening, part 1: wanderings.
We’re trying to figure out why the envers versioning records are not created when our project uses a JTA transaction manager — it creates the versioning records just fine when we’re using local Hibernate transactions.
Our approach last time was to see what differences there might be in the Hibernate configuration. I ended up that post with
Perhaps next I should capture the values of the rest of AnnotationConfiguration’s 47 fields, and compare them all between jta mode and Hibernate mode.
-1. The Other 47 Fields
After I stopped writing last time, I did go on to capture the 47 AnnotationConfiguration fields’ values when running in Hibernate mode and when running in JTA mode, and… they were the same! (Keith suspected they would be.)
0. No Other Apparent Magic During JBoss Startup
Still running in Hibernate mode, I followed the control flow after the creation of the Hibernate SessionFactory bean, but I didn’t see anything interesting-looking. It’s hard to let the idea go that something’s different at startup time, but I think next I need to take a closer look at what happens during a save to the database.
1. A list of work to do later
Let’s see where the envers onPostInsert() hook gets called from, in hibernate mode (i.e., where things are working correctly). Here’s the call stack:
Daemon Thread [http-127.0.0.1-8080-1] (Suspended (entry into method onPostInsert in VersionsEventListener))
VersionsEventListener.onPostInsert(PostInsertEvent) line: 88
EntityInsertAction.postInsert() line: 131
EntityInsertAction.execute() line: 110
ActionQueue.execute(Executable) line: 279
ActionQueue.executeActions(List) line: 263
ActionQueue.executeActions() line: 167
DefaultFlushEventListener(AbstractFlushingEventListener).performExecutions(EventSource) line: 298
DefaultFlushEventListener.onFlush(FlushEvent) line: 27
SessionImpl.flush() line: 1000
GreetingDAO(GenericDAO<PO,PK>).create(PO) line: 66
GreetingDBSvcImpl.saveGreeting(GreetingPTO) line: 25
GreetingSvcImpl.saveGreeting(GreetingDTO) line: 21
HelloWorldSvcImpl.writeGreetingToDatabase(Greeting) line: 24
NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not available [native method]
NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39
1.1. It’s all the same in JTA mode
I set breakpoints at most of these places. Let’s try it in jta mode:
- We get to the session.flush() in GreetingDAO(GenericDAO<PO,PK>).create(PO) line: 66
- We get to DefaultFlushEventListener.onFlush(FlushEvent) line: 27
- We get to DefaultFlushEventListener(AbstractFlushingEventListener).performExecutions(EventSource) line: 298
- We get to ActionQueue.executeActions() line: 167 with 1 element in our insertions ArrayList to do, just like in hibernate mode
- We get to EntityInsertAction.execute() line: 110
- We get into EntityInsertAction.postInsert(), with a org.jboss.envers.event.VersionsEventListener and a org.hibernate.search.event.FullTextIndexEventListenerin the postInsertEventListener[] array
- We even get into VersionsEventListener.onPostInsert(PostInsertEvent)!
So why doesn’t the versioning happen?
It turns out that VersionsEventListener.onPostInsert() isn’t where the real work is done.
1.2. What VersionsEventListener.onPostInsert() is responsible for
Summary:
VersionsEventListener.onPostInsert() adds a VersionsWorkUnit to a list, to be picked up and performed later. It doesn’t actually do the work.
Details:
org.jboss.envers.event.VersionsEventListener.onPostInsert(PostInsertEvent) does is to add the org.jboss.envers.synchronization.work.VersionsWorkUnit to the org.jboss.envers.synchronization.VersionsSync.workUnits linked list (VersionsSync is the class that implements javax.transaction.Synchronization).
3. Who picks up the work unit?
Who is responsible for picking up the work unit, then? I notice that the javax.transaction.Synchronization specifies two methods: beforeCompletion() and afterCompletion(int). Let’s see if anyone calls beforeCompletion() when we’re in Hibernate mode… setting breakpoints on these two methods and re-running my hibernate mode test, we break at beforeCompletion() with this call stack:
Daemon Thread [http-127.0.0.1-8080-1] (Suspended (entry into method beforeCompletion in VersionsSync))
VersionsSync.beforeCompletion() line: 125
JDBCTransaction.notifyLocalSynchsBeforeTransactionCompletion() line: 228
JDBCTransaction.commit() line: 109
HibernateTransactionManager.doCommit(DefaultTransactionStatus) line: 655
HibernateTransactionManager(AbstractPlatformTransactionManager).processCommit(DefaultTransactionStatus) line: 709
HibernateTransactionManager(AbstractPlatformTransactionManager).commit(TransactionStatus) line: 678
TransactionInterceptor(TransactionAspectSupport).commitTransactionAfterReturning(TransactionAspectSupport$TransactionInfo)line: 321
TransactionInterceptor.invoke(MethodInvocation) line: 116
ReflectiveMethodInvocation.proceed() line: 171
ExposeInvocationInterceptor.invoke(MethodInvocation) line: 89
ReflectiveMethodInvocation.proceed() line: 171
JdkDynamicAopProxy.invoke(Object, Method, Object[]) line: 204
$Proxy68.writeGreetingToDatabase(Greeting) line: not available
NativeMethodAccessorImpl.invoke0(Method, Object, Object[]) line: not available [native method]
NativeMethodAccessorImpl.invoke(Object, Object[]) line: 39
DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25
Method.invoke(Object, Object...) line: 585
JAXWSMethodInvoker(AbstractInvoker).performInvocation(Exchange, Object, Method, Object[]) line: 136
JAXWSMethodInvoker(AbstractInvoker).invoke(Exchange, Object, Method, List<Object>) line: 82
JAXWSMethodInvoker.invoke(Exchange, Object, Method, List<Object>) line: 97
JAXWSMethodInvoker(AbstractInvoker).invoke(Exchange, Object) line: 68
ServiceInvokerInterceptor$1.run() line: 56
SynchronousExecutor.execute(Runnable) line: 37
ServiceInvokerInterceptor.handleMessage(Message) line: 92
PhaseInterceptorChain.doIntercept(Message) line: 221
ChainInitiationObserver.onMessage(Message) line: 78
ServletDestination.invoke(ServletContext, HttpServletRequest, HttpServletResponse) line: 92
ServletController.invokeDestination(HttpServletRequest, HttpServletResponse, ServletDestination) line: 279
ServletController.invoke(HttpServletRequest, HttpServletResponse) line: 161
CXFServlet(AbstractCXFServlet).invoke(HttpServletRequest, HttpServletResponse) line: 174
CXFServlet(AbstractCXFServlet).doPost(HttpServletRequest, HttpServletResponse) line: 152
CXFServlet(HttpServlet).service(HttpServletRequest, HttpServletResponse) line: 710
CXFServlet(HttpServlet).service(ServletRequest, ServletResponse) line: 803
ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) line: 290
ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line: 206
ReplyHeaderFilter.doFilter(ServletRequest, ServletResponse, FilterChain) line: 96
ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse) line: 235
ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line: 206
StandardWrapperValve.invoke(Request, Response) line: 230
StandardContextValve.invoke(Request, Response) line: 175
SecurityAssociationValve.invoke(Request, Response) line: 179
JaccContextValve.invoke(Request, Response) line: 84
StandardHostValve.invoke(Request, Response) line: 127
ErrorReportValve.invoke(Request, Response) line: 102
CachedConnectionValve.invoke(Request, Response) line: 157
StandardEngineValve.invoke(Request, Response) line: 109
CoyoteAdapter.service(Request, Response) line: 262
Http11Processor.process(Socket) line: 844
Http11Protocol$Http11ConnectionHandler.process(Socket) line: 583
JIoEndpoint$Worker.run() line: 446
Thread.run() line: 595
So VersionsSync.beforeCompletion() does indeed get called when we’re in Hibernate mode.
3.1. Sidenote: The Point Where the Records Appear in the Tables
After some more lines of code, we get to org.hibernate.transaction.JDBCTransaction.commitAndResetAutoCommit(), which does a jdbcContext.connection().commit(). Before this line is executed, neither the main record nor the versioning record appear in the table; after that line, the records do appear.
4. JTA mode: no beforeCompletion call made
Next we’ll re-run the test we did in step 3 with the jta version deployed and with all the same breakpoints, to see if org.jboss.envers.synchronization.VersionsSync.beforeCompletion() gets called…
It doesn’t.
Tune in next time for an exploration of why VersionsSync.beforeCompletion() isn’t getting called in JTA mode!