Lazy initialization exception on mass indexing/intial indexing


#1

We have hibernate search elastic search 5.9.2 , hibernate search engine 5.9.2 and same hibernate orm version. But when we deploy our code on production TCServer the startup fails on massindexing the data to Elastic server 6.3.2 with an exception:

 org.hibernate.PropertyAccessException: Exception occurred inside setter of com.csc.pt.svc.data.to.Basclt0100TO.basclt0300toList
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.property.access.spi.EnhancedSetterImpl.set(EnhancedSetterImpl.java:86)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.tuple.entity.AbstractEntityTuplizer.setPropertyValues(AbstractEntityTuplizer.java:709)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.tuple.entity.PojoEntityTuplizer.setPropertyValues(PojoEntityTuplizer.java:205)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.persister.entity.AbstractEntityPersister.setPropertyValues(AbstractEntityPersister.java:4697)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.engine.internal.TwoPhaseLoad.doInitializeEntity(TwoPhaseLoad.java:183)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.engine.internal.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:125)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.loader.plan.exec.process.internal.AbstractRowReader.performTwoPhaseLoad(AbstractRowReader.java:238)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.loader.plan.exec.process.internal.AbstractRowReader.finishUp(AbstractRowReader.java:209)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.loader.plan.exec.process.internal.ResultSetProcessorImpl.extractResults(ResultSetProcessorImpl.java:133)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:122)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:86)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.loader.entity.plan.AbstractLoadPlanBasedEntityLoader.loadEntityBatch(AbstractLoadPlanBasedEntityLoader.java:127)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.loader.entity.plan.LegacyBatchingEntityLoaderBuilder$LegacyBatchingEntityLoader.load(LegacyBatchingEntityLoaderBuilder.java:99)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:4073)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.event.internal.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:508)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.event.internal.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:478)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.event.internal.DefaultLoadEventListener.load(DefaultLoadEventListener.java:219)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.event.internal.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:262)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.event.internal.DefaultLoadEventListener.doOnLoad(DefaultLoadEventListener.java:121)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.event.internal.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:89)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.internal.SessionImpl.fireLoad(SessionImpl.java:1237)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.internal.SessionImpl.internalLoad(SessionImpl.java:1120)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.type.EntityType.resolveIdentifier(EntityType.java:646)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.type.EntityType.resolve(EntityType.java:431)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.engine.internal.TwoPhaseLoad.doInitializeEntity(TwoPhaseLoad.java:165)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.engine.internal.TwoPhaseLoad.initializeEntity(TwoPhaseLoad.java:125)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.loader.Loader.initializeEntitiesAndCollections(Loader.java:1146)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.loader.Loader.processResultSet(Loader.java:1005)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.loader.Loader.doQuery(Loader.java:943)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:349)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.loader.Loader.doList(Loader.java:2615)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.loader.Loader.doList(Loader.java:2598)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2430)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.loader.Loader.list(Loader.java:2425)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.loader.criteria.CriteriaLoader.list(CriteriaLoader.java:109)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1896)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.internal.CriteriaImpl.list(CriteriaImpl.java:366)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.search.batchindexing.impl.IdentifierConsumerDocumentProducer.loadList(IdentifierConsumerDocumentProducer.java:174)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.search.batchindexing.impl.IdentifierConsumerDocumentProducer.loadAllFromQueue(IdentifierConsumerDocumentProducer.java:140)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.search.batchindexing.impl.IdentifierConsumerDocumentProducer.run(IdentifierConsumerDocumentProducer.java:120)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at java.lang.Thread.run(Thread.java:748)
INFO   | jvm 1    | 2018/09/28 16:58:11 | Caused by: java.lang.reflect.InvocationTargetException
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at java.lang.reflect.Method.invoke(Method.java:498)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.property.access.spi.EnhancedSetterImpl.set(EnhancedSetterImpl.java:54)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	... 44 more
INFO   | jvm 1    | 2018/09/28 16:58:11 | Caused by: org.hibernate.LazyInitializationException: failed to lazily initialize a collection, no session or session was closed
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.collection.internal.AbstractPersistentCollection.throwLazyInitializationException(AbstractPersistentCollection.java:582)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.collection.internal.AbstractPersistentCollection.throwLazyInitializationExceptionIfNotConnected(AbstractPersistentCollection.java:574)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.collection.internal.AbstractPersistentCollection.access$200(AbstractPersistentCollection.java:55)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.collection.internal.AbstractPersistentCollection$1.doWork(AbstractPersistentCollection.java:165)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.collection.internal.AbstractPersistentCollection$1.doWork(AbstractPersistentCollection.java:146)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.collection.internal.AbstractPersistentCollection.withTemporarySessionIfNeeded(AbstractPersistentCollection.java:247)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.collection.internal.AbstractPersistentCollection.readSize(AbstractPersistentCollection.java:145)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.collection.internal.PersistentSet.size(PersistentSet.java:143)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at java.util.AbstractSet.equals(AbstractSet.java:92)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.internal.util.compare.EqualsHelper.areEqual(EqualsHelper.java:53)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at com.csc.pt.svc.data.to.Basclt0100TO.$$_hibernate_write_basclt0300toList(Basclt0100TO.java)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	... 49 more
I

Below are the mapping files. Basically we are using the @IndexedEmbedded and @ContainedIn relationships. And have OneToMany and ManyToOne relationships.

