Unexpected exception during open the database

Hello,

do have an idea why we get following exception sometimes, if we open a database?

Exception 1:

Exception in thread "Thread-18" java.lang.NullPointerException
at com.objectdb.o.LFL.YC(LFL.java:987)
at com.objectdb.o.LFL.YC(LFL.java:962)
at com.objectdb.o.PCF.g(PCF.java:149)
at com.objectdb.o.PAG.N(PAG.java:494)
at com.objectdb.o.UPT.a(UPT.java:180)
at com.objectdb.o.URT.a(URT.java:183)
at com.objectdb.o.TSK.f(TSK.java:184)
at com.objectdb.o.TSK.b(TSK.java:157)
at com.objectdb.o.TSK.c(TSK.java:96)
at com.objectdb.o.TSM.a(TSM.java:88)
at com.objectdb.o.UTT.r(UTT.java:377)
at com.objectdb.o.UTT.g(UTT.java:205)
at com.objectdb.o.TSK.b(TSK.java:146)
at com.objectdb.o.TSK.c(TSK.java:96)
at com.objectdb.o.MST.Zc(MST.java:1180)
at com.objectdb.o.IXA$1.run(IXA.java:418)

Exception 2:

Exception in thread "ODB-IndexActivation" java.lang.NullPointerException
at com.objectdb.o.LFL.Yz(LFL.java:1154)
at com.objectdb.o.LFL.Yz(LFL.java:1127)
at com.objectdb.o.PAG.Q(PAG.java:953)
at com.objectdb.o.PGC.p(PGC.java:285)
at com.objectdb.o.SNP.v(SNP.java:459)
at com.objectdb.o.OBI.f(OBI.java:453)
at com.objectdb.o.OBI.e(OBI.java:362)
at com.objectdb.o.OBI.d(OBI.java:279)
at com.objectdb.o.MBI.a(MBI.java:53)
at com.objectdb.o.MBI.Zi(MBI.java:73)
at com.objectdb.o.MST.ZY(MST.java:811)
at com.objectdb.o.IXA.a(IXA.java:294)
at com.objectdb.o.IXA.run(IXA.java:266)
at java.lang.Thread.run(Thread.java:748)

This report seems to be related to Issue #1860, which is still open, but apparently there is a workaround.

See posts #11 and #13 by your company.

The problem seems to be related to opening and closing the database for a short period, when indexes require updates.

The issue is not related to Issue #1860.

It occurs, if an implict migration of package name and class name of an entity is defined in the objectdb.conf.

    <schema>
        <package name="com.btc.ep.bl.dmos">
            <class name="TestImpl" new-name="com.btc.ep.bl.internal.dmos.RenamedTestImpl"/>
        </package>                    
    </schema>

@Entity
public class RenamedTestImpl {

    ...

    @Index
    private String scopeID;

    ...

}

if we remove the @Index annotation in the entity or we remove the schema block from objectdb.conf all works fine during opening the database.

The automatic index update is not part of the objectdb.conf, this cannot be the reason.
<!--<index-update enabled="true" priority="40" />-->

The exception is thrown during index rebuild. It is strange that a schema change triggers an index update, unless the target class already exists with objects, and without the index.

Anyway, it seems that during index rebuild the database is closed, which is a known issue with the index rebuild. Could you please check if you get the exception, if you open the database and keep it open longer?

The issue also occurs, if we wait 10 minutes before we close the database.

We have also the code part, mentioned in Issue #1860, in order to synchronize the ODB-IndexActivation Thread.

> The issue also occurs, if we wait 10 minutes before we close the database.

Could please clarify if in this case the exception is also thrown after 10 minutes, immediately after closing the database?

The exception is thrown after closing the database.

I have still a question about the automatic index thread.

If the automatic index thread fails with an exception then I would expect that the index is automatically rebuild, if the database is opened again for a longer time. Is that the case?

> The exception is thrown after closing the database.

We will look into a way to silence this exception.

> If the automatic index thread fails with an exception then I would expect that the index is automatically rebuild, if the database is opened again for a longer time. Is that the case?

Yes.

It is still unclear why an index rebuild is required due to class name change. Are you sure that this is the only schema change?

