MVMap BufferOverflowException

[Brian Bray]

Thomas,

Here is a more elusive issue that I'm wondering if its a bug in MVMap/MVStore.  

I'm currently using MVStore as a large, temporary disk cache, I have a java program that scans about 10GB of raw CSV-ish files, and for each file, plucks out a few fields I care about and stores it in a MVMap. At the end, I merge the data from several MVMaps into a small JSON document which represents all the data buried in the CSV files for a particular entity.  I then store that JSON document in H2 for my app to use.

Its been working fairly well (and fast!), but there is one weird issue I'm encountering, that throws the exception below after 6-8M rows have been processed. Its going to be tough to extrapolate a test case, I was wondering if you had any insight into this?  It seems to go away when I shorten some key sizes, but I don't know if I'm just delaying the problem and eventually this would still happen?

I'm using 1.3.173, basically every 50k records or so I call MVstore.store() to flush to disk and eventually its throwing this:

Caused by: java.nio.BufferOverflowException

        at java.nio.HeapByteBuffer.put(HeapByteBuffer.java:183)

        at java.nio.ByteBuffer.put(ByteBuffer.java:832)

        at org.h2.mvstore.type.ObjectDataType$SerializedObjectType.write(ObjectDataTpe.java:1515)

        at org.h2.mvstore.type.ObjectDataType.write(ObjectDataType.java:113)

        at org.h2.mvstore.Page.write(Page.java:799)

        at org.h2.mvstore.Page.writeUnsavedRecursive(Page.java:860)

        at org.h2.mvstore.Page.writeUnsavedRecursive(Page.java:855)

        at org.h2.mvstore.Page.writeUnsavedRecursive(Page.java:855)

        at org.h2.mvstore.Page.writeUnsavedRecursive(Page.java:855)

        at org.h2.mvstore.MVStore.store(MVStore.java:921)

        at org.h2.mvstore.MVStore.store(MVStore.java:813)

Thanks,

Brian

[Thomas Mueller]

Hi,

We fixed quite a number of bugs in the MVStore recently. I suggest to try again with the nightly build at http://h2database.com/html/build.html#automated - direct link http://www.h2database.com/automated/h2-latest.jar - or of course you could build it yourself.

> I'm currently using MVStore as a large, temporary disk cache

Noel and me recently implemented an off-heap storage for the MVStore, so it's using memory (not disk) outside the normal Java heap. This might be interesting for you. The documentation is not online yet (as it's not released yet), it is only available in source form yet at https://h2database.googlecode.com/svn/trunk/h2/src/docsrc/html/mvstore.html (see 'off-heap'). To use it, call:

OffHeapStore offHeap = new OffHeapStore();
MVStore s = new MVStore.Builder().
        fileStore(offHeap).open();

I'm also thinking about combining the LIRS cache with the MVStore, so that you could build an off-heap LIRS cache. It shouldn't be complicated to implement (the cache would simply needs a map factory).

Regards,

Thomas

--
You received this message because you are subscribed to the Google Groups "H2 Database" group.
To unsubscribe from this group and stop receiving emails from it, send an email to h2-database...@googlegroups.com.
To post to this group, send email to h2-da...@googlegroups.com.
Visit this group at http://groups.google.com/group/h2-database.
For more options, visit https://groups.google.com/groups/opt_out.

[Brian Bray]

Thanks Thomas!  So I switched to h2-latest.jar and it fails sooner with an IllegalStateException:

Caused by: java.lang.IllegalStateException: Negative position -9223372036854646992 [1.3.173/6]

        at org.h2.mvstore.DataUtils.newIllegalStateException(DataUtils.java:709)

        at org.h2.mvstore.MVStore.readPage(MVStore.java:1439)

        at org.h2.mvstore.MVMap.readPage(MVMap.java:759)

        at org.h2.mvstore.Page.getChildPage(Page.java:207)

        at org.h2.mvstore.MVMap.binarySearch(MVMap.java:449)

        at org.h2.mvstore.MVMap.binarySearch(MVMap.java:450)

        at org.h2.mvstore.MVMap.get(MVMap.java:431)

Here is whats odd though, I basically have 3 large CSV files I'm parsing right now (#1=500MB/4M rows, #2=2.2GB/26M rows, #3=1.3GB/15M rows), it makes it through the first 2 fine, then I get the above exception about 100k rows into file #3. 

File #3 was also the only file failing with the previously mentioned BufferOverflowException in 1.3.173-release (it also seemed to have a slow memory leak), So I'm wondering if I have some weird data in file #3 that is causing issues?  Again, it might be difficult to extract a unit test out of this, but focusing on replicating file #3 might make it a bit easier.

Brian

[Thomas Mueller]

Hi,

I'm sorry I can't say what the problem is. It kind of looks like it's trying to read from a chunk while the chunk is not yet written. But I would need to know what your are doing exactly.

- Did you start with a new file?

- How large is the file when the problem occurs?

- How do you open the MVStore?

- How to you process the data (concurrently, when do you call commit, do you call save yourself and if yes when,...)? 

- How large is a typical record?

- What data types do you use?

Regards,

Thomas

[Brian Bray]