<property name="hibernate.search.default.indexmanager">elasticsearch</property>
<property name="hibernate.search.default.elasticsearch.host">http://127.0.0.1:9200</property>
<property name="hibernate.search.default.elasticsearch.index_schema_management_strategy">drop-and-create</property>
<property name="hibernate.search.default.elasticsearch.required_index_status">yellow</property>

Parent Class Basclt0100.hbm file which IndexedEmbed the other two entities.

 <set name="basclt0300toList" table="BASCLT0300" inverse="true" cascade="all"  fetch="join">
            <key>
                <column name="CLTSEQNUM" not-null="true" />
            </key>
            <one-to-many class="com.csc.pt.svc.data.to.Basclt0300TO" />
        </set>
        <set name="basclt0900toList" table="BASCLT0900" inverse="true" cascade="all" lazy="true" fetch="join">
            <key>
                <column name="CLTSEQNUM" not-null="true" />
            </key>
            <one-to-many class="com.csc.pt.svc.data.to.Basclt0900TO" />
        </set>

First Child class’s Basclt0900.hbm, which has the @ContainedIn annotation in entity

  <many-to-one name="basclt0100to" class="com.csc.pt.svc.data.to.Basclt0100TO" cascade="save-update, delete" fetch="select" insert="false" update="false">
            <column name="CLTSEQNUM" not-null="true" />
        </many-to-one>

Second child class Basclt0300.hbm, which has the @ContainedIn annotation in entity

    <many-to-one name="basclt0100to" class="com.csc.pt.svc.data.to.Basclt0100TO" cascade="all" fetch="select" insert="false" update="false">
            <column name="CLTSEQNUM" not-null="true" />
        </many-to-one>

and to index we call:

FullTextSession fullTextSession = Search.getFullTextSession(session.getSession());
fullTextSession.createIndexer().startAndWait();

Now, this full code works fine in development environment(Tomcat Server), but as soon as we put it on Prod(TC Server), it fails on index creation.

Also, I had to call manual refresh for elastic search data persistence ,after entity Basclt0900 is saved to database. Only after this I get all the three entities data into a single index/master, which is Basclt0100.

Please share your views.


#2

Hibernate Search is not the one throwing the exception. As you can see here, the error occurs while fetching results from Hibernate ORM:

|INFO   | jvm 1    | 2018/09/28 16:58:11 | |at org.hibernate.internal.SessionImpl.list(SessionImpl.java:1896)|
|---|---|
|INFO   | jvm 1    | 2018/09/28 16:58:11 | |at org.hibernate.internal.CriteriaImpl.list(CriteriaImpl.java:366)|
|INFO   | jvm 1    | 2018/09/28 16:58:11 | |at org.hibernate.search.batchindexing.impl.IdentifierConsumerDocumentProducer.loadList(IdentifierConsumerDocumentProducer.java:174)|

And as you can see here, the error is caused by some problem in the bytecode enhancement:

INFO   | jvm 1    | 2018/09/28 16:58:11 | Caused by: org.hibernate.LazyInitializationException: failed to lazily initialize a collection, no session or session was closed
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.collection.internal.AbstractPersistentCollection.throwLazyInitializationException(AbstractPersistentCollection.java:582)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.collection.internal.AbstractPersistentCollection.throwLazyInitializationExceptionIfNotConnected(AbstractPersistentCollection.java:574)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.collection.internal.AbstractPersistentCollection.access$200(AbstractPersistentCollection.java:55)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.collection.internal.AbstractPersistentCollection$1.doWork(AbstractPersistentCollection.java:165)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.collection.internal.AbstractPersistentCollection$1.doWork(AbstractPersistentCollection.java:146)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.collection.internal.AbstractPersistentCollection.withTemporarySessionIfNeeded(AbstractPersistentCollection.java:247)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.collection.internal.AbstractPersistentCollection.readSize(AbstractPersistentCollection.java:145)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.collection.internal.PersistentSet.size(PersistentSet.java:143)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at java.util.AbstractSet.equals(AbstractSet.java:92)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at org.hibernate.internal.util.compare.EqualsHelper.areEqual(EqualsHelper.java:53)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	at com.csc.pt.svc.data.to.Basclt0100TO.$$_hibernate_write_basclt0300toList(Basclt0100TO.java)
INFO   | jvm 1    | 2018/09/28 16:58:11 | 	... 49 more
I

If I was you, I would try to reproduce the problem with a basic Hibernate ORM query that tries to load entity Basclt0100TO. There is very probably either a mapping issue, or a bug in Hibernate ORM. In either case, getting rid of some complexity can only help you to debug it.

As side notes…

First, you’re using outdated versions of Hibernate Search an Hibernate ORM; the latest version of Hibernate Search is 5.10.4.Final and the latest version of Hibernate ORM is 5.3.6.Final. Switching to those versions could eliminate your problem, as several bugs have been fixed, in particular when it comes to bytecode enhancement.

Second, even though it’s unrelated to your problem, Hibernate Search 5 is not designed to work well with Elasticsearch 6. From the documentation:

Hibernate Search expects an Elasticsearch cluster running version 2.x or 5.x.

You probably also got a warning in your logs about that.

Now, as long as ES6 is backward-compatible with ES5, it should work, but since it’s a major version, there’s no guarantee. In particular Elasticsearch 6 does not allow to map multiple types in a single index, so you should avoid doing that.


#3

Thank You, @yrodiere. Will setup as per versions suggested by you. And will share the outcome. Thanks again for your time.