Hello everybody
I am experiencing a strange behaviour and I would like to show it to you. I
have coded an algorithm on Giraph and the computation itself is quick, but is
burdened by very long “waiting times". To better understand what I mean, I’d
like to share those snippets, taken from a computation I made in local (but
this behaviour can be seen on distributed platforms too) with a graph made up
only by 15 vertices during a single superstep (in this case, the seventh):
##########
2015-07-02 09:16:50,684 INFO [org.apache.giraph.master.MasterThread]
org.apache.giraph.master.BspServiceMaster: barrierOnWorkerList: 0 out of 1
workers finished on superstep 7 on path
/_hadoopBsp/job_1435820986516_0001/_applicationAttemptsDir/0/_superstepDir/7/_workerFinishedDir
2015-07-02 09:16:50,684 INFO [org.apache.giraph.master.MasterThread]
org.apache.giraph.master.BspServiceMaster: barrierOnWorkerList: Waiting on
[virtualubuntu_0]
2015-07-02 09:16:51,647 INFO [main] org.apache.giraph.graph.GraphTaskManager:
execute: 1 partitions to process with 1 compute thread(s), originally 1
thread(s) on superstep 7
##########
2015-07-02 09:16:51,660 INFO [main] org.apache.giraph.comm.netty.NettyClient:
logInfoAboutOpenRequests: 1 requests for taskId=-1,
2015-07-02 09:16:52,653 INFO [main] org.apache.giraph.comm.netty.NettyClient:
waitAllRequests: Finished all requests. MBytes/sec received = 0, MBytesReceived
= 0, ave received req MBytes = 0, secs waited = 0.99
##########
2015-07-02 09:16:53,658 INFO [compute-0]
org.apache.giraph.graph.ComputeCallable: call: Computation took 0.007531393
secs for 1 partitions on superstep 8. Flushing started
2015-07-02 09:16:53,658 INFO [main] org.apache.giraph.worker.BspServiceWorker:
finishSuperstep: Waiting on all requests, superstep 8 Memory (free/total/max) =
79.20M / 152.00M / 2731.00M
2015-07-02 09:16:53,659 INFO [main] org.apache.giraph.comm.netty.NettyClient:
waitAllRequests: Finished all requests. MBytes/sec received = 0, MBytesReceived
= 0, ave received req MBytes = 0, secs waited = 2.001
MBytes/sec sent = 0.0001, MBytesSent = 0.0001, ave sent req MBytes = 0.0001,
secs waited = 2.002
###########
When completed, these are the times for each superstep:
###########
Initialize (ms)=154
Input superstep (ms)=2042
Setup (ms)=37
Shutdown (ms)=18212
Superstep 0 SuperSeeder (ms)=2000
Superstep 1 SuperPropagator (ms)=2011
Superstep 10 SuperPropagator (ms)=2004
Superstep 100 SuperPropagator (ms)=998
Superstep 101 SuperPropagator (ms)=963
Superstep 102 SuperSeeder (ms)=998
Superstep 103 SuperPropagator (ms)=1004
Superstep 104 SuperPropagator (ms)=1015
Superstep 105 SuperSeeder (ms)=977
Superstep 106 SuperPropagator (ms)=1001
Superstep 107 SuperPropagator (ms)=1001
Superstep 108 SuperSeeder (ms)=1003
Superstep 109 SuperPropagator (ms)=2006
Superstep 11 SuperPropagator (ms)=2003
Superstep 110 SuperPropagator (ms)=1000
Superstep 111 SuperSeeder (ms)=1006
Superstep 112 SuperPropagator (ms)=992
Superstep 113 SuperPropagator (ms)=1036
Superstep 114 SuperSeeder (ms)=973
Superstep 115 SuperPropagator (ms)=1001
Superstep 116 SuperPropagator (ms)=1004
Superstep 117 SuperSeeder (ms)=996
Superstep 118 SuperPropagator (ms)=1003
Superstep 119 SuperPropagator (ms)=1003
Superstep 12 SuperSeeder (ms)=2002
Superstep 120 SuperSeeder (ms)=996
Superstep 121 SuperPropagator (ms)=1003
Superstep 122 SuperPropagator (ms)=1002
Superstep 123 SuperSeeder (ms)=2002
Superstep 124 SuperPropagator (ms)=1013
Superstep 125 SuperPropagator (ms)=988
Superstep 126 SuperSeeder (ms)=998
Superstep 127 SuperPropagator (ms)=2005
Superstep 128 SuperPropagator (ms)=2000
Superstep 129 SuperSeeder (ms)=2006
Superstep 13 SuperPropagator (ms)=2010
Superstep 130 SuperPropagator (ms)=1995
Superstep 131 SuperPropagator (ms)=2001
Superstep 132 SuperSeeder (ms)=2008
Superstep 133 SuperPropagator (ms)=2000
Superstep 134 SuperPropagator (ms)=2021
Superstep 135 SuperSeeder (ms)=2012
Superstep 136 FairSlopeReintegrateOneEdges (ms)=1976
Superstep 137 PlainDummyComputation (ms)=2003
Superstep 14 SuperPropagator (ms)=2000
Superstep 15 SuperSeeder (ms)=2001
Superstep 16 SuperPropagator (ms)=2003
Superstep 17 SuperPropagator (ms)=2003
Superstep 18 SuperSeeder (ms)=1000
Superstep 19 SuperPropagator (ms)=2002
Superstep 2 SuperPropagator (ms)=2004
Superstep 20 SuperPropagator (ms)=1999
Superstep 21 SuperSeeder (ms)=1000
Superstep 22 SuperPropagator (ms)=2005
Superstep 23 SuperPropagator (ms)=2002
Superstep 24 SuperSeeder (ms)=2001
Superstep 25 SuperPropagator (ms)=2006
Superstep 26 SuperPropagator (ms)=2000
Superstep 27 SuperSeeder (ms)=999
Superstep 28 SuperPropagator (ms)=2005
Superstep 29 SuperPropagator (ms)=999
Superstep 3 SuperSeeder (ms)=999
Superstep 30 SuperSeeder (ms)=1000
Superstep 31 SuperPropagator (ms)=2002
Superstep 32 SuperPropagator (ms)=1006
Superstep 33 SuperSeeder (ms)=996
Superstep 34 SuperPropagator (ms)=2004
Superstep 35 SuperPropagator (ms)=2003
Superstep 36 SuperSeeder (ms)=1000
Superstep 37 SuperPropagator (ms)=1000
Superstep 38 SuperPropagator (ms)=1001
Superstep 39 SuperSeeder (ms)=1002
Superstep 4 SuperPropagator (ms)=2003
Superstep 40 SuperPropagator (ms)=1000
Superstep 41 SuperPropagator (ms)=1001
Superstep 42 SuperSeeder (ms)=1005
Superstep 43 SuperPropagator (ms)=1003
Superstep 44 SuperPropagator (ms)=1001
Superstep 45 SuperSeeder (ms)=1003
Superstep 46 SuperPropagator (ms)=999
Superstep 47 SuperPropagator (ms)=998
Superstep 48 SuperSeeder (ms)=1004
Superstep 49 SuperPropagator (ms)=999
Superstep 5 SuperPropagator (ms)=2001
Superstep 50 SuperPropagator (ms)=1001
Superstep 51 SuperSeeder (ms)=1004
Superstep 52 SuperPropagator (ms)=999
Superstep 53 SuperPropagator (ms)=1002
Superstep 54 SuperSeeder (ms)=1001
Superstep 55 SuperPropagator (ms)=997
Superstep 56 SuperPropagator (ms)=1002
Superstep 57 SuperSeeder (ms)=1003
Superstep 58 SuperPropagator (ms)=1013
Superstep 59 SuperPropagator (ms)=987
Superstep 6 SuperSeeder (ms)=2005
Superstep 60 SuperSeeder (ms)=1012
Superstep 61 SuperPropagator (ms)=991
Superstep 62 SuperPropagator (ms)=1001
Superstep 63 SuperSeeder (ms)=2003
Superstep 64 SuperPropagator (ms)=998
Superstep 65 SuperPropagator (ms)=1001
Superstep 66 SuperSeeder (ms)=1006
Superstep 67 SuperPropagator (ms)=999
Superstep 68 SuperPropagator (ms)=1004
Superstep 69 SuperSeeder (ms)=1000
Superstep 7 SuperPropagator (ms)=1999
Superstep 70 SuperPropagator (ms)=1005
Superstep 71 SuperPropagator (ms)=997
Superstep 72 SuperSeeder (ms)=1005
Superstep 73 SuperPropagator (ms)=1000
Superstep 74 SuperPropagator (ms)=1003
Superstep 75 SuperSeeder (ms)=1004
Superstep 76 SuperPropagator (ms)=997
Superstep 77 SuperPropagator (ms)=997
Superstep 78 SuperSeeder (ms)=999
Superstep 79 SuperPropagator (ms)=1007
Superstep 8 SuperPropagator (ms)=2006
Superstep 80 SuperPropagator (ms)=996
Superstep 81 SuperSeeder (ms)=1003
Superstep 82 SuperPropagator (ms)=999
Superstep 83 SuperPropagator (ms)=1003
Superstep 84 SuperSeeder (ms)=1001
Superstep 85 SuperPropagator (ms)=998
Superstep 86 SuperPropagator (ms)=1000
Superstep 87 SuperSeeder (ms)=1013
Superstep 88 SuperPropagator (ms)=988
Superstep 89 SuperPropagator (ms)=1017
Superstep 9 SuperSeeder (ms)=1998
Superstep 90 SuperSeeder (ms)=1009
Superstep 91 SuperPropagator (ms)=985
Superstep 92 SuperPropagator (ms)=1003
Superstep 93 SuperSeeder (ms)=993
Superstep 94 SuperPropagator (ms)=1030
Superstep 95 SuperPropagator (ms)=974
Superstep 96 SuperSeeder (ms)=1003
Superstep 97 SuperPropagator (ms)=1004
Superstep 98 SuperPropagator (ms)=998
Superstep 99 SuperSeeder (ms)=1045
Total (ms)=200521
########
For a graph this tiny, the computation lasts WAY too much: I hope you can help
me at least to better understand the Giraph internals, because the computation
(which is, AFAIK, the time needed for each machine to complete the code I
wrote) is quick, but those waiting times just do not convince me.
Any help or explanation to better understand Giraph, would be greatly
appreciated.
Cheers :)
~~~~~~~~~~~~~~~~~~~
Ing. Alessio Arleo
Dottorando in Ingegneria Industriale e dell’Informazione
Dottore Magistrale in Ingegneria Informatica e dell’Automazione
Dottore in Ingegneria Informatica ed Elettronica
Linkedin: it.linkedin.com/in/IngArleo <http://it.linkedin.com/in/IngArleo>
Skype: Ing. Alessio Arleo
Tel: +39 075 5853920
Cell: +39 349 0575782
~~~~~~~~~~~~~~~~~~~
