Date
1 - 5 of 5
how to analyze profile(), explain() output
|
Ankur Goel <ankur...@...>
Hi, I am using profile(), explain() to see what composite / mixed index are getting used. gremlin> g.V().has('vl','tag').has('mob','0').count().profile() ==>Traversal Metrics Step Count Traversers Time (ms) % Dur ============================================================================================================= JanusGraphStep([],[vl.eq(tag), mobile.e... 3724 3724 15077.378 99.82 optimization 1059.911 backend-query 8000 1890.950 backend-query 3724 1391.268 backend-query 137479 7313.396 backend-query 3724 426.626 CountGlobalStep 1 1 27.644 0.18 >TOTAL - - 15105.022 - gremlin> Please help me how to identify the same or any pointer. ~ |
|
|
|
Ankur Goel <ankur...@...>
Any help on this? On Wednesday, October 11, 2017 at 10:58:20 AM UTC+5:30, Ankur Goel wrote:
|
|
|
|
Robert Dale <rob...@...>
This shows some examples of profile() in JanusGraph 0.2. 1. No Schema, No Indexes gremlin> g.V().has('vl','tag').has('mob','0').count().profile() ==>Traversal Metrics Step Count Traversers Time (ms) % Dur ============================================================================================================= JanusGraphStep([],[vl.eq(tag), mob.eq(0)]) 45.623 95.09 \_condition=false \_isFitted=true \_query=[] \_limit=0 \_orders=[] \_isOrdered=false optimization 28.220 CountGlobalStep 1 1 2.355 4.91 >TOTAL - - 47.978 - Because we are filtering on elements for which don't exist in the schema, nothing is actually done, not even a full scan. 2. Property Keys Defined, No Indexes mgmt.makePropertyKey('vl').dataType(String.class).cardinality(SINGLE).make(); mgmt.makePropertyKey('mob').dataType(String.class).cardinality(SINGLE).make(); gremlin> g.V().has('vl','tag').has('mob','0').count().profile() ==>Traversal Metrics Step Count Traversers Time (ms) % Dur ============================================================================================================= JanusGraphStep([],[vl.eq(tag), mob.eq(0)]) 74.317 90.25 \_condition=(vl = tag AND mob = 0) \_isFitted=false \_query=[] \_orders=[] \_isOrdered=true optimization 35.997 scan 0.000 \_condition=VERTEX \_query=[] \_fullscan=true CountGlobalStep 1 1 8.030 9.75 >TOTAL - - 82.348 - It now shows it will do a full scan. You may also see the following warning: 22:46:05 WARN org.janusgraph.graphdb.transaction.StandardJanusGraphTx - Query requires iterating over all vertices [(vl = tag AND mob = 0)]. For better performance, use indexes If you enable 'force-index', you'll get an error for queries that do not use an index thus do full scan. This is one way to assert that all queries use an index. mgmt.buildIndex('vlIdx', Vertex.class).addKey(mgmt.getPropertyKey('vl')).buildCompositeIndex(); gremlin> g.V().has('vl','tag').has('mob','0').count().profile() ==>Traversal Metrics Step Count Traversers Time (ms) % Dur ============================================================================================================= JanusGraphStep([],[vl.eq(tag), mob.eq(0)]) 5.642 99.10 \_condition=(vl = tag AND mob = 0) \_isFitted=false \_query=multiKSQ[1]@2147483647 \_index=vlIdx \_orders=[] \_isOrdered=true optimization 4.689 backend-query 0 0.598 \_query=vlIdx:multiKSQ[1]@2147483647 CountGlobalStep 1 1 0.051 0.90 >TOTAL - - 5.694 - 'isFitted=false' because the index doesn't return exact matches and there are additional filters to be applied 'index' shows the name of the index being queried mgmt.buildIndex('vlAndMobIdx', Vertex.class).addKey(mgmt.getPropertyKey('vl')).addKey(mgmt.getPropertyKey('mob')).buildCompositeIndex(); gremlin> g.V().has('vl','tag').has('mob','0').count().profile() ==>Traversal Metrics Step Count Traversers Time (ms) % Dur ============================================================================================================= JanusGraphStep([],[vl.eq(tag), mob.eq(0)]) 7.495 99.06 \_condition=(vl = tag AND mob = 0) \_isFitted=true \_query=multiKSQ[1]@2147483647 \_index=vlAndMobIdx \_orders=[] \_isOrdered=true optimization 6.561 backend-query 0 0.663 \_query=vlAndMobIdx:multiKSQ[1]@2147483647 CountGlobalStep 1 1 0.070 0.94 >TOTAL - - 7.566 - Both the single key index and dual key index exist. JanusGraph selects the best match, in this case, dual key. 'isFitted=true' because both has() filters will give an exact match on the index and there are no additional filters to be applied. 5. Mixed Index mgmt.buildIndex('vlAndMobIdxSearch', Vertex.class).addKey(mgmt.getPropertyKey('vl')).addKey(mgmt.getPropertyKey('mob')).buildMixedIndex('search'); gremlin> g.V().has('vl','tag').has('mob','0').count().profile() ==>Traversal Metrics Step Count Traversers Time (ms) % Dur ============================================================================================================= JanusGraphStep([],[vl.eq(tag), mob.eq(0)]) 8.529 99.38 \_condition=(vl = tag AND mob = 0) \_isFitted=true \_query=multiKSQ[1]@2147483647 \_index=vlAndMobIdx \_orders=[] \_isOrdered=true optimization 7.249 backend-query 0 0.132 \_query=vlAndMobIdx:multiKSQ[1]@2147483647 CountGlobalStep 1 1 0.053 0.62 >TOTAL - - 8.582 - This query used the composite index because the query is for exact matches and not ranges. Let's do a range query to see the mixed index being used. gremlin> g.V().has('vl',textContains('tag')).has('mob','0').count().profile() ==>Traversal Metrics Step Count Traversers Time (ms) % Dur ============================================================================================================= JanusGraphStep([],[vl.textContains(tag), mob.eq... 59.434 99.91 \_condition=(vl textContains tag AND mob = 0) \_isFitted=false \_query=[(vl textContains tag)]:vlAndMobIdxSearch \_index=vlAndMobIdxSearch \_orders=[] \_isOrdered=true \_index_impl=search optimization 1.098 backend-query 0 58.179 \_query=vlAndMobIdxSearch:[(vl textContains tag)]:vlAndMobIdxSearch CountGlobalStep 1 1 0.051 0.09 >TOTAL - - 59.485 - Here we can see that it's using the new search index. 'index_impl' contains the name of the search backend that was provided to the builder. But why is it not fitted? That is, why did the has('mob','0') not get included as a part of the search index query and instead acts as a follow-on filter? That is because the search index was created with the default Mapping of TEXT which tokenizes the string and does not allow for exact matches. If the dual-key composite index is disabled and a new mixed index with Mapping.STRING is created, JanusGraph will use the search backend for exact match queries. Not that you would necessarily want to do this. gremlin> g.V().has('vl','tag').has('mob','0').count().profile() ==>Traversal Metrics Step Count Traversers Time (ms) % Dur ============================================================================================================= JanusGraphStep([],[vl.eq(tag), mob.eq(0)]) 1 1 9.390 99.49 \_condition=(vl = tag AND mob = 0) \_isFitted=true \_query=[(vl = tag AND mob = 0)]:vlAndMobIdxSearchString \_index=vlAndMobIdxSearchString \_orders=[] \_isOrdered=true \_index_impl=search optimization 0.345 backend-query 1 8.725 \_query=vlAndMobIdxSearchString:[(vl = tag AND mob = 0)](4000):vlAndMobIdxSearchString \_limit=4000 CountGlobalStep 1 1 0.048 0.51 >TOTAL - - 9.438 - Now, when a full-text search is mixed with an exact match, there will be two backend queries... gremlin> g.V().has('vl',textContains('tag')).has('mob','0').count().profile() ==>Traversal Metrics Step Count Traversers Time (ms) % Dur ============================================================================================================= JanusGraphStep([],[vl.textContains(tag), mob.eq... 6.950 98.80 \_condition=(vl textContains tag AND mob = 0) \_isFitted=true \_query=[(vl textContains tag)]:vlAndMobIdxSearch \_index=vlAndMobIdxSearch \_orders=[] \_isOrdered=true \_index_impl=search optimization 0.219 backend-query 0 3.649 \_query=vlAndMobIdxSearch:[(vl textContains tag)](4000):vlAndMobIdxSearch \_limit=4000 backend-query 0 2.895 \_query=vlAndMobIdxSearchString:[(mob = 0)]:vlAndMobIdxSearchString CountGlobalStep 1 1 0.084 1.20 >TOTAL - - 7.035 - Ideally, a new index would be created for this particular scenario. HTH On Thursday, October 12, 2017 at 2:18:52 AM UTC-4, Ankur Goel wrote:
|
|
|
|
Ankur Goel <ankur...@...>
Thnx Robert, right now i am using 0.1 Same output of profile/explain is not available in it. Any pointer for 0.1.1. When 0.2 will be general available. ~AnkurG On Wednesday, October 11, 2017 at 10:58:20 AM UTC+5:30, Ankur Goel wrote:
|
|
|
|
bhawesh....@...
On Wednesday, 11 October 2017 10:58:20 UTC+5:30, Ankur Goel wrote:
how total time is calculated? Can you please explain.
|
|
|