Description

buko

opened on Oct 20, 2021

Issue body actions

This is a bit of a doozy.

We're in the process of moving an application to lmdbjava. We observe that when running the tests the following occurs:

1. If the tests are all run in the same JVM process then we consistently get very strange errors related to ByteBuf validation constraints:

For example:

Caused by: java.lang.IndexOutOfBoundsException: readerIndex: 1297, writerIndex: 1095 (expected: 0 <= readerIndex <= writerIndex <= capacity(1095))
        at io.netty.buffer.AbstractByteBuf.checkIndexBounds(AbstractByteBuf.java:112)
        at io.netty.buffer.AbstractByteBuf.writerIndex(AbstractByteBuf.java:135)
        at org.lmdbjava.ByteBufProxy.out(ByteBufProxy.java:166)
        at org.lmdbjava.ByteBufProxy.out(ByteBufProxy.java:41)
        at org.lmdbjava.KeyVal.valOut(KeyVal.java:134)
        at org.lmdbjava.Cursor.seek(Cursor.java:377)
        at org.lmdbjava.Cursor.first(Cursor.java:126)
        at org.lmdbjava.CursorIterable.executeCursorOp(CursorIterable.java:125)
        at org.lmdbjava.CursorIterable.update(CursorIterable.java:172)
        at org.lmdbjava.CursorIterable.access$100(CursorIterable.java:52)
        at org.lmdbjava.CursorIterable$1.hasNext(CursorIterable.java:99)

This occurs using the very standard code to iterate over all the keys in a table:

