We should look for a missing commit there. I think the connection pool does a rollback each time the connection is released back to the pool to safeguard against uncommitted work being committed by the next caller claiming the connection. My guess is we're seeing that.
Looking at RollerTaskWithLeasing.java it looks like what is happening is it is explicitly calling WebloggerFactory.getWeblogger().release() and this may be causing the connection release before the update gets committed.
--a. Dick Davies wrote:
OK, following on from yesterdays posts about scheduled tasks not running (https://issues.apache.org/roller/browse/ROL-1760) , I've 1. set the timestamps in roller_tasklock to hundredths of a second precisison 2. cleared out that table 3. redeployed roller and tasks are now running, with one caveat; our tasks won't run more often than every leaseTime minutes. After a bit more digging, we found our JPAThreadManagerImpl.unregisterLease() method is not updating the database, so any lease that is successfully taken out are kept , blocking that task from running, until they expire. In this case , the JPA-generated SQL looks ok, but the roller logs show what looks like a transaction rolling back: DEBUG 2008-11-21 11:47:00,097 CommonsLogFactory$LogAdapter:trace - Executing query: [UPDATE TaskLock t SET t.timeLeased=?1 WHERE t. name=?2 AND t.clientId=?3] with parameters: {3=ScheduledEntriesTask, 2=0, 1=devel-roller01} DEBUG 2008-11-21 11:47:00,097 CommonsLogFactory$LogAdapter:trace - <t 6810846, conn 4959010> executing prepstmnt 20488940 UPDATE ro ller_tasklock t0 SET timeleased = ? WHERE (t0.name = ? AND t0.client = ?) [params=(int) 0, (String) ScheduledEntriesTask, (String) devel-roller01] DEBUG 2008-11-21 11:47:00,098 CommonsLogFactory$LogAdapter:trace - <t 6810846, conn 4959010> [0 ms] spent DEBUG 2008-11-21 11:47:00,098 RollerTaskWithLeasing:run - ScheduledEntriesTask: Lease released, task finished DEBUG 2008-11-21 11:47:00,109 CommonsLogFactory$LogAdapter:trace - <t 6810846, conn 4959010> [10 ms] rollback ******* DEBUG 2008-11-21 11:47:00,109 CommonsLogFactory$LogAdapter:trace - <t 6810846, conn 4959010> [0 ms] close Is the line flagged '******' a transaction rolling back, or do I not understand JPA at all? If so, does anyone have any clue where I start looking to find out why JPA did that? I suppose I could work around this by setting leaseTime == interval, but this is a multi-server cluster and I've got enough headaches without adding race conditions into the mix :) Thanks (filed this as https://issues.apache.org/roller/browse/ROL-1761).
