Failed to deserialize SerializerPojo #261

jrumbinas · 2014-01-10T12:35:55Z

Here's a little background. I have a DB with 5m records (15GB).
Then 53k records are inserted. After insertion I try to reopen DB in read-only mode (on the same thread) and this exception is thrown.
I can repeat this every time I do massive insert.
Tested on master (519f779)
Update: committing and compacting after insert (before re-open) works perfectly however this doesn't fix the situation

DBMaker dbmaker = DBMaker
        .newFileDB(path.toFile())
        .closeOnJvmShutdown();
        .transactionDisable();
        .cacheSize(32768)
        .mmapFileEnablePartial()
        .cacheLRUEnable()
        .fullChunkAllocationEnable();

db.createTreeMap(MAIN_TREE_MAP)
            .counterEnable()
            .valuesOutsideNodesEnable()
            .makeOrGet();

Exception in thread "main" java.lang.IndexOutOfBoundsException
    at java.nio.Buffer.checkIndex(Buffer.java:532)
    at java.nio.HeapByteBuffer.get(HeapByteBuffer.java:139)
    at org.mapdb.DataInput2.readUnsignedByte(DataInput2.java:74)
    at org.mapdb.DataInput2.unpackInt(DataInput2.java:142)
    at org.mapdb.SerializerBase.deserializeString(SerializerBase.java:802)
    at org.mapdb.DataInput2.readUTF(DataInput2.java:131)
    at org.mapdb.SerializerPojo$1.deserialize(SerializerPojo.java:74)
    at org.mapdb.SerializerPojo$1.deserialize(SerializerPojo.java:39)
    at org.mapdb.Store.deserialize(Store.java:270)
    at org.mapdb.StoreDirect.get2(StoreDirect.java:456)
    at org.mapdb.StoreDirect.get(StoreDirect.java:409)
    at org.mapdb.Store.getSerializerPojo(Store.java:86)
    at org.mapdb.EngineWrapper.getSerializerPojo(EngineWrapper.java:123)
    at org.mapdb.EngineWrapper.getSerializerPojo(EngineWrapper.java:123)
    at org.mapdb.DB.<init>(DB.java:82)
    at org.mapdb.DBMaker.make(DBMaker.java:599)

The text was updated successfully, but these errors were encountered:

jrumbinas · 2014-01-10T15:04:33Z

Calling these lines before closing fixes the problem:

SerializerPojo serializer = db.getEngine().getSerializerPojo();
serializer.save(db.getEngine());

Update: Calling this resulted in another exception:

Exception in thread "main" java.lang.AssertionError: data were not fully read, check your serializer 
    at org.mapdb.Store.deserialize(Store.java:272)
    at org.mapdb.StoreDirect.get2(StoreDirect.java:456)
    at org.mapdb.StoreDirect.get(StoreDirect.java:409)
    at org.mapdb.EngineWrapper.get(EngineWrapper.java:59)
    at org.mapdb.Caches$LRU.get(Caches.java:69)
    at org.mapdb.BTreeMap.valExpand(BTreeMap.java:606)
    at org.mapdb.BTreeMap.remove2(BTreeMap.java:954)
    at org.mapdb.BTreeMap.remove(BTreeMap.java:926)

jankotek · 2014-01-10T15:10:17Z

How is DB closed on first run? Do
you call db.close() or is it done by
JVM shutdown hook?

jrumbinas · 2014-01-10T15:20:01Z

if (!db.isClosed()) {
    db.close();
}
db = open(readOnly);

jrumbinas · 2014-01-13T08:30:44Z

Just tested with 519f779 (recreated whole DB)
Note: class name is \u0000!

