Occasionally see error appending to Chronicle Queue

[mikeb01]

Occasionally when running benchmarks, I see the exception below.

Versions:

openjdk version "14.0.2" 2020-07-14
OpenJDK Runtime Environment AdoptOpenJDK (build 14.0.2+12)
OpenJDK 64-Bit Server VM AdoptOpenJDK (build 14.0.2+12, mixed mode, sharing)

Darwin x.x.x.x 19.6.0 Darwin Kernel Version 19.6.0: Thu Jun 18 20:49:00 PDT 2020; root:xnu-6153.141.1~1/RELEASE_X86_64 x86_64

net.openhft:chronicle-queue:5.20.4

Exception:

07 Sep 2020 17:00:00.021 [Dummy Exchange] ERROR b.s.w.i.j.ChronicleQueueJournalWriter - Issue appending to Chronicle Queue
java.lang.IllegalStateException: Not the last released
	at net.openhft.chronicle.core.io.VanillaReferenceCounted.releaseLast(VanillaReferenceCounted.java:110) ~[chronicle-queue-enterprise-all-2.19.352.jar:chronicle-bom:2.19.352]
	at net.openhft.chronicle.core.io.AbstractReferenceCounted.releaseLast(AbstractReferenceCounted.java:123) ~[chronicle-queue-enterprise-all-2.19.352.jar:chronicle-bom:2.19.352]
	at net.openhft.chronicle.bytes.MappedBytes.releaseLast(MappedBytes.java:853) ~[chronicle-queue-enterprise-all-2.19.352.jar:chronicle-bom:2.19.352]
	at net.openhft.chronicle.core.io.ReferenceCounted.releaseLast(ReferenceCounted.java:67) ~[chronicle-queue-enterprise-all-2.19.352.jar:chronicle-bom:2.19.352]
	at net.openhft.chronicle.queue.impl.single.StoreAppender.releaseBytesFor(StoreAppender.java:74) ~[chronicle-queue-enterprise-all-2.19.352.jar:chronicle-bom:2.19.352]
	at net.openhft.chronicle.queue.impl.single.StoreAppender.resetWires(StoreAppender.java:258) ~[chronicle-queue-enterprise-all-2.19.352.jar:chronicle-bom:2.19.352]
	at net.openhft.chronicle.queue.impl.single.StoreAppender.setCycle2(StoreAppender.java:237) ~[chronicle-queue-enterprise-all-2.19.352.jar:chronicle-bom:2.19.352]
	at net.openhft.chronicle.queue.impl.single.StoreAppender.rollCycleTo(StoreAppender.java:592) ~[chronicle-queue-enterprise-all-2.19.352.jar:chronicle-bom:2.19.352]
	at net.openhft.chronicle.queue.impl.single.StoreAppender.writingDocument(StoreAppender.java:336) ~[chronicle-queue-enterprise-all-2.19.352.jar:chronicle-bom:2.19.352]
	at net.openhft.chronicle.queue.impl.single.StoreAppender.writingDocument(StoreAppender.java:310) ~[chronicle-queue-enterprise-all-2.19.352.jar:chronicle-bom:2.19.352]
	at net.openhft.chronicle.queue.impl.single.StoreAppender.writeBytes(StoreAppender.java:93) ~[chronicle-queue-enterprise-all-2.19.352.jar:chronicle-bom:2.19.352]

[dpisklov]

Do you see this issue with Java 11 or below? We don't support Java 14.

[JerryShea]

Also, we have done a lot of work on cleaning up reference counting recently so I would also recommend trying out the latest version

[JerryShea]

Hi @mikeb01 are you using the pretoucher?

[peter-lawrey]

Can you enable the system property jvm.resource.tracing=true and it should show where the resource is still being used. You can do this on the command line or add it to the system.properties file

[peter-lawrey]

It might be worth updating to .x20 though I suspect it won't make a difference in this case.

[mikeb01]

Hi @mikeb01 are you using the pretoucher?

Yes. I'll re-run with JDK11 and with the later versions and debug settings.

[mikeb01]

Can't replicate on JDK 11. Still yet to run it with the tracing options.

[peter-lawrey]

This can happen if you are holding (or something is holding) a reference to the underlying Bytes used by the wire in the document context when you roll the cycle in the appender.

[RobAustin]

@mikeb01 is this still an issue, I'm going to close it, but happy to reopen it if you feel it has not been resolved.