giraph-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Claudio Martella <claudio.marte...@gmail.com>
Subject Re: more concurrency issues with requests management?
Date Wed, 20 Feb 2013 00:02:51 GMT
good point maja. i haven't changed the parameter yet, but just let the
previous job go.

apparently, at the resend, things get through. we get to superstep 1 and
the problem is there again. i tend to not thing about memory problem, as at
this stage (compute finished, hence flushing) basically all the messages
have been produced, the graph is in memory without mutations, so not much
additional pressure is put on the vm with new allocations (actually the
opposite as messages are flushed, minus the requests/transfert objects
overhead).

(next email has GC flagged output)

here's what happpens:



2013-02-20 00:21:13,353 INFO org.apache.giraph.worker.BspServiceWorker:
startSuperstep: Master(hostname=p-worker49.alley.sara.nl., MRtaskID=0,
port=30000)
2013-02-20 00:21:13,353 INFO org.apache.giraph.worker.BspServiceWorker:
startSuperstep: Ready for computation on superstep 1 since worker selection
and vertex range assignments are done in
/_hadoopBsp/job_201302051647_8364/_applicationAttemptsDir/0/_superstepDir/1/_addressesAndPartitions
2013-02-20 00:21:13,356 INFO org.apache.giraph.comm.netty.NettyClient:
connectAllAddresses: Successfully added 0 connections, (0 total connected)
0 failed, 0 failures total.
2013-02-20 00:21:13,356 INFO org.apache.giraph.comm.SendPartitionCache:
SendPartitionCache: maxVerticesPerTransfer = 10000
2013-02-20 00:21:13,356 INFO org.apache.giraph.comm.SendPartitionCache:
SendPartitionCache: maxEdgesPerTransfer = 80000
2013-02-20 00:21:13,372 INFO org.apache.giraph.comm.netty.NettyClient:
waitAllRequests: Finished all requests. MBytes/sec sent = 0, MBytes/sec
received = 0, MBytesSent = 0, MBytesReceived = 0, ave sent req MBytes = 0,
ave received req MBytes = 0, secs waited = 3.017
2013-02-20 00:21:14,025 INFO org.apache.giraph.worker.BspServiceWorker:
sendWorkerPartitions: Done sending all my partitions.
2013-02-20 00:21:14,081 INFO org.apache.giraph.worker.BspServiceWorker:
exchangeVertexPartitions: Done with exchange.
2013-02-20 00:21:14,081 INFO org.apache.giraph.worker.BspServiceWorker:
processEvent : partitionExchangeChildrenChanged (at least one worker is
done sending partitions)
2013-02-20 00:21:14,114 INFO org.apache.giraph.utils.ExpectedBarrier:
waitForRequiredPermits: Waiting for times required to be 526 (currently 36)
2013-02-20 00:21:15,221 INFO org.apache.giraph.graph.GraphTaskManager:
execute: 94 partitions to process with 1 compute thread(s), originally 1
thread(s) on superstep 1
2013-02-20 00:21:15,222 INFO org.apache.giraph.comm.SendPartitionCache:
SendPartitionCache: maxVerticesPerTransfer = 10000
2013-02-20 00:21:15,222 INFO org.apache.giraph.comm.SendPartitionCache:
SendPartitionCache: maxEdgesPerTransfer = 80000
2013-02-20 00:21:27,008 INFO
org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window
metrics MBytes/sec sent = 0.0003, MBytes/sec received = 0.0142, MBytesSent
= 0.013, MBytesReceived = 0.5811, ave sent req MBytes = 0, ave received req
MBytes = 0.0005, secs waited = 41.046
2013-02-20 00:21:31,479 INFO org.apache.giraph.graph.ComputeCallable: call:
Computation took 16.258244 secs for 94 partitions on superstep 1.  Flushing
started
2013-02-20 00:21:32,355 INFO org.apache.giraph.worker.BspServiceWorker:
finishSuperstep: Waiting on all requests, superstep 1 Memory
(free/total/max) = 4477.91M / 9352.63M / 14346.69M
2013-02-20 00:21:32,356 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 520 open requests,
waiting for it to be <= 0, MBytes/sec sent = 10.7769, MBytes/sec received =
0.0001, MBytesSent = 173.5304, MBytesReceived = 0.0009, ave sent req MBytes
= 0.2946, ave received req MBytes = 0, secs waited = 16.101
2013-02-20 00:21:52,377 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 41 open requests,
waiting for it to be <= 0, MBytes/sec sent = 4.8039, MBytes/sec received =
0.0002, MBytesSent = 173.5304, MBytesReceived = 0.0068, ave sent req MBytes
= 0.2946, ave received req MBytes = 0, secs waited = 36.122
2013-02-20 00:21:59,598 INFO
org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window
metrics MBytes/sec sent = 0.0002, MBytes/sec received = 4.1882, MBytesSent
= 0.0065, MBytesReceived = 136.4978, ave sent req MBytes = 0, ave received
req MBytes = 0.021, secs waited = 32.59
2013-02-20 00:22:08,992 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 36 open requests,
waiting for it to be <= 0, MBytes/sec sent = 3.2904, MBytes/sec received =
0.0001, MBytesSent = 173.5304, MBytesReceived = 0.0069, ave sent req MBytes
= 0.2946, ave received req MBytes = 0, secs waited = 52.737
2013-02-20 00:22:25,948 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 33 open requests,
waiting for it to be <= 0, MBytes/sec sent = 2.4899, MBytes/sec received =
0.0001, MBytesSent = 173.5304, MBytesReceived = 0.0069, ave sent req MBytes
= 0.2946, ave received req MBytes = 0, secs waited = 69.693
2013-02-20 00:22:52,219 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 1.8083, MBytes/sec received =
0.0001, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes
= 0.2946, ave received req MBytes = 0, secs waited = 95.964
2013-02-20 00:23:22,220 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 1.3776, MBytes/sec received =
0.0001, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes
= 0.2946, ave received req MBytes = 0, secs waited = 125.965
2013-02-20 00:23:52,221 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 1.1126, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 155.965
2013-02-20 00:24:07,221 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 1.015, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 170.966
2013-02-20 00:24:37,222 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.8635, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 200.967
2013-02-20 00:25:07,223 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.7513, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 230.967
2013-02-20 00:25:22,223 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.7055, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 245.968
2013-02-20 00:25:52,224 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.6288, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 275.969
2013-02-20 00:26:22,224 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.5671, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 305.969
2013-02-20 00:26:37,225 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.5406, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 320.97
2013-02-20 00:27:07,226 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.4944, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 350.971
2013-02-20 00:27:37,226 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.4555, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 380.971
2013-02-20 00:27:52,227 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.4382, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 395.972
2013-02-20 00:28:22,228 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.4074, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 425.973
2013-02-20 00:28:52,228 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.3806, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 455.973
2013-02-20 00:29:07,229 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.3684, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 470.974
2013-02-20 00:29:37,230 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.3464, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 500.975
2013-02-20 00:29:52,230 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.3363, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 515.975
2013-02-20 00:30:22,231 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.3178, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 545.976
2013-02-20 00:30:52,232 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.3013, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 575.976
2013-02-20 00:31:07,232 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.2936, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 590.977
2013-02-20 00:31:37,233 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.2794, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 620.978
2013-02-20 00:32:07,233 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.2666, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 650.978
2013-02-20 00:32:22,234 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.2606, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 665.979
2013-02-20 00:32:52,235 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.2493, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 695.98
2013-02-20 00:33:07,235 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.2441, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 710.98
2013-02-20 00:33:37,236 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.2342, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 740.981
2013-02-20 00:34:07,236 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.2251, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 770.981
2013-02-20 00:34:22,237 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.2208, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 785.982
2013-02-20 00:34:52,238 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.2127, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 815.983
2013-02-20 00:35:22,238 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.2051, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 845.983
2013-02-20 00:35:37,239 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.2015, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 860.984
2013-02-20 00:36:07,240 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.1948, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 890.985
2013-02-20 00:36:22,240 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.1915, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 905.985
2013-02-20 00:36:52,241 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.1854, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 935.986
2013-02-20 00:37:22,242 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.1796, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 965.987
2013-02-20 00:37:37,242 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.1769, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 980.987
2013-02-20 00:38:07,243 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.1716, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 1010.988
2013-02-20 00:38:37,243 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.1667, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 1040.988
2013-02-20 00:38:52,244 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.1643, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 1055.989
2013-02-20 00:39:22,245 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.1598, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 1085.99
2013-02-20 00:39:37,245 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.1576, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 1100.99
2013-02-20 00:40:07,246 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.1534, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 1130.991
2013-02-20 00:40:37,246 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.1495, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 1160.991
2013-02-20 00:40:52,247 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.1476, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 1175.992
2013-02-20 00:41:22,248 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=142)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1201114, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=142,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1201114123986,started=Thu
Jan 15 14:40:00 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:22,248 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=141)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1201663, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=141,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1201663636064,started=Thu
Jan 15 14:40:00 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:22,248 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=144)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1200172, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=144,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1200172989180,started=Thu
Jan 15 14:40:01 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:22,248 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=143)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1200600, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=143,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1200600050275,started=Thu
Jan 15 14:40:01 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:22,248 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=142,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=321299,started=Thu
Jan 15 15:00:01 CET 1970)
2013-02-20 00:41:22,249 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=141,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=843825,started=Thu
Jan 15 15:00:01 CET 1970)
2013-02-20 00:41:22,249 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=144,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1331721,started=Thu
Jan 15 15:00:01 CET 1970)
2013-02-20 00:41:22,250 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=143,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1804390,started=Thu
Jan 15 15:00:01 CET 1970)
2013-02-20 00:41:22,251 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 26 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.1456, MBytes/sec received =
0, MBytesSent = 175.5338, MBytesReceived = 0.007, ave sent req MBytes =
0.296, ave received req MBytes = 0, secs waited = 1205.996
2013-02-20 00:41:22,417 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 142
2013-02-20 00:41:23,042 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 141
2013-02-20 00:41:23,191 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 144
2013-02-20 00:41:23,345 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 143
2013-02-20 00:41:30,588 INFO
org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window
metrics MBytes/sec sent = 0, MBytes/sec received = 0.0003, MBytesSent = 0,
MBytesReceived = 0.3326, ave sent req MBytes = 0, ave received req MBytes =
0.0158, secs waited = 1170.99
2013-02-20 00:41:38,345 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=149)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1214191, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=149,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1214191850304,started=Thu
Jan 15 14:40:03 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,345 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=147)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1215031, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=147,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1215031132480,started=Thu
Jan 15 14:40:02 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,346 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=155)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1211766, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=155,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1211766017164,started=Thu
Jan 15 14:40:06 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,346 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=152)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1212981, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=152,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1212981461913,started=Thu
Jan 15 14:40:05 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,346 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=165)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1207196, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=165,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1207196540669,started=Thu
Jan 15 14:40:10 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,346 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=145)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1215865, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=145,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1215865165785,started=Thu
Jan 15 14:40:02 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,346 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=154)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1212175, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=154,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1212175408664,started=Thu
Jan 15 14:40:05 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,346 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=159)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1210172, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=159,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1210172453494,started=Thu
Jan 15 14:40:07 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,346 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=158)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1210588, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=158,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1210588860723,started=Thu
Jan 15 14:40:07 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,346 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=162)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1208976, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=162,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1208976756778,started=Thu
Jan 15 14:40:09 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,346 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=166)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1206266, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=166,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1206266030996,started=Thu
Jan 15 14:40:11 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,346 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=150)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1213790, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=150,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1213790815483,started=Thu
Jan 15 14:40:04 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,346 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=164)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1207850, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=164,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1207850775142,started=Thu
Jan 15 14:40:10 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,346 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=146)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1215449, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=146,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1215449508109,started=Thu
Jan 15 14:40:02 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,347 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=161)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1209387, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=161,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1209387452969,started=Thu
Jan 15 14:40:08 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,347 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=163)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1208561, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=163,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1208561568739,started=Thu
Jan 15 14:40:09 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,347 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=157)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1210977, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=157,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1210977725442,started=Thu
Jan 15 14:40:07 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,347 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=156)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1211367, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=156,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1211368011623,started=Thu
Jan 15 14:40:06 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,347 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=151)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1213387, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=151,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1213387720795,started=Thu
Jan 15 14:40:04 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,347 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=148)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1214593, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=148,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1214593618261,started=Thu
Jan 15 14:40:03 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,347 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=153)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1212579, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=153,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1212580004744,started=Thu
Jan 15 14:40:05 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,347 WARN org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Problem with request id (destTask=49,reqId=160)
connected = true, future done = true, success = true, cause = null, elapsed
time = 1209779, destination =
p-worker52.alley.sara.nl./145.100.41.62:30049(reqId=160,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1209779216512,started=Thu
Jan 15 14:40:08 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:41:38,347 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=149,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=1787535,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,348 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=147,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=2249635,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,348 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=155,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=2790270,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,349 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=152,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=3245668,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,349 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=165,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=3592639,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,350 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=145,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=3939589,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,350 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=154,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=4303272,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,351 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=159,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=4684187,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,351 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=158,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=5040917,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,352 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=162,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=5417404,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,352 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=166,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=5805286,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,352 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=150,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=5984959,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,353 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=164,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=6417244,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,353 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=146,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=6844848,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,354 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=161,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=7292149,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,355 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=163,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=7770460,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,355 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=157,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=8288008,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,356 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=156,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=8781125,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,356 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=151,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=9231724,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,357 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=148,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=9724092,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,357 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=153,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=10266335,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,358 INFO org.apache.giraph.comm.netty.NettyClient:
checkRequestsForProblems: Re-issuing request
(reqId=160,destAddr=p-worker52.alley.sara.nl.:30049,elapsedNanos=10865225,started=Thu
Jan 15 15:00:18 CET 1970)
2013-02-20 00:41:38,359 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 22 open requests,
waiting for it to be <= 0, MBytes/sec sent = 0.1524, MBytes/sec received =
0, MBytesSent = 186.2411, MBytesReceived = 0.007, ave sent req MBytes =
0.3028, ave received req MBytes = 0, secs waited = 1222.104
2013-02-20 00:41:38,939 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 149
2013-02-20 00:41:40,417 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 147
2013-02-20 00:41:42,121 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 155
2013-02-20 00:41:42,627 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 152
2013-02-20 00:41:42,737 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 165
2013-02-20 00:41:43,754 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 145
2013-02-20 00:41:44,386 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 154
2013-02-20 00:41:44,995 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 159
2013-02-20 00:41:45,572 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 158
2013-02-20 00:41:46,262 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 162
2013-02-20 00:41:47,239 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 166
2013-02-20 00:41:47,406 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 150
2013-02-20 00:41:47,876 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 164
2013-02-20 00:41:48,054 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 146
2013-02-20 00:41:48,835 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 161
2013-02-20 00:41:50,519 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 163
2013-02-20 00:41:50,894 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 157
2013-02-20 00:41:51,271 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 156
2013-02-20 00:41:51,428 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 151
2013-02-20 00:41:51,596 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 148
2013-02-20 00:41:51,752 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 153
2013-02-20 00:41:52,126 INFO
org.apache.giraph.comm.netty.handler.ResponseClientHandler:
messageReceived: Already completed request 160
2013-02-20 00:41:52,126 INFO org.apache.giraph.comm.netty.NettyClient:
waitAllRequests: Finished all requests. MBytes/sec sent = 0.1507,
MBytes/sec received = 0, MBytesSent = 186.2411, MBytesReceived = 0.0073,
ave sent req MBytes = 0.3028, ave received req MBytes = 0, secs waited =
1235.871
2013-02-20 00:41:52,157 INFO org.apache.giraph.utils.ExpectedBarrier:
waitForRequiredPermits: Waiting for times required to be 526 (currently
174)
2013-02-20 00:42:01,050 INFO
org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window
metrics MBytes/sec sent = 0.0002, MBytes/sec received = 0.0009, MBytesSent
= 0.006, MBytesReceived = 0.0271, ave sent req MBytes = 0, ave received req
MBytes = 0.0001, secs waited = 30.462
2013-02-20 00:42:02,333 INFO org.apache.giraph.utils.ExpectedBarrier:
waitForRequiredPermits: Waiting for times required to be 526 (currently
487)
2013-02-20 00:42:19,405 INFO org.apache.giraph.utils.ExpectedBarrier:
waitForRequiredPermits: Waiting for times required to be 526 (currently
525)
2013-02-20 00:42:21,199 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 1 open requests, waiting
for it to be <= 0, MBytes/sec sent = 0.0238, MBytes/sec received = 0,
MBytesSent = 0, MBytesReceived = 0, ave sent req MBytes = 0, ave received
req MBytes = 0, secs waited = 0.0
2013-02-20 00:42:21,199 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting for request (destTask=0,reqId=2) -
(reqId=2,destAddr=p-worker49.alley.sara.nl.:30000,elapsedNanos=336686,started=Thu
Jan 15 15:01:00 CET 1970,writeDone=true,writeSuccess=true)
2013-02-20 00:42:21,217 INFO org.apache.giraph.comm.netty.NettyClient:
waitAllRequests: Finished all requests. MBytes/sec sent = 0.0013,
MBytes/sec received = 0.0007, MBytesSent = 0, MBytesReceived = 0, ave sent
req MBytes = 0, ave received req MBytes = 0, secs waited = 0.018
2013-02-20 00:42:21,217 INFO org.apache.giraph.worker.BspServiceWorker:
finishSuperstep: Superstep 1, messages = 15141252 Memory (free/total/max) =
6177.96M / 8853.63M / 14346.69M
2013-02-20 00:42:21,342 INFO org.apache.giraph.worker.BspServiceWorker:
finishSuperstep: (waiting for rest of workers) WORKER_ONLY - Attempt=0,
Superstep=1
2013-02-20 00:42:21,794 INFO org.apache.giraph.bsp.BspService: process:
superstepFinished signaled
2013-02-20 00:42:21,843 INFO org.apache.giraph.worker.BspServiceWorker:
finishSuperstep: Completed superstep 1 with global stats
(vtx=1413511394,finVtx=0,edges=8050112169,msgCount=8050112169,haltComputation=false)
2013-02-20 00:42:22,254 INFO org.apache.giraph.worker.BspServiceWorker:
registerHealth: Created my health node for attempt=0, superstep=2 with
/_hadoopBsp/job_201302051647_8364/_applicationAttemptsDir/0/_superstepDir/2/_workerHealthyDir/p-worker47.alley.sara.nl._1
and workerInfo= Worker(hostname=p-worker47.alley.sara.nl., MRtaskID=1,
port=30001)
2013-02-20 00:42:27,279 WARN org.apache.giraph.bsp.BspService: process:
Unknown and unprocessed event
(path=/_hadoopBsp/job_201302051647_8364/_applicationAttemptsDir/0/_superstepDir/0/_addressesAndPartitions,
type=NodeDeleted, state=SyncConnected)
2013-02-20 00:42:32,121 WARN org.apache.giraph.bsp.BspService: process:
Unknown and unprocessed event
(path=/_hadoopBsp/job_201302051647_8364/_applicationAttemptsDir/0/_superstepDir/0/_superstepFinished,
type=NodeDeleted, state=SyncConnected)
2013-02-20 00:42:37,217 INFO org.apache.giraph.bsp.BspService: process:
partitionAssignmentsReadyChanged (partitions are assigned)
2013-02-20 00:42:37,277 INFO
org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window
metrics MBytes/sec sent = 0, MBytes/sec received = 0.0001, MBytesSent =
0.0006, MBytesReceived = 0.0026, ave sent req MBytes = 0, ave received req
MBytes = 0.0001, secs waited = 36.227
2013-02-20 00:42:37,643 INFO org.apache.giraph.worker.BspServiceWorker:
startSuperstep: Master(hostname=p-worker49.alley.sara.nl., MRtaskID=0,
port=30000)
2013-02-20 00:42:37,644 INFO org.apache.giraph.worker.BspServiceWorker:
startSuperstep: Ready for computation on superstep 2 since worker selection
and vertex range assignments are done in
/_hadoopBsp/job_201302051647_8364/_applicationAttemptsDir/0/_superstepDir/2/_addressesAndPartitions
2013-02-20 00:42:37,646 INFO org.apache.giraph.comm.netty.NettyClient:
connectAllAddresses: Successfully added 0 connections, (0 total connected)
0 failed, 0 failures total.
2013-02-20 00:42:37,646 INFO org.apache.giraph.comm.SendPartitionCache:
SendPartitionCache: maxVerticesPerTransfer = 10000
2013-02-20 00:42:37,646 INFO org.apache.giraph.comm.SendPartitionCache:
SendPartitionCache: maxEdgesPerTransfer = 80000
2013-02-20 00:42:37,662 INFO org.apache.giraph.comm.netty.NettyClient:
waitAllRequests: Finished all requests. MBytes/sec sent = 0, MBytes/sec
received = 0, MBytesSent = 0, MBytesReceived = 0, ave sent req MBytes = 0,
ave received req MBytes = 0, secs waited = 16.463
2013-02-20 00:42:38,724 INFO org.apache.giraph.worker.BspServiceWorker:
sendWorkerPartitions: Done sending all my partitions.
2013-02-20 00:42:38,872 INFO org.apache.giraph.worker.BspServiceWorker:
exchangeVertexPartitions: Done with exchange.
2013-02-20 00:42:38,882 INFO org.apache.giraph.worker.BspServiceWorker:
processEvent : partitionExchangeChildrenChanged (at least one worker is
done sending partitions)
2013-02-20 00:42:38,895 INFO org.apache.giraph.utils.ExpectedBarrier:
waitForRequiredPermits: Waiting for times required to be 526 (currently
258)
2013-02-20 00:42:39,035 INFO org.apache.giraph.graph.GraphTaskManager:
execute: 94 partitions to process with 1 compute thread(s), originally 1
thread(s) on superstep 2
2013-02-20 00:42:39,036 INFO org.apache.giraph.comm.SendPartitionCache:
SendPartitionCache: maxVerticesPerTransfer = 10000
2013-02-20 00:42:39,036 INFO org.apache.giraph.comm.SendPartitionCache:
SendPartitionCache: maxEdgesPerTransfer = 80000
2013-02-20 00:43:00,361 INFO org.apache.giraph.graph.ComputeCallable: call:
Computation took 21.326271 secs for 94 partitions on superstep 2.  Flushing
started
2013-02-20 00:43:00,626 INFO org.apache.giraph.worker.BspServiceWorker:
finishSuperstep: Waiting on all requests, superstep 2 Memory
(free/total/max) = 6623.93M / 9103.13M / 14346.69M
2013-02-20 00:43:00,626 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 557 open requests,
waiting for it to be <= 0, MBytes/sec sent = 8.3168, MBytes/sec received =
0, MBytesSent = 173.5304, MBytesReceived = 0.0004, ave sent req MBytes =
0.2946, ave received req MBytes = 0, secs waited = 20.864
2013-02-20 00:43:07,443 INFO
org.apache.giraph.comm.netty.handler.RequestDecoder: decode: Server window
metrics MBytes/sec sent = 0.0004, MBytes/sec received = 4.5005, MBytesSent
= 0.013, MBytesReceived = 135.7663, ave sent req MBytes = 0, ave received
req MBytes = 0.0151, secs waited = 30.166
2013-02-20 00:43:18,585 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 41 open requests,
waiting for it to be <= 0, MBytes/sec sent = 4.4697, MBytes/sec received =
0.0002, MBytesSent = 173.5304, MBytesReceived = 0.0068, ave sent req MBytes
= 0.2946, ave received req MBytes = 0, secs waited = 38.823
2013-02-20 00:43:40,745 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 32 open requests,
waiting for it to be <= 0, MBytes/sec sent = 2.8455, MBytes/sec received =
0.0001, MBytesSent = 173.5304, MBytesReceived = 0.0069, ave sent req MBytes
= 0.2946, ave received req MBytes = 0, secs waited = 60.983
2013-02-20 00:44:04,375 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 25 open requests,
waiting for it to be <= 0, MBytes/sec sent = 2.0508, MBytes/sec received =
0.0001, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes
= 0.2946, ave received req MBytes = 0, secs waited = 84.613
2013-02-20 00:44:34,375 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 25 open requests,
waiting for it to be <= 0, MBytes/sec sent = 1.514, MBytes/sec received =
0.0001, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes
= 0.2946, ave received req MBytes = 0, secs waited = 114.613
2013-02-20 00:44:49,376 INFO org.apache.giraph.comm.netty.NettyClient:
waitSomeRequests: Waiting interval of 15000 msecs, 25 open requests,
waiting for it to be <= 0, MBytes/sec sent = 1.3388, MBytes/sec received =
0.0001, MBytesSent = 173.5304, MBytesReceived = 0.007, ave sent req MBytes
= 0.2946, ave received req MBytes = 0, secs waited = 129.614




On Wed, Feb 20, 2013 at 12:24 AM, Maja Kabiljo <majakabiljo@fb.com> wrote:

> Also you can try decreasing giraph.maxRequestMilliseconds and see what
> happens when requests get resent. If you have a problem on the worker they
> won't arrive again, if it is some concurrency issue then they should
> arrive on second try.
>
> On 2/19/13 3:18 PM, "Avery Ching" <aching@apache.org> wrote:
>
> >Try these to start:
> >
> >-XX:+PrintGC -XX:+PrintGCDateStamps -XX:+PrintGCDetails
> >-XX:+PrintGCTimeStamps -verbose:gc
> >
> >On 2/19/13 3:04 PM, Claudio Martella wrote:
> >> Looking at the second line of the logs, it does not look like the case,
> >>but
> >> it could be. do you have any suggestion for the flags in particular? I'm
> >> running with -XX:+HeapDumpOnOutOfMemoryError  now, and I don't get any
> >>dump.
> >>
> >> It could be the case, but the behavior is quite consistent currently,
> >>I'd
> >> get a Child error/OOM pretty soon in these cases.
> >>
> >>
> >> On Tue, Feb 19, 2013 at 11:45 PM, Avery Ching <aching@apache.org>
> wrote:
> >>
> >>> Can you add GC flags?  Perhaps you are running into full GCs...
> >>>
> >>>
> >>> On 2/19/13 1:45 PM, Claudio Martella wrote:
> >>>
> >>>> I have not investigated further yet, but this does not look connected
> >>>>to
> >>>> ZK, but mostly to some concurrency on the queues. The number of
> >>>>requests
> >>>> stays to 29...
> >>>>
> >>>>
> >>>> On Tue, Feb 19, 2013 at 9:58 PM, Sebastian Schelter <ssc@apache.org>
> >>>> wrote:
> >>>>
> >>>>   For me, Giraph on Hadoop 1.0.4 runs into some kind of deadlock
> >>>>after the
> >>>>> input was loaded when using it with 200 workers on a billion-scale
> >>>>> graph....
> >>>>>
> >>>>> I tried several versions of zookeeper, but nothing helped.
> >>>>>
> >>>>> Best,
> >>>>> Sebastian
> >>>>>
> >>>>>
> >>>>> On 19.02.2013 21:55, Claudio Martella wrote:
> >>>>>
> >>>>>> I'm running PR with trunk on yahoo webgraph across 528 workers and
> >>>>>>I get
> >>>>>> the workers hanging at the flushing:
> >>>>>>
> >>>>>> 2013-02-19 21:40:07,187 INFO
> >>>>>>org.apache.giraph.graph.**ComputeCallable:
> >>>>>>
> >>>>> call:
> >>>>>
> >>>>>> Computation took 28.386961 secs for 95 partitions on superstep 0.
> >>>>>>
> >>>>>    Flushing
> >>>>>
> >>>>>> started
> >>>>>> 2013-02-19 21:40:07,604 INFO org.apache.giraph.worker.**
> >>>>>> BspServiceWorker:
> >>>>>> finishSuperstep: Waiting on all requests, superstep 0 Memory
> >>>>>> (free/total/max) = 5993.42M / 8661.44M / 14346.69M
> >>>>>> 2013-02-19 21:40:07,605 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 558 open
> >>>>>>requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 6.4758, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0003, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 27.083
> >>>>>> 2013-02-19 21:40:26,717 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 39 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 3.7965, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0.0001, MBytesSent = 175.3834, MBytesReceived = 0.0068, ave sent req
> >>>>>>
> >>>>> MBytes
> >>>>>
> >>>>>> = 0.2998, ave received req MBytes = 0, secs waited = 46.195
> >>>>>> 2013-02-19 21:40:32,248 INFO
> >>>>>> org.apache.giraph.comm.netty.**handler.RequestDecoder: decode:
> >>>>>>Server
> >>>>>>
> >>>>> window
> >>>>>
> >>>>>> metrics MBytes/sec sent = 0.0002, MBytes/sec received = 3.9824,
> >>>>>>
> >>>>> MBytesSent
> >>>>>
> >>>>>> = 0.0066, MBytesReceived = 155.4787, ave sent req MBytes = 0, ave
> >>>>>>
> >>>>> received
> >>>>>
> >>>>>> req MBytes = 0.0155, secs waited = 39.04
> >>>>>> 2013-02-19 21:40:42,041 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 36 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 2.8509, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0.0001, MBytesSent = 175.3834, MBytesReceived = 0.0068, ave sent req
> >>>>>>
> >>>>> MBytes
> >>>>>
> >>>>>> = 0.2998, ave received req MBytes = 0, secs waited = 61.519
> >>>>>> 2013-02-19 21:41:07,456 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 2.0174, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0.0001, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>
> >>>>> MBytes
> >>>>>
> >>>>>> = 0.2998, ave received req MBytes = 0, secs waited = 86.933
> >>>>>> 2013-02-19 21:41:22,456 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 1.7205, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0.0001, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>
> >>>>> MBytes
> >>>>>
> >>>>>> = 0.2998, ave received req MBytes = 0, secs waited = 101.934
> >>>>>> 2013-02-19 21:41:37,457 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 1.4998, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0.0001, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>
> >>>>> MBytes
> >>>>>
> >>>>>> = 0.2998, ave received req MBytes = 0, secs waited = 116.935
> >>>>>> 2013-02-19 21:41:52,458 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 1.3293, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0.0001, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>
> >>>>> MBytes
> >>>>>
> >>>>>> = 0.2998, ave received req MBytes = 0, secs waited = 131.936
> >>>>>> 2013-02-19 21:42:22,459 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 1.083, MBytes/sec
> >>>>>>received
> >>>>>> =
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 161.937
> >>>>>> 2013-02-19 21:42:37,460 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.9912, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 176.938
> >>>>>> 2013-02-19 21:43:07,461 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.8475, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 206.939
> >>>>>> 2013-02-19 21:43:37,462 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.7402, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 236.94
> >>>>>> 2013-02-19 21:43:52,463 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.6961, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 251.941
> >>>>>> 2013-02-19 21:44:07,464 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.657, MBytes/sec
> >>>>>>received
> >>>>>> =
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 266.942
> >>>>>> 2013-02-19 21:44:37,465 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.5906, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 296.943
> >>>>>> 2013-02-19 21:45:07,466 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.5364, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 326.944
> >>>>>> 2013-02-19 21:45:22,467 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.5129, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 341.945
> >>>>>> 2013-02-19 21:45:37,468 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.4913, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 356.946
> >>>>>> 2013-02-19 21:46:07,469 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.4532, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 386.947
> >>>>>> 2013-02-19 21:46:22,470 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.4363, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 401.948
> >>>>>> 2013-02-19 21:46:52,471 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.406, MBytes/sec
> >>>>>>received
> >>>>>> =
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 431.949
> >>>>>> 2013-02-19 21:47:07,472 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.3924, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 446.95
> >>>>>> 2013-02-19 21:47:37,473 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.3677, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 476.951
> >>>>>> 2013-02-19 21:48:07,474 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.346, MBytes/sec
> >>>>>>received
> >>>>>> =
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 506.952
> >>>>>> 2013-02-19 21:48:22,475 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.336, MBytes/sec
> >>>>>>received
> >>>>>> =
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 521.953
> >>>>>> 2013-02-19 21:48:52,476 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.3177, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 551.954
> >>>>>> 2013-02-19 21:49:07,477 INFO org.apache.giraph.comm.netty.**
> >>>>>> NettyClient:
> >>>>>> waitSomeRequests: Waiting interval of 15000 msecs, 29 open requests,
> >>>>>> waiting for it to be <= 0, MBytes/sec sent = 0.3093, MBytes/sec
> >>>>>>received
> >>>>>>
> >>>>> =
> >>>>>
> >>>>>> 0, MBytesSent = 175.3834, MBytesReceived = 0.0069, ave sent req
> >>>>>>MBytes =
> >>>>>> 0.2998, ave received req MBytes = 0, secs waited = 566.955
> >>>>>>
> >>>>>> It looks similar to the problem we had earlier with concurrency.
> >>>>>>
> >>>>>> Are you guys experiencing something similar at large-scale?
> >>>>>>
> >>>>>>
> >>
> >
>
>


-- 
   Claudio Martella
   claudio.martella@gmail.com

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message