Issue #2127: again merger missing logs + objectdb exception

we are facing similar problems as we had before, in the log we have a lot of entries merger ... missing + an objectdb exception. Some objects in the system behave strange. This is a part of the log:

...

[2017-09-26 12:16:14 #1222 store]
SectionClassifier: SectionClassifier{238146996->merger[3309]-missing:1}

[2017-09-26 12:16:25 #1223 store]
SectionClassifier: SectionClassifier{238146996->merger[3309]-missing:1}

[2017-09-26 12:16:33 #1224 store]
SectionClassifier: SectionClassifier{2->merger[3309]-missing:1}

[2017-09-29 06:18:10 #1225 *]
[ObjectDB 2.7.1_01] Unexpected exception (Error 990)
  Generated by Java HotSpot(TM) 64-Bit Server VM 1.8.0_91 (on Windows Server 2012 R2 6.3).
Please report this error on http://www.objectdb.com/database/issue/new
com.objectdb.o.InternalException: null
com.objectdb.o.InternalException
at com.objectdb.o.BYR.o(BYR.java:113)
at com.objectdb.o.BYR.w(BYR.java:206)
at com.objectdb.o.VUT.j(VUT.java:357)
at com.objectdb.o.ACN.VA(ACN.java:173)
at com.objectdb.o.RTT.H(RTT.java:282)
at com.objectdb.o.RST.C(RST.java:183)
at com.objectdb.o.RTT.l(RTT.java:134)
at com.objectdb.o.RST.l(RST.java:24)
at com.objectdb.o.RTT.D(RTT.java:179)
at com.objectdb.o.RST.s(RST.java:121)
at com.objectdb.o.PGT.q(PGT.java:109)
at com.objectdb.o.RST.B(RST.java:93)
at com.objectdb.o.RTT.l(RTT.java:132)
at com.objectdb.o.RST.l(RST.java:24)
at com.objectdb.o.RTT.D(RTT.java:179)
at com.objectdb.o.RST.s(RST.java:121)
at com.objectdb.o.PGT.q(PGT.java:109)
at com.objectdb.o.RST.B(RST.java:93)
at com.objectdb.o.RTT.l(RTT.java:132)
at com.objectdb.o.RST.l(RST.java:24)
at com.objectdb.o.TSK.i(TSK.java:145)
at com.objectdb.o.TSK.f(TSK.java:95)
at com.objectdb.o.TSM.e(TSM.java:86)
at com.objectdb.o.RTT.D(RTT.java:177)
at com.objectdb.o.RST.s(RST.java:121)
at com.objectdb.o.PGT.q(PGT.java:109)
at com.objectdb.o.RST.B(RST.java:93)
at com.objectdb.o.RTT.l(RTT.java:132)
at com.objectdb.o.RST.l(RST.java:24)
at com.objectdb.o.TSK.i(TSK.java:145)
at com.objectdb.o.TSK.f(TSK.java:95)
at com.objectdb.o.TSM.e(TSM.java:86)
at com.objectdb.o.RTT.D(RTT.java:177)
at com.objectdb.o.RST.s(RST.java:121)
at com.objectdb.o.PGT.q(PGT.java:109)
at com.objectdb.o.RST.B(RST.java:93)
at com.objectdb.o.RTT.l(RTT.java:132)
at com.objectdb.o.RST.l(RST.java:24)
at com.objectdb.o.TSK.i(TSK.java:145)
at com.objectdb.o.TSK.f(TSK.java:95)
at com.objectdb.o.MST.a1(MST.java:609)
at com.objectdb.o.MST.U7(MST.java:565)
at com.objectdb.o.BTP.U7(BTP.java:642)
at com.objectdb.o.TAI.A(TAI.java:201)
at com.objectdb.o.TAI.UI(TAI.java:134)
at com.objectdb.o.PRG.ag(PRG.java:687)
at com.objectdb.o.PRG.af(PRG.java:555)
at com.objectdb.o.QRM.U9(QRM.java:286)
at com.objectdb.o.MST.U9(MST.java:988)
at com.objectdb.o.WRA.U9(WRA.java:311)
at com.objectdb.o.WSM.U9(WSM.java:115)
at com.objectdb.o.QRR.g(QRR.java:247)
at com.objectdb.o.QRR.f(QRR.java:153)
at com.objectdb.jpa.JpaQuery.getResultList(JpaQuery.java:719)
at com.agile.hummingbird.CT_Container.computeContainer(CT_Container.java:163)
at com.agile.hummingbird.API.handleGetContainer(API.java:2745)
at com.agile.hummingbird.API.directRequest(API.java:802)
at com.agile.hummingbird.API.handleWebSocketRequest(API.java:630)
at com.agile.hummingbird.WebSocketServerListener.onWebSocketText(WebSocketServerListener.java:128)
at org.eclipse.jetty.websocket.common.events.JettyListenerEventDriver.onTextMessage(JettyListenerEventDriver.java:128)
at org.eclipse.jetty.websocket.common.message.SimpleTextMessage.messageComplete(SimpleTextMessage.java:69)
at org.eclipse.jetty.websocket.common.events.AbstractEventDriver.appendMessage(AbstractEventDriver.java:65)
at org.eclipse.jetty.websocket.common.events.JettyListenerEventDriver.onTextFrame(JettyListenerEventDriver.java:122)
at org.eclipse.jetty.websocket.common.events.AbstractEventDriver.incomingFrame(AbstractEventDriver.java:161)
at org.eclipse.jetty.websocket.common.WebSocketSession.incomingFrame(WebSocketSession.java:309)
at org.eclipse.jetty.websocket.common.extensions.AbstractExtension.nextIncomingFrame(AbstractExtension.java:163)
at org.eclipse.jetty.websocket.common.extensions.compress.PerMessageDeflateExtension.nextIncomingFrame(PerMessageDeflateExtension.java:105)
at org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension.forwardIncoming(CompressExtension.java:136)
at org.eclipse.jetty.websocket.common.extensions.compress.PerMessageDeflateExtension.incomingFrame(PerMessageDeflateExtension.java:85)
at org.eclipse.jetty.websocket.common.extensions.ExtensionStack.incomingFrame(ExtensionStack.java:214)
at org.eclipse.jetty.websocket.common.Parser.notifyFrame(Parser.java:220)
at org.eclipse.jetty.websocket.common.Parser.parse(Parser.java:258)
at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.readParse(AbstractWebSocketConnection.java:632)
at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:480)
at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)
at java.lang.Thread.run(Unknown Source)

Can you share the database with these errors?

we'll do that this night

due to the tough production situation we could not shut down tonight, hopefully we have a chance to shutdown the system tomorrow morning

Hopefully you will be able to fix the database with the Doctor before restarting the server.

Please consider enabling recording. If we cannot find the cause now by analyzing the database this could enable reproducing the problem if it happens again.

which options should we use for recording (we have heavy traffic all the time serving hundreds of clients, so the mode all option could be a problem)

"write" mode should be sufficient to reproduce the problem.

the corrupt database is available

login to our extranet at hummingbird-systems.com using objectdb twice, there is a main menu objectdb, and the rar, download it

We are working on this problem and there is some progress in understanding the context in which the corruption happened. The exact cause is unknown yet so additional work is needed. With no ability to reproduce the problem (yet) progress is slow, but we are getting closer and hope to have a solution (at least a workaround to prevent future corruption) in the next days.

Meanwhile, have you fixed the database using the Doctor and started the system again successfully?

again we have an assert (we could only stop and copy the database 2 days ago, there was not enough time to do a repair)

------------------------------------------------------------------------------------------------------------------------

[2017-10-04 08:15:32 #1 store]
Database 'F:\Hummingbird\Objectdb\db\coreSystemDb.odb' is opened by 13072@wzbhb101

[2017-10-04 08:15:32 #2 server]
Server on port 3333 has started by 13072@wzbhb101

[2017-10-05 12:25:26 #3 *]
[ObjectDB 2.7.1_01] Unexpected exception (Error 990)
  Generated by Java HotSpot(TM) 64-Bit Server VM 1.8.0_91 (on Windows Server 2012 R2 6.3).
Please report this error on http://www.objectdb.com/database/issue/new
com.objectdb.o.InternalException: null
com.objectdb.o.InternalException
at com.objectdb.o.BYR.o(BYR.java:113)
at com.objectdb.o.BYR.w(BYR.java:206)
at com.objectdb.o.VUT.j(VUT.java:357)
at com.objectdb.o.ACN.VA(ACN.java:173)
at com.objectdb.o.RTT.H(RTT.java:282)
at com.objectdb.o.RST.C(RST.java:183)
at com.objectdb.o.RTT.l(RTT.java:134)
at com.objectdb.o.RST.l(RST.java:24)
at com.objectdb.o.RTT.D(RTT.java:179)
at com.objectdb.o.RST.s(RST.java:121)
at com.objectdb.o.PGT.q(PGT.java:109)
at com.objectdb.o.RST.B(RST.java:93)
at com.objectdb.o.RTT.l(RTT.java:132)
at com.objectdb.o.RST.l(RST.java:24)
at com.objectdb.o.RTT.D(RTT.java:179)
at com.objectdb.o.RST.s(RST.java:121)
at com.objectdb.o.PGT.q(PGT.java:109)
at com.objectdb.o.RST.B(RST.java:93)
at com.objectdb.o.RTT.l(RTT.java:132)
at com.objectdb.o.RST.l(RST.java:24)
at com.objectdb.o.TSK.i(TSK.java:145)
at com.objectdb.o.TSK.f(TSK.java:95)
at com.objectdb.o.TSM.e(TSM.java:86)
at com.objectdb.o.RTT.D(RTT.java:177)
at com.objectdb.o.RST.s(RST.java:121)
at com.objectdb.o.PGT.q(PGT.java:109)
at com.objectdb.o.RST.B(RST.java:93)
at com.objectdb.o.RTT.l(RTT.java:132)
at com.objectdb.o.RST.l(RST.java:24)
at com.objectdb.o.TSK.i(TSK.java:145)
at com.objectdb.o.TSK.f(TSK.java:95)
at com.objectdb.o.TSM.e(TSM.java:86)
at com.objectdb.o.RTT.D(RTT.java:177)
at com.objectdb.o.RST.s(RST.java:121)
at com.objectdb.o.PGT.q(PGT.java:109)
at com.objectdb.o.RST.B(RST.java:93)
at com.objectdb.o.RTT.l(RTT.java:132)
at com.objectdb.o.RST.l(RST.java:24)
at com.objectdb.o.TSK.i(TSK.java:145)
at com.objectdb.o.TSK.f(TSK.java:95)
at com.objectdb.o.MST.a1(MST.java:609)
at com.objectdb.o.MST.U7(MST.java:565)
at com.objectdb.o.BTP.U7(BTP.java:642)
at com.objectdb.o.TAI.A(TAI.java:201)
at com.objectdb.o.TAI.UI(TAI.java:134)
at com.objectdb.o.PRG.ag(PRG.java:687)
at com.objectdb.o.PRG.af(PRG.java:555)
at com.objectdb.o.QRM.U9(QRM.java:286)
at com.objectdb.o.MST.U9(MST.java:988)
at com.objectdb.o.WRA.U9(WRA.java:311)
at com.objectdb.o.WSM.U9(WSM.java:115)
at com.objectdb.o.QRR.g(QRR.java:247)
at com.objectdb.o.QRR.f(QRR.java:153)
at com.objectdb.jpa.JpaQuery.getResultList(JpaQuery.java:719)
at com.agile.hummingbird.CT_Container.computeContainer(CT_Container.java:163)
at com.agile.hummingbird.API.handleGetContainer(API.java:2745)
at com.agile.hummingbird.API.directRequest(API.java:802)
at com.agile.hummingbird.API.handleWebSocketRequest(API.java:630)
at com.agile.hummingbird.WebSocketServerListener.onWebSocketText(WebSocketServerListener.java:128)
at org.eclipse.jetty.websocket.common.events.JettyListenerEventDriver.onTextMessage(JettyListenerEventDriver.java:128)
at org.eclipse.jetty.websocket.common.message.SimpleTextMessage.messageComplete(SimpleTextMessage.java:69)
at org.eclipse.jetty.websocket.common.events.AbstractEventDriver.appendMessage(AbstractEventDriver.java:65)
at org.eclipse.jetty.websocket.common.events.JettyListenerEventDriver.onTextFrame(JettyListenerEventDriver.java:122)
at org.eclipse.jetty.websocket.common.events.AbstractEventDriver.incomingFrame(AbstractEventDriver.java:161)
at org.eclipse.jetty.websocket.common.WebSocketSession.incomingFrame(WebSocketSession.java:309)
at org.eclipse.jetty.websocket.common.extensions.AbstractExtension.nextIncomingFrame(AbstractExtension.java:163)
at org.eclipse.jetty.websocket.common.extensions.compress.PerMessageDeflateExtension.nextIncomingFrame(PerMessageDeflateExtension.java:105)
at org.eclipse.jetty.websocket.common.extensions.compress.CompressExtension.forwardIncoming(CompressExtension.java:136)
at org.eclipse.jetty.websocket.common.extensions.compress.PerMessageDeflateExtension.incomingFrame(PerMessageDeflateExtension.java:85)
at org.eclipse.jetty.websocket.common.extensions.ExtensionStack.incomingFrame(ExtensionStack.java:214)
at org.eclipse.jetty.websocket.common.Parser.notifyFrame(Parser.java:220)
at org.eclipse.jetty.websocket.common.Parser.parse(Parser.java:258)
at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.readParse(AbstractWebSocketConnection.java:632)
at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillable(AbstractWebSocketConnection.java:480)
at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)
at java.lang.Thread.run(Unknown Source)

This exception was thrown during query execution.

Can you locate a sample query that generates such an InternalException?

We will try to find that query

The connection between the InternalException (logs #1225, #3 above) and the corruption of one large ObjectProperty object (logs #1222 - #1224 above) is unclear yet, so if we can reproduce the exception by running a specific query it would be a great help.

The Doctor also lists many broken references. Broken references could be application issue rather then ObjectDB (if an object is removed from the database but still referenced). Are you aware for something in your application that can cause broken references or is it something that usually doesn't happen in your system and should be probably related to the database corruption?

the broken references are something that we are aware of, not connected in general to the database corruption. For this we probably have meanwhile a fix.

As regards the query, we'll try to find that. What is the id of that large corrupt property object ?

The id of the corrupted object property is 238146996.

There is another object property (not corrupted) with an issue, id 286779361.

Some information about the corruption problem. Large objects that cannot fit in one database page are split by ObjectDB into multiple sections and each section is stored in a separate page and has a wrapper key that consists of the original primary key of the object with additional information about the section (e.g. section number). Somehow these two specific ObjectProperty instances have nested wrappers, i.e. a section key wrapper that wraps another section key wrapper that wraps the original primary key. This is an unexpected state. Unfortunately we cannot see how this could happen by analyzing relevant ObjectDB code (although it is probably related to updating these large objects). It doesn't happen in our tests. A wrapper section key behaves mainly as the key that it wraps, so this extra nesting doesn't cause corruption, unless the key is also needed in higher levels of the BTree, which is what happened with object 238146996.

We will release a new build that will:

• prevent further corruption by stripping nested section key wrappers when they happen.
• Log information on nested section key wrappers, if found, to help finding the cause of this unexpected situation.
• Log queries that fail with internal exceptions automatically.

The connection between the queries that failed and the corruption of the the ObjectProperty instance is unclear. These query failed during reading of indexes rather than primary data and no corruption is currently found in indexes in the provided database (except number of entries, which is due to the missing ObjectProperty instance). Hopefully there is an index corruption that is caused by the nested section key wrapper problem, so these two problems will be solved together, but we cannot be sure.

Will you have a window anytime soon in which you may be able to repair the database with the Doctor?

We will be able to repair monday to tuesday night. Can you make available the update before ?

one more question regarding the broken references:

- for some references we keep a reference on both sides (for performance reasons)

- some of these references are broken when we delete objects

- there is a mechanism in our application that deals with these broken references as the costs of maintaining these specific references on deleting are very high.

is there a problem to have this kind of broken references ?

The new ObjectDB version will be released today or tomorrow morning.

No problem with broken references, if their existence is planned and managed by the application.

Version 2.7.2 includes the changes that are specified on #15 above.

Please run the Doctor of the new version (2.7.2) to repair the database.

If you have a daily backup that you can run the Doctor on it every day after the repair it would help monitoring the issue further, as the bug has not been solved yet. Hopefully the workaround in version 2.7.2 will prevent database corruption but this is not something that we could test, as we cannot reproduce the bug yet.

Please report any unusual output of the Doctor or in the log (particularly "[unexpected section]" log lines, and failed queries if internal exceptions are thrown and queries are logged).

Thank you for your cooperation in this matter. This bug is complicated to trace but we are getting closer, so hopefully soon it will be solved completely.

after repairing this night we have a log full of exceptions (see attachment), upload of the database before repair is currently in progress

Good. These are not exceptions in the log but logging of stack traces in which a nested section key were created (now this is fixed as it happens, so the database is expected to remain healthy).

It shows that this happens when an optimistic lock exception is thrown during commit, and failed (locked) objects are loaded by keys (which could be section keys) for the error message. This can be repaired permanently now but version 2.7.2 already handles this situation, so no need to worry about these stack traces.

To be on the safe side please use the Doctor to check the database (or generated backups) and report any errors except the expected broken references error.

we see that our system behaves unexpected now, the functionalities that are shown in the trace are not executed

Which trace? The log just shows locations of optimistic lock exceptions, which should fail regardless of printing their location now to the log.

ok, we'll check the other changes that we made

our fault, sorry

query and exception in log:

[2017-10-17 21:57:29 #96 store]
RetrievalTask.reportSecondaryResult: page#21867681, reader.getPos() = 497

[2017-10-17 21:57:29 #97 query]
Error during query execution: select o from ObjectNode o join o.nodePath np where np in
("/(CR)ACCESSRIGHTS1","/(CR)SOFLEXCOMTEST","/(CR)15346","/(CR)15395","/(CR)15560",
"/(CR)15602","/(CR)15759","/(CR)16077","/(CR)16205","/(CR)16225","/(CR)16357",
"/(CR)16531","/(CR)16532","/(CR)16551","/(CR)16560","/(CR)16572","/(CR)16577",
"/(CR)16589","/(CR)16603","/(CR)16621","/(CR)16622","/(CR)16626","/(CR)16627",
"/(CR)16630","/(CR)16640","/(CR)16650","/(CR)16652","/(CR)16653","/(CR)16673",
"/(CR)16674","/(CR)16705","/(CR)16711","/(CR)16731","/(CR)16747","/(CR)16754",
"/(CR)16760","/(CR)16797","/(CR)16809","/(CR)16815","/(CR)16827","/(CR)16840",
"/(CR)16841","/(CR)16857","/(CR)16868","/(CR)16882","/(CR)16883","/(CR)16884",
"/(CR)16884","/(CR)16885","/(CR)16885","/(CR)16895","/(CR)16902","/(CR)16916",
"/(CR)16917","/(CR)16920","/(CR)16922","/(CR)16923","/(CR)16924","/(CR)16925",
"/(CR)16931","/(CR)16934","/(CR)16935","/(CR)16943","/(CR)16950","/(CR)16953",
"/(CR)16969","/(CR)16970","/(CR)16972","/(CR)16973","/(CR)16975","/(CR)16977",
"/(CR)16978","/(CR)16979","/(CR)16981","/(CR)16982","/(CR)16986","/(CR)16989",
"/(CR)16990","/(CR)16991","/(CR)16992","/(CR)16993","/(CR)16994","/(CR)16995",
"/(CR)16996","/(CR)16997","/(CR)16998","/(CR)16999","/(CR)17001","/(CR)17002",
"/(CR)17005","/(CR)17006","/(CR)17007","/(CR)17011","/(CR)17014","/(CR)17019",
"/(CR)17020","/(CR)17021","/(CR)17022","/(CR)17023","/(CR)17024","/(CR)17025",
"/(CR)17026","/(CR)17028","/(CR)17029","/(CR)17030","/(CR)17032","/(CR)17033",
"/(CR)17034","/(CR)17035","/(CR)17036","/(CR)17037","/(CR)17038","/(CR)17039",
"/(CR)17041","/(CR)17042","/(CR)17044","/(CR)17046","/(CR)17047","/(CR)17048",
"/(CR)17049","/(CR)17050","/(CR)17067","/(CR)17068","/(CR)17069","/(CR)17070",
"/(CR)17071","/(CR)17074","/(CR)17080","/(CR)17081","/(CR)17082","/(CR)17083",
"/(CR)17086","/(CR)26947","/(CR)26988","/(CR)41462","/(CR)41894","/(CR)41930",
"/(CR)41941","/(CR)41943","/(CR)41949","/(CR)41955","/(CR)41957","/(CR)41958",
"/(CR)41959","/(CR)50080","/(CR)54211","/(CR)58501","/(CR)59205","/(CR)70006")
(null)

[2017-10-17 21:57:29 #98 *]
[ObjectDB 2.7.2] Unexpected exception (Error 990)
  Generated by Java HotSpot(TM) 64-Bit Server VM 1.8.0_91 (on Windows Server 2012 R2 6.3).
Please report this error on http://www.objectdb.com/database/issue/new
com.objectdb.o.InternalException: null
com.objectdb.o.InternalException
at com.objectdb.o.BYR.o(BYR.java:113)
at com.objectdb.o.BYR.w(BYR.java:206)
at com.objectdb.o.VUT.j(VUT.java:357)
at com.objectdb.o.ACN.VB(ACN.java:173)
at com.objectdb.o.RTT.H(RTT.java:292)
at com.objectdb.o.RST.C(RST.java:183)
at com.objectdb.o.RTT.l(RTT.java:134)
at com.objectdb.o.RST.l(RST.java:24)
at com.objectdb.o.RTT.D(RTT.java:179)
at com.objectdb.o.RST.s(RST.java:121)
at com.objectdb.o.PGT.q(PGT.java:109)
at com.objectdb.o.RST.B(RST.java:93)
at com.objectdb.o.RTT.l(RTT.java:132)
at com.objectdb.o.RST.l(RST.java:24)
at com.objectdb.o.RTT.D(RTT.java:179)
at com.objectdb.o.RST.s(RST.java:121)
at com.objectdb.o.PGT.q(PGT.java:109)
at com.objectdb.o.RST.B(RST.java:93)
at com.objectdb.o.RTT.l(RTT.java:132)
at com.objectdb.o.RST.l(RST.java:24)
at com.objectdb.o.TSK.i(TSK.java:145)
at com.objectdb.o.TSK.f(TSK.java:95)
at com.objectdb.o.TSM.e(TSM.java:86)
at com.objectdb.o.RTT.D(RTT.java:177)
at com.objectdb.o.RST.s(RST.java:121)
at com.objectdb.o.PGT.q(PGT.java:109)
at com.objectdb.o.RST.B(RST.java:93)
at com.objectdb.o.RTT.l(RTT.java:132)
at com.objectdb.o.RST.l(RST.java:24)
at com.objectdb.o.TSK.i(TSK.java:145)
at com.objectdb.o.TSK.f(TSK.java:95)
at com.objectdb.o.TSM.e(TSM.java:86)
at com.objectdb.o.RTT.D(RTT.java:177)
at com.objectdb.o.RST.s(RST.java:121)
at com.objectdb.o.PGT.q(PGT.java:109)
at com.objectdb.o.RST.B(RST.java:93)
at com.objectdb.o.RTT.l(RTT.java:132)
at com.objectdb.o.RST.l(RST.java:24)
at com.objectdb.o.TSK.i(TSK.java:145)
at com.objectdb.o.TSK.f(TSK.java:95)
at com.objectdb.o.MST.a1(MST.java:609)
at com.objectdb.o.MST.U8(MST.java:565)
at com.objectdb.o.BTP.U8(BTP.java:642)
at com.objectdb.o.TAI.A(TAI.java:201)
at com.objectdb.o.TAI.UI(TAI.java:134)
at com.objectdb.o.PRG.ag(PRG.java:687)
at com.objectdb.o.PRG.af(PRG.java:555)
at com.objectdb.o.QRM.Va(QRM.java:286)
at com.objectdb.o.MST.Va(MST.java:991)
at com.objectdb.o.WRA.Va(WRA.java:311)
at com.objectdb.o.WSM.Va(WSM.java:115)
at com.objectdb.o.QRR.g(QRR.java:247)
at com.objectdb.o.QRR.f(QRR.java:153)
at com.objectdb.jpa.JpaQuery.getResultList(JpaQuery.java:721)

It seems that two separate issues are discussed in this thread:

1. The large object corruption (nested section key), which hopefully was fixed in version 2.7.2 (temporary stack traces in the log will be removed in the next build). If you cannot see these section errors when running the Doctor then we should consider this issue as fixed.
2. The exceptions during queries. Your new report (#26) includes useful logging information, including a position in the database in which there is an error. If you can share an up to date copy of the database we will be able to examine this further.

another question regarding the log:

these entries we see only on WINDOWS based systems, under osx we have the same problematic situation but no log entry:

[2017-10-10 02:13:49 #5 section]
[unexpected section] 286779361#0/2-0/3161

[2017-10-10 02:13:49 #6 section]
java.lang.RuntimeException: Stack Trace

at com.objectdb.o.STH.O(STH.java:695)

at com.objectdb.o.SEV.ab(SEV.java:317)
at com.objectdb.o.ENT.C(ENT.java:302)
at com.objectdb.o.OBC.aN(OBC.java:950)
at com.objectdb.o.OBM.bX(OBM.java:1170)
at com.objectdb.o.OBM.bP(OBM.java:878)
at com.objectdb.o.OBM.bN(OBM.java:754)
at com.objectdb.jpa.EMImpl.commit(EMImpl.java:287)
at com.agile.hummingbird.SS_ScheduledSlot.linkSetSlot(SS_ScheduledSlot.java:396)

The log entries in #28 above are temporary logging of the nested section key workaround that will be removed in the next build, and may be ignored now.

They should be shown on any OS when there is an optimistic lock exception on a large object (>= ~2KB).

Assuming you have ObjectDB 2.7.2 also on osx - probably on that system there are no optimistic lock exceptions on large objects.

Regarding the error in #26 above, it seems to be a duplicate of issue #1107, issue #1128 and issue #1564.

The list in log entry #97 (post #26 above) indeed shows a repeating value: "/(CR)16885","/(CR)16885".

Unfortunately this bug has not been fixed yet and of course it should be fixed as soon as possible, but the workaround of eliminating duplicate search values by your application before running the query is reported to solve the exception.

Build 2.7.2_01 should fix issue #1107 and should also remove the stack traces of #28 above.

So both issues that are discussed in this thread are now considered to be fixed.

using 2.7.2_01 we still have these outputs in the log:

[2017-10-25 23:30:19 #4 section]
[unexpected section] 286779361#0/2-0/3808

[2017-10-25 23:30:19 #5 section]
java.lang.RuntimeException: Stack Trace
at com.objectdb.o.STH.O(STH.java:695)
at com.objectdb.o.SEV.ab(SEV.java:317)
at com.objectdb.o.SPV.<init>(SPV.java:45)
at com.objectdb.o.SPV.U(SPV.java:151)
at com.objectdb.o.VUT.k(VUT.java:691)
at com.objectdb.o.VUT.j(VUT.java:371)
at com.objectdb.o.VUT.j(VUT.java:357)
at com.objectdb.o.RRT.B(RRT.java:119)
at com.objectdb.o.RTT.l(RTT.java:132)
at com.objectdb.o.RRT.l(RRT.java:32)
at com.objectdb.o.RTT.D(RTT.java:179)
at com.objectdb.o.RRT.B(RRT.java:125)
at com.objectdb.o.RTT.l(RTT.java:132)
at com.objectdb.o.RRT.l(RRT.java:32)
at com.objectdb.o.TSK.i(TSK.java:145)
at com.objectdb.o.TSK.f(TSK.java:95)
at com.objectdb.o.TSM.e(TSM.java:86)
at com.objectdb.o.RTT.D(RTT.java:177)
at com.objectdb.o.RRT.B(RRT.java:125)
at com.objectdb.o.RTT.l(RTT.java:132)
at com.objectdb.o.RRT.l(RRT.java:32)
at com.objectdb.o.TSK.i(TSK.java:145)
at com.objectdb.o.TSK.f(TSK.java:95)
at com.objectdb.o.TSM.e(TSM.java:86)
at com.objectdb.o.RTT.D(RTT.java:177)
at com.objectdb.o.RRT.B(RRT.java:125)
at com.objectdb.o.RTT.l(RTT.java:132)
at com.objectdb.o.RRT.l(RRT.java:32)
at com.objectdb.o.TSK.i(TSK.java:145)
at com.objectdb.o.TSK.f(TSK.java:95)
at com.objectdb.o.MST.a2(MST.java:698)
at com.objectdb.o.MST.aZ(MST.java:476)
at com.objectdb.o.MST.U7(MST.java:442)
at com.objectdb.o.INR.h(INR.java:127)
at com.objectdb.o.REG.W(REG.java:925)
at com.objectdb.o.VAR.aA(VAR.java:826)
at com.objectdb.o.XQI.VN(XQI.java:71)
at com.objectdb.o.TQI.VN(TQI.java:69)
at com.objectdb.o.TQI.VN(TQI.java:69)
at com.objectdb.o.MQI.VN(MQI.java:145)
at com.objectdb.o.PRG.ai(PRG.java:784)
at com.objectdb.o.PRG.ag(PRG.java:713)
at com.objectdb.o.PRG.af(PRG.java:555)
at com.objectdb.o.QRM.Va(QRM.java:286)
at com.objectdb.o.MST.Va(MST.java:991)
at com.objectdb.o.WRA.Va(WRA.java:311)
at com.objectdb.o.WSM.Va(WSM.java:115)
at com.objectdb.o.QRR.g(QRR.java:247)
at com.objectdb.o.QRR.f(QRR.java:153)
at com.objectdb.jpa.JpaQuery.getResultList(JpaQuery.java:721)

Is it a database that was fixed with the Doctor when moving to version 2.7.2?

Unfortunately every database that you have must be fixed, as the new versions (2.7.2, 2.7.2_01) prevent further database corruption, but do not fix problematic section keys that already exist in the database, and the last stack trace seems to be related to such an existing defective section key that was created before version 2.7.2 and was not fixed yet.

the database was not fixed, we'll do that, thanks

2.7.2_01 suddenly some queries do only have 1 result even there are more results (you can use the database that you have):

this query gives 1 result even there are a lot more:

select o from ObjectNode o where o.classIdentifier = '(OP)' and o.state = 98 and o.type = 0 and o.parentNode.classIdentifier = '(XX)'

if you take away the last condition you can see a lot of fitting results, a number of them fit with the complete condition

This must be a side effect of fixing issue 191, we will try to fix it and report in issue #2142.