Yes, the reason is the schema change for an entity which have a field with @Index.

If we remove the @Index from the entity or we remove the schema change from objectdb.conf then all works fine.

Thank you for this clarification. Some more information may help.

Are these exceptions written to the log? thrown? stop anything?

We can provide a quick fix that catches and hides the exception by simply exiting the index update thread in that case, but it is important to understand if there are any side effects except getting these exception in the log.

You wrote:

> do have an idea why we get following exception sometimes, if we open a database?

But the stack traces do not show opening a database. Maybe you have other stack traces that show the caller methods that try to open the database?

Sorry for the late reply, I will try to pick up the conversation from my colleague.

Are these exceptions written to the log? thrown? stop anything?

In this particular case, the access to the database is part of an external java process that we have triggered with the process builder. The errors are retrieved from process.getErrorStream().

This process migrates the database of an older release of our product to the recent one. We don't observe any issues caused by the failing index activation and we don't expect one, since we "discard" the database anyway, once the migration is finished.

But the stack traces do not show opening a database. Maybe you have other stack traces that show the caller methods that try to open the database?

I can try to get a better stack trace for you.

> This process migrates the database of an older release of our product to the recent one. We don't observe any issues caused by the failing index activation and we don't expect one, since we "discard" the database anyway, once the migration is finished.

Note that an index will be rebuilt if it is defined in the up to date schema (i.e. in the available entity class), whether you need it or not.

Indeed, it makes no sense to build a new index in the old database, so you may try disabling index activation by using a special configuration with index-update disabled.

Currently, we have not specified the index activation at all, i.e. <index-update> element is not present in the configuration file. Your comment suggests that the default value for this is tag is "true" and hence index update is always performed in our case. Can you please confirm this?

Just checked, and indeed, the default is enabled.

Good Morning,

unfortunately, if we introduce the <index-update> element and set it to false, we still get errors. I'm not sure, but I thinke we now have a different stack trace:

Exception in thread "Thread-25" java.lang.NullPointerException
at com.objectdb.o.LFL.YC(LFL.java:987)
at com.objectdb.o.LFL.YC(LFL.java:962)
at com.objectdb.o.FIW.ZS(FIW.java:96)
at com.objectdb.o.DSS.F(DSS.java:964)
at com.objectdb.o.DSS.j(DSS.java:723)
at com.objectdb.o.DSS.ZR(DSS.java:699)
at com.objectdb.o.MST.Zc(MST.java:1181)
at com.objectdb.o.IXA$1.run(IXA.java:418)

