Performance with HBase as backend with Gremlin and Janusgraph

[Sarthak Ghosh]

Hi,

In our project we were previously using Cassandra as backend but recently switched to HBase. 

The problem is that a simple query is taking a lot of time to return the data and we are facing TIMEOUT exception. 

```

Error org.apache.tinkerpop.gremlin.driver.exception.ResponseException: Script evaluation exceeded the configured 'scriptEvaluationTimeout' threshold of 120000 ms or evaluation was otherwise cancelled directly for request 
[fciGraph.V().has('nodeLabel','account').has('sar',false).order().by('association_score',Order.decr).limit(150).toList();]

```

In gremlin.log file, there is so much data but there is no error. (graph-log.txt)

This is my janusgraph-hbase.properties file configs

```
gremlin.graph=org.janusgraph.core.JanusGraphFactory
storage.backend=hbase
storage.hostname=host

storage.hbase.ext.zookeeper.znode.parent=/hbase-unsecure
      
      

        
storage.hbase.ext.hbase.zookeeper.property.clientPort=2181
cache.db-cache=true
      
      

        
storage.hbase.table=fci-graph
cache.db-cache-clean-wait=20
cache.db-cache-time=180000
cache.db-cache-size=0.5
index.search.backend=elasticsearch
      
      

        
index.search.hostname=fci-elasticsearch
      
      

        
index.search.port=9200
      
      

        
index.search.elasticsearch.ssl.enabled=true
      
      

        
index.search.elasticsearch.ssl.keystore.location=/fciexports/graph-writer/fci_universal_ks.jks
      
      

        
index.search.elasticsearch.ssl.keystore.keypassword=password

index.search.elasticsearch.ssl.keystore.storepassword=password

index.search.elasticsearch.ssl.allow-self-signed-certificates=true
      
      

        
index.search.elasticsearch.ssl.disable-hostname-verification=true
      
      

        
index.search.elasticsearch.http.auth.type=basic
      
      

        
index.search.elasticsearch.http.auth.basic.username=fci_logs
      
      

        
index.search.elasticsearch.http.auth.basic.password=password
```

I have attached my gremlin-server.yaml (gremlin-server.yaml) file as well.

[Florian Hockmann]

The traversal probably has to iterate over all vertices in the graph. Even if you have an index on this sar property, it would be very inefficient if that's a boolean. Depending on the size of your graph, it's expected that the traversal takes a very long time to be executed.

Did this traversal completely fast on Cassandra before (with a similar graph size)?

One general note: Please ask questions that are specific to JanusGraph like this one in the JanusGraph users group in the future.

[Sarthak Ghosh]

 Hi Florian,
Thanks for replying. I didn't specifically know whether it was gremlin's issue or janusgraph's. Anyway, I'll keep that in mind for future queries.

As for the graph size, yes, that was exactly the same which we were loading on cassandra. Loading and Querying on cassandra was really good and the queries executed were same as well. Everything was same, data, schema.
Only change was the backend.

Though cassandra was on the same local machine, HBase setup was on a different machine. But could network latency cause such slowness?

[Sarthak Ghosh]

Also, in gremlin-server.yaml I am getting these logs repeatedly