I was able to boil my stuff down quite a bit by focusing on the troublemaker portion. See attached unit test.  Using h2-latest.jar, I seem to get the IllegalStateException ("negative position exception") after 2-5 minutes of letting this run.  Using h2-1.3.173-release, after 5-6 minutes I see the classic signs of a memory leak in jvisualvm (I didn't wait long enough for a OutOfMemoryError).

I've tinkered with a bunch of different aspects of this:

- writeBufferSize()

- w/ and wo/ mvstore.store() calls every 25k records.

- various cache sizes

- store-per-map instead of storing all maps in 1 store/file.

- Tried different data types in mrrels MVMap (string[], List<String>, Map<String,String>)

I realize this test may look a little strange, but there is a lot more going on in my real tool and this is representative how it works and the strange data I'm working with. 

It seems like my issue is in the second loop, where I'm interspersing lots of .get()'s from 1 map and .put()'s to another.

Thanks for your help,

Brian

[Thomas Mueller]

Hi,

Thanks a lot for the great test case! I think I found the problem, but couldn't fix it yet. It is a concurrency problem. By default, the MVStore now stores changes in a background thread. This background writing thread conflicts with the main thread. Concurrency problems are always hard to test... I'm thinking about how to ensure things like this can't happen.

Anyway, for your use case, the solution is quite easy: disable the background thread. You don't need it, as you call store yourself. To do that, use a write delay of -1:

        MVStore mvstore = new MVStore.Builder().
             writeBufferSize(25).
             writeDelay(-1).
             fileName(fileName).
             cacheSize(100).
             open();

Regards,
Thomas

[Brian Bray]

I'm glad to be able to help you stabilize MVStore!  writeDelay(-1) fixed the IllegalStateException (and slow memory leak), but even with the h2-latest.jar I still have the original BufferOverflowException, plus a new NPE that I had not seen yet (both stack's below):

I found that I'm getting the exception with one entity based on data anomaly with 84K+ relationships in one file (I was never expecting more than a few hundred), so I'm trying to store a map with 84K entries as a value and eventually it fails.  So I thought that would be fairly easy to test with a unit test, but I tried a few things and can't seem to replicate.

So, now that I have checked out the code, I instrumented ObjectDataType.SerializedObjectType.write(ByteBuffer buff, Object obj) like this to better capture the state:

        @Override
        public ByteBuffer write(ByteBuffer buff, Object obj) {
            DataType t = getType(obj);
            if (t != this) {
                return t.write(buff, obj);
            }
            buff.put((byte) TYPE_SERIALIZED_OBJECT);
            byte[] data = serialize(obj);
            DataUtils.writeVarInt(buff, data.length);
            int prevbuffremain = buff.remaining();
            buff = DataUtils.ensureCapacity(buff, data.length);
            try {
            buff.put(data);
            } catch (BufferOverflowException ex) {
            if (obj instanceof Map) {
            System.err.println("map.size: " + ((Map) obj).size());
            }
            System.err.println("data.length: " + data.length);
            System.err.println("buff.limit:" + buff.limit());
            System.err.println("buff.pos:" +buff.position());
            System.err.println("buff.capacity: " +buff.capacity());
            System.err.println("buff.remain: " + buff.remaining());
            System.err.println("buff.prevbuffremain: " + prevbuffremain);
            ex.printStackTrace();
            }
            return buff;
        }

Then ran my app and after about 7 million rows processed it finally failed with this:

map.size: 84083
data.length: 3424297
buff.limit:4752468
buff.pos:2329143
buff.capacity: 4752468
buff.remain: 2423325
buff.prevbuffremain: 47091

java.nio.BufferOverflowException
at java.nio.HeapByteBuffer.put(HeapByteBuffer.java:183)
at java.nio.ByteBuffer.put(ByteBuffer.java:832)

at org.h2.mvstore.type.ObjectDataType$SerializedObjectType.write(ObjectDataType.java:1519)
at org.h2.mvstore.type.ObjectDataType.write(ObjectDataType.java:115)
at org.h2.mvstore.Page.write(Page.java:801)
at org.h2.mvstore.Page.writeUnsavedRecursive(Page.java:862)
at org.h2.mvstore.Page.writeUnsavedRecursive(Page.java:857)
at org.h2.mvstore.Page.writeUnsavedRecursive(Page.java:857)
at org.h2.mvstore.Page.writeUnsavedRecursive(Page.java:857)
at org.h2.mvstore.MVStore.storeNow(MVStore.java:903)
at org.h2.mvstore.MVStore.store(MVStore.java:822)
at org.h2.mvstore.MVStore.store(MVStore.java:791)

So it looks like DataUtils.ensureCapacity() isn't making a large enough ByteBuffer?  But its under some strange circumstance that I can't seem to isolate.  I also tried switching from Map values to StringBuilder values and got the same result, with a large serialized object value, it seems to fail to expand the ByteBuffer large enough sometimes.

As a side node, at one point I also got this NPE, but only once, I couldn't get it to happen again:

Caused by: java.lang.NullPointerException
        at org.h2.mvstore.cache.CacheLongKeyLIRS$Segment.pruneStack(CacheLongKeyLIRS.java:824)
        at org.h2.mvstore.cache.CacheLongKeyLIRS$Segment.convertOldestHotToCold(CacheLongKeyLIRS.java:815)
        at org.h2.mvstore.cache.CacheLongKeyLIRS$Segment.evict(CacheLongKeyLIRS.java:783)
        at org.h2.mvstore.cache.CacheLongKeyLIRS$Segment.put(CacheLongKeyLIRS.java:711)
        at org.h2.mvstore.cache.CacheLongKeyLIRS.put(CacheLongKeyLIRS.java:162)
        at org.h2.mvstore.MVStore.readPage(MVStore.java:1443)

        at org.h2.mvstore.MVMap.readPage(MVMap.java:759)
        at org.h2.mvstore.Page.getChildPage(Page.java:207)
        at org.h2.mvstore.MVMap.binarySearch(MVMap.java:449)
        at org.h2.mvstore.MVMap.binarySearch(MVMap.java:450)
        at org.h2.mvstore.MVMap.binarySearch(MVMap.java:450)
        at org.h2.mvstore.MVMap.get(MVMap.java:431)

Hope this helps,

Brian

[Thomas Mueller]

Hi,

By the way, those bugs have been fixed now. There is now a WriteBuffer that auto-increases capacity (similar to a ByteArrayOutputStream). And there was a bug in the LIRS cache that has been fixed.

Regards,

Thomas

On Friday, October 11, 2013, Thomas Mueller wrote:

Hi,

> DataUtils.ensureCapacity() isn't making a large enough ByteBuffer?

Yes, or maybe the method is not called in some cases where it should. Maybe it's better to wrap the ByteBuffer into a WriteBuffer that internally calls ensureCapacity when required. The current mechanism might be a bit more efficient, but also much more error prone.

> CacheLongKeyLIRS

Yes, this looks like a bug. While there are many test cases for this class, what is not tested is overflow (when using a large cache size). I just found the following code runs into an endless loop after about 54'458'000 entries. This is a really large cache, given that by default there are 16 segments (so it would fail with 16 times that number of entries), but it's still a bug. Strange is that it doesn't always fail at the same entry, so it might be a combination of a JVM bug and a bug in the cache. There might be other overflow problems.

    int size = 100 * 1024 * 1024;

    CacheLongKeyLIRS<Integer> test = new CacheLongKeyLIRS<Integer>(size, 1, 1, 0);

    Integer value = 1;

    for (int i = 0; i < size; i++) {

        test.put(i, value);

    }

Regards,

Thomas

    

    

On Fri, Oct 11, 2013 at 8:33 AM, Noel Grandin <noelg...@gmail.com> wrote:

Hi

I had a quick look at this exception that Brian reported:

   Caused by: java.lang.NullPointerException
            at
   org.h2.mvstore.cache.CacheLongKeyLIRS$Segment.pruneStack(CacheLongKeyLIRS.java:824)
            at
   org.h2.mvstore.cache.CacheLongKeyLIRS$Segment.convertOldestHotToCold(CacheLongKeyLIRS.java:815)
            at
   org.h2.mvstore.cache.CacheLongKeyLIRS$Segment.evict(CacheLongKeyLIRS.java:783)
            at
   org.h2.mvstore.cache.CacheLongKeyLIRS$Segment.put(CacheLongKeyLIRS.java:711)
            at
   org.h2.mvstore.cache.CacheLongKeyLIRS.put(CacheLongKeyLIRS.java:162)
            at org.h2.mvstore.MVStore.readPage(MVStore.java:1443)
            at org.h2.mvstore.MVMap.readPage(MVMap.java:759)
            at org.h2.mvstore.Page.getChildPage(Page.java:207)
            at org.h2.mvstore.MVMap.binarySearch(MVMap.java:449)
            at org.h2.mvstore.MVMap.binarySearch(MVMap.java:450)
            at org.h2.mvstore.MVMap.binarySearch(MVMap.java:450)
            at org.h2.mvstore.MVMap.get(MVMap.java:431)

I suspect that this code in CacheLongKeyLIRS$Segment is the problem:
        private void evict(Entry<V> newCold) {
            // ensure there are not too many hot entries:
            // left shift of 5 is multiplication by 32, that means if there are less
            // than 1/32 (3.125%) cold entries, a new hot entry needs to become cold
            while ((queueSize << 5) < mapSize) {
                convertOldestHotToCold();
            }

"queueSize" is an int , and if the queue gets big enough, the "<< 5" will operation will generate a zero because it will run move all of the bits outside the available 32 bits.

I think the code should look like:
            while ((((long)queueSize) << 5) < mapSize) {
                convertOldestHotToCold();
            }
or maybe
            while (queueSize < (mapSize >> 5)) {
                convertOldestHotToCold();
            }

[Brian Bray]

Thanks!

I did try 1.3.174 the other day and noticed it fixed my issues!

Brian

--
You received this message because you are subscribed to a topic in the Google Groups "H2 Database" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/h2-database/d5ewTdLDqiw/unsubscribe.
To unsubscribe from this group and all its topics, send an email to h2-database...@googlegroups.com.