try (final CursorIterable<ByteBuf> cursor = table.iterate(txn)) {
			
			for (final KeyVal<ByteBuf> kv : cursor) {
				final ByteBuf keyBuffer = kv.key();
				final ByteBuf valueBuffer = kv.val();

2. If the maven build is run using -DforkCount=1C -DreuseForks=false then all the tests run perfectly fine. These system properties tell maven to run each test class in its own JVM and it eliminates all errors in the build at the expense of a much slower build.

Additionally if we run a single test using the -Dtest=$TestName syntax the test passes fine.

Clearly there is some erorr related to static state that is leading to inter-test dependencies. If we eliminate static state by running each Test in its own JVM all the tests pass. If we run the tests run the tests in the same JVM fails.

I've tried to dig into this and get some idea of what's happening and I doi believe the problem is related to the ByteBufProxy class. There are some red flags in this class:

1. This class maintains significant static state in a threadlocal BUFFERS cache. There seems to be no way to reset or clear this BUFFERS. As far I can tell the cache persists even if you call Env.close() and it might explain why we're getting ByteBufs whose readIndex is larger than their writeIndex.

2. The ByteBufProxy class is also hardcoded to use PooledByteBufAllocator.DEFAULT. We've had problems in the past with multiple components (netty, netty extensions) all mucking around with PooledByteBufAllocator.DEFAULT. We tend to avoid using PooledByteBufAllocator.DEFAULT and instead having each component use its own explicit PooledByteBufAllocator. Unfortunately there's no way to configure ByteBufProxy to use a different ByteBufAllocator.

3. The ByteBufProxy class makes several questionable assumptions. ByteBufs are allocated and not released, and no attempt is made to clear() ByteBufs returned from the pool.

Activity

1. buko commented on Oct 20, 2021

   

   buko

   on Oct 20, 2021

   Author

   More actions

   So... all of the issues mentioned above are fixed by upgrading to lmdbjava 0.8.2.

   Thanks to this commit it's now possible to pass a custom PooledByteBufAllocator to the ByteBufProxy class and the ByteBufProxy.deallocate method is guaranteed to always call ByteBufProxy.release().

   There is still some questionable code like ByteBufProxy#150 where the writeIndex is set the BEFORE setting the readerIndex. (IIRC readerIndex should be set first, then writerIndex) but... all the crazy test errors are gone.

   I'll leave this issue here: maybe it'll show up on Google and point some other unfortunate soul in the right direction.
2. buko

   closed this as completedon Oct 20, 2021
3. bp-alex commented on Oct 22, 2021

   

   bp-alex

   on Oct 22, 2021

   Member

   More actions

   @buko I have never used the Netty integration and only maintain it as minimally necessary to pass the tests. If you think there should be improvements I highly encourage a PR as if the tests pass I am most happy to merge it.
4. buko commented on Oct 23, 2021

   

   buko

   on Oct 23, 2021

   Author

   More actions

   If you think there should be improvements I highly encourage a PR as if the tests pass I am most happy to merge it.

   I'm starting to think there is a bug in the code. One thing I find suspicious and strange is line #150 in ByteBufProxy:

   buffer.writerIndex((int) size).readerIndex(0);

   Could this be a bhug?

   I only ask because every once in a while we get errors while trying to scan over integer-based key tables. Probably 95% of tests work fine but then I see something like:

           java.lang.IndexOutOfBoundsException: readerIndex: 1294, writerIndex: 1203 (expected: 0 <= readerIndex <= writerIndex <= capacity(1203))
   	at io.netty.buffer.AbstractByteBuf.checkIndexBounds(AbstractByteBuf.java:112)
   	at io.netty.buffer.AbstractByteBuf.writerIndex(AbstractByteBuf.java:135)
   	at org.lmdbjava.ByteBufProxy.out(ByteBufProxy.java:150)
   	at org.lmdbjava.ByteBufProxy.out(ByteBufProxy.java:40)
   	at org.lmdbjava.KeyVal.valOut(KeyVal.java:134)
   	at org.lmdbjava.Cursor.seek(Cursor.java:377)
   	at org.lmdbjava.Cursor.next(Cursor.java:213)
   
5. buko

   reopened this on Oct 23, 2021
6. buko commented on Oct 23, 2021

   

   buko

   on Oct 23, 2021

   Author

   More actions

   Well, that was interesting. After debugging the code this is what I have learned:

   1. There is a single KeyVal object associated with the Txn class. This KeyVal object, and its associated buffers, are used for all operations in the transaction.

   2. When you iterate over the table using code like:

    try (final CursorIterable<ByteBuf> ci = table.iterate(txn)) {
   			 for (final KeyVal<ByteBuf> kv : ci) {
   				final ByteBuf keyBuffer = kv.key();
   				final ByteBuf valueBuffer = kv.val();

   The problem is the KeyVal.valOut method that gets invokved no matter how you iterate over the table (using Dbi.get(), CursorIterable, or plain old Cursor objects). What this method does is call BufferProxy.out() which then calls ByteBufProxy.out().

   ByteBufProxy does this thing where it sets the writerIndex on the buffer and then it sets the readerIndex to zero.

   The bug occurs when you read a large value followed by a small value. (Which explains why it showed up so rarely in our tests... we rarely do this.) In this case if you read a large value -- say size 2000 -- and you read it fully, then the ByteBuf associated with the KeyVal (which is associated with the underlying Transaction) will end up in a state where readerIndex=2000,writerIndex=2000.

   After reading this large value if you read a small value, say size=500 then the call to ByteBufProxy.out() will attempt to set the writerIndex to 500 on the KeyVal's buffer. The problem is that the readerIndex for the ByteBuf is still 2000 at this point. This is what triggers the exceptions of the form:

    java.lang.IndexOutOfBoundsException: readerIndex: 1294, writerIndex: 1203 (expected: 0 <= readerIndex <= writerIndex <= capacity(1203))
   	at io.netty.buffer.AbstractByteBuf.checkIndexBounds(AbstractByteBuf.java:112)
   	at io.netty.buffer.AbstractByteBuf.writerIndex(AbstractByteBuf.java:135)
   	at org.lmdbjava.ByteBufProxy.out(ByteBufProxy.java:150)
   	at org.lmdbjava.ByteBufProxy.out(ByteBufProxy.java:40)
   	at org.lmdbjava.KeyVal.valOut(KeyVal.java:134)
   	at org.lmdbjava.Cursor.seek(Cursor.java:377)
   	at org.lmdbjava.Cursor.next(Cursor.java:213)
   

   lmdbjava, operating on the single KeyVal/Buffer associated with a Txn, is attempting to set a writerIndex to a value and that is smaller than the readerIndex (which was set by reading all the data associated with the previous value).

   Workaround

   The work around is to simply clear the valueBuffer after reading an entry from LMDB:

    try (final CursorIterable<ByteBuf> ci = table.iterate(txn)) {
   			 for (final KeyVal<ByteBuf> kv : ci) {
   				final ByteBuf keyBuffer = kv.key();
   				final ByteBuf valueBuffer = kv.val();
                                   ...process the buffers
                                  valueBuffer.clear(); // clear the valueBuffer!
                             }
   }

   What this does is it immediately sets writerIndex,readerIndex to 0 on the valueBuffer. When lmdbjava goes to read the next entry, regardless of size, tnow that readerIndex is zero, any size will not trigger the IndexOutOfBoundsException.

   Making this change seems to get all tests consistently passing regardless of the associated test data. The bug is tricky because the code is fine, the problem was the underlying data.
7. buko

   changed the title [-]mvn test -DforkCount=1C is required to pass tests[/-] [+]Reading variable sized data (a small entry followed by a large entry) leads to IndexOutOfBoundsException[/+] on Oct 23, 2021
8. bp-alex

   added a commit that references this issue on Oct 24, 2021

   Support Netty ByteBuf variable sized data (#183)

   1d991f8
9. bp-alex commented on Oct 24, 2021

   

   bp-alex

   on Oct 24, 2021

   Member

   More actions

   Thanks for the research. I just added a commit which passes the current test suite. Would you be able to please it with your variable-sized data?
10. bp-alex commented on Apr 15, 2022

    

    bp-alex

    on Apr 15, 2022

    Member

    More actions

    I'll close this ticket given there has been no update in nearly six months and I believe it has been fixed.
11. bp-alex

    closed this as completedon Apr 15, 2022

Issue actions