Unconfigured table exceptions in Janusgraph 0.6.0


Mladen Marović
 

Hello,

I wanted to try out the new Janusgraph 0.6.0 release and I encountered some unexpected issues while trying to deploy it on Cassandra 3.11.5.

The first issue occurs during graph creation. I'm trying to set up a ConfiguredGraphFactory. When starting Janusgraph for the first time, it attempts to create its internal tables ('graphindex', 'janusgraph_ids', ...), but sometimes fails to create a table and throws the following exception:

java.lang.RuntimeException: java.lang.reflect.InvocationTargetException
        at org.apache.tinkerpop.gremlin.server.util.ServerGremlinExecutor.<init>(ServerGremlinExecutor.java:95)
        at org.apache.tinkerpop.gremlin.server.GremlinServer.<init>(GremlinServer.java:124)
        at org.apache.tinkerpop.gremlin.server.GremlinServer.<init>(GremlinServer.java:87)
        at org.janusgraph.graphdb.server.JanusGraphServer.start(JanusGraphServer.java:85)
        at org.janusgraph.graphdb.server.JanusGraphServer.main(JanusGraphServer.java:53)
Caused by: java.lang.reflect.InvocationTargetException
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        at org.apache.tinkerpop.gremlin.server.util.ServerGremlinExecutor.<init>(ServerGremlinExecutor.java:84)
        ... 4 more
Caused by: com.datastax.oss.driver.api.core.servererrors.InvalidQueryException: unconfigured table janusgraph_ids
        at com.datastax.oss.driver.api.core.servererrors.InvalidQueryException.copy(InvalidQueryException.java:48)
        at com.datastax.oss.driver.internal.core.util.concurrent.CompletableFutures.getUninterruptibly(CompletableFutures.java:149)
        at com.datastax.oss.driver.internal.core.cql.CqlPrepareSyncProcessor.process(CqlPrepareSyncProcessor.java:59)
        at com.datastax.oss.driver.internal.core.cql.CqlPrepareSyncProcessor.process(CqlPrepareSyncProcessor.java:31)
        at com.datastax.oss.driver.internal.core.session.DefaultSession.execute(DefaultSession.java:230)
        at com.datastax.oss.driver.api.core.cql.SyncCqlSession.prepare(SyncCqlSession.java:206)
        at org.janusgraph.diskstorage.cql.CQLKeyColumnValueStore.<init>(CQLKeyColumnValueStore.java:168)
        at org.janusgraph.diskstorage.cql.CQLStoreManager.lambda$openDatabase$7(CQLStoreManager.java:267)
        at java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1660)
        at org.janusgraph.diskstorage.cql.CQLStoreManager.openDatabase(CQLStoreManager.java:267)
        at org.janusgraph.diskstorage.keycolumnvalue.KeyColumnValueStoreManager.openDatabase(KeyColumnValueStoreManager.java:43)
        at org.janusgraph.diskstorage.Backend.initialize(Backend.java:312)
        at org.janusgraph.graphdb.configuration.GraphDatabaseConfiguration.getBackend(GraphDatabaseConfiguration.java:1356)
        at org.janusgraph.graphdb.database.StandardJanusGraph.<init>(StandardJanusGraph.java:184)
        at org.janusgraph.core.JanusGraphFactory.lambda$open$0(JanusGraphFactory.java:165)
        at org.janusgraph.graphdb.management.JanusGraphManager.openGraph(JanusGraphManager.java:239)
        at org.janusgraph.core.JanusGraphFactory.open(JanusGraphFactory.java:165)
        at org.janusgraph.core.JanusGraphFactory.open(JanusGraphFactory.java:115)
        at org.janusgraph.graphdb.management.JanusGraphManager.lambda$new$0(JanusGraphManager.java:73)
        at java.util.LinkedHashMap.forEach(LinkedHashMap.java:684)
        at org.janusgraph.graphdb.management.JanusGraphManager.<init>(JanusGraphManager.java:72)

Inspecting the keyspaces via cqlsh shows that the keyspace is created, as well as some (but not all) of the tables:

cqlsh> describe keyspaces;

configuration_management_graph  system_auth  system_distributed
system_schema                   system       system_traces     

cqlsh> select table_name from system_schema.tables where keyspace_name = 'configuration_management_graph';

 table_name
-------------------
    janusgraph_ids
 system_properties

Upon restarting, Janusgraph continues from where it last failed and tries to create the other missing tables. Eventually, cqlsh shows that all tables are created.

