I am using BDBje 3.3.75 with Java 6 (the problem also happens with Java 5).
My application is multithreaded and use BDBje transactionality. I have observed from time to time the below stack trace (note: line number may vary as I have added a few debugging statement - read below).
After some debugging, it happens that there is a threading issue when LogManager.marshallIntoBuffer is about to write an LNLogEntry instance. The LogManager.marshallIntoBuffer (as far as I can see) get the entry size and creates a bytebuffer (step a) and then write into it (step b).
My analysis is that it happens that between (a) and (b) some other thread is changing the LNLogEntry' transaction' lastLoggedLsn field and as this one is written as a packed long, when it gets change by some other thread in the middle, it can then take more place than (a) computed which then blows the buffer in (b).
With my added debugging statements in bdbje sources I observe the following Txn dumps
for step (a) <txn id="16793"><DbLsn val="0xffffffff/0xffffffff"/></txn>
for step (b) <txn id="16793"><DbLsn val="0xe4/0x46d893"/></txn>
It took me a while to figure out which structure in the LNLogEntry was growing to blow the buffer but this is as far as I have narrowed it down.
I can probably try to reproduce this in a test case but the application flow currently producing this is rather complex.
Can you please advise on the following:
- is it expected that a LNLogEntry might be changed (in particular its transaction' lastLoggedLsn) during this BDBje LogManager.marshallIntoBuffer code sequence ?
- if so, what should the application do to avoid that, what is the likely root cause ?
I am afraid it looks like a threading issue within BDBje low layers - although I'd love to hear otherwise.
Caused by: Environment invalid because of previous exception: com.sleepycat.je.RunRecoveryException: java.nio.BufferOverflowException
at com.sleepycat.je.log.LogManager.multiLog(LogManager.java:334)
at com.sleepycat.je.log.LogManager.log(LogManager.java:280)
at com.sleepycat.je.log.LogManager.log(LogManager.java:269)
at com.sleepycat.je.log.LogManager.log(LogManager.java:200)
at com.sleepycat.je.tree.LN.log(LN.java:511)
at com.sleepycat.je.tree.LN.optionalLog(LN.java:402)
at com.sleepycat.je.tree.LN.modify(LN.java:259)
at com.sleepycat.je.dbi.CursorImpl.putCurrent(CursorImpl.java:1364)
at com.sleepycat.je.dbi.CursorImpl.put(CursorImpl.java:1078)
at com.sleepycat.je.Cursor.putAllowPhantoms(Cursor.java:1470)
at com.sleepycat.je.Cursor.putNoNotify(Cursor.java:1406)
at com.sleepycat.je.Cursor.putInternal(Cursor.java:1361)
at com.sleepycat.je.Database.putInternal(Database.java:995)
at com.sleepycat.je.Database.put(Database.java:885)
...
... 3 more
Caused by: java.nio.BufferOverflowException
at java.nio.HeapByteBuffer.put(HeapByteBuffer.java:165)
at java.nio.ByteBuffer.put(ByteBuffer.java:813)
at com.sleepycat.je.log.LogUtils.writeBytesNoLength(LogUtils.java:356)
at com.sleepycat.je.log.entry.LNLogEntry.writeEntry(LNLogEntry.java:358)
at com.sleepycat.je.log.LogManager.marshallIntoBuffer(LogManager.java:632)
at com.sleepycat.je.log.LogManager.multiLog(LogManager.java:311)