Chronicle write introducing 1-2 sec latency at file roll over time

193 views Asked by At

We have a single threaded java process that is writing messages into chronicle queue. The queue (SingleChronicleQueue) is configured with RollCycle HOURLY. At the hourly mark, when the file roll happens, chronicle write takes more than a second (typically 1-2 sec), which seem to be happening with bigger file sizes (~50-90 GB). We're using 4.5.x chronicle-queue version. Any ideas on how to address this problem?

I took a thread dump using jstack tool to see where the thread is stuck.

at sun.nio.ch.FileChannelImpl.unmap0(Native Method)
at sun.reflect.GeneratedMethodAccessor3.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at net.openhft.chronicle.core.OS.unmap(OS.java:345)
at net.openhft.chronicle.core.OS$Unmapper.run(OS.java:434)
at sun.misc.Cleaner.clean(Cleaner.java:143)
at net.openhft.chronicle.bytes.NativeBytesStore.performRelease(NativeBytesStore.java:501)
at net.openhft.chronicle.bytes.NativeBytesStore$$Lambda$68/1804441305.run(Unknown Source)
at net.openhft.chronicle.core.ReferenceCounter.release(ReferenceCounter.java:81)
at net.openhft.chronicle.bytes.NativeBytesStore.release(NativeBytesStore.java:265)
at net.openhft.chronicle.bytes.MappedFile.performRelease(MappedFile.java:296)
at net.openhft.chronicle.bytes.MappedFile$$Lambda$63/90346768.run(Unknown Source)
at net.openhft.chronicle.core.ReferenceCounter.release(ReferenceCounter.java:81)
at net.openhft.chronicle.bytes.MappedFile.release(MappedFile.java:277)
at net.openhft.chronicle.bytes.MappedBytes.performRelease(MappedBytes.java:209)
at net.openhft.chronicle.bytes.AbstractBytes$$Lambda$65/18179709.run(Unknown Source)
at net.openhft.chronicle.core.ReferenceCounter.release(ReferenceCounter.java:81)
at net.openhft.chronicle.bytes.AbstractBytes.release(AbstractBytes.java:395)
at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.resetWires(SingleChronicleQueueExcerpts.java:233)
at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.setCycle2(SingleChronicleQueueExcerpts.java:210)
at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.rollCycleTo(SingleChronicleQueueExcerpts.java:579)
at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.writingDocument(SingleChronicleQueueExcerpts.java:273)
at net.openhft.chronicle.wire.MarshallableOut.writingDocument(MarshallableOut.java:55)
at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.writeBytes(SingleChronicleQueueExcerpts.java:117)
1

There are 1 answers

2
Dmitry Pisklov On

You're using ancient version of Chronicle Queue (last 4.5.x version was released on 26/02/2017 - over 3 years ago). Since then, Chronicle Queue has changed drastically, and one of the changes was to do unmapping in a separate service thread not to stall the writers (the change dates back to the end of 2017, btw), as it was identified that as you point out such unmapping can take quite a long time. So your solution is to upgrade to one of the latest versions (5.19.X).