1. Janusgraph-Users
  2. Topics

org.janusgraph.diskstorage.PermanentBackendException: Read 1 locks with our rid but mismatched timestamps

Ronnie
 

Hi Mark,
Thanks for the suggestions.

Narrowed down the issue to JanusGraph's support for Azul Prime JDK 8, which generates nanosecond precision for Instant.now() API, as compared to the millisecond precision for OpenJDK 8. So the issue was resolved by applying the patch for https://github.com/JanusGraph/janusgraph/issues/1979.

Thanks!
Ronnie
hadoopmarc@...
 

Hi Ronnie
No idea what is going on here, but just being pragmatic:

the bin/janusgraph.sh script starts Cassandra, Elasticsearch and Gremlin Server using the conf/janusgraph-cql-es.conf graph configuration. As you can check in the janusgraph distribution files, this config does not specify the graph.timestamps  property (so defaults to MICRO).

So some things to try:
  • does your Cassandra cluster have custom settings for the timestamp type? Then you hit an existing janusgraph issue.
  • does your system have a locale different than english-international and does changing the locale recover the issue? Then you discovered a janusgraph issue!
  • does removing the graph.timestamps=MICRO line help? Note that you can only try this on a new graph, because this setting is FIXED.
Best wishes,    Marc
Ronnie
 

Hi,

Environment
- JanusGraph 0.5.3 on JDK: 1.8
- Backend: Cassandra 3.11.3 running on JDK 1.8

Warning and error during first time server startup
2021-08-17T22:26:20,861 - WARN  [main:o.j.d.l.c.ConsistentKeyLocker@510] - Skipping outdated lock on KeyColumn [k=0x 16-165-160-103-105- 30- 71-114- 97-112-104- 95- 78- 97-109-101- 95- 73-110-100-101-248, c=0x  0] with our rid ( 48- 97- 55- 50- 97- 97- 57- 57- 49- 56- 57- 56- 57- 45-115-104- 97-114-101-100-106- 97-110-117-115-103-114- 97-112-104- 48- 49- 45-112- 50- 55- 45-101-110-103- 45-105-110- 48- 51- 45-113-117- 97-108-121-115- 45- 99-111-109- 49) but mismatched timestamp (actual ts 2021-08-17T22:26:20.755981Z, expected ts 2021-08-17T22:26:20.755981926Z)
2021-08-17T22:26:20,863 - ERROR [main:o.j.g.d.StandardJanusGraph@724] - Could not commit transaction [1] due to storage exception in system-commit
Caused by: org.janusgraph.diskstorage.PermanentBackendException: Read 1 locks with our rid  48- 97- 55- 50- 97- 97- 57- 57- 49- 56- 57- 56- 57- 45-115-104- 97-114-101-100-106- 97-110-117-115-103-114- 97-112-104- 48- 49- 45-112- 50- 55- 45-101-110-103- 45-105-110- 48- 51- 45-113-117- 97-108-121-115- 45- 99-111-109- 49 but mismatched timestamps; no lock column contained our timestamp (2021-08-17T22:26:20.755981926Z)
at org.janusgraph.diskstorage.locking.consistentkey.ConsistentKeyLocker.checkSeniority(ConsistentKeyLocker.java:542)
at org.janusgraph.diskstorage.locking.consistentkey.ConsistentKeyLocker.checkSingleLock(ConsistentKeyLocker.java:468)
at org.janusgraph.diskstorage.locking.consistentkey.ConsistentKeyLocker.checkSingleLock(ConsistentKeyLocker.java:118)
at org.janusgraph.diskstorage.locking.AbstractLocker.checkLocks(AbstractLocker.java:351)
... 27 more
2021-08-17T22:26:20,864 - ERROR [main:o.a.t.g.s.u.ServerGremlinExecutor@87] - Could not invoke constructor on class org.janusgraph.graphdb.management.JanusGraphManager (defined by the 'graphManager' setting) with one argument of class Settings
Graph configuration:
gremlin.graph=org.janusgraph.core.ConfiguredGraphFactory
graph.graphname=ConfigurationManagementGraph
graph.timestamps=MICRO
storage.backend=cql
storage.hostname=10.114.171.91,10.114.171.92,10.114.171.93
storage.cql.keyspace= sharedjanusgraph
storage.read-time=50000
cache.db-cache = true
cache.db-cache-clean-wait = 20
cache.db-cache-time = 180000
cache.db-cache-size = 0.4
tx.log-tx=true
tx.max-commit-time=15000
metrics.enabled=False
metrics.jmx.enabled=False
cluster.max-partitions=32
Note: Explicitly set graph.timestamps=MICRO ; when setting this to NANO as suggested here https://stackoverflow.com/questions/58916854/janusgraph-janusgraphexception-could-not-commit-transaction-due-to-exception-dur i get the following error:
java.lang.IllegalArgumentException: Timestamp overflow detected: 2021-08-17T23:20:11.611614212Z
at org.janusgraph.diskstorage.log.kcvs.KCVSLog.getTimeSlice(KCVSLog.java:330)
at org.janusgraph.diskstorage.log.kcvs.KCVSLog.add(KCVSLog.java:418)
at org.janusgraph.diskstorage.log.kcvs.KCVSLog.add(KCVSLog.java:394)
at org.janusgraph.diskstorage.log.kcvs.KCVSLog.add(KCVSLog.java:377)
at org.janusgraph.graphdb.database.StandardJanusGraph.commit(StandardJanusGraph.java:690)
at org.janusgraph.graphdb.transaction.StandardJanusGraphTx.commit(StandardJanusGraphTx.java:1438)
... 14 more
Any pointers why this time resolution mismatch is happening?

Thanks,
Ronnie

1 - 3 of 3