You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@giraph.apache.org by Eric Kimbrel <Er...@soteradefense.com> on 2013/05/16 22:50:17 UTC

Broadcast of large aggregated value is slow.

I have an giraph job in which the Master will read a chunk of a file from HDFS, and then use an aggregator to broadcast the data to all vertices.  No other messages are sent, and no vertices aggregate values, only the master.

In the attached logs you can see that the time spent to broadcast the data to all vertices is slow, and seems to be hanging up somehwere.  It appears that the majority of workers receive the data in 10-15 seconds, but then nothing happens for around 10 minutes.  Log snippet shown below

Is there a known reason why transmitting this data during the synchronization is taking so long, or anything that can be done to speed it up?


2013-05-16 11:09:03,041 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 30 more tasks to send their aggregator data
2013-05-16 11:09:14,444 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 10 more tasks to send their aggregator data, task ids: [13, 20, 22, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:25,190 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:45,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:05,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:15,192 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:35,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:55,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:05,194 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:25,195 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:45,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:05,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:15,197 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:35,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:55,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:05,199 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:25,200 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:45,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:05,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:15,202 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:35,203 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:55,204 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:15,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:35,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:45,206 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:05,207 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:25,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:45,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:55,209 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:15,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:35,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:45,211 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:05,212 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:19,841 INFO org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window metrics MBytes/sec sent = 0, MBytes/sec received = 0.027, MBytesSent = 0.0006, MBytesReceived = 15.4028, ave sent req MBytes = 0, ave received req MBytes = 0.0034, secs waited = 571.136






Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<http://www.potomacfusion.com/> | www.soteradefense.com<http://www.soteradefense.com/>
Agility. Ingenuity. Integrity.

Re: Broadcast of large aggregated value is slow.

Posted by Eric Kimbrel <Er...@soteradefense.com>.
No, I only have the one aggregator.  I'll try to think of a way to split it up, but that doesn't really fit gracefully with the concept of having a broadcast variable, which is what I thought I could accomplish here.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<http://www.potomacfusion.com/> | www.soteradefense.com<http://www.soteradefense.com/>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Monday, May 27, 2013 10:46 AM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Not all aggregators are assigned to a single worker, but each aggregator is randomly assigned to one of the workers. This way, in case you have enough aggregators, the job of both aggregation and sending values of aggregators is balanced across workers. In your case, it might be that network is the bottleneck, since one aggregator of size S requires that the worker which that aggregator is assigned to sends S*w amount of data. And as Avery suggested, splitting data across several aggregators can help, and it shouldn't be hard for you to try out.

That being said, logs you sent are not showing exactly what I'd expect to happen in this case. Do you maybe have a couple of small aggregators as well?

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Monday, May 27, 2013 10:02 AM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

Im a little confused still I think.  I understand that in the normal use of aggregators one worker is assigned to aggregate all values and then broadcast them out.  But here I am not doing any aggregation at all.  setValue on the aggregator is called exactly once per superstep by exactly one worker (the master compute class).  There is no work to do except to send the value out to all vertices.  A one to all broad cast is all I am looking for.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=plPQC3Ca71jQW2YcL3ZCUyYKZLrgPvFzDwicHcNb1ic%3D%0A&s=dc3e0d75cc49fb39e21992f6b589c5d748e141d225cea2bfe915ed138fdf1f5f> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=plPQC3Ca71jQW2YcL3ZCUyYKZLrgPvFzDwicHcNb1ic%3D%0A&s=d5818827b7fb404dec2d356128c934a677d0030ef55cecdaa8d9ac160963da1b>
Agility. Ingenuity. Integrity.


From: Avery Ching <ac...@apache.org>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Monday, May 27, 2013 9:47 AM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

This kind of use case (massive all to all broadcast of a single aggregator) is not optimized.  A tree-based aggregation implementation would likely improve the performance of this kind of use case.  You're welcome to implement it if you like.

If you could break it up into multiple aggregators, this would be a workaround that would get better performance (as it gets distributed to multiple workers, rather than a single worker).

Avery

On 5/27/13 9:28 AM, Eric Kimbrel wrote:
Are there any recommendations for alternative ways to handle this sort of use case ( mater compute doing a large broadcast to all vertices) or any ideas of whats happening underneath to cause everything to wait?

Any other test cases I can try or data I could gather that may be illuminating?


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=plPQC3Ca71jQW2YcL3ZCUyYKZLrgPvFzDwicHcNb1ic%3D%0A&s=dc3e0d75cc49fb39e21992f6b589c5d748e141d225cea2bfe915ed138fdf1f5f> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=plPQC3Ca71jQW2YcL3ZCUyYKZLrgPvFzDwicHcNb1ic%3D%0A&s=d5818827b7fb404dec2d356128c934a677d0030ef55cecdaa8d9ac160963da1b>
Agility. Ingenuity. Integrity.


From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Tuesday, May 21, 2013 10:43 AM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

I use only one aggregator.  The code for it is extremely simple as it is not actually used as an aggregator at all.  The only use is for the master compute class to set a large object value, and then for each vertex to read that value.  The Size of the Bytes writable is ~ 100M



Heres the code for the aggregator:



publicclass BroadcastAggregator extends BasicAggregator<RowListWritable>{


// no user code ever calls aggregate.

// Master compute class calls setAggregatedValue once per superstep.



// This method is not used, but is provided for flexibility.

//If a non empty value is added it will be added to the current value and then set

@Override

publicvoid aggregate(RowListWritable rw) {

if (rw.index.length == 0) return;

if (this.getAggregatedValue().index.length > 0){

rw.add(this.getAggregatedValue());

}

this.setAggregatedValue(rw);

}


@Override

public RowListWritable createInitialValue() {

returnnew RowListWritable();

}


}



Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=plPQC3Ca71jQW2YcL3ZCUyYKZLrgPvFzDwicHcNb1ic%3D%0A&s=dc3e0d75cc49fb39e21992f6b589c5d748e141d225cea2bfe915ed138fdf1f5f> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=plPQC3Ca71jQW2YcL3ZCUyYKZLrgPvFzDwicHcNb1ic%3D%0A&s=d5818827b7fb404dec2d356128c934a677d0030ef55cecdaa8d9ac160963da1b>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 8:18 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Thanks, Eric. I'm not sure what's going on, it's strange that there are a couple of machines which wait for aggregators for a very long time, but then in exactly same moment they receive them. Can you send us the code for Aggregator which you are using? Do you know approximately how big aggregators are and how many of them do you have?

Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:36 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

My apologies. You are correct, I attached the wrong long.   Correct one attached here.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=JneyqIVoubY0J4ko9BK2DwfsA%2BN6Qy8nBTZj%2BVg78Uw%3D%0A&s=9cf5380dcf55ff5999b2f5b12c9a93b206777c47e775a949e9da6f6a8ce4f173> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=JneyqIVoubY0J4ko9BK2DwfsA%2BN6Qy8nBTZj%2BVg78Uw%3D%0A&s=70d18c70634f46634d557cf4f36276e3e5936b40e403d69a1ac10e3e4e5ff52b>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:25 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Eric,

Can you please check it again, in both logs you attached we are waiting on the worker 13 to send data, so none of those can't be worker 13's log.

Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:15 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

One of the attached logs is worker 13,  During this time period it is waiting for an aggregator request so that it can start the super step.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=b933c5068d68b34f5bfbac0db0f8eb919a01dacd3555330fe3147bbf53399d72> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=f5fe0f489b7bfc207fb44206c50b2f74d0763169d0db18557586da3ce1d83443>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:11 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Eric,

Can you please take a look at the logs of one of the workers listed (13, 34, 38, 50, 48, 52, 58, 56), what are they doing? The fact that a worker is waiting on aggregator can have different causes, it doesn’t necessarily mean that sending aggregators is slow. It can for example mean that some workers finished computing before others and are now waiting for others to finish and send their data.
How big are aggregators which you are using?

Thanks,
Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:00 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

>From the attached logs in original post, you can see that both workers use about 4 seconds of compute time on super step 4, but they complete super step 4 about 10 minutes apart.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.


From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 1:50 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Broadcast of large aggregated value is slow.


I have an giraph job in which the Master will read a chunk of a file from HDFS, and then use an aggregator to broadcast the data to all vertices.  No other messages are sent, and no vertices aggregate values, only the master.

In the attached logs you can see that the time spent to broadcast the data to all vertices is slow, and seems to be hanging up somehwere.  It appears that the majority of workers receive the data in 10-15 seconds, but then nothing happens for around 10 minutes.  Log snippet shown below

Is there a known reason why transmitting this data during the synchronization is taking so long, or anything that can be done to speed it up?


2013-05-16 11:09:03,041 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 30 more tasks to send their aggregator data
2013-05-16 11:09:14,444 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 10 more tasks to send their aggregator data, task ids: [13, 20, 22, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:25,190 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:45,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:05,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:15,192 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:35,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:55,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:05,194 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:25,195 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:45,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:05,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:15,197 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:35,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:55,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:05,199 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:25,200 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:45,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:05,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:15,202 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:35,203 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:55,204 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:15,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:35,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:45,206 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:05,207 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:25,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:45,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:55,209 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:15,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:35,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:45,211 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:05,212 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:19,841 INFO org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window metrics MBytes/sec sent = 0, MBytes/sec received = 0.027, MBytesSent = 0.0006, MBytesReceived = 15.4028, ave sent req MBytes = 0, ave received req MBytes = 0.0034, secs waited = 571.136






Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.

Re: Broadcast of large aggregated value is slow.

Posted by Maja Kabiljo <ma...@fb.com>.
Not all aggregators are assigned to a single worker, but each aggregator is randomly assigned to one of the workers. This way, in case you have enough aggregators, the job of both aggregation and sending values of aggregators is balanced across workers. In your case, it might be that network is the bottleneck, since one aggregator of size S requires that the worker which that aggregator is assigned to sends S*w amount of data. And as Avery suggested, splitting data across several aggregators can help, and it shouldn't be hard for you to try out.

That being said, logs you sent are not showing exactly what I'd expect to happen in this case. Do you maybe have a couple of small aggregators as well?

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Monday, May 27, 2013 10:02 AM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

Im a little confused still I think.  I understand that in the normal use of aggregators one worker is assigned to aggregate all values and then broadcast them out.  But here I am not doing any aggregation at all.  setValue on the aggregator is called exactly once per superstep by exactly one worker (the master compute class).  There is no work to do except to send the value out to all vertices.  A one to all broad cast is all I am looking for.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=plPQC3Ca71jQW2YcL3ZCUyYKZLrgPvFzDwicHcNb1ic%3D%0A&s=dc3e0d75cc49fb39e21992f6b589c5d748e141d225cea2bfe915ed138fdf1f5f> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=plPQC3Ca71jQW2YcL3ZCUyYKZLrgPvFzDwicHcNb1ic%3D%0A&s=d5818827b7fb404dec2d356128c934a677d0030ef55cecdaa8d9ac160963da1b>
Agility. Ingenuity. Integrity.


From: Avery Ching <ac...@apache.org>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Monday, May 27, 2013 9:47 AM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

This kind of use case (massive all to all broadcast of a single aggregator) is not optimized.  A tree-based aggregation implementation would likely improve the performance of this kind of use case.  You're welcome to implement it if you like.

If you could break it up into multiple aggregators, this would be a workaround that would get better performance (as it gets distributed to multiple workers, rather than a single worker).

Avery

On 5/27/13 9:28 AM, Eric Kimbrel wrote:
Are there any recommendations for alternative ways to handle this sort of use case ( mater compute doing a large broadcast to all vertices) or any ideas of whats happening underneath to cause everything to wait?

Any other test cases I can try or data I could gather that may be illuminating?


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=plPQC3Ca71jQW2YcL3ZCUyYKZLrgPvFzDwicHcNb1ic%3D%0A&s=dc3e0d75cc49fb39e21992f6b589c5d748e141d225cea2bfe915ed138fdf1f5f> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=plPQC3Ca71jQW2YcL3ZCUyYKZLrgPvFzDwicHcNb1ic%3D%0A&s=d5818827b7fb404dec2d356128c934a677d0030ef55cecdaa8d9ac160963da1b>
Agility. Ingenuity. Integrity.


From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Tuesday, May 21, 2013 10:43 AM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

I use only one aggregator.  The code for it is extremely simple as it is not actually used as an aggregator at all.  The only use is for the master compute class to set a large object value, and then for each vertex to read that value.  The Size of the Bytes writable is ~ 100M



Heres the code for the aggregator:



publicclass BroadcastAggregator extends BasicAggregator<RowListWritable>{


// no user code ever calls aggregate.

// Master compute class calls setAggregatedValue once per superstep.



// This method is not used, but is provided for flexibility.

//If a non empty value is added it will be added to the current value and then set

@Override

publicvoid aggregate(RowListWritable rw) {

if (rw.index.length == 0) return;

if (this.getAggregatedValue().index.length > 0){

rw.add(this.getAggregatedValue());

}

this.setAggregatedValue(rw);

}


@Override

public RowListWritable createInitialValue() {

returnnew RowListWritable();

}


}



Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=plPQC3Ca71jQW2YcL3ZCUyYKZLrgPvFzDwicHcNb1ic%3D%0A&s=dc3e0d75cc49fb39e21992f6b589c5d748e141d225cea2bfe915ed138fdf1f5f> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=plPQC3Ca71jQW2YcL3ZCUyYKZLrgPvFzDwicHcNb1ic%3D%0A&s=d5818827b7fb404dec2d356128c934a677d0030ef55cecdaa8d9ac160963da1b>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 8:18 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Thanks, Eric. I'm not sure what's going on, it's strange that there are a couple of machines which wait for aggregators for a very long time, but then in exactly same moment they receive them. Can you send us the code for Aggregator which you are using? Do you know approximately how big aggregators are and how many of them do you have?

Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:36 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

My apologies. You are correct, I attached the wrong long.   Correct one attached here.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=JneyqIVoubY0J4ko9BK2DwfsA%2BN6Qy8nBTZj%2BVg78Uw%3D%0A&s=9cf5380dcf55ff5999b2f5b12c9a93b206777c47e775a949e9da6f6a8ce4f173> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=JneyqIVoubY0J4ko9BK2DwfsA%2BN6Qy8nBTZj%2BVg78Uw%3D%0A&s=70d18c70634f46634d557cf4f36276e3e5936b40e403d69a1ac10e3e4e5ff52b>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:25 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Eric,

Can you please check it again, in both logs you attached we are waiting on the worker 13 to send data, so none of those can't be worker 13's log.

Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:15 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

One of the attached logs is worker 13,  During this time period it is waiting for an aggregator request so that it can start the super step.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=b933c5068d68b34f5bfbac0db0f8eb919a01dacd3555330fe3147bbf53399d72> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=f5fe0f489b7bfc207fb44206c50b2f74d0763169d0db18557586da3ce1d83443>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:11 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Eric,

Can you please take a look at the logs of one of the workers listed (13, 34, 38, 50, 48, 52, 58, 56), what are they doing? The fact that a worker is waiting on aggregator can have different causes, it doesn’t necessarily mean that sending aggregators is slow. It can for example mean that some workers finished computing before others and are now waiting for others to finish and send their data.
How big are aggregators which you are using?

Thanks,
Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:00 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

>From the attached logs in original post, you can see that both workers use about 4 seconds of compute time on super step 4, but they complete super step 4 about 10 minutes apart.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.


From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 1:50 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Broadcast of large aggregated value is slow.


I have an giraph job in which the Master will read a chunk of a file from HDFS, and then use an aggregator to broadcast the data to all vertices.  No other messages are sent, and no vertices aggregate values, only the master.

In the attached logs you can see that the time spent to broadcast the data to all vertices is slow, and seems to be hanging up somehwere.  It appears that the majority of workers receive the data in 10-15 seconds, but then nothing happens for around 10 minutes.  Log snippet shown below

Is there a known reason why transmitting this data during the synchronization is taking so long, or anything that can be done to speed it up?


2013-05-16 11:09:03,041 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 30 more tasks to send their aggregator data
2013-05-16 11:09:14,444 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 10 more tasks to send their aggregator data, task ids: [13, 20, 22, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:25,190 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:45,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:05,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:15,192 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:35,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:55,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:05,194 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:25,195 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:45,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:05,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:15,197 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:35,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:55,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:05,199 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:25,200 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:45,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:05,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:15,202 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:35,203 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:55,204 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:15,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:35,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:45,206 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:05,207 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:25,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:45,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:55,209 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:15,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:35,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:45,211 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:05,212 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:19,841 INFO org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window metrics MBytes/sec sent = 0, MBytes/sec received = 0.027, MBytesSent = 0.0006, MBytesReceived = 15.4028, ave sent req MBytes = 0, ave received req MBytes = 0.0034, secs waited = 571.136






Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.

Re: Broadcast of large aggregated value is slow.

Posted by Eric Kimbrel <Er...@soteradefense.com>.
Im a little confused still I think.  I understand that in the normal use of aggregators one worker is assigned to aggregate all values and then broadcast them out.  But here I am not doing any aggregation at all.  setValue on the aggregator is called exactly once per superstep by exactly one worker (the master compute class).  There is no work to do except to send the value out to all vertices.  A one to all broad cast is all I am looking for.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<http://www.potomacfusion.com/> | www.soteradefense.com<http://www.soteradefense.com/>
Agility. Ingenuity. Integrity.


From: Avery Ching <ac...@apache.org>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Monday, May 27, 2013 9:47 AM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

This kind of use case (massive all to all broadcast of a single aggregator) is not optimized.  A tree-based aggregation implementation would likely improve the performance of this kind of use case.  You're welcome to implement it if you like.

If you could break it up into multiple aggregators, this would be a workaround that would get better performance (as it gets distributed to multiple workers, rather than a single worker).

Avery

On 5/27/13 9:28 AM, Eric Kimbrel wrote:
Are there any recommendations for alternative ways to handle this sort of use case ( mater compute doing a large broadcast to all vertices) or any ideas of whats happening underneath to cause everything to wait?

Any other test cases I can try or data I could gather that may be illuminating?


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<http://www.potomacfusion.com/> | www.soteradefense.com<http://www.soteradefense.com/>
Agility. Ingenuity. Integrity.


From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Tuesday, May 21, 2013 10:43 AM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

I use only one aggregator.  The code for it is extremely simple as it is not actually used as an aggregator at all.  The only use is for the master compute class to set a large object value, and then for each vertex to read that value.  The Size of the Bytes writable is ~ 100M



Heres the code for the aggregator:



publicclass BroadcastAggregator extends BasicAggregator<RowListWritable>{


// no user code ever calls aggregate.

// Master compute class calls setAggregatedValue once per superstep.



// This method is not used, but is provided for flexibility.

//If a non empty value is added it will be added to the current value and then set

@Override

publicvoid aggregate(RowListWritable rw) {

if (rw.index.length == 0) return;

if (this.getAggregatedValue().index.length > 0){

rw.add(this.getAggregatedValue());

}

this.setAggregatedValue(rw);

}


@Override

public RowListWritable createInitialValue() {

returnnew RowListWritable();

}


}



Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<http://www.potomacfusion.com/> | www.soteradefense.com<http://www.soteradefense.com/>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 8:18 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Thanks, Eric. I'm not sure what's going on, it's strange that there are a couple of machines which wait for aggregators for a very long time, but then in exactly same moment they receive them. Can you send us the code for Aggregator which you are using? Do you know approximately how big aggregators are and how many of them do you have?

Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:36 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

My apologies. You are correct, I attached the wrong long.   Correct one attached here.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=JneyqIVoubY0J4ko9BK2DwfsA%2BN6Qy8nBTZj%2BVg78Uw%3D%0A&s=9cf5380dcf55ff5999b2f5b12c9a93b206777c47e775a949e9da6f6a8ce4f173> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=JneyqIVoubY0J4ko9BK2DwfsA%2BN6Qy8nBTZj%2BVg78Uw%3D%0A&s=70d18c70634f46634d557cf4f36276e3e5936b40e403d69a1ac10e3e4e5ff52b>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:25 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Eric,

Can you please check it again, in both logs you attached we are waiting on the worker 13 to send data, so none of those can't be worker 13's log.

Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:15 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

One of the attached logs is worker 13,  During this time period it is waiting for an aggregator request so that it can start the super step.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=b933c5068d68b34f5bfbac0db0f8eb919a01dacd3555330fe3147bbf53399d72> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=f5fe0f489b7bfc207fb44206c50b2f74d0763169d0db18557586da3ce1d83443>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:11 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Eric,

Can you please take a look at the logs of one of the workers listed (13, 34, 38, 50, 48, 52, 58, 56), what are they doing? The fact that a worker is waiting on aggregator can have different causes, it doesn’t necessarily mean that sending aggregators is slow. It can for example mean that some workers finished computing before others and are now waiting for others to finish and send their data.
How big are aggregators which you are using?

Thanks,
Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:00 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

>From the attached logs in original post, you can see that both workers use about 4 seconds of compute time on super step 4, but they complete super step 4 about 10 minutes apart.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.


From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 1:50 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Broadcast of large aggregated value is slow.


I have an giraph job in which the Master will read a chunk of a file from HDFS, and then use an aggregator to broadcast the data to all vertices.  No other messages are sent, and no vertices aggregate values, only the master.

In the attached logs you can see that the time spent to broadcast the data to all vertices is slow, and seems to be hanging up somehwere.  It appears that the majority of workers receive the data in 10-15 seconds, but then nothing happens for around 10 minutes.  Log snippet shown below

Is there a known reason why transmitting this data during the synchronization is taking so long, or anything that can be done to speed it up?


2013-05-16 11:09:03,041 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 30 more tasks to send their aggregator data
2013-05-16 11:09:14,444 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 10 more tasks to send their aggregator data, task ids: [13, 20, 22, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:25,190 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:45,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:05,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:15,192 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:35,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:55,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:05,194 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:25,195 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:45,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:05,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:15,197 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:35,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:55,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:05,199 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:25,200 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:45,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:05,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:15,202 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:35,203 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:55,204 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:15,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:35,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:45,206 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:05,207 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:25,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:45,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:55,209 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:15,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:35,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:45,211 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:05,212 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:19,841 INFO org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window metrics MBytes/sec sent = 0, MBytes/sec received = 0.027, MBytesSent = 0.0006, MBytesReceived = 15.4028, ave sent req MBytes = 0, ave received req MBytes = 0.0034, secs waited = 571.136






Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.

Re: Broadcast of large aggregated value is slow.

Posted by Avery Ching <ac...@apache.org>.
This kind of use case (massive all to all broadcast of a single 
aggregator) is not optimized.  A tree-based aggregation implementation 
would likely improve the performance of this kind of use case.  You're 
welcome to implement it if you like.

If you could break it up into multiple aggregators, this would be a 
workaround that would get better performance (as it gets distributed to 
multiple workers, rather than a single worker).

Avery

On 5/27/13 9:28 AM, Eric Kimbrel wrote:
> Are there any recommendations for alternative ways to handle this sort 
> of use case ( mater compute doing a large broadcast to all vertices) 
> or any ideas of whats happening underneath to cause everything to wait?
>
> Any other test cases I can try or data I could gather that may be 
> illuminating?
>
>
> Eric Kimbrel
> Software Engineer***I* Data Fusion & Analytics
>
> *Sotera Defense Solutions, Inc.*
>
> o: 360-516-6621
>
> c: 360-990-1873
>
> e: Eric.Kimbrel@soteradefense.com <ma...@soteradefense.com>
> w: www.potomacfusion.com <http://www.potomacfusion.com/>_ | 
> _www.soteradefense.com <http://www.soteradefense.com/>__
>
> */Agility/**/. /**/Ingenuity/**/. /**/Integrity/**/.
> /*
>
>
>
> From: Eric Kimbrel <Eric.Kimbrel@soteradefense.com 
> <ma...@soteradefense.com>>
> Reply-To: "user@giraph.apache.org <ma...@giraph.apache.org>" 
> <user@giraph.apache.org <ma...@giraph.apache.org>>
> Date: Tuesday, May 21, 2013 10:43 AM
> To: "user@giraph.apache.org <ma...@giraph.apache.org>" 
> <user@giraph.apache.org <ma...@giraph.apache.org>>
> Subject: Re: Broadcast of large aggregated value is slow.
>
> I use only one aggregator.  The code for it is extremely simple as it 
> is not actually used as an aggregator at all.  The only use is for the 
> master compute class to set a large object value, and then for each 
> vertex to read that value.  The Size of the Bytes writable is ~ 100M
>
>
>
> Heres the code for the aggregator:
>
>
> publicclass BroadcastAggregator extends BasicAggregator<RowListWritable>{
>
>
> // no user code ever calls aggregate.
>
> // Master compute class calls setAggregatedValue once per superstep.
>
>
>
> // This method is not used, but is provided for flexibility.
>
> //If a non empty value is added it will be added to the current value 
> and then set
>
> @Override
>
> publicvoid aggregate(RowListWritable rw) {
>
> if (rw.index.length == 0) return;
>
> if (this.getAggregatedValue().index.length > 0){
>
> rw.add(this.getAggregatedValue());
>
> }
>
> this.setAggregatedValue(rw);
>
> }
>
>
> @Override
>
> public RowListWritable createInitialValue() {
>
> returnnew RowListWritable();
>
> }
>
>
> }
>
>
>
>
> Eric Kimbrel
> Software Engineer***I* Data Fusion & Analytics
>
> *Sotera Defense Solutions, Inc.*
>
> o: 360-516-6621
>
> c: 360-990-1873
>
> e: Eric.Kimbrel@soteradefense.com <ma...@soteradefense.com>
> w: www.potomacfusion.com <http://www.potomacfusion.com/>_ | 
> _www.soteradefense.com <http://www.soteradefense.com/>__
>
> */Agility/**/. /**/Ingenuity/**/. /**/Integrity/**/.
> /*
>
>
>
> From: Maja Kabiljo <majakabiljo@fb.com <ma...@fb.com>>
> Reply-To: "user@giraph.apache.org <ma...@giraph.apache.org>" 
> <user@giraph.apache.org <ma...@giraph.apache.org>>
> Date: Thursday, May 16, 2013 8:18 PM
> To: "user@giraph.apache.org <ma...@giraph.apache.org>" 
> <user@giraph.apache.org <ma...@giraph.apache.org>>
> Subject: Re: Broadcast of large aggregated value is slow.
> Resent-From: <eric.kimbrel@soteradefense.com 
> <ma...@soteradefense.com>>
>
> Thanks, Eric. I'm not sure what's going on, it's strange that there 
> are a couple of machines which wait for aggregators for a very long 
> time, but then in exactly same moment they receive them. Can you send 
> us the code for Aggregator which you are using? Do you know 
> approximately how big aggregators are and how many of them do you have?
>
> Maja
>
> From: Eric Kimbrel <Eric.Kimbrel@soteradefense.com 
> <ma...@soteradefense.com>>
> Reply-To: "user@giraph.apache.org <ma...@giraph.apache.org>" 
> <user@giraph.apache.org <ma...@giraph.apache.org>>
> Date: Thursday, May 16, 2013 2:36 PM
> To: "user@giraph.apache.org <ma...@giraph.apache.org>" 
> <user@giraph.apache.org <ma...@giraph.apache.org>>
> Subject: Re: Broadcast of large aggregated value is slow.
>
> My apologies. You are correct, I attached the wrong long.   Correct 
> one attached here.
>
>
> Eric Kimbrel
> Software Engineer***I* Data Fusion & Analytics
>
> *Sotera Defense Solutions, Inc.*
>
> o: 360-516-6621
>
> c: 360-990-1873
>
> e: Eric.Kimbrel@soteradefense.com <ma...@soteradefense.com>
> w: www.potomacfusion.com 
> <https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=JneyqIVoubY0J4ko9BK2DwfsA%2BN6Qy8nBTZj%2BVg78Uw%3D%0A&s=9cf5380dcf55ff5999b2f5b12c9a93b206777c47e775a949e9da6f6a8ce4f173>_ | 
> _www.soteradefense.com 
> <https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=JneyqIVoubY0J4ko9BK2DwfsA%2BN6Qy8nBTZj%2BVg78Uw%3D%0A&s=70d18c70634f46634d557cf4f36276e3e5936b40e403d69a1ac10e3e4e5ff52b>__
>
> */Agility/**/. /**/Ingenuity/**/. /**/Integrity/**/.
> /*
>
>
>
> From: Maja Kabiljo <majakabiljo@fb.com <ma...@fb.com>>
> Reply-To: "user@giraph.apache.org <ma...@giraph.apache.org>" 
> <user@giraph.apache.org <ma...@giraph.apache.org>>
> Date: Thursday, May 16, 2013 2:25 PM
> To: "user@giraph.apache.org <ma...@giraph.apache.org>" 
> <user@giraph.apache.org <ma...@giraph.apache.org>>
> Subject: Re: Broadcast of large aggregated value is slow.
> Resent-From: <eric.kimbrel@soteradefense.com 
> <ma...@soteradefense.com>>
>
> Eric,
>
> Can you please check it again, in both logs you attached we are 
> waiting on the worker 13 to send data, so none of those can't be 
> worker 13's log.
>
> Maja
>
> From: Eric Kimbrel <Eric.Kimbrel@soteradefense.com 
> <ma...@soteradefense.com>>
> Reply-To: "user@giraph.apache.org <ma...@giraph.apache.org>" 
> <user@giraph.apache.org <ma...@giraph.apache.org>>
> Date: Thursday, May 16, 2013 2:15 PM
> To: "user@giraph.apache.org <ma...@giraph.apache.org>" 
> <user@giraph.apache.org <ma...@giraph.apache.org>>
> Subject: Re: Broadcast of large aggregated value is slow.
>
> One of the attached logs is worker 13,  During this time period it is 
> waiting for an aggregator request so that it can start the super step.
>
>
> Eric Kimbrel
> Software Engineer***I* Data Fusion & Analytics
>
> *Sotera Defense Solutions, Inc.*
>
> o: 360-516-6621
>
> c: 360-990-1873
>
> e: Eric.Kimbrel@soteradefense.com <ma...@soteradefense.com>
> w: www.potomacfusion.com 
> <https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=b933c5068d68b34f5bfbac0db0f8eb919a01dacd3555330fe3147bbf53399d72>_ | 
> _www.soteradefense.com 
> <https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=f5fe0f489b7bfc207fb44206c50b2f74d0763169d0db18557586da3ce1d83443>__
>
> */Agility/**/. /**/Ingenuity/**/. /**/Integrity/**/.
> /*
>
>
>
> From: Maja Kabiljo <majakabiljo@fb.com <ma...@fb.com>>
> Reply-To: "user@giraph.apache.org <ma...@giraph.apache.org>" 
> <user@giraph.apache.org <ma...@giraph.apache.org>>
> Date: Thursday, May 16, 2013 2:11 PM
> To: "user@giraph.apache.org <ma...@giraph.apache.org>" 
> <user@giraph.apache.org <ma...@giraph.apache.org>>
> Subject: Re: Broadcast of large aggregated value is slow.
> Resent-From: <eric.kimbrel@soteradefense.com 
> <ma...@soteradefense.com>>
>
> Eric,
>
> Can you please take a look at the logs of one of the workers listed 
> (13, 34, 38, 50, 48, 52, 58, 56), what are they doing? The fact that a 
> worker is waiting on aggregator can have different causes, it doesn’t 
> necessarily mean that sending aggregators is slow. It can for example 
> mean that some workers finished computing before others and are now 
> waiting for others to finish and send their data.
> How big are aggregators which you are using?
>
> Thanks,
> Maja
>
> From: Eric Kimbrel <Eric.Kimbrel@soteradefense.com 
> <ma...@soteradefense.com>>
> Reply-To: "user@giraph.apache.org <ma...@giraph.apache.org>" 
> <user@giraph.apache.org <ma...@giraph.apache.org>>
> Date: Thursday, May 16, 2013 2:00 PM
> To: "user@giraph.apache.org <ma...@giraph.apache.org>" 
> <user@giraph.apache.org <ma...@giraph.apache.org>>
> Subject: Re: Broadcast of large aggregated value is slow.
>
> From the attached logs in original post, you can see that both workers 
> use about 4 seconds of compute time on super step 4, but they complete 
> super step 4 about 10 minutes apart.
>
>
> Eric Kimbrel
> Software Engineer***I* Data Fusion & Analytics
>
> *Sotera Defense Solutions, Inc.*
>
> o: 360-516-6621
>
> c: 360-990-1873
>
> e: Eric.Kimbrel@soteradefense.com <ma...@soteradefense.com>
> w: www.potomacfusion.com 
> <https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c>_ | 
> _www.soteradefense.com 
> <https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>__
>
> */Agility/**/. /**/Ingenuity/**/. /**/Integrity/**/.
> /*
>
>
>
> From: Eric Kimbrel <Eric.Kimbrel@soteradefense.com 
> <ma...@soteradefense.com>>
> Reply-To: "user@giraph.apache.org <ma...@giraph.apache.org>" 
> <user@giraph.apache.org <ma...@giraph.apache.org>>
> Date: Thursday, May 16, 2013 1:50 PM
> To: "user@giraph.apache.org <ma...@giraph.apache.org>" 
> <user@giraph.apache.org <ma...@giraph.apache.org>>
> Subject: Broadcast of large aggregated value is slow.
>
>
> I have an giraph job in which the Master will read a chunk of a file 
> from HDFS, and then use an aggregator to broadcast the data to all 
> vertices.  No other messages are sent, and no vertices aggregate 
> values, only the master.
>
> In the attached logs you can see that the time spent to broadcast the 
> data to all vertices is slow, and seems to be hanging up somehwere. 
>  It appears that the majority of workers receive the data in 10-15 
> seconds, but then nothing happens for around 10 minutes.  Log snippet 
> shown below
>
> Is there a known reason why transmitting this data during the 
> synchronization is taking so long, or anything that can be done to 
> speed it up?
>
> 2013-05-16 11:09:03,041 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 30 more tasks to send their aggregator data
> 2013-05-16 11:09:14,444 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 10 more tasks to send their aggregator data, task ids: [13, 20, 22, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:09:25,190 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:09:45,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:10:05,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:10:15,192 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:10:35,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:10:55,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:11:05,194 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:11:25,195 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:11:45,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:12:05,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:12:15,197 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:12:35,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:12:55,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:13:05,199 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:13:25,200 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:13:45,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:14:05,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:14:15,202 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:14:35,203 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:14:55,204 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:15:15,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:15:35,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:15:45,206 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:16:05,207 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:16:25,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:16:45,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:16:55,209 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:17:15,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:17:35,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:17:45,211 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:18:05,212 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
> 2013-05-16 11:18:19,841 INFO org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window metrics MBytes/sec sent = 0, MBytes/sec received = 0.027, MBytesSent = 0.0006, MBytesReceived = 15.4028, ave sent req MBytes = 0, ave received req MBytes = 0.0034, secs waited = 571.136
>
>
>
>
>
>
> Eric Kimbrel
> Software Engineer***I* Data Fusion & Analytics
>
> *Sotera Defense Solutions, Inc.*
>
> o: 360-516-6621
>
> c: 360-990-1873
>
> e: Eric.Kimbrel@soteradefense.com <ma...@soteradefense.com>
> w: www.potomacfusion.com 
> <https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c>_ | 
> _www.soteradefense.com 
> <https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>__
>
> */Agility/**/. /**/Ingenuity/**/. /**/Integrity/**/.
> /*
>
>

Re: Broadcast of large aggregated value is slow.

Posted by Eric Kimbrel <Er...@soteradefense.com>.
Are there any recommendations for alternative ways to handle this sort of use case ( mater compute doing a large broadcast to all vertices) or any ideas of whats happening underneath to cause everything to wait?

Any other test cases I can try or data I could gather that may be illuminating?


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<http://www.potomacfusion.com/> | www.soteradefense.com<http://www.soteradefense.com/>
Agility. Ingenuity. Integrity.


From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Tuesday, May 21, 2013 10:43 AM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

I use only one aggregator.  The code for it is extremely simple as it is not actually used as an aggregator at all.  The only use is for the master compute class to set a large object value, and then for each vertex to read that value.  The Size of the Bytes writable is ~ 100M



Heres the code for the aggregator:



publicclass BroadcastAggregator extends BasicAggregator<RowListWritable>{


// no user code ever calls aggregate.

// Master compute class calls setAggregatedValue once per superstep.



// This method is not used, but is provided for flexibility.

//If a non empty value is added it will be added to the current value and then set

@Override

publicvoid aggregate(RowListWritable rw) {

if (rw.index.length == 0) return;

if (this.getAggregatedValue().index.length > 0){

rw.add(this.getAggregatedValue());

}

this.setAggregatedValue(rw);

}


@Override

public RowListWritable createInitialValue() {

returnnew RowListWritable();

}


}



Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<http://www.potomacfusion.com/> | www.soteradefense.com<http://www.soteradefense.com/>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 8:18 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Thanks, Eric. I'm not sure what's going on, it's strange that there are a couple of machines which wait for aggregators for a very long time, but then in exactly same moment they receive them. Can you send us the code for Aggregator which you are using? Do you know approximately how big aggregators are and how many of them do you have?

Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:36 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

My apologies. You are correct, I attached the wrong long.   Correct one attached here.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=JneyqIVoubY0J4ko9BK2DwfsA%2BN6Qy8nBTZj%2BVg78Uw%3D%0A&s=9cf5380dcf55ff5999b2f5b12c9a93b206777c47e775a949e9da6f6a8ce4f173> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=JneyqIVoubY0J4ko9BK2DwfsA%2BN6Qy8nBTZj%2BVg78Uw%3D%0A&s=70d18c70634f46634d557cf4f36276e3e5936b40e403d69a1ac10e3e4e5ff52b>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:25 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Eric,

Can you please check it again, in both logs you attached we are waiting on the worker 13 to send data, so none of those can't be worker 13's log.

Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:15 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

One of the attached logs is worker 13,  During this time period it is waiting for an aggregator request so that it can start the super step.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=b933c5068d68b34f5bfbac0db0f8eb919a01dacd3555330fe3147bbf53399d72> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=f5fe0f489b7bfc207fb44206c50b2f74d0763169d0db18557586da3ce1d83443>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:11 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Eric,

Can you please take a look at the logs of one of the workers listed (13, 34, 38, 50, 48, 52, 58, 56), what are they doing? The fact that a worker is waiting on aggregator can have different causes, it doesn’t necessarily mean that sending aggregators is slow. It can for example mean that some workers finished computing before others and are now waiting for others to finish and send their data.
How big are aggregators which you are using?

Thanks,
Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:00 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

>From the attached logs in original post, you can see that both workers use about 4 seconds of compute time on super step 4, but they complete super step 4 about 10 minutes apart.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.


From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 1:50 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Broadcast of large aggregated value is slow.


I have an giraph job in which the Master will read a chunk of a file from HDFS, and then use an aggregator to broadcast the data to all vertices.  No other messages are sent, and no vertices aggregate values, only the master.

In the attached logs you can see that the time spent to broadcast the data to all vertices is slow, and seems to be hanging up somehwere.  It appears that the majority of workers receive the data in 10-15 seconds, but then nothing happens for around 10 minutes.  Log snippet shown below

Is there a known reason why transmitting this data during the synchronization is taking so long, or anything that can be done to speed it up?


2013-05-16 11:09:03,041 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 30 more tasks to send their aggregator data
2013-05-16 11:09:14,444 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 10 more tasks to send their aggregator data, task ids: [13, 20, 22, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:25,190 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:45,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:05,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:15,192 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:35,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:55,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:05,194 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:25,195 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:45,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:05,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:15,197 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:35,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:55,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:05,199 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:25,200 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:45,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:05,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:15,202 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:35,203 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:55,204 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:15,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:35,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:45,206 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:05,207 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:25,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:45,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:55,209 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:15,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:35,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:45,211 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:05,212 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:19,841 INFO org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window metrics MBytes/sec sent = 0, MBytes/sec received = 0.027, MBytesSent = 0.0006, MBytesReceived = 15.4028, ave sent req MBytes = 0, ave received req MBytes = 0.0034, secs waited = 571.136






Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.

Re: Broadcast of large aggregated value is slow.

Posted by Eric Kimbrel <Er...@soteradefense.com>.
I use only one aggregator.  The code for it is extremely simple as it is not actually used as an aggregator at all.  The only use is for the master compute class to set a large object value, and then for each vertex to read that value.  The Size of the Bytes writable is ~ 100M



Heres the code for the aggregator:



public class BroadcastAggregator extends BasicAggregator<RowListWritable>{


// no user code ever calls aggregate.

// Master compute class calls setAggregatedValue once per superstep.



// This method is not used, but is provided for flexibility.

//If a non empty value is added it will be added to the current value and then set

@Override

public void aggregate(RowListWritable rw) {

if (rw.index.length == 0) return;

if (this.getAggregatedValue().index.length > 0){

rw.add(this.getAggregatedValue());

}

this.setAggregatedValue(rw);

}


@Override

public RowListWritable createInitialValue() {

return new RowListWritable();

}


}



Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<http://www.potomacfusion.com/> | www.soteradefense.com<http://www.soteradefense.com/>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 8:18 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Thanks, Eric. I'm not sure what's going on, it's strange that there are a couple of machines which wait for aggregators for a very long time, but then in exactly same moment they receive them. Can you send us the code for Aggregator which you are using? Do you know approximately how big aggregators are and how many of them do you have?

Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:36 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

My apologies. You are correct, I attached the wrong long.   Correct one attached here.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=JneyqIVoubY0J4ko9BK2DwfsA%2BN6Qy8nBTZj%2BVg78Uw%3D%0A&s=9cf5380dcf55ff5999b2f5b12c9a93b206777c47e775a949e9da6f6a8ce4f173> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=JneyqIVoubY0J4ko9BK2DwfsA%2BN6Qy8nBTZj%2BVg78Uw%3D%0A&s=70d18c70634f46634d557cf4f36276e3e5936b40e403d69a1ac10e3e4e5ff52b>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:25 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Eric,

Can you please check it again, in both logs you attached we are waiting on the worker 13 to send data, so none of those can't be worker 13's log.

Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:15 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

One of the attached logs is worker 13,  During this time period it is waiting for an aggregator request so that it can start the super step.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=b933c5068d68b34f5bfbac0db0f8eb919a01dacd3555330fe3147bbf53399d72> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=f5fe0f489b7bfc207fb44206c50b2f74d0763169d0db18557586da3ce1d83443>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:11 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Eric,

Can you please take a look at the logs of one of the workers listed (13, 34, 38, 50, 48, 52, 58, 56), what are they doing? The fact that a worker is waiting on aggregator can have different causes, it doesn’t necessarily mean that sending aggregators is slow. It can for example mean that some workers finished computing before others and are now waiting for others to finish and send their data.
How big are aggregators which you are using?

Thanks,
Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:00 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

>From the attached logs in original post, you can see that both workers use about 4 seconds of compute time on super step 4, but they complete super step 4 about 10 minutes apart.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.


From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 1:50 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Broadcast of large aggregated value is slow.


I have an giraph job in which the Master will read a chunk of a file from HDFS, and then use an aggregator to broadcast the data to all vertices.  No other messages are sent, and no vertices aggregate values, only the master.

In the attached logs you can see that the time spent to broadcast the data to all vertices is slow, and seems to be hanging up somehwere.  It appears that the majority of workers receive the data in 10-15 seconds, but then nothing happens for around 10 minutes.  Log snippet shown below

Is there a known reason why transmitting this data during the synchronization is taking so long, or anything that can be done to speed it up?


2013-05-16 11:09:03,041 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 30 more tasks to send their aggregator data
2013-05-16 11:09:14,444 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 10 more tasks to send their aggregator data, task ids: [13, 20, 22, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:25,190 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:45,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:05,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:15,192 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:35,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:55,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:05,194 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:25,195 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:45,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:05,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:15,197 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:35,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:55,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:05,199 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:25,200 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:45,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:05,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:15,202 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:35,203 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:55,204 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:15,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:35,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:45,206 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:05,207 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:25,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:45,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:55,209 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:15,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:35,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:45,211 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:05,212 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:19,841 INFO org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window metrics MBytes/sec sent = 0, MBytes/sec received = 0.027, MBytesSent = 0.0006, MBytesReceived = 15.4028, ave sent req MBytes = 0, ave received req MBytes = 0.0034, secs waited = 571.136






Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.

Re: Broadcast of large aggregated value is slow.

Posted by Maja Kabiljo <ma...@fb.com>.
Thanks, Eric. I'm not sure what's going on, it's strange that there are a couple of machines which wait for aggregators for a very long time, but then in exactly same moment they receive them. Can you send us the code for Aggregator which you are using? Do you know approximately how big aggregators are and how many of them do you have?

Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:36 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

My apologies. You are correct, I attached the wrong long.   Correct one attached here.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=JneyqIVoubY0J4ko9BK2DwfsA%2BN6Qy8nBTZj%2BVg78Uw%3D%0A&s=9cf5380dcf55ff5999b2f5b12c9a93b206777c47e775a949e9da6f6a8ce4f173> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=JneyqIVoubY0J4ko9BK2DwfsA%2BN6Qy8nBTZj%2BVg78Uw%3D%0A&s=70d18c70634f46634d557cf4f36276e3e5936b40e403d69a1ac10e3e4e5ff52b>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:25 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Eric,

Can you please check it again, in both logs you attached we are waiting on the worker 13 to send data, so none of those can't be worker 13's log.

Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:15 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

One of the attached logs is worker 13,  During this time period it is waiting for an aggregator request so that it can start the super step.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=b933c5068d68b34f5bfbac0db0f8eb919a01dacd3555330fe3147bbf53399d72> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=f5fe0f489b7bfc207fb44206c50b2f74d0763169d0db18557586da3ce1d83443>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:11 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Eric,

Can you please take a look at the logs of one of the workers listed (13, 34, 38, 50, 48, 52, 58, 56), what are they doing? The fact that a worker is waiting on aggregator can have different causes, it doesn’t necessarily mean that sending aggregators is slow. It can for example mean that some workers finished computing before others and are now waiting for others to finish and send their data.
How big are aggregators which you are using?

Thanks,
Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:00 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

>From the attached logs in original post, you can see that both workers use about 4 seconds of compute time on super step 4, but they complete super step 4 about 10 minutes apart.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.


From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 1:50 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Broadcast of large aggregated value is slow.


I have an giraph job in which the Master will read a chunk of a file from HDFS, and then use an aggregator to broadcast the data to all vertices.  No other messages are sent, and no vertices aggregate values, only the master.

In the attached logs you can see that the time spent to broadcast the data to all vertices is slow, and seems to be hanging up somehwere.  It appears that the majority of workers receive the data in 10-15 seconds, but then nothing happens for around 10 minutes.  Log snippet shown below

Is there a known reason why transmitting this data during the synchronization is taking so long, or anything that can be done to speed it up?


2013-05-16 11:09:03,041 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 30 more tasks to send their aggregator data
2013-05-16 11:09:14,444 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 10 more tasks to send their aggregator data, task ids: [13, 20, 22, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:25,190 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:45,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:05,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:15,192 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:35,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:55,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:05,194 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:25,195 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:45,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:05,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:15,197 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:35,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:55,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:05,199 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:25,200 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:45,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:05,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:15,202 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:35,203 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:55,204 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:15,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:35,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:45,206 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:05,207 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:25,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:45,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:55,209 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:15,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:35,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:45,211 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:05,212 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:19,841 INFO org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window metrics MBytes/sec sent = 0, MBytes/sec received = 0.027, MBytesSent = 0.0006, MBytesReceived = 15.4028, ave sent req MBytes = 0, ave received req MBytes = 0.0034, secs waited = 571.136






Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.

Re: Broadcast of large aggregated value is slow.

Posted by Eric Kimbrel <Er...@soteradefense.com>.
My apologies. You are correct, I attached the wrong long.   Correct one attached here.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<http://www.potomacfusion.com/> | www.soteradefense.com<http://www.soteradefense.com/>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:25 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Eric,

Can you please check it again, in both logs you attached we are waiting on the worker 13 to send data, so none of those can't be worker 13's log.

Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:15 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

One of the attached logs is worker 13,  During this time period it is waiting for an aggregator request so that it can start the super step.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=b933c5068d68b34f5bfbac0db0f8eb919a01dacd3555330fe3147bbf53399d72> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=f5fe0f489b7bfc207fb44206c50b2f74d0763169d0db18557586da3ce1d83443>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:11 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Eric,

Can you please take a look at the logs of one of the workers listed (13, 34, 38, 50, 48, 52, 58, 56), what are they doing? The fact that a worker is waiting on aggregator can have different causes, it doesn’t necessarily mean that sending aggregators is slow. It can for example mean that some workers finished computing before others and are now waiting for others to finish and send their data.
How big are aggregators which you are using?

Thanks,
Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:00 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

>From the attached logs in original post, you can see that both workers use about 4 seconds of compute time on super step 4, but they complete super step 4 about 10 minutes apart.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.


From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 1:50 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Broadcast of large aggregated value is slow.


I have an giraph job in which the Master will read a chunk of a file from HDFS, and then use an aggregator to broadcast the data to all vertices.  No other messages are sent, and no vertices aggregate values, only the master.

In the attached logs you can see that the time spent to broadcast the data to all vertices is slow, and seems to be hanging up somehwere.  It appears that the majority of workers receive the data in 10-15 seconds, but then nothing happens for around 10 minutes.  Log snippet shown below

Is there a known reason why transmitting this data during the synchronization is taking so long, or anything that can be done to speed it up?


2013-05-16 11:09:03,041 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 30 more tasks to send their aggregator data
2013-05-16 11:09:14,444 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 10 more tasks to send their aggregator data, task ids: [13, 20, 22, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:25,190 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:45,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:05,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:15,192 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:35,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:55,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:05,194 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:25,195 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:45,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:05,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:15,197 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:35,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:55,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:05,199 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:25,200 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:45,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:05,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:15,202 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:35,203 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:55,204 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:15,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:35,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:45,206 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:05,207 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:25,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:45,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:55,209 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:15,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:35,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:45,211 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:05,212 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:19,841 INFO org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window metrics MBytes/sec sent = 0, MBytes/sec received = 0.027, MBytesSent = 0.0006, MBytesReceived = 15.4028, ave sent req MBytes = 0, ave received req MBytes = 0.0034, secs waited = 571.136






Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.

Re: Broadcast of large aggregated value is slow.

Posted by Maja Kabiljo <ma...@fb.com>.
Eric,

Can you please check it again, in both logs you attached we are waiting on the worker 13 to send data, so none of those can't be worker 13's log.

Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:15 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

One of the attached logs is worker 13,  During this time period it is waiting for an aggregator request so that it can start the super step.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=b933c5068d68b34f5bfbac0db0f8eb919a01dacd3555330fe3147bbf53399d72> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=IVLhuSbQeHVpz2XEdAMnlmA5DbtqWgrwg930PpuMQoQ%3D%0A&s=f5fe0f489b7bfc207fb44206c50b2f74d0763169d0db18557586da3ce1d83443>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:11 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Eric,

Can you please take a look at the logs of one of the workers listed (13, 34, 38, 50, 48, 52, 58, 56), what are they doing? The fact that a worker is waiting on aggregator can have different causes, it doesn’t necessarily mean that sending aggregators is slow. It can for example mean that some workers finished computing before others and are now waiting for others to finish and send their data.
How big are aggregators which you are using?

Thanks,
Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:00 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

>From the attached logs in original post, you can see that both workers use about 4 seconds of compute time on super step 4, but they complete super step 4 about 10 minutes apart.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.


From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 1:50 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Broadcast of large aggregated value is slow.


I have an giraph job in which the Master will read a chunk of a file from HDFS, and then use an aggregator to broadcast the data to all vertices.  No other messages are sent, and no vertices aggregate values, only the master.

In the attached logs you can see that the time spent to broadcast the data to all vertices is slow, and seems to be hanging up somehwere.  It appears that the majority of workers receive the data in 10-15 seconds, but then nothing happens for around 10 minutes.  Log snippet shown below

Is there a known reason why transmitting this data during the synchronization is taking so long, or anything that can be done to speed it up?


2013-05-16 11:09:03,041 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 30 more tasks to send their aggregator data
2013-05-16 11:09:14,444 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 10 more tasks to send their aggregator data, task ids: [13, 20, 22, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:25,190 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:45,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:05,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:15,192 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:35,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:55,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:05,194 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:25,195 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:45,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:05,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:15,197 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:35,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:55,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:05,199 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:25,200 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:45,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:05,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:15,202 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:35,203 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:55,204 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:15,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:35,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:45,206 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:05,207 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:25,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:45,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:55,209 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:15,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:35,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:45,211 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:05,212 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:19,841 INFO org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window metrics MBytes/sec sent = 0, MBytes/sec received = 0.027, MBytesSent = 0.0006, MBytesReceived = 15.4028, ave sent req MBytes = 0, ave received req MBytes = 0.0034, secs waited = 571.136






Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.

Re: Broadcast of large aggregated value is slow.

Posted by Eric Kimbrel <Er...@soteradefense.com>.
One of the attached logs is worker 13,  During this time period it is waiting for an aggregator request so that it can start the super step.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<http://www.potomacfusion.com/> | www.soteradefense.com<http://www.soteradefense.com/>
Agility. Ingenuity. Integrity.


From: Maja Kabiljo <ma...@fb.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:11 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.
Resent-From: <er...@soteradefense.com>>

Eric,

Can you please take a look at the logs of one of the workers listed (13, 34, 38, 50, 48, 52, 58, 56), what are they doing? The fact that a worker is waiting on aggregator can have different causes, it doesn’t necessarily mean that sending aggregators is slow. It can for example mean that some workers finished computing before others and are now waiting for others to finish and send their data.
How big are aggregators which you are using?

Thanks,
Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:00 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

>From the attached logs in original post, you can see that both workers use about 4 seconds of compute time on super step 4, but they complete super step 4 about 10 minutes apart.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.


From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 1:50 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Broadcast of large aggregated value is slow.


I have an giraph job in which the Master will read a chunk of a file from HDFS, and then use an aggregator to broadcast the data to all vertices.  No other messages are sent, and no vertices aggregate values, only the master.

In the attached logs you can see that the time spent to broadcast the data to all vertices is slow, and seems to be hanging up somehwere.  It appears that the majority of workers receive the data in 10-15 seconds, but then nothing happens for around 10 minutes.  Log snippet shown below

Is there a known reason why transmitting this data during the synchronization is taking so long, or anything that can be done to speed it up?


2013-05-16 11:09:03,041 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 30 more tasks to send their aggregator data
2013-05-16 11:09:14,444 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 10 more tasks to send their aggregator data, task ids: [13, 20, 22, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:25,190 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:45,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:05,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:15,192 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:35,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:55,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:05,194 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:25,195 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:45,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:05,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:15,197 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:35,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:55,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:05,199 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:25,200 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:45,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:05,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:15,202 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:35,203 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:55,204 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:15,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:35,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:45,206 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:05,207 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:25,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:45,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:55,209 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:15,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:35,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:45,211 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:05,212 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:19,841 INFO org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window metrics MBytes/sec sent = 0, MBytes/sec received = 0.027, MBytesSent = 0.0006, MBytesReceived = 15.4028, ave sent req MBytes = 0, ave received req MBytes = 0.0034, secs waited = 571.136






Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.

Re: Broadcast of large aggregated value is slow.

Posted by Maja Kabiljo <ma...@fb.com>.
Eric,

Can you please take a look at the logs of one of the workers listed (13, 34, 38, 50, 48, 52, 58, 56), what are they doing? The fact that a worker is waiting on aggregator can have different causes, it doesn’t necessarily mean that sending aggregators is slow. It can for example mean that some workers finished computing before others and are now waiting for others to finish and send their data.
How big are aggregators which you are using?

Thanks,
Maja

From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 2:00 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Re: Broadcast of large aggregated value is slow.

>From the attached logs in original post, you can see that both workers use about 4 seconds of compute time on super step 4, but they complete super step 4 about 10 minutes apart.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.


From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 1:50 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Broadcast of large aggregated value is slow.


I have an giraph job in which the Master will read a chunk of a file from HDFS, and then use an aggregator to broadcast the data to all vertices.  No other messages are sent, and no vertices aggregate values, only the master.

In the attached logs you can see that the time spent to broadcast the data to all vertices is slow, and seems to be hanging up somehwere.  It appears that the majority of workers receive the data in 10-15 seconds, but then nothing happens for around 10 minutes.  Log snippet shown below

Is there a known reason why transmitting this data during the synchronization is taking so long, or anything that can be done to speed it up?


2013-05-16 11:09:03,041 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 30 more tasks to send their aggregator data
2013-05-16 11:09:14,444 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 10 more tasks to send their aggregator data, task ids: [13, 20, 22, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:25,190 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:45,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:05,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:15,192 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:35,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:55,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:05,194 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:25,195 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:45,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:05,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:15,197 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:35,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:55,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:05,199 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:25,200 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:45,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:05,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:15,202 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:35,203 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:55,204 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:15,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:35,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:45,206 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:05,207 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:25,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:45,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:55,209 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:15,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:35,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:45,211 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:05,212 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:19,841 INFO org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window metrics MBytes/sec sent = 0, MBytes/sec received = 0.027, MBytesSent = 0.0006, MBytesReceived = 15.4028, ave sent req MBytes = 0, ave received req MBytes = 0.0034, secs waited = 571.136






Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<https://urldefense.proofpoint.com/v1/url?u=http://www.potomacfusion.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=206a9bd1407d0a4e7cdc6007d5c113baf96438de1c17043e501877ff185a6a3c> | www.soteradefense.com<https://urldefense.proofpoint.com/v1/url?u=http://www.soteradefense.com/&k=ZVNjlDMF0FElm4dQtryO4A%3D%3D%0A&r=RGg8bUFUf%2FM2K95hnYD1RGWK1CQ%2BbcclArMcjzJodKY%3D%0A&m=rMjEN5TrXaS2BX1KqSuqFERFV5ssM40qL4bcaGFCtvE%3D%0A&s=e2806a46969606798541933625edcd907e560f71b173ad03f7eda8fb18ff175a>
Agility. Ingenuity. Integrity.

Re: Broadcast of large aggregated value is slow.

Posted by Eric Kimbrel <Er...@soteradefense.com>.
>From the attached logs in original post, you can see that both workers use about 4 seconds of compute time on super step 4, but they complete super step 4 about 10 minutes apart.


Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<http://www.potomacfusion.com/> | www.soteradefense.com<http://www.soteradefense.com/>
Agility. Ingenuity. Integrity.


From: Eric Kimbrel <Er...@soteradefense.com>>
Reply-To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Date: Thursday, May 16, 2013 1:50 PM
To: "user@giraph.apache.org<ma...@giraph.apache.org>" <us...@giraph.apache.org>>
Subject: Broadcast of large aggregated value is slow.


I have an giraph job in which the Master will read a chunk of a file from HDFS, and then use an aggregator to broadcast the data to all vertices.  No other messages are sent, and no vertices aggregate values, only the master.

In the attached logs you can see that the time spent to broadcast the data to all vertices is slow, and seems to be hanging up somehwere.  It appears that the majority of workers receive the data in 10-15 seconds, but then nothing happens for around 10 minutes.  Log snippet shown below

Is there a known reason why transmitting this data during the synchronization is taking so long, or anything that can be done to speed it up?


2013-05-16 11:09:03,041 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 30 more tasks to send their aggregator data
2013-05-16 11:09:14,444 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 10 more tasks to send their aggregator data, task ids: [13, 20, 22, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:25,190 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:09:45,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:05,191 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:15,192 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:35,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:10:55,193 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:05,194 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:25,195 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:11:45,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:05,196 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:15,197 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:35,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:12:55,198 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:05,199 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:25,200 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:13:45,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:05,201 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:15,202 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:35,203 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:14:55,204 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:15,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:35,205 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:15:45,206 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:05,207 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:25,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:45,208 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:16:55,209 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:15,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:35,210 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:17:45,211 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:05,212 INFO org.apache.giraph.utils.TaskIdsPermitsBarrier: waitForRequiredPermits: Waiting for 8 more tasks to send their aggregator data, task ids: [13, 34, 38, 50, 48, 52, 58, 56]
2013-05-16 11:18:19,841 INFO org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window metrics MBytes/sec sent = 0, MBytes/sec received = 0.027, MBytesSent = 0.0006, MBytesReceived = 15.4028, ave sent req MBytes = 0, ave received req MBytes = 0.0034, secs waited = 571.136






Eric Kimbrel
Software Engineer I Data Fusion & Analytics
Sotera Defense Solutions, Inc.
o: 360-516-6621
c: 360-990-1873
e: Eric.Kimbrel@soteradefense.com<ma...@soteradefense.com>
w: www.potomacfusion.com<http://www.potomacfusion.com/> | www.soteradefense.com<http://www.soteradefense.com/>
Agility. Ingenuity. Integrity.