seit kurzer Zeit treten während unserers Jobs zur Vollgenerierung hin und wieder Fehler in Form von Deadlocks auf. Dieser Vollgenerierungsjob erzeugt die Webseite in parallelen läufenden Teilaufträgen. Wie im Handbuch beschrieben, haben wir diese so angelegt, dass immer disjunkte Teilbereiche der Webseite in allen Sprachvarianten erzeugt werden.
Wir können uns nicht erklären woher dieser Fehler kommt, denn wir haben schon länger keine Updates mehr eingespielt oder Strukturen im Projekt verändert.
Wie in der Fehlermeldung zu erkennen handelt es sich um ein Deadlock in der über die Datenquellen angebundene externe PostgreSQL-Datenbank. Was ich jedoch nicht verstehe ist, dass bei der Generierung Write-Locks gesetzt werden.
EDIT: Im Log steht ganz klar etwas von 'ACL', daher noch kurz der Hinweis dass das Häckchen 'ACL-Datenbank benutzen' generell in unseren Aufträgen nicht gesetzt ist.
ERROR 19.07.2013 00:15:52.476 {seID=236403} (de.espirit.firstspirit.server.scheduler.ScheduleManagerImpl): error in task 'Städte & Kultur' - schedule entry 'Auto-Deploy [ALL]' (id=236403) - java.io.IOException: Database error - com.sleepycat.je.DeadlockException: (JE 3.3.98) Lock expired. Locker 1097681797 1866979388_Queue[DEFAULT]:task 'Städte & Kultur' - schedule entry 'Auto-Deploy [ALL]' (id=236403)_Txn: waited for lock on database=persist#AccessControlDb#de.espirit.firstspirit.acl.File#_acl LockAddr:975760178 node=57 type=WRITE grant=WAIT_NEW timeoutMillis=500 startTime=1374185751112 endTime=1374185752458
Owners: [<LockInfo locker="443154114 1866979386_Queue[DEFAULT]:task 'REST' - schedule entry 'Auto-Deploy [ALL]' (id=236403)_Txn" type="WRITE"/>]
Waiters: []
java.io.IOException: Database error - com.sleepycat.je.DeadlockException: (JE 3.3.98) Lock expired. Locker 1097681797 1866979388_Queue[DEFAULT]:task 'Städte & Kultur' - schedule entry 'Auto-Deploy [ALL]' (id=236403)_Txn: waited for lock on database=persist#AccessControlDb#de.espirit.firstspirit.acl.File#_acl LockAddr:975760178 node=57 type=WRITE grant=WAIT_NEW timeoutMillis=500 startTime=1374185751112 endTime=1374185752458
Owners: [<LockInfo locker="443154114 1866979386_Queue[DEFAULT]:task 'REST' - schedule entry 'Auto-Deploy [ALL]' (id=236403)_Txn" type="WRITE"/>]
Waiters: []
at de.espirit.common.io.IoUtil.newIoException(IoUtil.java:460)
at de.espirit.firstspirit.io.AclFileHandleImpl.updateAclFile(AclFileHandleImpl.java:260)
at de.espirit.firstspirit.io.AclFileHandleImpl$AclUpdateStream.close(AclFileHandleImpl.java:325)
at sun.nio.cs.StreamEncoder.implClose(StreamEncoder.java:301)
at sun.nio.cs.StreamEncoder.close(StreamEncoder.java:130)
at java.io.OutputStreamWriter.close(OutputStreamWriter.java:216)
at de.espirit.common.io.UnsyncedBufferedWriter.close(UnsyncedBufferedWriter.java:257)
at de.espirit.firstspirit.generate.SiteProduction.render(SiteProduction.java:181)
at de.espirit.firstspirit.generate.SiteProduction.render(SiteProduction.java:135)
at de.espirit.firstspirit.generate.SiteProduction.render(SiteProduction.java:138)
at de.espirit.firstspirit.generate.SiteProduction.start(SiteProduction.java:105)
at de.espirit.firstspirit.server.scheduler.GenerateTaskExecutor.run(GenerateTaskExecutor.java:235)
at de.espirit.firstspirit.server.scheduler.ScheduleManagerImpl$TaskCallable.executeLocal(ScheduleManagerImpl.java:2021)
at de.espirit.firstspirit.server.scheduler.ScheduleManagerImpl$TaskCallable.executeLocal(ScheduleManagerImpl.java:2001)
at de.espirit.firstspirit.server.scheduler.ScheduleManagerImpl$TaskCallable.call(ScheduleManagerImpl.java:1929)
at de.espirit.firstspirit.server.ExecutionManagerImpl$ExtendedCallable.call(ExecutionManagerImpl.java:520)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at de.espirit.common.util.BoundedExecutorService$RunnableWrapper.run(BoundedExecutorService.java:419)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441)
at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
at java.util.concurrent.FutureTask.run(FutureTask.java:138)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
at java.lang.Thread.run(Thread.java:662)
at de.espirit.common.util.SuspendableThread.run(SuspendableThread.java:36)
Caused by: com.sleepycat.je.DeadlockException: (JE 3.3.98) Lock expired. Locker 1097681797 1866979388_Queue[DEFAULT]:task 'Städte & Kultur' - schedule entry 'Auto-Deploy [ALL]' (id=236403)_Txn: waited for lock on database=persist#AccessControlDb#de.espirit.firstspirit.acl.File#_acl LockAddr:975760178 node=57 type=WRITE grant=WAIT_NEW timeoutMillis=500 startTime=1374185751112 endTime=1374185752458
Owners: [<LockInfo locker="443154114 1866979386_Queue[DEFAULT]:task 'REST' - schedule entry 'Auto-Deploy [ALL]' (id=236403)_Txn" type="WRITE"/>]
Waiters: []
at com.sleepycat.je.txn.LockManager.makeTimeoutMsgInternal(LockManager.java:469)
at com.sleepycat.je.txn.SyncedLockManager.makeTimeoutMsg(SyncedLockManager.java:77)
at com.sleepycat.je.txn.LockManager.lock(LockManager.java:278)
at com.sleepycat.je.txn.Txn.lockInternal(Txn.java:425)
at com.sleepycat.je.txn.Locker.lock(Locker.java:360)
at com.sleepycat.je.dbi.CursorImpl.lockDupCountLN(CursorImpl.java:2594)
at com.sleepycat.je.tree.Tree.insertDuplicate(Tree.java:2731)
at com.sleepycat.je.tree.Tree.insert(Tree.java:2678)
at com.sleepycat.je.dbi.CursorImpl.putLN(CursorImpl.java:1052)
at com.sleepycat.je.dbi.CursorImpl.putNoDupData(CursorImpl.java:1208)
at com.sleepycat.je.Cursor.putAllowPhantoms(Cursor.java:1470)
at com.sleepycat.je.Cursor.putNoNotify(Cursor.java:1402)
at com.sleepycat.je.Cursor.putInternal(Cursor.java:1356)
at com.sleepycat.je.SecondaryDatabase.insertKey(SecondaryDatabase.java:880)
at com.sleepycat.je.SecondaryDatabase.updateSecondary(SecondaryDatabase.java:754)
at com.sleepycat.je.SecondaryTrigger.databaseUpdated(SecondaryTrigger.java:42)
at com.sleepycat.je.Database.notifyTriggers(Database.java:1735)
at com.sleepycat.je.Cursor.putInternal(Cursor.java:1364)
at com.sleepycat.je.Database.putInternal(Database.java:995)
at com.sleepycat.je.Database.putNoOverwrite(Database.java:930)
at com.sleepycat.persist.PrimaryIndex.putNoOverwrite(PrimaryIndex.java:476)
at de.espirit.firstspirit.acl.db.AccessControlDb.createFile(AccessControlDb.java:283)
at de.espirit.firstspirit.io.AclFileHandleImpl.updateAclFile(AclFileHandleImpl.java:257)
... 24 more