java.lang.IllegalStateException: Unable to index 268435456

[mikeb01]

With the attached appender and tailer after ~268M messages I get the following exception

Exception in thread "main" java.lang.IllegalStateException: Unable to index 268435456
	at net.openhft.chronicle.queue.impl.single.SCQIndexing.setPositionForSequenceNumber(SCQIndexing.java:625)
	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueStore.setPositionForSequenceNumber(SingleChronicleQueueStore.java:350)
	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.writeIndexForPosition(SingleChronicleQueueExcerpts.java:689)
	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender$StoreAppenderContext.close(SingleChronicleQueueExcerpts.java:818)
	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender$StoreAppenderContext.close(SingleChronicleQueueExcerpts.java:784)
	at net.openhft.chronicle.queue.impl.single.SingleChronicleQueueExcerpts$StoreAppender.writeBytes(SingleChronicleQueueExcerpts.java:174)
	at bitmex.gateway.trading.engine.chronicle.TimestampAppender.main(TimestampAppender.java:21)

And at that point the queue is corrupt.

import net.openhft.chronicle.queue.ExcerptAppender;
import net.openhft.chronicle.queue.RollCycles;
import net.openhft.chronicle.queue.impl.single.SingleChronicleQueue;
import net.openhft.chronicle.queue.impl.single.SingleChronicleQueueBuilder;

public class TimestampAppender {

    public static void main(String[] args) {

        SingleChronicleQueue build = SingleChronicleQueueBuilder
                .binary("src/test/resources/sandbox/times_publication")
                .rollCycle(RollCycles.HOURLY)
                .timeProvider(System::currentTimeMillis)
                .build();

        ExcerptAppender excerptAppender = build.acquireAppender().methodWriterBuilder().recordHistory();

        while (true) {
            excerptAppender.writeBytes(bytesOut -> {
                bytesOut.writeLong(System.nanoTime());
            });
        }
    }
}

import net.openhft.chronicle.queue.ExcerptTailer;
import net.openhft.chronicle.queue.RollCycles;
import net.openhft.chronicle.queue.impl.single.SingleChronicleQueue;
import net.openhft.chronicle.queue.impl.single.SingleChronicleQueueBuilder;
import net.openhft.chronicle.wire.DocumentContext;

public class TimestampTailer {

    public static void main(String[] args) throws InterruptedException {
        SingleChronicleQueue build = SingleChronicleQueueBuilder
                .binary("src/test/resources/sandbox/times_publication")
                .rollCycle(RollCycles.HOURLY)
                .timeProvider(System::currentTimeMillis)
                .build();

        ExcerptTailer tailer = build.createTailer();

        long previousTimestamp = 0;
        long counter = 0;

        while (true) {
            try (DocumentContext documentContext = tailer.readingDocument()) {
                if (!documentContext.isPresent()) {
                    Thread.sleep(1);
                    continue;
                }

                long timestamp = documentContext.wire().bytes().readLong();
                if (timestamp < previousTimestamp) {
                    throw new RuntimeException();
                }

                ++counter;
                if (counter % 1000000 == 0) {
                    System.out.println("Seen " + counter + " events");
                }

                previousTimestamp = timestamp;
            }
        }
    }
}

uname -a: Darwin MacBook-Pro 19.5.0 Darwin Kernel Version 19.5.0: Tue May 26 20:41:44 PDT 2020; root:xnu-6153.121.2~2/RELEASE_X86_64 x86_64
JDK:

openjdk version "1.8.0_252"
OpenJDK Runtime Environment (Zulu 8.46.0.19-CA-macosx) (build 1.8.0_252-b14)
OpenJDK 64-Bit Server VM (Zulu 8.46.0.19-CA-macosx) (build 25.252-b14, mixed mode)

Chronicle 5.19.32

[JerryShea]

Hi @mikeb01, HOURLY roll cycle is limited to 256M entries per hour so if you use one of the other RollCycles e.g. LARGE_HOURLY_SPARSE I can confirm that you won't see this problem. The only downside of using e.g. LARGE_HOURLY_SPARSE is that less index entries will be written and thus random access seek performance will be affected. If you are not concerned about random access seek performance then the sparse roll cycles are better for write performance too.

public enum RollCycles implements RollCycle {
    ...
    HOURLY(/*----------*/"yyyyMMdd-HH", 60 * 60 * 1000, 4 << 10, 16), // 256 million entries per hour.
    LARGE_HOURLY(/*----*/"yyyyMMdd-HH'L'", 60 * 60 * 1000, 8 << 10, 64), // 2 billion entries per hour.
    LARGE_HOURLY_SPARSE("yyyyMMdd-HH'LS'", 60 * 60 * 1000, 4 << 10, 1024), // 16 billion entries per hour with sparse indexing
    LARGE_HOURLY_XSPARSE("yyyyMMdd-HH'LX'", 60 * 60 * 1000, 2 << 10, 1 << 20), // 16 billion entries per hour with super-sparse indexing

The error message you saw is not very helpful - we will look into improving that.

[JerryShea]

@mikeb01 I checked this myself but happy to wait for you to close once you have confirmed

[mikeb01]

Worth noting that it also corrupts the queue and it can't be used after this failure.

[JerryShea]

Yes, thanks - will address that. Thanks for notifying us!

…

On Wed., 10 Jun. 2020, 11:54 am Michael Barker, ***@***.***> wrote: Worth noting that it also corrupts the queue and it can't be used after this failure. — You are receiving this because you modified the open/close state. Reply to this email directly, view it on GitHub <#684 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AG5XOHK3H6DYLS2TQQEJPYLRV3RWLANCNFSM4NZ3CH6Q> .

[dpisklov]

I improved the message but we can't fix the behaviour without too many changes, and it's probably not wise to make those changes to cover the user error - the javadoc (now) clearly says how many messages you can write for each roll cycle.

[mikeb01]

Is there any API to get the remaining time and number of messages left in the current roll cycle?

[dpisklov]

@mikeb01 the time is in the name of the roll cycle. Queue rolls starting from midnight UTC, so e.g. for *HOURLY roll cycles (there're few) the roll will happen at the hour boundary. As for the number of messages left, it's max number of messages per roll cycle minus current sequence number (RollCycle#toSequenceNumber(long) can help you to convert output of appender#index() or tailer#index() to the sequence number within the current roll cycle)

[RobAustin]

If for example you are using hourly rolling then the time remaining will be the time it takes before the hour changes. With regards to the number of messages you have written, for each message you have written you can get its index, if you obtain the sequence number of your last message this is equal to the number of messages you have written in that cycle ( see javadocs regarding sequence numbers ) , to calculate the “ number of messages left in the current roll cycle” this equals the total number of allowed messages in the roll cycle minus the number of messages you have written so far in that cycle. We don’t have an API for this but as you can see ( from my description above ) it’s very easy to calculate. If you would like us to add this feature or get professional support please contact sales@chronicle.software

…

On 10 Jun 2020, at 20:22, Michael Barker ***@***.***> wrote:  Is there any API to get the remaining time and number of messages left in the current roll cycle? — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub, or unsubscribe.

[JerryShea]

@mikeb01 the queue should not be corrupt, reads should still work. You just won't be able to write to it until the roll cycle ticks over. Is this what you saw?

[mikeb01]

I can confirm that the queue is not corrupt, it was just continuing to through the IllegalStateException until the hourly rollover.