Profile() seems inconsisten with System.currentTimeMillis
HadoopMarc <bi...@...>
Hi,
Can anyone explain why the total duration displayed by the profile() step is more than twice as large as the time difference clocked with System.currentTimeMillis?
see below, For those who wonder, the query without profile() also takes about 300 msec.
Thanks, Marc
gremlin> start = System.currentTimeMillis()
==>1607676127027
gremlin> g.V().has('serial', within('1654145144','1648418968','1652445288','1654952168','1653379120', '1654325440','1653383216','1658298568','1649680536','1649819672','1654964456','1649729552', '1656103144','1655460032','1656111336','1654669360')).inE('assembled').outV().profile()
==>Traversal Metrics
Step Count Traversers Time (ms) % Dur
=============================================================================================================
JanusGraphStep([],[serial.within([1654145144, 1... 16 16 0,486 59,26
\_condition=((serial = 1654145144 OR serial = 1648418968 OR serial = 1652445288 OR serial = 1654952168 OR
serial = 1653379120 OR serial = 1654325440 OR serial = 1653383216 OR serial = 1658298568 OR se
rial = 1649680536 OR serial = 1649819672 OR serial = 1654964456 OR serial = 1649729552 OR seri
al = 1656103144 OR serial = 1655460032 OR serial = 1656111336 OR serial = 1654669360))
\_orders=[]
\_isFitted=true
\_isOrdered=true
\_query=multiKSQ[16]@2000
\_index=bySerial
optimization 0,009
optimization 0,267
JanusGraphVertexStep(IN,[assembled],vertex) 73 73 0,334 40,74
\_condition=type[assembled]
\_orders=[]
\_isFitted=true
\_isOrdered=true
\_query=org.janusgraph.diskstorage.keycolumnvalue.SliceQuery@812bd43d
\_vertices=1
optimization 0,037
optimization 0,008
optimization 0,005
optimization 0,004
optimization 0,004
optimization 0,004
optimization 0,017
optimization 0,004
optimization 0,004
optimization 0,004
optimization 0,004
optimization 0,004
optimization 0,004
optimization 0,004
optimization 0,004
optimization 0,004
>TOTAL - - 0,820 -
gremlin> System.currentTimeMillis() - start
==>322
==>1607676127027
gremlin> g.V().has('serial', within('1654145144','1648418968','1652445288','1654952168','1653379120', '1654325440','1653383216','1658298568','1649680536','1649819672','1654964456','1649729552', '1656103144','1655460032','1656111336','1654669360')).inE('assembled').outV().profile()
==>Traversal Metrics
Step Count Traversers Time (ms) % Dur
=============================================================================================================
JanusGraphStep([],[serial.within([1654145144, 1... 16 16 0,486 59,26
\_condition=((serial = 1654145144 OR serial = 1648418968 OR serial = 1652445288 OR serial = 1654952168 OR
serial = 1653379120 OR serial = 1654325440 OR serial = 1653383216 OR serial = 1658298568 OR se
rial = 1649680536 OR serial = 1649819672 OR serial = 1654964456 OR serial = 1649729552 OR seri
al = 1656103144 OR serial = 1655460032 OR serial = 1656111336 OR serial = 1654669360))
\_orders=[]
\_isFitted=true
\_isOrdered=true
\_query=multiKSQ[16]@2000
\_index=bySerial
optimization 0,009
optimization 0,267
JanusGraphVertexStep(IN,[assembled],vertex) 73 73 0,334 40,74
\_condition=type[assembled]
\_orders=[]
\_isFitted=true
\_isOrdered=true
\_query=org.janusgraph.diskstorage.keycolumnvalue.SliceQuery@812bd43d
\_vertices=1
optimization 0,037
optimization 0,008
optimization 0,005
optimization 0,004
optimization 0,004
optimization 0,004
optimization 0,017
optimization 0,004
optimization 0,004
optimization 0,004
optimization 0,004
optimization 0,004
optimization 0,004
optimization 0,004
optimization 0,004
optimization 0,004
>TOTAL - - 0,820 -
gremlin> System.currentTimeMillis() - start
==>322