Skip to content

Instantly share code, notes, and snippets.

@kilburn
Created May 22, 2014 05:49
Show Gist options
  • Save kilburn/57161dbfb828988eb4c4 to your computer and use it in GitHub Desktop.
Save kilburn/57161dbfb828988eb4c4 to your computer and use it in GitHub Desktop.
Task Logs: 'attempt_201405212016_0002_m_000002_0'
stdout logs
org.apache.giraph.comm.netty.NettyServer - NettyServer: Using execution group with 8 threads for requestFrameDecoder.
org.apache.giraph.comm.netty.NettyServer - start: Started server communication server: master/192.168.50.4:30002 with up to 16 threads on bind attempt 0 with sendBufferSize = 32768 receiveBufferSize = 524288
org.apache.giraph.comm.netty.NettyClient - NettyClient: Using execution handler with 8 threads after request-encoder.
org.apache.giraph.comm.netty.NettyServer - start: Using Netty without authentication.
org.apache.giraph.comm.netty.handler.RequestServerHandler - channelActive: Connected the channel on /192.168.50.5:53267
org.apache.giraph.comm.netty.NettyClient - Using Netty without authentication.
org.apache.giraph.comm.netty.NettyClient - Using Netty without authentication.
org.apache.giraph.comm.netty.NettyClient - connectAllAddresses: Connected to slave2/192.168.50.6:30001, open = true
org.apache.giraph.comm.netty.NettyClient - connectAllAddresses: Connected to slave1/192.168.50.5:30000, open = true
org.apache.giraph.comm.netty.NettyClient - connectAllAddresses: Successfully added 2 connections, (2 total connected) 0 failed, 0 failures total.
org.apache.giraph.comm.netty.NettyServer - start: Using Netty without authentication.
org.apache.giraph.comm.netty.handler.RequestServerHandler - channelActive: Connected the channel on /192.168.50.6:50028
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0xbc5ac3c6, /192.168.50.5:53267 => /192.168.50.4:30002] buffer size = 105, total bytes = 105
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Server window metrics MBytes/sec received = 0, MBytesReceived = 0.0001, ave received req MBytes = 0.0001, secs waited = 1.40070374E9
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client -1, requestId 0, SEND_AGGREGATORS_TO_OWNER_REQUEST, with size 101 took 3261132 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendAggregatorsToOwnerRequest
org.apache.giraph.comm.aggregators.AllAggregatorServerData - getDataFromMasterWhenReady: Aggregator data for distribution ready
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client -1, requestId 0, SEND_AGGREGATORS_TO_OWNER_REQUEST took 2151797 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0xbc5ac3c6, /192.168.50.5:53267 => /192.168.50.4:30002] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 2, requestId 0, size = 105, SEND_AGGREGATORS_TO_WORKER_REQUEST took 790686 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 105, total bytes = 105
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 1)(reqId=0,destAddr=slave2:30001,elapsedNanos=38949342,started=Thu Jan 01 09:03:19 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x876c33e7, /192.168.50.6:50028 => /192.168.50.4:30002] buffer size = 170, total bytes = 170
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 1, requestId 0, SEND_AGGREGATORS_TO_WORKER_REQUEST, with size 166 took 149715 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendAggregatorsToWorkerRequest
org.apache.giraph.comm.aggregators.AllAggregatorServerData - fillNextSuperstepMapsWhenReady: Aggregators ready
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 1, requestId 0, SEND_AGGREGATORS_TO_WORKER_REQUEST took 40824634 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x876c33e7, /192.168.50.6:50028 => /192.168.50.4:30002] buffer size = 13, total bytes = 26
org.apache.giraph.comm.aggregators.AllAggregatorServerData - reset: Ready for next superstep
ml.grafos.okapi.clustering.ap.APEdgeInputFormatter - Read edge from (ROW, 1) to (COLUMN, 1) value 1.0.
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 900794733
org.apache.giraph.comm.netty.NettyWorkerClientRequestProcessor - sendEdgeRequest: Send bytes ((targetVertexId = (COLUMN, 1), value = 1.0)) to (ROW, 1) on worker Worker(hostname=slave2, MRtaskID=1, port=30001)
ml.grafos.okapi.clustering.ap.APEdgeInputFormatter - Read edge from (ROW, 1) to (COLUMN, 2) value 1.0.
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 900794733
org.apache.giraph.comm.netty.NettyWorkerClientRequestProcessor - sendEdgeRequest: Send bytes ((targetVertexId = (COLUMN, 2), value = 1.0)) to (ROW, 1) on worker Worker(hostname=slave2, MRtaskID=1, port=30001)
ml.grafos.okapi.clustering.ap.APEdgeInputFormatter - Read edge from (ROW, 1) to (COLUMN, 3) value 5.0.
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 900794733
org.apache.giraph.comm.netty.NettyWorkerClientRequestProcessor - sendEdgeRequest: Send bytes ((targetVertexId = (COLUMN, 3), value = 5.0)) to (ROW, 1) on worker Worker(hostname=slave2, MRtaskID=1, port=30001)
ml.grafos.okapi.clustering.ap.APEdgeInputFormatter - Read edge from (ROW, 2) to (COLUMN, 1) value 1.0.
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
org.apache.giraph.comm.netty.NettyWorkerClientRequestProcessor - sendEdgeRequest: Send bytes ((targetVertexId = (COLUMN, 1), value = 1.0)) to (ROW, 2) on worker Worker(hostname=master, MRtaskID=2, port=30002)
ml.grafos.okapi.clustering.ap.APEdgeInputFormatter - Read edge from (ROW, 2) to (COLUMN, 2) value 1.0.
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
org.apache.giraph.comm.netty.NettyWorkerClientRequestProcessor - sendEdgeRequest: Send bytes ((targetVertexId = (COLUMN, 2), value = 1.0)) to (ROW, 2) on worker Worker(hostname=master, MRtaskID=2, port=30002)
ml.grafos.okapi.clustering.ap.APEdgeInputFormatter - Read edge from (ROW, 2) to (COLUMN, 3) value 3.0.
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
org.apache.giraph.comm.netty.NettyWorkerClientRequestProcessor - sendEdgeRequest: Send bytes ((targetVertexId = (COLUMN, 3), value = 3.0)) to (ROW, 2) on worker Worker(hostname=master, MRtaskID=2, port=30002)
ml.grafos.okapi.clustering.ap.APEdgeInputFormatter - Read edge from (ROW, 3) to (COLUMN, 1) value 4.0.
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 900794735
org.apache.giraph.comm.netty.NettyWorkerClientRequestProcessor - sendEdgeRequest: Send bytes ((targetVertexId = (COLUMN, 1), value = 4.0)) to (ROW, 3) on worker Worker(hostname=slave2, MRtaskID=1, port=30001)
ml.grafos.okapi.clustering.ap.APEdgeInputFormatter - Read edge from (ROW, 3) to (COLUMN, 2) value 3.0.
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 900794735
org.apache.giraph.comm.netty.NettyWorkerClientRequestProcessor - sendEdgeRequest: Send bytes ((targetVertexId = (COLUMN, 2), value = 3.0)) to (ROW, 3) on worker Worker(hostname=slave2, MRtaskID=1, port=30001)
ml.grafos.okapi.clustering.ap.APEdgeInputFormatter - Read edge from (ROW, 3) to (COLUMN, 3) value 1.0.
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 900794735
org.apache.giraph.comm.netty.NettyWorkerClientRequestProcessor - sendEdgeRequest: Send bytes ((targetVertexId = (COLUMN, 3), value = 1.0)) to (ROW, 3) on worker Worker(hostname=slave2, MRtaskID=1, port=30001)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 2, requestId 1, size = 229, SEND_WORKER_EDGES_REQUEST took 98703 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 229, total bytes = 229
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 1)(reqId=1,destAddr=slave2:30001,elapsedNanos=86718436,started=Thu Jan 01 09:03:20 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0.0001, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.088
MBytes/sec sent = 0.0025, MBytesSent = 0.0002, ave sent req MBytes = 0.0002, secs waited = 0.088
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0.0001, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.176
MBytes/sec sent = 0.0012, MBytesSent = 0.0002, ave sent req MBytes = 0.0002, secs waited = 0.176
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 2, requestId 2, size = 78, SEND_WORKER_AGGREGATORS_REQUEST took 47019 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 78, total bytes = 78
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 1)(reqId=2,destAddr=slave2:30001,elapsedNanos=2424888,started=Thu Jan 01 09:03:20 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x876c33e7, /192.168.50.6:50028 => /192.168.50.4:30002] buffer size = 63, total bytes = 233
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 1, requestId 1, SEND_WORKER_AGGREGATORS_REQUEST, with size 59 took 118769 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendWorkerAggregatorsRequest
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 1, requestId 1, SEND_WORKER_AGGREGATORS_REQUEST took 94581 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x876c33e7, /192.168.50.6:50028 => /192.168.50.4:30002] buffer size = 13, total bytes = 39
org.apache.giraph.comm.aggregators.OwnerAggregatorServerData - getMyAggregatorValuesWhenReady: Values ready
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 2, requestId 0, size = 25, SEND_AGGREGATORS_TO_MASTER_REQUEST took 55127 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x6129d2e1, /192.168.50.4:58823 => slave1/192.168.50.5:30000] buffer size = 25, total bytes = 25
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x6129d2e1, /192.168.50.4:58823 => slave1/192.168.50.5:30000] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = -1)(reqId=0,destAddr=slave1:30000,elapsedNanos=45647579,started=Thu Jan 01 09:03:20 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0.0003, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.048
MBytes/sec sent = 0.0005, MBytesSent = 0, ave sent req MBytes = 0, secs waited = 0.048
org.apache.giraph.comm.aggregators.OwnerAggregatorServerData - reset: Ready for next superstep
org.apache.giraph.comm.messages.InMemoryMessageStoreFactory - newStore: Created class org.apache.giraph.comm.messages.ByteArrayMessagesPerVertexStore for vertex id class ml.grafos.okapi.clustering.ap.APVertexID and message value class ml.grafos.okapi.clustering.ap.APMessage and no combiner
org.apache.giraph.comm.messages.InMemoryMessageStoreFactory - newStore: Created class org.apache.giraph.comm.messages.ByteArrayMessagesPerVertexStore for vertex id class ml.grafos.okapi.clustering.ap.APVertexID and message value class ml.grafos.okapi.clustering.ap.APMessage and no combiner
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0xbc5ac3c6, /192.168.50.5:53267 => /192.168.50.4:30002] buffer size = 105, total bytes = 338
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client -1, requestId 1, SEND_AGGREGATORS_TO_OWNER_REQUEST, with size 101 took 80046 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendAggregatorsToOwnerRequest
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client -1, requestId 1, SEND_AGGREGATORS_TO_OWNER_REQUEST took 47782 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0xbc5ac3c6, /192.168.50.5:53267 => /192.168.50.4:30002] buffer size = 13, total bytes = 52
org.apache.giraph.comm.netty.NettyClient - connectAllAddresses: Successfully added 0 connections, (0 total connected) 0 failed, 0 failures total.
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.503
MBytes/sec sent = 0, MBytesSent = 0, ave sent req MBytes = 0, secs waited = 0.504
org.apache.giraph.comm.aggregators.AllAggregatorServerData - getDataFromMasterWhenReady: Aggregator data for distribution ready
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 2, requestId 3, size = 105, SEND_AGGREGATORS_TO_WORKER_REQUEST took 52761 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 105, total bytes = 105
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 1)(reqId=3,destAddr=slave2:30001,elapsedNanos=1956222,started=Thu Jan 01 09:03:21 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x876c33e7, /192.168.50.6:50028 => /192.168.50.4:30002] buffer size = 170, total bytes = 508
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 1, requestId 2, SEND_AGGREGATORS_TO_WORKER_REQUEST, with size 166 took 71996 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendAggregatorsToWorkerRequest
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 1, requestId 2, SEND_AGGREGATORS_TO_WORKER_REQUEST took 110035 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x876c33e7, /192.168.50.6:50028 => /192.168.50.4:30002] buffer size = 13, total bytes = 65
org.apache.giraph.comm.aggregators.AllAggregatorServerData - fillNextSuperstepMapsWhenReady: Aggregators ready
org.apache.giraph.comm.aggregators.AllAggregatorServerData - reset: Ready for next superstep
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - vertex (ROW, 2), superstep 0
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): -1363588386
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): -1363588386
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): -1363588386
org.apache.giraph.comm.SendMessageCache - sendMessageRequest: Send bytes (APMessage{from=(ROW, 2), value=0.0}) to (COLUMN, 1) on worker Worker(hostname=master, MRtaskID=2, port=30002)
ml.grafos.okapi.clustering.ap.AffinityPropagation - Sending init message from (ROW, 2) to (COLUMN, 1)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): -1363588385
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): -1363588385
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): -1363588385
org.apache.giraph.comm.SendMessageCache - sendMessageRequest: Send bytes (APMessage{from=(ROW, 2), value=0.0}) to (COLUMN, 2) on worker Worker(hostname=slave2, MRtaskID=1, port=30001)
ml.grafos.okapi.clustering.ap.AffinityPropagation - Sending init message from (ROW, 2) to (COLUMN, 2)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
org.apache.giraph.comm.SendMessageCache - sendMessageRequest: Send bytes (APMessage{from=(ROW, 2), value=0.0}) to (COLUMN, 3) on worker Worker(hostname=master, MRtaskID=2, port=30002)
ml.grafos.okapi.clustering.ap.AffinityPropagation - Sending init message from (ROW, 2) to (COLUMN, 3)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): -1363588386
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): -1363588386
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 2, requestId 4, size = 62, SEND_WORKER_MESSAGES_REQUEST took 63278 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 62, total bytes = 62
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x876c33e7, /192.168.50.6:50028 => /192.168.50.4:30002] buffer size = 94, total bytes = 602
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 1, requestId 3, SEND_WORKER_MESSAGES_REQUEST, with size 90 took 200031 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendWorkerMessagesRequest
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): -1363588385
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): -1363588385
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): -1363588385
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 1, requestId 3, SEND_WORKER_MESSAGES_REQUEST took 228821 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x876c33e7, /192.168.50.6:50028 => /192.168.50.4:30002] buffer size = 13, total bytes = 78
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 1)(reqId=4,destAddr=slave2:30001,elapsedNanos=77258967,started=Thu Jan 01 09:03:21 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x876c33e7, /192.168.50.6:50028 => /192.168.50.4:30002] buffer size = 63, total bytes = 665
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0.0002, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.078
MBytes/sec sent = 0.0007, MBytesSent = 0.0001, ave sent req MBytes = 0.0001, secs waited = 0.078
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 2, requestId 5, size = 78, SEND_WORKER_AGGREGATORS_REQUEST took 38057 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 78, total bytes = 78
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 1, requestId 4, SEND_WORKER_AGGREGATORS_REQUEST, with size 59 took 70966 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendWorkerAggregatorsRequest
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 1, requestId 4, SEND_WORKER_AGGREGATORS_REQUEST took 47091 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x876c33e7, /192.168.50.6:50028 => /192.168.50.4:30002] buffer size = 13, total bytes = 91
org.apache.giraph.comm.aggregators.OwnerAggregatorServerData - getMyAggregatorValuesWhenReady: Values ready
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 2, requestId 1, size = 25, SEND_AGGREGATORS_TO_MASTER_REQUEST took 19976 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x6129d2e1, /192.168.50.4:58823 => slave1/192.168.50.5:30000] buffer size = 25, total bytes = 103
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x6129d2e1, /192.168.50.4:58823 => slave1/192.168.50.5:30000] buffer size = 13, total bytes = 26
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = -1)(reqId=1,destAddr=slave1:30000,elapsedNanos=2041893,started=Thu Jan 01 09:03:21 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 1 requests
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 1)(reqId=5,destAddr=slave2:30001,elapsedNanos=3967863,started=Thu Jan 01 09:03:21 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0.0041, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.005
MBytes/sec sent = 0.0164, MBytesSent = 0.0001, ave sent req MBytes = 0, secs waited = 0.005
org.apache.giraph.comm.aggregators.OwnerAggregatorServerData - reset: Ready for next superstep
org.apache.giraph.comm.messages.InMemoryMessageStoreFactory - newStore: Created class org.apache.giraph.comm.messages.ByteArrayMessagesPerVertexStore for vertex id class ml.grafos.okapi.clustering.ap.APVertexID and message value class ml.grafos.okapi.clustering.ap.APMessage and no combiner
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): -1363588385
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): -1363588385
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): -1363588386
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): -1363588386
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): -1363588385
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): -1363588385
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): -1363588385
org.apache.giraph.comm.netty.NettyWorkerServer - resolveMutations: Resolved vertex index (COLUMN, 2) with original vertex null, returned vertex null on superstep 1 with mutations null
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
org.apache.giraph.comm.netty.NettyWorkerServer - resolveMutations: Resolved vertex index (COLUMN, 3) with original vertex null, returned vertex Vertex(id=(COLUMN, 3),value=ml.grafos.okapi.clustering.ap.APVertexValue@767e557b,#edges=0) on superstep 1 with mutations null
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): -1363588386
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): -1363588386
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): -1363588386
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): -1363588386
org.apache.giraph.comm.netty.NettyWorkerServer - resolveMutations: Resolved vertex index (COLUMN, 1) with original vertex null, returned vertex Vertex(id=(COLUMN, 1),value=ml.grafos.okapi.clustering.ap.APVertexValue@601e3b03,#edges=0) on superstep 1 with mutations null
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): -1363588386
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0xbc5ac3c6, /192.168.50.5:53267 => /192.168.50.4:30002] buffer size = 105, total bytes = 770
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client -1, requestId 2, SEND_AGGREGATORS_TO_OWNER_REQUEST, with size 101 took 67539 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendAggregatorsToOwnerRequest
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client -1, requestId 2, SEND_AGGREGATORS_TO_OWNER_REQUEST took 32182 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0xbc5ac3c6, /192.168.50.5:53267 => /192.168.50.4:30002] buffer size = 13, total bytes = 104
org.apache.giraph.comm.netty.NettyClient - connectAllAddresses: Successfully added 0 connections, (0 total connected) 0 failed, 0 failures total.
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0.0002, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.11
MBytes/sec sent = 0.0009, MBytesSent = 0.0001, ave sent req MBytes = 0, secs waited = 0.11
org.apache.giraph.comm.aggregators.AllAggregatorServerData - getDataFromMasterWhenReady: Aggregator data for distribution ready
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 2, requestId 6, size = 105, SEND_AGGREGATORS_TO_WORKER_REQUEST took 74307 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 105, total bytes = 105
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x876c33e7, /192.168.50.6:50028 => /192.168.50.4:30002] buffer size = 170, total bytes = 940
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 1, requestId 5, SEND_AGGREGATORS_TO_WORKER_REQUEST, with size 166 took 74297 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendAggregatorsToWorkerRequest
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 1, requestId 5, SEND_AGGREGATORS_TO_WORKER_REQUEST took 120951 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x876c33e7, /192.168.50.6:50028 => /192.168.50.4:30002] buffer size = 13, total bytes = 117
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 1)(reqId=6,destAddr=slave2:30001,elapsedNanos=3309218,started=Thu Jan 01 09:03:21 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.aggregators.AllAggregatorServerData - fillNextSuperstepMapsWhenReady: Aggregators ready
org.apache.giraph.comm.aggregators.AllAggregatorServerData - reset: Ready for next superstep
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
ml.grafos.okapi.clustering.ap.AffinityPropagation - vertex (COLUMN, 3), superstep 1
ml.grafos.okapi.clustering.ap.AffinityPropagation - (COLUMN, 3) Receives message from (ROW, 2)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
org.apache.giraph.comm.SendMessageCache - sendMessageRequest: Send bytes (APMessage{from=(ROW, 2), value=0.0}) to (ROW, 2) on worker Worker(hostname=master, MRtaskID=2, port=30002)
ml.grafos.okapi.clustering.ap.AffinityPropagation - Sending init message from (COLUMN, 3) to (ROW, 2)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - vertex (ROW, 2), superstep 1
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): -1363588386
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): -1363588386
ml.grafos.okapi.clustering.ap.AffinityPropagation - vertex (COLUMN, 1), superstep 1
ml.grafos.okapi.clustering.ap.AffinityPropagation - (COLUMN, 1) Receives message from (ROW, 2)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
org.apache.giraph.comm.SendMessageCache - sendMessageRequest: Send bytes (APMessage{from=(ROW, 2), value=0.0}) to (ROW, 2) on worker Worker(hostname=master, MRtaskID=2, port=30002)
ml.grafos.okapi.clustering.ap.AffinityPropagation - Sending init message from (COLUMN, 1) to (ROW, 2)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): -1363588386
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): -1363588386
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0.0009, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.013
MBytes/sec sent = 0.0072, MBytesSent = 0.0001, ave sent req MBytes = 0.0001, secs waited = 0.014
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 2, requestId 7, size = 78, SEND_WORKER_AGGREGATORS_REQUEST took 52158 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 78, total bytes = 78
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 1)(reqId=7,destAddr=slave2:30001,elapsedNanos=2221013,started=Thu Jan 01 09:03:21 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x876c33e7, /192.168.50.6:50028 => /192.168.50.4:30002] buffer size = 63, total bytes = 1003
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 1, requestId 6, SEND_WORKER_AGGREGATORS_REQUEST, with size 59 took 80133 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendWorkerAggregatorsRequest
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 1, requestId 6, SEND_WORKER_AGGREGATORS_REQUEST took 53491 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x876c33e7, /192.168.50.6:50028 => /192.168.50.4:30002] buffer size = 13, total bytes = 130
org.apache.giraph.comm.aggregators.OwnerAggregatorServerData - getMyAggregatorValuesWhenReady: Values ready
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 2, requestId 2, size = 25, SEND_AGGREGATORS_TO_MASTER_REQUEST took 62248 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x6129d2e1, /192.168.50.4:58823 => slave1/192.168.50.5:30000] buffer size = 25, total bytes = 25
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x6129d2e1, /192.168.50.4:58823 => slave1/192.168.50.5:30000] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = -1)(reqId=2,destAddr=slave1:30000,elapsedNanos=2310526,started=Thu Jan 01 09:03:21 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0.0041, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.002
MBytes/sec sent = 0.0079, MBytesSent = 0, ave sent req MBytes = 0, secs waited = 0.003
org.apache.giraph.comm.aggregators.OwnerAggregatorServerData - reset: Ready for next superstep
org.apache.giraph.comm.messages.InMemoryMessageStoreFactory - newStore: Created class org.apache.giraph.comm.messages.ByteArrayMessagesPerVertexStore for vertex id class ml.grafos.okapi.clustering.ap.APVertexID and message value class ml.grafos.okapi.clustering.ap.APMessage and no combiner
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0xbc5ac3c6, /192.168.50.5:53267 => /192.168.50.4:30002] buffer size = 105, total bytes = 1108
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client -1, requestId 3, SEND_AGGREGATORS_TO_OWNER_REQUEST, with size 101 took 85149 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendAggregatorsToOwnerRequest
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client -1, requestId 3, SEND_AGGREGATORS_TO_OWNER_REQUEST took 47138 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0xbc5ac3c6, /192.168.50.5:53267 => /192.168.50.4:30002] buffer size = 13, total bytes = 143
org.apache.giraph.comm.netty.NettyClient - connectAllAddresses: Successfully added 0 connections, (0 total connected) 0 failed, 0 failures total.
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0.0001, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.087
MBytes/sec sent = 0.0003, MBytesSent = 0, ave sent req MBytes = 0, secs waited = 0.087
org.apache.giraph.comm.aggregators.AllAggregatorServerData - getDataFromMasterWhenReady: Aggregator data for distribution ready
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 2, requestId 8, size = 105, SEND_AGGREGATORS_TO_WORKER_REQUEST took 67351 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 105, total bytes = 105
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x3c1967f2, /192.168.50.4:44002 => slave2/192.168.50.6:30001] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 1)(reqId=8,destAddr=slave2:30001,elapsedNanos=3113780,started=Thu Jan 01 09:03:21 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x876c33e7, /192.168.50.6:50028 => /192.168.50.4:30002] buffer size = 170, total bytes = 1278
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 1, requestId 7, SEND_AGGREGATORS_TO_WORKER_REQUEST, with size 166 took 34995 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendAggregatorsToWorkerRequest
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 1, requestId 7, SEND_AGGREGATORS_TO_WORKER_REQUEST took 80 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x876c33e7, /192.168.50.6:50028 => /192.168.50.4:30002] buffer size = 13, total bytes = 156
org.apache.giraph.comm.aggregators.AllAggregatorServerData - fillNextSuperstepMapsWhenReady: Aggregators ready
org.apache.giraph.comm.aggregators.AllAggregatorServerData - reset: Ready for next superstep
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): -1363588384
ml.grafos.okapi.clustering.ap.AffinityPropagation - vertex (COLUMN, 3), superstep 2
ml.grafos.okapi.clustering.ap.AffinityPropagation - (COLUMN, 3) adds neighbor (ROW, 2)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 2): 900794734
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 900794735
org.apache.giraph.utils.LogStacktraceCallable - Execution of callable failed
java.lang.NullPointerException
at es.csic.iiia.bms.factors.AbstractFactor.getMessage(AbstractFactor.java:123)
at es.csic.iiia.bms.factors.ConditionedDeactivationFactor.run(ConditionedDeactivationFactor.java:64)
at ml.grafos.okapi.clustering.ap.AffinityPropagation.computeBMSIteration(AffinityPropagation.java:190)
at ml.grafos.okapi.clustering.ap.AffinityPropagation.compute(AffinityPropagation.java:90)
at org.apache.giraph.graph.ComputeCallable.computePartition(ComputeCallable.java:248)
at org.apache.giraph.graph.ComputeCallable.call(ComputeCallable.java:169)
at org.apache.giraph.graph.ComputeCallable.call(ComputeCallable.java:72)
at org.apache.giraph.utils.LogStacktraceCallable.call(LogStacktraceCallable.java:51)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
org.apache.giraph.worker.BspServiceWorker - unregisterHealth: Got failure, unregistering health on /_hadoopBsp/job_201405212016_0002/_applicationAttemptsDir/0/_superstepDir/2/_workerHealthyDir/master_2 on superstep 2
stderr logs
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [file:/tmp/hadoop-hadoop/mapred/local/taskTracker/hadoop/jobcache/job_201405212016_0002/jars/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [file:/tmp/hadoop-hadoop/mapred/local/taskTracker/hadoop/distcache/1286953439157593619_-1189634963_544213566/master/tmp/hadoop-hadoop/mapred/staging/hadoop/.staging/job_201405212016_0002/libjars/okapi-0.3.2-SNAPSHOT-jar-with-dependencies.jar/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/home/hadoop/hadoop-0.20.203.0/lib/slf4j-log4j12-1.4.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [org.slf4j.impl.Log4jLoggerFactory]
log4j:WARN No appenders could be found for logger (org.apache.giraph.comm.netty.handler.ResponseClientHandler).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
Task Logs: 'attempt_201405212016_0002_m_000001_0'
stdout logs
org.apache.giraph.comm.netty.NettyServer - NettyServer: Using execution group with 8 threads for requestFrameDecoder.
org.apache.giraph.comm.netty.NettyServer - start: Started server communication server: slave2/192.168.50.6:30001 with up to 16 threads on bind attempt 0 with sendBufferSize = 32768 receiveBufferSize = 524288
org.apache.giraph.comm.netty.NettyClient - NettyClient: Using execution handler with 8 threads after request-encoder.
org.apache.giraph.comm.netty.NettyServer - start: Using Netty without authentication.
org.apache.giraph.comm.netty.NettyServer - start: Using Netty without authentication.
org.apache.giraph.comm.netty.NettyClient - Using Netty without authentication.
org.apache.giraph.comm.netty.handler.RequestServerHandler - channelActive: Connected the channel on /192.168.50.5:57197
org.apache.giraph.comm.netty.handler.RequestServerHandler - channelActive: Connected the channel on /192.168.50.4:44002
org.apache.giraph.comm.netty.NettyClient - Using Netty without authentication.
org.apache.giraph.comm.netty.NettyClient - connectAllAddresses: Connected to master/192.168.50.4:30002, open = true
org.apache.giraph.comm.netty.NettyClient - connectAllAddresses: Connected to slave1/192.168.50.5:30000, open = true
org.apache.giraph.comm.netty.NettyClient - connectAllAddresses: Successfully added 2 connections, (2 total connected) 0 failed, 0 failures total.
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x5fcc61e7, /192.168.50.5:57197 => /192.168.50.6:30001] buffer size = 170, total bytes = 170
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Server window metrics MBytes/sec received = 0, MBytesReceived = 0.0002, ave received req MBytes = 0.0002, secs waited = 1.40070374E9
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client -1, requestId 0, SEND_AGGREGATORS_TO_OWNER_REQUEST, with size 166 took 30192770 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendAggregatorsToOwnerRequest
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 105, total bytes = 105
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 2, requestId 0, SEND_AGGREGATORS_TO_WORKER_REQUEST, with size 101 took 242697 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendAggregatorsToWorkerRequest
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 2, requestId 0, SEND_AGGREGATORS_TO_WORKER_REQUEST took 1210533 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 13, total bytes = 13
org.apache.giraph.comm.aggregators.OwnerAggregatorServerData - registerAggregator: The first registration after a reset()
org.apache.giraph.comm.aggregators.AllAggregatorServerData - getDataFromMasterWhenReady: Aggregator data for distribution ready
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client -1, requestId 0, SEND_AGGREGATORS_TO_OWNER_REQUEST took 73806249 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x5fcc61e7, /192.168.50.5:57197 => /192.168.50.6:30001] buffer size = 13, total bytes = 26
org.apache.giraph.comm.aggregators.AllAggregatorServerData - fillNextSuperstepMapsWhenReady: Aggregators ready
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 1, requestId 0, size = 170, SEND_AGGREGATORS_TO_WORKER_REQUEST took 94085143 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x08b0aa75, /192.168.50.6:50028 => master/192.168.50.4:30002] buffer size = 170, total bytes = 170
org.apache.giraph.comm.aggregators.AllAggregatorServerData - reset: Ready for next superstep
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x08b0aa75, /192.168.50.6:50028 => master/192.168.50.4:30002] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.729
MBytes/sec sent = 0.0002, MBytesSent = 0.0002, ave sent req MBytes = 0.0002, secs waited = 0.729
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 229, total bytes = 334
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 2, requestId 1, SEND_WORKER_EDGES_REQUEST, with size 225 took 14455258 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendWorkerEdgesRequest
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 2, requestId 1, SEND_WORKER_EDGES_REQUEST took 69269886 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 13, total bytes = 39
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 2)(reqId=0,destAddr=master:30002,elapsedNanos=657893882,started=Thu Jan 01 09:01:33 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 78, total bytes = 412
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 2, requestId 2, SEND_WORKER_AGGREGATORS_REQUEST, with size 74 took 207908 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendWorkerAggregatorsRequest
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 2, requestId 2, SEND_WORKER_AGGREGATORS_REQUEST took 133219 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 13, total bytes = 52
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 1.004
MBytes/sec sent = 0.0002, MBytesSent = 0.0002, ave sent req MBytes = 0.0002, secs waited = 1.004
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 1, requestId 1, size = 63, SEND_WORKER_AGGREGATORS_REQUEST took 53905 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x08b0aa75, /192.168.50.6:50028 => master/192.168.50.4:30002] buffer size = 63, total bytes = 63
org.apache.giraph.comm.aggregators.OwnerAggregatorServerData - getMyAggregatorValuesWhenReady: Values ready
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x08b0aa75, /192.168.50.6:50028 => master/192.168.50.4:30002] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 2)(reqId=1,destAddr=master:30002,elapsedNanos=5349467,started=Thu Jan 01 09:01:34 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 1, requestId 0, size = 40, SEND_AGGREGATORS_TO_MASTER_REQUEST took 120176 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0xce240259, /192.168.50.6:52345 => slave1/192.168.50.5:30000] buffer size = 40, total bytes = 40
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0xce240259, /192.168.50.6:52345 => slave1/192.168.50.5:30000] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = -1)(reqId=0,destAddr=slave1:30000,elapsedNanos=29427779,started=Thu Jan 01 09:01:34 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0.0004, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.03
MBytes/sec sent = 0.0012, MBytesSent = 0, ave sent req MBytes = 0, secs waited = 0.031
org.apache.giraph.comm.aggregators.OwnerAggregatorServerData - reset: Ready for next superstep
org.apache.giraph.comm.messages.InMemoryMessageStoreFactory - newStore: Created class org.apache.giraph.comm.messages.ByteArrayMessagesPerVertexStore for vertex id class ml.grafos.okapi.clustering.ap.APVertexID and message value class ml.grafos.okapi.clustering.ap.APMessage and no combiner
org.apache.giraph.comm.messages.InMemoryMessageStoreFactory - newStore: Created class org.apache.giraph.comm.messages.ByteArrayMessagesPerVertexStore for vertex id class ml.grafos.okapi.clustering.ap.APVertexID and message value class ml.grafos.okapi.clustering.ap.APMessage and no combiner
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x5fcc61e7, /192.168.50.5:57197 => /192.168.50.6:30001] buffer size = 170, total bytes = 582
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client -1, requestId 1, SEND_AGGREGATORS_TO_OWNER_REQUEST, with size 166 took 77126 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendAggregatorsToOwnerRequest
org.apache.giraph.comm.aggregators.OwnerAggregatorServerData - registerAggregator: The first registration after a reset()
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client -1, requestId 1, SEND_AGGREGATORS_TO_OWNER_REQUEST took 147074 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x5fcc61e7, /192.168.50.5:57197 => /192.168.50.6:30001] buffer size = 13, total bytes = 65
org.apache.giraph.comm.netty.NettyClient - connectAllAddresses: Successfully added 0 connections, (0 total connected) 0 failed, 0 failures total.
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.488
MBytes/sec sent = 0.0001, MBytesSent = 0, ave sent req MBytes = 0, secs waited = 0.488
org.apache.giraph.comm.aggregators.AllAggregatorServerData - getDataFromMasterWhenReady: Aggregator data for distribution ready
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 105, total bytes = 687
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 2, requestId 3, SEND_AGGREGATORS_TO_WORKER_REQUEST, with size 101 took 54124 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendAggregatorsToWorkerRequest
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 2, requestId 3, SEND_AGGREGATORS_TO_WORKER_REQUEST took 26530 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 13, total bytes = 78
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 1, requestId 2, size = 170, SEND_AGGREGATORS_TO_WORKER_REQUEST took 59048 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x08b0aa75, /192.168.50.6:50028 => master/192.168.50.4:30002] buffer size = 170, total bytes = 170
org.apache.giraph.comm.aggregators.AllAggregatorServerData - fillNextSuperstepMapsWhenReady: Aggregators ready
org.apache.giraph.comm.aggregators.AllAggregatorServerData - reset: Ready for next superstep
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x08b0aa75, /192.168.50.6:50028 => master/192.168.50.4:30002] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 2)(reqId=2,destAddr=master:30002,elapsedNanos=3653046,started=Thu Jan 01 09:01:34 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 62, total bytes = 749
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 2, requestId 4, SEND_WORKER_MESSAGES_REQUEST, with size 58 took 345890 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendWorkerMessagesRequest
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): 549655836
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): 549655836
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - vertex (ROW, 1), superstep 0
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
org.apache.giraph.comm.SendMessageCache - sendMessageRequest: Send bytes (APMessage{from=(ROW, 1), value=0.0}) to (COLUMN, 1) on worker Worker(hostname=slave2, MRtaskID=1, port=30001)
ml.grafos.okapi.clustering.ap.AffinityPropagation - Sending init message from (ROW, 1) to (COLUMN, 1)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): 549655836
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): 549655836
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): 549655836
org.apache.giraph.comm.SendMessageCache - sendMessageRequest: Send bytes (APMessage{from=(ROW, 1), value=0.0}) to (COLUMN, 2) on worker Worker(hostname=master, MRtaskID=2, port=30002)
ml.grafos.okapi.clustering.ap.AffinityPropagation - Sending init message from (ROW, 1) to (COLUMN, 2)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
org.apache.giraph.comm.SendMessageCache - sendMessageRequest: Send bytes (APMessage{from=(ROW, 1), value=0.0}) to (COLUMN, 3) on worker Worker(hostname=slave2, MRtaskID=1, port=30001)
ml.grafos.okapi.clustering.ap.AffinityPropagation - Sending init message from (ROW, 1) to (COLUMN, 3)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - vertex (ROW, 3), superstep 0
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
org.apache.giraph.comm.SendMessageCache - sendMessageRequest: Send bytes (APMessage{from=(ROW, 3), value=0.0}) to (COLUMN, 1) on worker Worker(hostname=slave2, MRtaskID=1, port=30001)
ml.grafos.okapi.clustering.ap.AffinityPropagation - Sending init message from (ROW, 3) to (COLUMN, 1)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): 549655836
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): 549655836
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): 549655836
org.apache.giraph.comm.SendMessageCache - sendMessageRequest: Send bytes (APMessage{from=(ROW, 3), value=0.0}) to (COLUMN, 2) on worker Worker(hostname=master, MRtaskID=2, port=30002)
ml.grafos.okapi.clustering.ap.AffinityPropagation - Sending init message from (ROW, 3) to (COLUMN, 2)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
org.apache.giraph.comm.SendMessageCache - sendMessageRequest: Send bytes (APMessage{from=(ROW, 3), value=0.0}) to (COLUMN, 3) on worker Worker(hostname=slave2, MRtaskID=1, port=30001)
ml.grafos.okapi.clustering.ap.AffinityPropagation - Sending init message from (ROW, 3) to (COLUMN, 3)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 1, requestId 3, size = 94, SEND_WORKER_MESSAGES_REQUEST took 84999 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x08b0aa75, /192.168.50.6:50028 => master/192.168.50.4:30002] buffer size = 94, total bytes = 94
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x08b0aa75, /192.168.50.6:50028 => master/192.168.50.4:30002] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 2)(reqId=3,destAddr=master:30002,elapsedNanos=1956428,started=Thu Jan 01 09:01:35 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 2, requestId 4, SEND_WORKER_MESSAGES_REQUEST took 72216778 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 13, total bytes = 91
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0.0004, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.033
MBytes/sec sent = 0.0026, MBytesSent = 0.0001, ave sent req MBytes = 0.0001, secs waited = 0.033
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 1, requestId 4, size = 63, SEND_WORKER_AGGREGATORS_REQUEST took 45040 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x08b0aa75, /192.168.50.6:50028 => master/192.168.50.4:30002] buffer size = 63, total bytes = 63
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 78, total bytes = 827
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 2, requestId 5, SEND_WORKER_AGGREGATORS_REQUEST, with size 74 took 28 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendWorkerAggregatorsRequest
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x08b0aa75, /192.168.50.6:50028 => master/192.168.50.4:30002] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 2)(reqId=4,destAddr=master:30002,elapsedNanos=4617099,started=Thu Jan 01 09:01:35 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 2, requestId 5, SEND_WORKER_AGGREGATORS_REQUEST took 912894 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 13, total bytes = 104
org.apache.giraph.comm.aggregators.OwnerAggregatorServerData - getMyAggregatorValuesWhenReady: Values ready
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 1, requestId 1, size = 40, SEND_AGGREGATORS_TO_MASTER_REQUEST took 65521 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0xce240259, /192.168.50.6:52345 => slave1/192.168.50.5:30000] buffer size = 40, total bytes = 40
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0xce240259, /192.168.50.6:52345 => slave1/192.168.50.5:30000] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = -1)(reqId=1,destAddr=slave1:30000,elapsedNanos=2417326,started=Thu Jan 01 09:01:35 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0.0031, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.003
MBytes/sec sent = 0.0095, MBytesSent = 0, ave sent req MBytes = 0, secs waited = 0.003
org.apache.giraph.comm.aggregators.OwnerAggregatorServerData - reset: Ready for next superstep
org.apache.giraph.comm.messages.InMemoryMessageStoreFactory - newStore: Created class org.apache.giraph.comm.messages.ByteArrayMessagesPerVertexStore for vertex id class ml.grafos.okapi.clustering.ap.APVertexID and message value class ml.grafos.okapi.clustering.ap.APMessage and no combiner
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): 549655836
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): 549655836
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
org.apache.giraph.comm.netty.NettyWorkerServer - resolveMutations: Resolved vertex index (COLUMN, 3) with original vertex null, returned vertex Vertex(id=(COLUMN, 3),value=ml.grafos.okapi.clustering.ap.APVertexValue@244ff48e,#edges=0) on superstep 1 with mutations null
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): 549655836
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): 549655836
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 2): 549655836
org.apache.giraph.comm.netty.NettyWorkerServer - resolveMutations: Resolved vertex index (COLUMN, 2) with original vertex null, returned vertex null on superstep 1 with mutations null
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
org.apache.giraph.comm.netty.NettyWorkerServer - resolveMutations: Resolved vertex index (COLUMN, 1) with original vertex null, returned vertex Vertex(id=(COLUMN, 1),value=ml.grafos.okapi.clustering.ap.APVertexValue@7d40a941,#edges=0) on superstep 1 with mutations null
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x5fcc61e7, /192.168.50.5:57197 => /192.168.50.6:30001] buffer size = 170, total bytes = 997
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client -1, requestId 2, SEND_AGGREGATORS_TO_OWNER_REQUEST, with size 166 took 89322 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendAggregatorsToOwnerRequest
org.apache.giraph.comm.aggregators.OwnerAggregatorServerData - registerAggregator: The first registration after a reset()
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client -1, requestId 2, SEND_AGGREGATORS_TO_OWNER_REQUEST took 207095 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x5fcc61e7, /192.168.50.5:57197 => /192.168.50.6:30001] buffer size = 13, total bytes = 117
org.apache.giraph.comm.netty.NettyClient - connectAllAddresses: Successfully added 0 connections, (0 total connected) 0 failed, 0 failures total.
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0.0001, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.108
MBytes/sec sent = 0.0003, MBytesSent = 0, ave sent req MBytes = 0, secs waited = 0.108
org.apache.giraph.comm.aggregators.AllAggregatorServerData - getDataFromMasterWhenReady: Aggregator data for distribution ready
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 1, requestId 5, size = 170, SEND_AGGREGATORS_TO_WORKER_REQUEST took 77888 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x08b0aa75, /192.168.50.6:50028 => master/192.168.50.4:30002] buffer size = 170, total bytes = 170
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 105, total bytes = 1102
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 2, requestId 6, SEND_AGGREGATORS_TO_WORKER_REQUEST, with size 101 took 61164 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendAggregatorsToWorkerRequest
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 2, requestId 6, SEND_AGGREGATORS_TO_WORKER_REQUEST took 40982 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 13, total bytes = 130
org.apache.giraph.comm.aggregators.AllAggregatorServerData - fillNextSuperstepMapsWhenReady: Aggregators ready
org.apache.giraph.comm.aggregators.AllAggregatorServerData - reset: Ready for next superstep
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x08b0aa75, /192.168.50.6:50028 => master/192.168.50.4:30002] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 2)(reqId=5,destAddr=master:30002,elapsedNanos=2727230,started=Thu Jan 01 09:01:35 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 78, total bytes = 1180
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 2, requestId 7, SEND_WORKER_AGGREGATORS_REQUEST, with size 74 took 72981 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendWorkerAggregatorsRequest
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 2, requestId 7, SEND_WORKER_AGGREGATORS_REQUEST took 80306 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 13, total bytes = 143
ml.grafos.okapi.clustering.ap.AffinityPropagation - vertex (COLUMN, 3), superstep 1
ml.grafos.okapi.clustering.ap.AffinityPropagation - (COLUMN, 3) Receives message from (ROW, 1)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
org.apache.giraph.comm.SendMessageCache - sendMessageRequest: Send bytes (APMessage{from=(ROW, 1), value=0.0}) to (ROW, 1) on worker Worker(hostname=slave2, MRtaskID=1, port=30001)
ml.grafos.okapi.clustering.ap.AffinityPropagation - Sending init message from (COLUMN, 3) to (ROW, 1)
ml.grafos.okapi.clustering.ap.AffinityPropagation - (COLUMN, 3) Receives message from (ROW, 3)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
org.apache.giraph.comm.SendMessageCache - sendMessageRequest: Send bytes (APMessage{from=(ROW, 3), value=0.0}) to (ROW, 3) on worker Worker(hostname=slave2, MRtaskID=1, port=30001)
ml.grafos.okapi.clustering.ap.AffinityPropagation - Sending init message from (COLUMN, 3) to (ROW, 3)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 3): 549655837
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - vertex (ROW, 1), superstep 1
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
ml.grafos.okapi.clustering.ap.AffinityPropagation - vertex (COLUMN, 1), superstep 1
ml.grafos.okapi.clustering.ap.AffinityPropagation - (COLUMN, 1) Receives message from (ROW, 1)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
org.apache.giraph.comm.SendMessageCache - sendMessageRequest: Send bytes (APMessage{from=(ROW, 1), value=0.0}) to (ROW, 1) on worker Worker(hostname=slave2, MRtaskID=1, port=30001)
ml.grafos.okapi.clustering.ap.AffinityPropagation - Sending init message from (COLUMN, 1) to (ROW, 1)
ml.grafos.okapi.clustering.ap.AffinityPropagation - (COLUMN, 1) Receives message from (ROW, 3)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
org.apache.giraph.comm.SendMessageCache - sendMessageRequest: Send bytes (APMessage{from=(ROW, 3), value=0.0}) to (ROW, 3) on worker Worker(hostname=slave2, MRtaskID=1, port=30001)
ml.grafos.okapi.clustering.ap.AffinityPropagation - Sending init message from (COLUMN, 1) to (ROW, 3)
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (COLUMN, 1): 549655835
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - vertex (ROW, 3), superstep 1
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0.0002, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.075
MBytes/sec sent = 0.0021, MBytesSent = 0.0002, ave sent req MBytes = 0.0002, secs waited = 0.075
org.apache.giraph.comm.aggregators.OwnerAggregatorServerData - getMyAggregatorValuesWhenReady: Values ready
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 1, requestId 6, size = 63, SEND_WORKER_AGGREGATORS_REQUEST took 45770 ns
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 1, requestId 2, size = 40, SEND_AGGREGATORS_TO_MASTER_REQUEST took 31411 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x08b0aa75, /192.168.50.6:50028 => master/192.168.50.4:30002] buffer size = 63, total bytes = 63
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0xce240259, /192.168.50.6:52345 => slave1/192.168.50.5:30000] buffer size = 40, total bytes = 103
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x08b0aa75, /192.168.50.6:50028 => master/192.168.50.4:30002] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 2)(reqId=6,destAddr=master:30002,elapsedNanos=2705760,started=Thu Jan 01 09:01:35 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 1 requests
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0xce240259, /192.168.50.6:52345 => slave1/192.168.50.5:30000] buffer size = 13, total bytes = 26
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = -1)(reqId=2,destAddr=slave1:30000,elapsedNanos=3054659,started=Thu Jan 01 09:01:35 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0.0062, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.003
MBytes/sec sent = 0.0246, MBytesSent = 0.0001, ave sent req MBytes = 0, secs waited = 0.003
org.apache.giraph.comm.aggregators.OwnerAggregatorServerData - reset: Ready for next superstep
org.apache.giraph.comm.messages.InMemoryMessageStoreFactory - newStore: Created class org.apache.giraph.comm.messages.ByteArrayMessagesPerVertexStore for vertex id class ml.grafos.okapi.clustering.ap.APVertexID and message value class ml.grafos.okapi.clustering.ap.APMessage and no combiner
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
org.apache.giraph.comm.netty.NettyWorkerServer - resolveMutations: Resolved vertex index (ROW, 3) with original vertex null, returned vertex Vertex(id=(ROW, 3),value=ml.grafos.okapi.clustering.ap.APVertexValue@1261db2b,#edges=0) on superstep 2 with mutations null
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
org.apache.giraph.comm.netty.NettyWorkerServer - resolveMutations: Resolved vertex index (ROW, 1) with original vertex null, returned vertex Vertex(id=(ROW, 1),value=ml.grafos.okapi.clustering.ap.APVertexValue@567bed7a,#edges=0) on superstep 2 with mutations null
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 1): 2010440527
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x5fcc61e7, /192.168.50.5:57197 => /192.168.50.6:30001] buffer size = 170, total bytes = 1350
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client -1, requestId 3, SEND_AGGREGATORS_TO_OWNER_REQUEST, with size 166 took 90229 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendAggregatorsToOwnerRequest
org.apache.giraph.comm.aggregators.OwnerAggregatorServerData - registerAggregator: The first registration after a reset()
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client -1, requestId 3, SEND_AGGREGATORS_TO_OWNER_REQUEST took 220140 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x5fcc61e7, /192.168.50.5:57197 => /192.168.50.6:30001] buffer size = 13, total bytes = 156
org.apache.giraph.comm.netty.NettyClient - connectAllAddresses: Successfully added 0 connections, (0 total connected) 0 failed, 0 failures total.
org.apache.giraph.comm.netty.NettyClient - waitAllRequests: Finished all requests. MBytes/sec received = 0.0003, MBytesReceived = 0, ave received req MBytes = 0, secs waited = 0.095
MBytes/sec sent = 0.001, MBytesSent = 0.0001, ave sent req MBytes = 0, secs waited = 0.095
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 105, total bytes = 1455
org.apache.giraph.comm.netty.handler.RequestDecoder - decode: Client 2, requestId 8, SEND_AGGREGATORS_TO_WORKER_REQUEST, with size 101 took 60177 ns
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Got class org.apache.giraph.comm.requests.SendAggregatorsToWorkerRequest
org.apache.giraph.comm.netty.handler.RequestServerHandler - messageReceived: Processing client 2, requestId 8, SEND_AGGREGATORS_TO_WORKER_REQUEST took 35664 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x63c8c2bc, /192.168.50.4:44002 => /192.168.50.6:30001] buffer size = 13, total bytes = 169
org.apache.giraph.comm.aggregators.AllAggregatorServerData - getDataFromMasterWhenReady: Aggregator data for distribution ready
org.apache.giraph.comm.netty.handler.RequestEncoder - encode: Client 1, requestId 7, size = 170, SEND_AGGREGATORS_TO_WORKER_REQUEST took 47029 ns
org.apache.giraph.comm.netty.OutboundByteCounter - write: [id: 0x08b0aa75, /192.168.50.6:50028 => master/192.168.50.4:30002] buffer size = 170, total bytes = 170
org.apache.giraph.comm.aggregators.AllAggregatorServerData - fillNextSuperstepMapsWhenReady: Aggregators ready
org.apache.giraph.comm.aggregators.AllAggregatorServerData - reset: Ready for next superstep
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - hashCode of (ROW, 3): 2010440529
ml.grafos.okapi.clustering.ap.AffinityPropagation - vertex (ROW, 3), superstep 2
org.apache.giraph.comm.netty.InboundByteCounter - channelRead: [id: 0x08b0aa75, /192.168.50.6:50028 => master/192.168.50.4:30002] buffer size = 13, total bytes = 13
org.apache.giraph.comm.netty.handler.ResponseClientHandler - messageReceived: Completed (taskId = 2)(reqId=7,destAddr=master:30002,elapsedNanos=2067513,started=Thu Jan 01 09:01:35 UTC 1970,writeDone=true,writeSuccess=true). Waiting on 0 requests
org.apache.giraph.utils.LogStacktraceCallable - Execution of callable failed
java.lang.IllegalArgumentException: Requested potential for a non-existent neighbor
at es.csic.iiia.bms.factors.WeightingFactor.getPotential(WeightingFactor.java:106)
at es.csic.iiia.bms.factors.WeightingFactor.receive(WeightingFactor.java:149)
at ml.grafos.okapi.clustering.ap.AffinityPropagation.computeBMSIteration(AffinityPropagation.java:188)
at ml.grafos.okapi.clustering.ap.AffinityPropagation.compute(AffinityPropagation.java:90)
at org.apache.giraph.graph.ComputeCallable.computePartition(ComputeCallable.java:248)
at org.apache.giraph.graph.ComputeCallable.call(ComputeCallable.java:169)
at org.apache.giraph.graph.ComputeCallable.call(ComputeCallable.java:72)
at org.apache.giraph.utils.LogStacktraceCallable.call(LogStacktraceCallable.java:51)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
org.apache.giraph.worker.BspServiceWorker - unregisterHealth: Got failure, unregistering health on /_hadoopBsp/job_201405212016_0002/_applicationAttemptsDir/0/_superstepDir/2/_workerHealthyDir/slave2_1 on superstep 2
stderr logs
SLF4J: Class path contains multiple SLF4J bindings.
SLF4J: Found binding in [file:/tmp/hadoop-hadoop/mapred/local/taskTracker/hadoop/jobcache/job_201405212016_0002/jars/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [file:/tmp/hadoop-hadoop/mapred/local/taskTracker/hadoop/distcache/2216257887722654186_-1189634963_544213566/master/tmp/hadoop-hadoop/mapred/staging/hadoop/.staging/job_201405212016_0002/libjars/okapi-0.3.2-SNAPSHOT-jar-with-dependencies.jar/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: Found binding in [jar:file:/home/hadoop/hadoop-0.20.203.0/lib/slf4j-log4j12-1.4.3.jar!/org/slf4j/impl/StaticLoggerBinder.class]
SLF4J: See http://www.slf4j.org/codes.html#multiple_bindings for an explanation.
SLF4J: Actual binding is of type [org.slf4j.impl.Log4jLoggerFactory]
log4j:WARN No appenders could be found for logger (org.apache.giraph.comm.netty.handler.ResponseClientHandler).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment