You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@giraph.apache.org by "Ing. Alessio Arleo" <in...@icloud.com> on 2015/07/02 10:18:03 UTC

LONG Waiting times

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

~~~~~~~~~~~~~~~~~~~