Log's timestamp does not match in Java 11 (Zulu JDK) #317

[makeshitdev]

calculated two timestamp difference and fail if it's over a threshold 1000 nanoseconds.

[pietermartin]

Do you know why the difference is happening in the first place?

[makeshitdev]

timestamp fetched from logs (sqlg result) returns without nanosecond and notifyTimestamp in the argument comes with nanoseconds.

[pietermartin]

But is this a purely Zulu JDK issue? Where are the nano's being dropped?

The original timestamp being sent to notify is from

    private void beforeCommit() {
        if (this.distributed) {
            Optional<JsonNode> jsonNodeOptional = this.toNotifyJson();
            if (jsonNodeOptional.isPresent()) {
                SqlSchemaChangeDialect sqlSchemaChangeDialect = (SqlSchemaChangeDialect) this.sqlgGraph.getSqlDialect();
                LocalDateTime timestamp = LocalDateTime.now();
                int pid = sqlSchemaChangeDialect.notifyChange(sqlgGraph, timestamp, jsonNodeOptional.get());
                this.ownPids.add(new ImmutablePair<>(pid, timestamp));
            }
        }
    }

...
    sqlgGraph.addVertex(
            T.label,
            SQLG_SCHEMA + "." + SQLG_SCHEMA_LOG,
            "timestamp", timestamp,
            "pid", pid,
            "log", jsonNode
    );
    try (Statement statement = connection.createStatement()) {
        statement.execute("NOTIFY " + SQLG_NOTIFICATION_CHANNEL + ", '" + timestamp.format(DateTimeFormatter.ISO_LOCAL_DATE_TIME) + "'");
    }

LocalDateTime.now(); has nanos and the same nano's are asserted later.

[makeshitdev]

nano seconds are dropped while storing timestamp in Postgres DB (sqlg_schema.log)

[pietermartin]

Afraid I still don't get it. Your image does show nano's which is already a tad odd.

In my db timestamps have only millis.

        this.sqlgGraph.addVertex(T.label, "A", "dateTime", now);
        this.sqlgGraph.tx().commit();
        System.out.println(now.format(DateTimeFormatter.ISO_LOCAL_DATE_TIME));
        System.out.println(now.getNano());

prints,

2019-02-13T08:52:22.408
408000000

LocalDateTime.now() is system dependent. I am on Ubuntu and it seems to only have milli's with the rest of the nanos zero.

Can you please show me both timestamps. The log and notification mechanism's timestamps. Afraid I do not want to just suppress the nano's if I don't know why its happening nor can write a test for it. I'll try out Zulu but alas not this day.

[makeshitdev]

In my image, column timestamp has values up to micro seconds . nanoseconds are dropped there

notifyTimestamp = 2019-02-13T13:08:28.961006400

logs.get(0).value("timestamp") = 2019-02-13T13:08:28.961006

400 nanoseconds were dropped while persist in Postgress and while fetching from vertex property (timestamp) , it has the nanoseconds dropped value .

So comparison fails because of this.

[pietermartin]

For some reason you have 6 nanos and I only 3. If you print out LocalDateTime.now() does it have 6 decimals (nanos)? Are you on linux, mac or windows and is this still a purely Zulu JDK issue?

[makeshitdev]

I am using Windows machine if i print - Zulu jdk 11 - 2019-02-13T13:19:50.907189900 oracle jdk 8 - 2019-02-13T13:28:00.977

Yes it is Zulu jdk issue.

[pietermartin]

Thanks