It is unclear how this stack trace can be generated due to setting index-update to false. Actually, such a stack trace is expected when index-update is set to true and the database is closed before the update is completed (see the stack trace at post #1)

Therefore, please verify that the correct configuration file is changed. Quite often changes in the configuration files do not affect, because they are applied in a wrong configuration file. See this manual page regarding where objectdb searches the configuration file.

I am fairly certain that we use the correct configuration file, as we also define schema evolution inside of it and a few other things that would otherise cause serious issues.

At the same time, it looks like adding

<index-update enabled="false" priority="40" />

inside of the <database> tag does not do anything.

I would be thankful, if you can have a look on your side that the code does work and disables the index update. Otherwise, I'm out of ideas :/

OK, so after excluding the possibility that the active configuration was not changed, we will have to look elsewhere. On our side it is seems that index update, when disabled, doesn't cause any issue.

Could you please try your conversion program with a new empty log file and then search for the exact stack traces in the log file? The stack trace at #16 above is likely to appear with other additional stack traces.

Do this help?

Exception in thread "ODB-IndexActivation" com.objectdb.o.UserException: Failed to read from file 'C:\Users\developer\AppData\Roaming\BTC\ep\profileMigration\2.7.0\profiles\bnk_16mi47fob\profile\eppdb.odb'
    at com.objectdb.o.MSG.a(MSG.java:77)
    at com.objectdb.o.LFL.Yz(LFL.java:1163)
    at com.objectdb.o.LFL.Yz(LFL.java:1127)
    at com.objectdb.o.PAG.Q(PAG.java:953)
    at com.objectdb.o.PGC.p(PGC.java:285)
    at com.objectdb.o.SNP.v(SNP.java:459)
    at com.objectdb.o.OBI.f(OBI.java:453)
    at com.objectdb.o.OBI.e(OBI.java:362)
    at com.objectdb.o.OBI.d(OBI.java:279)
    at com.objectdb.o.MBI.a(MBI.java:53)
    at com.objectdb.o.MBI.Zi(MBI.java:73)
    at com.objectdb.o.MST.ZY(MST.java:811)
    at com.objectdb.o.IXA.a(IXA.java:294)
    at com.objectdb.o.IXA.run(IXA.java:266)
    at java.base/java.lang.Thread.run(Unknown Source)
Caused by: java.io.IOException: Stream Closed
    at java.base/java.io.RandomAccessFile.seek0(Native Method)
    at java.base/java.io.RandomAccessFile.seek(Unknown Source)
    at com.objectdb.o.LFL.Yz(LFL.java:1154)
    ... 13 more

Please note that we have enabled index activation in the example above. I'm waiting for new results, where we try to disable the index activation.

Sure, it helps. It shows that the index update is not disabled.

This stack trace is not expected when the index update is disabled.

> I am fairly certain that we use the correct configuration file, as we also define schema evolution inside of it and a few other things that would otherwise cause serious issues.

Maybe you have more than one copy of the configuration file with this schema change? or maybe different processes using different configuration files?

Try to change that configuration file by entering an XML syntax error - if your application still works, with no exception regarding that error, then this is not the correct configuration file.

I have now disabled the index update in *all* objectdb config files that we use, including the ones, where it must be enabled. However, we still see the NPE with the stack that starts with

Exception in thread "ODB-IndexActivation" java.lang.NullPointerException
    at com.objectdb.o.LFL.Yz(LFL.java:1154)
    at com.objectdb.o.LFL.Yz(LFL.java:1127)
    at com.objectdb.o.PAG.Q(PAG.java:953)

In our case, the index activation is obviously still enabled and I don't know why. I've attached our config file to this post. Can you please have a look, if something is wrong there. If not, can you please test it on your end?

Your configuration file seems fine. Have you tried the suggestion in #21 to add an error and see if you get exception? Note that if ObjectDB doesn't find the configuration in the expected path it uses an internal configuration, which is a resource file inside the objectdb jar file. You may also try changing that internal resource file (META-INF/objectdb.conf) in the jar file.

We tested several times, and the ODB-IndexActivation is not run when disabled in the configuration, including now, with the configuration file that you just sent.

Another path we can try is to silent this exception. Does it cause any issue except an error in the log?

Hello again,

we have now tried a lot of things but can't solve the issue. As a result, we would like to follow your other suggestion and ask you to silent this particular exception. It does not cause any other issues for us.

OK. Please try build 2.8.3_06.

Exceptions can still be logged by setting the "index" logger to "debug" level.

The issue occurs yet with the version 2.8.5_05.

Exception in thread "ODB-IndexActivation" java.lang.NullPointerException
 at com.objectdb.o.LFL.Yz(LFL.java:1154)
 at com.objectdb.o.LFL.Yz(LFL.java:1127)
 at com.objectdb.o.PAG.Q(PAG.java:953)
 at com.objectdb.o.PGC.p(PGC.java:285)
 at com.objectdb.o.SNP.v(SNP.java:459)
 at com.objectdb.o.OBI.f(OBI.java:453)
 at com.objectdb.o.OBI.e(OBI.java:362)
 at com.objectdb.o.OBI.d(OBI.java:279)
 at com.objectdb.o.MBI.a(MBI.java:53)
 at com.objectdb.o.MBI.Zi(MBI.java:73)
 at com.objectdb.o.MST.ZY(MST.java:811)
 at com.objectdb.o.IXA.a(IXA.java:294)
 at com.objectdb.o.IXA.run(IXA.java:266)
 at java.base/java.lang.Thread.run(Unknown Source)

The line numbers in this stack trace are not compatible with version 2.8.5_05, indicating that an earlier build was probably used. Please check for old ObjectDB jar files in the classpath.

Yes, you are right. We use also different older versions of ObjectDB. My fault. Sorry.

I will observe the version 2.8.5_05 regarding IndexActivation errors and give you feedback in the next weeks.