Log Change Processor works in Gremlin Console but not Java app

[jekramer]

I've been playing around with simple log change processors to make sure the updates come through, and the same code seems to work fine in the gremlin console but not when I use it in our java service. The main difference I noticed is that when adding a processor in the console I get these info logs with an accurate time:

11:13:51 INFO  org.janusgraph.diskstorage.log.kcvs.KCVSLog$MessagePuller.initializeTimepoint - Loaded identified ReadMarker start time 2023-02-13T11:15:00Z into org.janusgraph.diskstorage.log.kcvs.KCVSLog$MessagePuller@4bc9389
11:13:51 INFO  org.janusgraph.diskstorage.log.kcvs.KCVSLog$MessagePuller.initializeTimepoint - Loaded identified ReadMarker start time 2023-02-13T11:15:00Z into org.janusgraph.diskstorage.log.kcvs.KCVSLog$MessagePuller@662061e3
11:13:51 INFO  org.janusgraph.diskstorage.log.kcvs.KCVSLog$MessagePuller.initializeTimepoint - Loaded identified ReadMarker start time 2023-02-13T11:15:00Z into org.janusgraph.diskstorage.log.kcvs.KCVSLog$MessagePuller@79e15c4a

but then in java, I am seeing start times for different days of Jan 1970. I've tried both .setStartTimeNow() and .setStartTime(Instant.now()) when adding a log processor, but the read marker start time is always at most a few hours later in 1970 each time I run it. (This thread seems to indicate .setStartTime() would fix it: https://groups.google.com/g/janusgraph-users/c/JN4ZsB9_DMM)

2023-02-13 18:16:52.983 [main] INFO  org.janusgraph.diskstorage.log.kcvs.KCVSLog  - Loaded identified ReadMarker start time 1970-01-09T07:01:40Z into org.janusgraph.diskstorage.log.kcvs.KCVSLog$MessagePuller@249f95a2
2023-02-13 18:16:53.008 [main] INFO  org.janusgraph.diskstorage.log.kcvs.KCVSLog  - Loaded identified ReadMarker start time 1970-01-09T07:00:00Z into org.janusgraph.diskstorage.log.kcvs.KCVSLog$MessagePuller@611d867
2023-02-13 18:16:53.033 [main] INFO  org.janusgraph.diskstorage.log.kcvs.KCVSLog  - Loaded identified ReadMarker start time 1970-01-09T07:00:00Z into org.janusgraph.diskstorage.log.kcvs.KCVSLog$MessagePuller@34775090
2023-02-13 18:16:53.056 [main] INFO  org.janusgraph.diskstorage.log.kcvs.KCVSLog  - Loaded identified ReadMarker start time 1970-01-09T06:58:20Z into org.janusgraph.diskstorage.log.kcvs.KCVSLog$MessagePuller@76ad0058

I've tried using different graph.timestamps config values with no luck. And the console is using the same config file, so all other config values would be the same.

If anyone has ideas for why the java service might end up with the wrong date I'd appreciate it!

[jekramer]

It ended up being that I was using a log processor identifier without understanding what that does. The first time I used it combined with .setStartTimeNow() which seems to actually set timestamp to zero. And then I kept using the same identifier, so it was picking up where it left off reading.

[hadoopmarc]

Thanks for reporting back.