cqlsh> select table_name from system_schema.tables where keyspace_name = 'configuration_management_graph';

 table_name
-------------------------
               edgestore
         edgestore_lock_
              graphindex
        graphindex_lock_
          janusgraph_ids
       system_properties
 system_properties_lock_
               systemlog
                   txlog

I tried to test this multiple times by shutting down Janusgraph, dropping its keyspaces in Cassandra, and starting it again. Sometimes it successfully finishes from the first try, sometimes it fails once, and sometimes multiple times, on different tables.

As for the relevant configuration, I've updated it according to the 0.6.0 changelog. I'm using the following gremlin-server.yaml:

host: 0.0.0.0

port: 8183

evaluationTimeout: 60000

channelizer: org.apache.tinkerpop.gremlin.server.channel.WsAndHttpChannelizer

graphManager: org.janusgraph.graphdb.management.JanusGraphManager

graphs:
  ConfigurationManagementGraph: /home/test/janusgraph/conf/configuration-management-graph.properties

scriptEngines:
  gremlin-groovy:
    plugins:
      org.janusgraph.graphdb.tinkerpop.plugin.JanusGraphGremlinPlugin: {}
      org.apache.tinkerpop.gremlin.server.jsr223.GremlinServerGremlinPlugin: {}
      org.apache.tinkerpop.gremlin.tinkergraph.jsr223.TinkerGraphGremlinPlugin: {}
      org.apache.tinkerpop.gremlin.jsr223.ImportGremlinPlugin:
        classImports:
          - java.lang.Math
        methodImports:
          - java.lang.Math#*
      org.apache.tinkerpop.gremlin.jsr223.ScriptFileGremlinPlugin:
        files:
          - /home/test/janusgraph/storage/scripts/globals.groovy

processors:
  - className: org.apache.tinkerpop.gremlin.server.op.session.SessionOpProcessor
    config:
      sessionTimeout: 28800000
  - className: org.apache.tinkerpop.gremlin.server.op.traversal.TraversalOpProcessor
    config:
      cacheExpirationTime: 600000
      cacheMaxSize: 1000

metrics:
  consoleReporter:
    enabled: true
    interval: 180000

maxInitialLineLength: 4096

maxHeaderSize: 32768

maxChunkSize: 32768

maxContentLength: 2097152

maxAccumulationBufferComponents: 2048

resultIterationBatchSize: 2048

writeBufferLowWaterMark: 131072

writeBufferHighWaterMark: 2097152

threadPoolWorker: 4

gremlinPool: 8

and configuration-management-graph.properties is as follows:

graph.graphname=configuration_management_graph
gremlin.graph=org.janusgraph.core.ConfiguredGraphFactory

storage.backend=cql
storage.hostname=test-master,test-worker1
storage.cql.keyspace=configuration_management_graph
storage.cql.replication-factor=1
storage.cql.read-consistency-level=LOCAL_QUORUM
storage.cql.write-consistency-level=LOCAL_QUORUM
storage.cql.only-use-local-consistency-for-system-operations=true
storage.cql.local-datacenter=dc1
storage.cql.replication-strategy-options=dc1,1
storage.cql.replication-strategy-class=NetworkTopologyStrategy
storage.cql.local-max-connections-per-host=5
storage.cql.max-requests-per-connection=1024
storage.cql.executor-service.enabled=false
storage.parallel-backend-executor-service.core-pool-size=100

query.smart-limit=false

# disable this property as soon as the upgrade is done to avoid unwanted upgrades
graph.allow-upgrade=false

Since this is my first look at Janusgraph 0.6.0, I'm testing it on two local VMs. I'm using Ansible scripts to automate the deployment for Janusgraph, Cassandra and Elasticsearch, and the entire setup has previously been tested on multiple different Janusgraph versions (0.2.0, 0.3.1, 0.4.0, 0.5.1, 0.5.3) and on several different environments. Therefore, I do not expect there to be any issues with Cassandra, Elasticsearch, the deployment scripts, or the setup itself, unless I missed some breaking change in the 0.6.0 changelog that I'm not aware of.

Did anyone else have a similar issue?

Kind regards,

Mladen Marović

P.S. Since this turned out to be a lengthy post, I'll create another post about the other issue I mentioned.


Oleksandr Porunov
 

Hi,

Mladen that issue is most likely related to this discussion of how the new CQL driver updates schema view: https://groups.google.com/a/lists.datastax.com/g/java-driver-user/c/Bc0gQuOVVL0