```

07:16:30.481 [pool-8-thread-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter FilterList AND (2/2): [ColumnRangeFilter [\x00\x00\x01m\x00H\x0D\x12, \x00\x00\x01m\x00H \x9D), ColumnPaginationFilter(1024, \x00\x00\x01m\x00H\x0D\x12)]

07:16:33.880 [pool-13-thread-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter FilterList AND (2/2): [ColumnRangeFilter [\x00\x00\x01m\x00H\x1AX, \x00\x00\x01m\x00H-\xE3), ColumnPaginationFilter(1024, \x00\x00\x01m\x00H\x1AX)]

07:16:34.834 [main-SendThread(9.46.72.119:2181)] DEBUG o.a.h.h.s.o.a.zookeeper.ClientCnxn - Got ping response for sessionid: 0x16cb580a3751b4f after 1ms

07:16:35.503 [pool-8-thread-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter FilterList AND (2/2): [ColumnRangeFilter [\x00\x00\x01m\x00H \x9D, \x00\x00\x01m\x00H4;), ColumnPaginationFilter(1024, \x00\x00\x01m\x00H \x9D)]

07:16:35.770 [main-SendThread(9.46.72.119:2181)] DEBUG o.a.h.h.s.o.a.zookeeper.ClientCnxn - Got ping response for sessionid: 0x16cb580a3751b50 after 1ms

07:16:38.889 [pool-13-thread-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter FilterList AND (2/2): [ColumnRangeFilter [\x00\x00\x01m\x00H-\xE3, \x00\x00\x01m\x00HAu), ColumnPaginationFilter(1024, \x00\x00\x01m\x00H-\xE3)]

07:16:40.507 [pool-8-thread-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter FilterList AND (2/2): [ColumnRangeFilter [\x00\x00\x01m\x00H4;, \x00\x00\x01m\x00HG\xC7), ColumnPaginationFilter(1024, \x00\x00\x01m\x00H4;)]

07:16:43.892 [pool-13-thread-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter FilterList AND (2/2): [ColumnRangeFilter [\x00\x00\x01m\x00HAu, \x00\x00\x01m\x00HU\x00), ColumnPaginationFilter(1024, \x00\x00\x01m\x00HAu)]

07:16:45.510 [pool-8-thread-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter FilterList AND (2/2): [ColumnRangeFilter [\x00\x00\x01m\x00HG\xC7, \x00\x00\x01m\x00H[R), ColumnPaginationFilter(1024, \x00\x00\x01m\x00HG\xC7)]

07:16:48.895 [pool-13-thread-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter FilterList AND (2/2): [ColumnRangeFilter [\x00\x00\x01m\x00HU\x00, \x00\x00\x01m\x00Hh\x8B), ColumnPaginationFilter(1024, \x00\x00\x01m\x00HU\x00)]

07:16:50.513 [pool-8-thread-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter FilterList AND (2/2): [ColumnRangeFilter [\x00\x00\x01m\x00H[R, \x00\x00\x01m\x00Hn\xDD), ColumnPaginationFilter(1024, \x00\x00\x01m\x00H[R)]
```

```

06:44:02.387 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.388 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.389 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.592 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.595 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.596 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.597 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.800 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.802 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.804 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.805 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.807 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.808 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.809 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.811 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.812 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.813 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.814 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:02.817 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:03.020 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:03.022 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:03.023 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:03.025 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)

06:44:03.027 [gremlin-server-exec-1] DEBUG o.j.d.hbase.HBaseKeyColumnValueStore - Generated HBase Filter ColumnRangeFilter [@, `)
```

```

07:01:31.469 [main] DEBUG o.j.d.hbase.HBaseStoreManager - Dumping HBase config key=value pairs

07:01:31.470 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] mapreduce.jobtracker.address=local

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] dfs.namenode.resource.check.interval=5000

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] mapreduce.jobhistory.client.thread-count=10

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] yarn.admin.acl=*

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] yarn.app.mapreduce.am.job.committer.cancel-timeout=60000

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] mapreduce.job.emit-timeline-data=false

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] dfs.journalnode.rpc-address=0.0.0.0:8485

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] yarn.resourcemanager.leveldb-state-store.path=${hadoop.tmp.dir}/yarn/system/rmstore

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] hbase.master.hfilecleaner.plugins=org.apache.hadoop.hbase.master.cleaner.TimeToLiveHFileCleaner

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] ipc.client.connection.maxidletime=10000

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] yarn.nodemanager.process-kill-wait.ms=2000

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] hbase.regionserver.regionSplitLimit=1000

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] mapreduce.jobtracker.handler.count=10

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] io.map.index.interval=128

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] dfs.namenode.https-address=0.0.0.0:50470

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] hbase.client.scanner.timeout.period=60000

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] mapreduce.task.profile.reduces=0-2

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] fs.s3n.multipart.uploads.enabled=false

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] io.seqfile.sorter.recordlimit=1000000

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] mapreduce.tasktracker.tasks.sleeptimebeforesigkill=5000

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] hadoop.util.hash.type=murmur

07:01:31.471 [main] DEBUG o.j.d.hbase.HBaseStoreManager - [HBaseConfig] hbase.master.logcleaner.plugins=org.apache.hadoop.hbase.master.cleaner.TimeToLiveLogCleaner
```

Is there a way to turn them off or put them in WARNING or ERROR config in either gremlin-server.yaml or janusgrah-hbase.properties?

[Stephen Mallette]

Gremlin Server uses slf4j so you can use standard log configuration files to tweak log settings - see log4j-server.properties.

--
You received this message because you are subscribed to the Google Groups "Gremlin-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to gremlin-user...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/gremlin-users/7ba1abef-fdd1-42cf-a862-c4b1e5e461d2%40googlegroups.com.

[Sarthak Ghosh]

 Hi Stephen,

I saw log4j-server.properties file in the conf folder of gremlin-server. Below are the properties I have set

```

log4j.rootLogger=WARNING

