Help with understanding higher than expected query results times

[jankoulaga]

Hey,

we've been trying to run Janusgraph in front of scylla, and we did an extremely simple test where we inserted 1001 nodes and 1000 edges, using the following schema:

sLabel  = mgmt.makeVertexLabel('s').make()
hLabel  = mgmt.makeVertexLabel('h').make()
containsLabel = mgmt.makeEdgeLabel('contains').multiplicity(SIMPLE).make()

mgmt.addConnection(containsLabel, sLabel, hLabel)

h = mgmt.makePropertyKey('h').dataType(String.class).make()
memberUntil = mgmt.makePropertyKey('m').dataType(Long.class).make()
sdp = mgmt.makePropertyKey('dp').dataType(String.class).make()
sId = mgmt.makePropertyKey('s_id').dataType(Long.class).make()
sVersion = mgmt.makePropertyKey('s_version').dataType(Long.class).make()
ttl = mgmt.makePropertyKey('ttl').dataType(Long.class).make()

mgmt.addProperties(containsLabel, memberUntil)
mgmt.addProperties(hLabel, h)
mgmt.addProperties(sLabel, sdp, sId, ttl, sVersion)

mgmt.buildIndex('by_s_id', Vertex.class).addKey(sId).buildCompositeIndex()
mgmt.buildIndex('by_h', Vertex.class).addKey(h).buildCompositeIndex()

Now, what we've done is we've inserted 1 h node, 1000 s nodes and created edges between them.

Our goal is to determine how fast we can get all the properties for all 1000 s nodes tied to the h node.
The results were surprising, as it took 2 seconds to return those values.
Is this expected behaviour? I had assumed that the 1000 edges would not really classify as a super node.

We'd appreciate any help or input whether what we're trying to do is achievable.

[li-boxuan]

2 seconds sound too long. Can you add profile() step to the end of your query and paste the result together with your query here?

UPDATE: Try enabling query.batch: https://docs.janusgraph.org/basics/configuration-reference/#query

[melgenek]

Hi @li-boxuan,

thank you for your prompt response!

The query plan looks as follows:

gremlin> g.V().has("h", "h", "QBSRzReoQC").in("contains").valueMap("s_id").profile()
==>Traversal Metrics
Step                                                               Count  Traversers       Time (ms)    % Dur
=============================================================================================================
JanusGraphStep([],[~label.eq(h   ),    h.eq(QBS...                     1           1           4.341     0.62
    \_condition=(~label = h AND h = QBSRzReoQC)
    \_orders=[]
    \_isFitted=false
    \_isOrdered=true
    \_query=multiKSQ[1]@2000
    \_index=by_h
  optimization                                                                                 0.018
  optimization                                                                                 0.133
  backend-query                                                        1                       3.742
    \_query=by_h:multiKSQ[1]@2000
    \_limit=2000
JanusGraphVertexStep(IN,[contains],vertex)                          1000        1000          41.565     5.90
    \_condition=type[contains]
    \_orders=[]
    \_isFitted=true
    \_isOrdered=true
    \_query=org.janusgraph.diskstorage.keycolumnvalue.SliceQuery@812bd43d
    \_multi=true
    \_vertices=1
  optimization                                                                                 0.069
  backend-query                                                     1000                       2.497
    \_query=org.janusgraph.diskstorage.keycolumnvalue.SliceQuery@812bd43d
PropertyMapStep([      s_id],value)                                 1000        1000         659.058    93.49
                                            >TOTAL                     -           -         704.965        -

We connect to Janus via remote gremlin. Janus runs in docker with the following properties:

gremlin.graph=org.janusgraph.core.JanusGraphFactory
schema.default=none
storage.backend=cql
storage.hostname=scylla

Here are a couple things that we tried and our observations:

1. adding the query.batch=true and query.batch-property-prefetch=true don't seem to make any difference.
2. The .valueMap is in the query because it seems to be faster than .elementMap.
3. valueMap() without specified properties seems to perform the same way as valueMap("s_id", "dp")
4. The .id() query is an order of magnitude faster than the .valueMap:

gremlin> g.V().has("h", "h", "QBSRzReoQC").in("contains").id().profile()
==>Traversal Metrics
Step                                                               Count  Traversers       Time (ms)    % Dur
=============================================================================================================
JanusGraphStep([],[~label.eq(h   ),    h.eq(QBS...                     1           1           0.693     1.47
    \_condition=(~label = h AND h = QBSRzReoQC)
    \_orders=[]
    \_isFitted=false
    \_isOrdered=true
    \_query=multiKSQ[1]@2000
    \_index=by_h
  optimization                                                                                 0.017
  optimization                                                                                 0.148
JanusGraphVertexStep(IN,[contains],vertex)                          1000        1000          16.594    35.08
    \_condition=type[contains]
    \_orders=[]
    \_isFitted=true
    \_isOrdered=true
    \_query=org.janusgraph.diskstorage.keycolumnvalue.SliceQuery@812bd43d
    \_multi=true
    \_vertices=1
  optimization                                                                                 0.032
IdStep                                                              1000        1000          30.020    63.46
                                            >TOTAL                     -           -          47.308        -

The size of the json response with .id() is 35kb vs 100kb in .valueMap(), so some time is also spent on the serialization.
Still, it seems that getting the s properties takes a lot of time.

Thank you for your help!

[li-boxuan]

Yes, your observation is correct. It takes a lot of time to get the properties because JanusGraph has to fire 1000 calls to scylla to fetch the property values one by one. Using query.batch=true should work much better because it fires calls concurrently, but unfortunately, until #2444 is fixed, valueMap() step does not do batching. Try using values() step - hopefully, that would be much faster.

[melgenek]

The values() step is indeed faster. Thank you!