As suggested in that thread, to improve performance we set metadata_schema_window to 0 (to keep schema creation performance similar to the previous driver). That said, we probably made a mistake when hardcoded that value to 0. We probably should make it configurable in the next minor release. (you can see that configuration set here: https://github.com/JanusGraph/janusgraph/blob/abe67055a23c729d55e0e4ac1508189d93f9820c/janusgraph-cql/src/main/java/org/janusgraph/diskstorage/cql/builder/CQLProgrammaticConfigurationLoaderBuilder.java#L144)

Luckily, there is a way to overwrite JanusGraph default CQL Driver configurations.
See explanation here (configuration options under `storage.cql.internal`): https://docs.janusgraph.org/configs/configuration-reference/#storagecqlinternal

Probably the easiest way to overwrite that value as for now would be to use `storage.cql.internal.string-configuration`. I.e. something like:
```
storage.cql.internal.string-configuration = "datastax-java-driver { advanced.metadata.schema.debouncer.window = 1 second }"
```
The DataStax default value is "1 second" thus, I would recommend to try 1 second as they recommend. In case that isn't enough you could try to increase that value but be aware that your schema creation (i.e. new graphs initial creation) will be longer due to this window delay.

I have opened the issue to tack here: https://github.com/JanusGraph/janusgraph/issues/2809
Let me know if increasing `advanced.metadata.schema.debouncer.window` helps with your issue.

Best regards,
Oleksandr Porunov


Oleksandr Porunov
 

You can also play with `advanced.metadata.schema.debouncer.max-events`. For more configurations see: https://docs.datastax.com/en/developer/java-driver/4.13/manual/core/configuration/reference/


Oleksandr Porunov
 

Also, notice, if you want to use multiple configuration options, you will need to split them using new line character. I.e. `\n` and not `;`.
See example here: https://github.com/JanusGraph/janusgraph/blob/26a06a0d27931d5e97ca7870493336fe21b522be/janusgraph-cql/src/test/java/org/janusgraph/diskstorage/cql/CQLConfigTest.java#L98


Mladen Marović
 

Hello,

thanks for the responses. I attempted to add storage.cql.internal.string-configuration = "datastax-java-driver { advanced.metadata.schema.debouncer.window = 1 second }" to my configuration-management-graph.properties, but got the following exception after starting Janusgraph:

java.lang.RuntimeException: java.lang.reflect.InvocationTargetException
        at org.apache.tinkerpop.gremlin.server.util.ServerGremlinExecutor.<init>(ServerGremlinExecutor.java:95)
        at org.apache.tinkerpop.gremlin.server.GremlinServer.<init>(GremlinServer.java:124)
        at org.apache.tinkerpop.gremlin.server.GremlinServer.<init>(GremlinServer.java:87)
        at org.janusgraph.graphdb.server.JanusGraphServer.start(JanusGraphServer.java:85)
        at org.janusgraph.graphdb.server.JanusGraphServer.main(JanusGraphServer.java:53)
Caused by: java.lang.reflect.InvocationTargetException
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        at org.apache.tinkerpop.gremlin.server.util.ServerGremlinExecutor.<init>(ServerGremlinExecutor.java:84)
        ... 4 more
Caused by: java.lang.IllegalArgumentException: Could not instantiate implementation: org.janusgraph.diskstorage.cql.CQLStoreManager
        at org.janusgraph.util.system.ConfigurationUtil.instantiate(ConfigurationUtil.java:79)
        at org.janusgraph.diskstorage.Backend.getImplementationClass(Backend.java:525)
        at org.janusgraph.diskstorage.Backend.getStorageManager(Backend.java:489)
        at org.janusgraph.graphdb.configuration.builder.GraphDatabaseConfigurationBuilder.build(GraphDatabaseConfigurationBuilder.java:64)
        at org.janusgraph.core.JanusGraphFactory.lambda$open$0(JanusGraphFactory.java:165)
        at org.janusgraph.graphdb.management.JanusGraphManager.openGraph(JanusGraphManager.java:239)
        at org.janusgraph.core.JanusGraphFactory.open(JanusGraphFactory.java:165)
        at org.janusgraph.core.JanusGraphFactory.open(JanusGraphFactory.java:115)
        at org.janusgraph.graphdb.management.JanusGraphManager.lambda$new$0(JanusGraphManager.java:73)
        at java.util.LinkedHashMap.forEach(LinkedHashMap.java:684)
        at org.janusgraph.graphdb.management.JanusGraphManager.<init>(JanusGraphManager.java:72)
        ... 9 more
Caused by: java.lang.reflect.InvocationTargetException
        at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
        at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
        at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
        at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
        at org.janusgraph.util.system.ConfigurationUtil.instantiate(ConfigurationUtil.java:73)
        ... 19 more
Caused by: com.typesafe.config.ConfigException$Parse: String: 1: Key '"datastax-java-driver { advanced.metadata.schema.debouncer.window = 1 second }"' may not be followed by token: end of file
        at com.typesafe.config.impl.ConfigDocumentParser$ParseContext.parseError(ConfigDocumentParser.java:201)
        at com.typesafe.config.impl.ConfigDocumentParser$ParseContext.parseError(ConfigDocumentParser.java:197)
        at com.typesafe.config.impl.ConfigDocumentParser$ParseContext.parseObject(ConfigDocumentParser.java:461)
        at com.typesafe.config.impl.ConfigDocumentParser$ParseContext.parse(ConfigDocumentParser.java:648)
        at com.typesafe.config.impl.ConfigDocumentParser.parse(ConfigDocumentParser.java:14)
        at com.typesafe.config.impl.Parseable.rawParseValue(Parseable.java:262)
        at com.typesafe.config.impl.Parseable.rawParseValue(Parseable.java:250)
        at com.typesafe.config.impl.Parseable.parseValue(Parseable.java:180)
        at com.typesafe.config.impl.Parseable.parseValue(Parseable.java:174)
        at com.typesafe.config.impl.Parseable.parse(Parseable.java:301)
        at com.typesafe.config.ConfigFactory.parseString(ConfigFactory.java:1187)
        at com.typesafe.config.ConfigFactory.parseString(ConfigFactory.java:1197)
        at com.datastax.oss.driver.internal.core.config.typesafe.DefaultDriverConfigLoader.lambda$fromString$4(DefaultDriverConfigLoader.java:125)
        at com.datastax.oss.driver.internal.core.config.typesafe.DefaultDriverConfigLoader.<init>(DefaultDriverConfigLoader.java:196)
        at com.datastax.oss.driver.internal.core.config.typesafe.DefaultDriverConfigLoader.fromString(DefaultDriverConfigLoader.java:120)
        at com.datastax.oss.driver.api.core.config.DriverConfigLoader.fromString(DriverConfigLoader.java:196)
        at org.janusgraph.diskstorage.cql.builder.CQLSessionBuilder.build(CQLSessionBuilder.java:74)
        at org.janusgraph.diskstorage.cql.CQLStoreManager.<init>(CQLStoreManager.java:135)
        at org.janusgraph.diskstorage.cql.CQLStoreManager.<init>(CQLStoreManager.java:116)
        ... 24 more

I'm guessing something's wrong with the syntax, but I couldn't get it right. Instead, I set storage.cql.internal.file-configuration=/home/test/janusgraph/conf/datastax_java_driver.conf and created the following file:

datastax-java-driver {
  advanced.metadata {
    schema {
      debouncer {
        window = 1 second
      }
    }
  }
}

This seems to give acceptable results because out of about 20-25 attempts at creating different graphs, only one resulted in the same error as before.

For completeness, i also went to the extreme by setting the same parameter to 5 seconds which resulted in:

...
Caused by: com.datastax.oss.driver.api.core.DriverTimeoutException: Query timed out after PT2S
...

so I'm guessing there are some other timeouts to consider as well, but did not look further into that.

Additionally, I also tested advanced.metadata.schema.debouncer.max-events with the following values:

  • 1 - often fails; same behaviour as setting window to 0
  • 3 - occasionally fails
  • 9 - occasionally fails
  • 10 - seems to be about the same as setting window to 1 second

Right now setting window to 1 seconds seems good enough to me, but I'll let you know if this issue persists even with that setting on different environments.

Kind regards,

Mladen Marović

P.S. I managed to get the string configuration to work as well by adding storage.cql.internal.string-configuration = datastax-java-driver { advanced.metadata.schema.debouncer.window = 1 second } (no double quotes).


Oleksandr Porunov
 

Great to hear that worked for you.

Caused by: com.datastax.oss.driver.api.core.DriverTimeoutException: Query timed out after PT2S
As seen from this PR: https://github.com/JanusGraph/janusgraph/pull/2812 the default cql request timeout of 10 seconds isn't applied if you don't provide it explicitly. Thus, it now default to 2 seconds (as seen from DataStax driver default configurations). You can set it explicitly by providing the next config: `storage.cql.request-timeout = 10000` (to make it 10 seconds timeout).

Best regards,
Oleksandr Porunov