log4j.appender.stdout=org.apache.log4j.ConsoleAppender

log4j.appender.stdout.layout=org.apache.log4j.PatternLayout

log4j.appender.stdout.layout.ConversionPattern=[%p] %C{1} - %m%n

log4j.logger.org.apache.tinkerpop.gremlin.driver.Connection=OFF

log4j.logger.org.apache.tinkerpop.gremlin.driver.ConnectionPool=OFF

log4j.logger.org.apache.tinkerpop.gremlin.neo4j.structure.Neo4jGraph=WARNING

log4j.logger.org.apache.hadoop.mapred.JobClient=WARNING

log4j.logger.org.apache.hadoop.mapreduce.Job=WARNING

log4j.logger.org.apache.tinkerpop.gremlin.hadoop.process.computer.mapreduce.MapReduceGraphComputer=WARNING

log4j.logger.org.apache.tinkerpop.gremlin.hadoop.structure.HadoopGraph=WARNING

log4j.logger.org.apache.tinkerpop.gremlin.spark.process.computer.SparkGraphComputer=WARNING

log4j.logger.org.apache.spark.metrics.MetricsSystem=WARNING
```

As you can see all of them are set to WARNING. I even tried ERROR but logs still shows what I posted earlier, DEBUG state.

Is there something I'm missing in yaml or properties file?

 

 

[Stephen Mallette]

well, it doesn't seem to be respecting the rootLogger configuration, unless there is some other logger writing that out.  i don't recall what logging framework JanusGraph is using. you might need a separate configuration file. Maybe someone more familiar with JanusGraph could supply an answer to this.

--

You received this message because you are subscribed to the Google Groups "Gremlin-users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to gremlin-user...@googlegroups.com.

To view this discussion on the web visit https://groups.google.com/d/msgid/gremlin-users/a286ba80-4a00-4bc6-83b6-0acfe4b71802%40googlegroups.com.

[Florian Hockmann]

Not sure what's happening here, but log4-server.properties is definitely the right file to configure the logging and the format also looks correct to me.

Regarding the original question here of slow performance:

As for the graph size, yes, that was exactly the same which we were loading on cassandra. Loading and Querying on cassandra was really good and the queries executed were same as well. Everything was same, data, schema.
Only change was the backend.

Though cassandra was on the same local machine, HBase setup was on a different machine. But could network latency cause such slowness?

Not sure whether it's expected to get a better performance with Cassandra over HBase for this traversal as I've never used HBase. I'm also not sure about whether the network latency is to blame here, but you could try that out of course, for example by setting up Cassandra in a similar way and then compare the results again.

I just realized that I was wrong with my earlier comment where I said that this traversal can't use an index as I misread the first step as hasLabel('account') opposed to has('nodeLabel','account'). So, if you have an index on the property nodeLabel, then it can use that index for this traversal. The execution time should mostly depend on the number of account vertices here.

It could also help here to compare the profile() output of the traversal for both setups.

To unsubscribe from this group and stop receiving emails from it, send an email to gremli...@googlegroups.com.

[Sarthak Ghosh]

Okay, so I was able to find fix to this issue. So in gremlin libraries, what I found was there were many *log* jars present which comes with Janusgraph bundle (versions can be different since I'm using JS 0.4.1). Below is the list:

jcabi-log-0.14.jar

commons-logging-1.1.1.jar

slf4j-log4j12-1.7.12.jar

log4j-1.2.16.jar

jboss-logging-3.1.2.GA.jar

minlog-1.3.0.jar

slf4j-log4j12-1.7.25.jar

log4j-1.2.17.jar

logback-core-1.1.3.jar

logback-classic-1.1.3.jar

I removed jboss-logging-3.1.2.GA.jar,log4j-1.2.16.jar,logback-classic-1.1.3.jar,slf4j-log4j12-1.7.12.jar,minlog-1.3.0.jar,logback-core-1.1.3.jar.. 
Also, log4j-server.properties file present in conf folder was somehow causing issue (not sure about this), so I replaced it with the following configs:

# Set root logger level to DEBUG and its only appender to A1.

log4j.rootLogger=INFO, A1

# A1 is set to be a ConsoleAppender.

log4j.appender.A1=org.apache.log4j.ConsoleAppender

# A1 uses PatternLayout.

log4j.appender.A1.layout=org.apache.log4j.PatternLayout

log4j.appender.A1.layout.ConversionPattern=%-4r [%t] %-5p %c %x - %m%n

After this, logs can be controlled according to rootLogger (INFO, DEBUG, etc)

To unsubscribe from this group and stop receiving emails from it, send an email to gremli...@googlegroups.com.