Exception in thread "main" java.lang.RuntimeException: java.lang.ClassNotFoundException: �
    at org.mapdb.SerializerPojo.classForName(SerializerPojo.java:95)
    at org.mapdb.SerializerPojo$1.deserialize(SerializerPojo.java:74)
    at org.mapdb.SerializerPojo$1.deserialize(SerializerPojo.java:39)
    at org.mapdb.Store.deserialize(Store.java:270)
    at org.mapdb.StoreDirect.get2(StoreDirect.java:456)
    at org.mapdb.StoreDirect.get(StoreDirect.java:409)
    at org.mapdb.Store.getSerializerPojo(Store.java:86)
    at org.mapdb.EngineWrapper.getSerializerPojo(EngineWrapper.java:123)
    at org.mapdb.DB.<init>(DB.java:82)
    at org.mapdb.DBMaker.make(DBMaker.java:599)
    at com.r9.atlas.util.MapDB.open(MapDB.java:164)
    at com.r9.atlas.util.MapDB.reopen(MapDB.java:184)
    at com.r9.atlas.util.MapDB.applyChanges(MapDB.java:343)

jrumbinas · 2014-01-13T10:57:41Z

The strangest thing is that SerializerPojo state doesn't change at all (I've manually checked registered class array)

jrumbinas · 2014-01-13T11:40:04Z

I found an actual record, which if added will cause this exception to happen. Only a single instance of GroupedData object containing 106 HotelDescriptionPhoto items. It must be related to storage format change.
In this particular case serialized object takes 11kb.

public class GroupedData implements Serializable {
    private final ArrayList<T> items;

    public GroupedData(List<T> items) {
        if (items == null || items.isEmpty()){
            throw new IllegalArgumentException();
        }
        this.items = new ArrayList<>(items.size());
        this.items.addAll(items);
    }
public class HotelDescriptionPhoto implements Serializable {
    public final Integer hotel_id;
    public final Integer photo_id;
    public final Integer descriptiontype_id;
    public final String url_max300;
    public final String url_original;
    public final String url_square60;
}

jrumbinas · 2014-01-13T13:25:35Z

I've filtered the data and inserted only small bunch of records. This resulted in the same exception but with different className

Exception in thread "main" java.lang.RuntimeException: java.lang.ClassNotFoundException: �㢈Of
    at org.mapdb.SerializerPojo.classForName(SerializerPojo.java:95)
    at org.mapdb.SerializerPojo$1.deserialize(SerializerPojo.java:74)
    at org.mapdb.SerializerPojo$1.deserialize(SerializerPojo.java:39)
    at org.mapdb.Store.deserialize(Store.java:270)
    at org.mapdb.StoreDirect.get2(StoreDirect.java:456)
    at org.mapdb.StoreDirect.get(StoreDirect.java:409)
    at org.mapdb.Store.getSerializerPojo(Store.java:86)
    at org.mapdb.EngineWrapper.getSerializerPojo(EngineWrapper.java:123)
    at org.mapdb.EngineWrapper.getSerializerPojo(EngineWrapper.java:123)
    at org.mapdb.DB.<init>(DB.java:82)
    at org.mapdb.DBMaker.make(DBMaker.java:599)
    at com.r9.atlas.util.MapDB.open(MapDB.java:163)
    at com.r9.atlas.util.MapDB.reopen(MapDB.java:183)
    at com.r9.atlas.util.MapDB.applyChanges(MapDB.java:335)

jrumbinas · 2014-01-13T16:02:16Z

I found another test cases when two simple classes (no list) result in the following exception:

public class HotelDescriptionTranslation implements Serializable {
    public final Integer hotel_id;
    public final Integer descriptiontype_id;
    public final String description;
    public final String languagecode;
}

Exception in thread "main" java.lang.RuntimeException: java.lang.ClassNotFoundException: �������쀢.parsers.hotels.BookingUtils.model.Hotel����address��java.lang.String�ch
    at org.mapdb.SerializerPojo.classForName(SerializerPojo.java:95)
    at org.mapdb.SerializerPojo$1.deserialize(SerializerPojo.java:74)
    at org.mapdb.SerializerPojo$1.deserialize(SerializerPojo.java:39)
    at org.mapdb.Store.deserialize(Store.java:270)
    at org.mapdb.StoreDirect.get2(StoreDirect.java:456)
    at org.mapdb.StoreDirect.get(StoreDirect.java:409)
    at org.mapdb.Store.getSerializerPojo(Store.java:86)
    at org.mapdb.EngineWrapper.getSerializerPojo(EngineWrapper.java:123)
    at org.mapdb.EngineWrapper.getSerializerPojo(EngineWrapper.java:123)
    at org.mapdb.DB.<init>(DB.java:82)
    at org.mapdb.DBMaker.make(DBMaker.java:599)
    at com.r9.atlas.util.MapDB.open(MapDB.java:164)
    at com.r9.atlas.util.MapDB.reopen(MapDB.java:184)
    at com.r9.atlas.util.MapDB.applyChanges(MapDB.java:336)

jrumbinas · 2014-01-13T16:12:40Z

Maybe it has something to do with string encoding? We do have text translated in various languages.

jankotek · 2014-01-14T01:10:37Z

MapDB has central class catalog, which stores class names and class structure. It looks like that record got corrupted or overwritten by some other data. I will try to fix it now.

jankotek · 2014-01-14T01:23:26Z

MapDB supports crc32 checksums. Perhaps enable this option to get better error message:

  DBMaker.checksumEnable()

jankotek · 2014-01-14T01:57:50Z

I have trouble to replicate this issue. Could you:

run your scenario with checksum enabled? I think it could produce more meaning full error message.
checkout this test case, perhaps it needs more settings? I run this example twice, second time with read-only mode enabled.
https://github.com/jankotek/MapDB/blob/dd39d3c56c2c53e38e85c38e4381a20f7488bc93/src/test/java/org/mapdb/Issues261Test.java

jrumbinas · 2014-01-14T08:12:45Z

1st option doesn't help much. DB has 4926540 records, one was added and after reopen I get this:

Exception in thread "main" java.io.IOError: java.io.IOException: Checksum does not match, data broken
    at org.mapdb.StoreDirect.get(StoreDirect.java:411)
    at org.mapdb.Store.getSerializerPojo(Store.java:86)
    at org.mapdb.EngineWrapper.getSerializerPojo(EngineWrapper.java:123)
    at org.mapdb.EngineWrapper.getSerializerPojo(EngineWrapper.java:123)
    at org.mapdb.DB.<init>(DB.java:82)
    at org.mapdb.DBMaker.make(DBMaker.java:599)
    at com.r9.atlas.util.MapDB.open(MapDB.java:163)
    at com.r9.atlas.util.MapDB.reopen(MapDB.java:183)
    at com.r9.atlas.util.MapDB.applyChanges(MapDB.java:335)

jrumbinas · 2014-01-14T15:44:49Z

Unfortunately I'm unable to reproduce this bug in test environment. With 0.9.8 I get the very same error.
Is there anything else I could try? Any Ideas?

jankotek · 2014-01-14T16:30:47Z

1st option helps to isolate problem. I have about 5 theories, it will probably take a week to fix this.

jankotek · 2014-01-14T16:31:35Z

I think enabling transaction could work-around this problem.

jrumbinas · 2014-01-14T20:15:47Z

PojoSerializer contains 17 classes. Tuple2 is used as a key: 1st value is hotel ID, 2nd auto pk counter. This results in data sorted by hotel ID. Data is inserted in 8 passes. In the resulting tree single hotel has up to 1000 objects (mean is about 50)

jrumbinas · 2014-01-15T16:02:08Z

Enabling transactions actually did not helped to workaround the issue :/
Please let me know when I can test if this bug is fixed for sure.

jankotek · 2014-01-28T18:03:28Z

I have no idea howto reproduce this issue

jankotek · 2014-01-28T18:05:42Z

Perhaps if you could send me your full dataset with code to reproduce it.

jrumbinas · 2014-01-28T19:26:57Z

I'm sorry, but the data I'm using is confidential. Have you checked all five theories?

jankotek · 2014-01-29T07:51:25Z

Yes, no luck. For now I think that file failed to sync on last close and some data were not written to disk.

jankotek · 2014-01-29T09:20:19Z

One more thing: would you ran your test with assertions enabled (-ea command line switch). This could catch some issues early.

jrumbinas · 2014-01-31T19:14:07Z

Apparently the -ea flag was set by IntelliJ so no luck about it too :/

jankotek · 2014-02-14T15:34:22Z

Hallelujah.

I think I found problem. There was typo and class catalog in SerializerPojo would not be saved when database closed. I am 99% sure this is now fixed in trunk. 0.9.10 with this fix will be released in 2 days.

jrumbinas · 2014-02-14T15:38:46Z

Thanks, I'll give it a shot on Monday :)

jrumbinas · 2014-02-17T13:28:37Z

Seems like the issue is gone, nice job!

jrumbinas · 2014-02-17T13:32:52Z

P.s. do you have a unit test to check this?

jankotek · 2014-02-17T15:02:33Z

I do, but it runs longer, so is not inside mapdb project. I have burn tests
which verify this type of stuff

On Monday, February 17, 2014 05:32:53 Justinas wrote:

P.s. do you have a unit test to check this?

jankotek · 2014-02-18T14:51:25Z

MapDB 0.9.10 is out

jankotek added a commit that referenced this issue Jan 14, 2014

#261 add test case

dd39d3c

jankotek added a commit that referenced this issue Feb 14, 2014

StoreDirect: SerializerPojo could get corrupted on close. See #261

e517b32

jankotek added the fixed in trunk label Feb 14, 2014

jankotek closed this as completed Feb 18, 2014

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Failed to deserialize SerializerPojo #261

Failed to deserialize SerializerPojo #261

jrumbinas commented Jan 10, 2014

jrumbinas commented Jan 10, 2014

jankotek commented Jan 10, 2014

jrumbinas commented Jan 10, 2014

jrumbinas commented Jan 13, 2014

jrumbinas commented Jan 13, 2014

jrumbinas commented Jan 13, 2014

jrumbinas commented Jan 13, 2014

jrumbinas commented Jan 13, 2014

jrumbinas commented Jan 13, 2014

jankotek commented Jan 14, 2014

jankotek commented Jan 14, 2014

jankotek commented Jan 14, 2014

jrumbinas commented Jan 14, 2014

jrumbinas commented Jan 14, 2014

jankotek commented Jan 14, 2014

jankotek commented Jan 14, 2014

jrumbinas commented Jan 14, 2014

jrumbinas commented Jan 15, 2014

jankotek commented Jan 28, 2014

jankotek commented Jan 28, 2014

jrumbinas commented Jan 28, 2014

jankotek commented Jan 29, 2014

jankotek commented Jan 29, 2014

jrumbinas commented Jan 31, 2014

jankotek commented Feb 14, 2014

jrumbinas commented Feb 14, 2014

jrumbinas commented Feb 17, 2014

jrumbinas commented Feb 17, 2014

jankotek commented Feb 17, 2014

jankotek commented Feb 18, 2014

Failed to deserialize SerializerPojo #261

Failed to deserialize SerializerPojo #261

Comments

jrumbinas commented Jan 10, 2014

jrumbinas commented Jan 10, 2014

jankotek commented Jan 10, 2014

jrumbinas commented Jan 10, 2014

jrumbinas commented Jan 13, 2014

jrumbinas commented Jan 13, 2014

jrumbinas commented Jan 13, 2014

jrumbinas commented Jan 13, 2014

jrumbinas commented Jan 13, 2014

jrumbinas commented Jan 13, 2014

jankotek commented Jan 14, 2014

jankotek commented Jan 14, 2014

jankotek commented Jan 14, 2014

jrumbinas commented Jan 14, 2014

jrumbinas commented Jan 14, 2014

jankotek commented Jan 14, 2014

jankotek commented Jan 14, 2014

jrumbinas commented Jan 14, 2014

jrumbinas commented Jan 15, 2014

jankotek commented Jan 28, 2014

jankotek commented Jan 28, 2014

jrumbinas commented Jan 28, 2014

jankotek commented Jan 29, 2014

jankotek commented Jan 29, 2014

jrumbinas commented Jan 31, 2014

jankotek commented Feb 14, 2014

jrumbinas commented Feb 14, 2014

jrumbinas commented Feb 17, 2014

jrumbinas commented Feb 17, 2014

jankotek commented Feb 17, 2014

jankotek commented Feb 18, 2014