osdir.com

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

streaming errors with sstableloader


Hello community,

I'm receiving some strange streaming errors while trying to restore certain sstables snapshots with sstableloader to a new cluster.

While the cluster is up and running and nodes are communicating with each other, I can see streams failing to the nodes with no obvious reason and the only exception thrown is:

ERROR 14:00:08,403 [Stream #3d572210-f95f-11e8-bf2d-01149b1d085c] Streaming error occurred on session with peer 10.35.81.88
java.lang.NullPointerException: null
       at org.apache.cassandra.db.SerializationHeader$Component.access$400(SerializationHeader.java:271) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.db.SerializationHeader$Serializer.serialize(SerializationHeader.java:445) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.messages.FileMessageHeader$FileMessageHeaderSerializer.serialize(FileMessageHeader.java:216) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.messages.OutgoingFileMessage.serialize(OutgoingFileMessage.java:94) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.messages.OutgoingFileMessage$1.serialize(OutgoingFileMessage.java:52) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.messages.OutgoingFileMessage$1.serialize(OutgoingFileMessage.java:41) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.messages.StreamMessage.serialize(StreamMessage.java:50) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.ConnectionHandler$OutgoingMessageHandler.sendMessage(ConnectionHandler.java:408) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.ConnectionHandler$OutgoingMessageHandler.run(ConnectionHandler.java:380) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at java.lang.Thread.run(Thread.java:748) [na:1.8.0_191]
progress: [/10.35.81.88]0:0/3 0  % [/10.35.81.79]0:1/3 0  % [cassandra01-test.sofia.elex.be/10.35.81.76]0:1/3 0  % total: 0% 2.652KiB/s (avg: 2.652KiB/s)
progress: [/10.35.81.88]0:0/3 0  % [/10.35.81.79]0:1/3 0  % [cassandra01-test.sofia.elex.be/10.35.81.76]0:1/3 0  % total: 0% 0.000KiB/s (avg: 2.651KiB/s)
progress: [/10.35.81.88]0:0/3 0  % [/10.35.81.79]0:1/3 0  % [cassandra01-test.sofia.elex.be/10.35.81.76]0:1/3 0  % total: 0% 0.000KiB/s (avg: 2.650KiB/s)
ERROR 14:00:08,406 [Stream #3d572210-f95f-11e8-bf2d-01149b1d085c] Streaming error occurred on session with peer 10.35.81.79
java.lang.NullPointerException: null
       at org.apache.cassandra.db.SerializationHeader$Component.access$400(SerializationHeader.java:271) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.db.SerializationHeader$Serializer.serialize(SerializationHeader.java:445) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.messages.FileMessageHeader$FileMessageHeaderSerializer.serialize(FileMessageHeader.java:216) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.messages.OutgoingFileMessage.serialize(OutgoingFileMessage.java:94) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.messages.OutgoingFileMessage$1.serialize(OutgoingFileMessage.java:52) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.messages.OutgoingFileMessage$1.serialize(OutgoingFileMessage.java:41) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.messages.StreamMessage.serialize(StreamMessage.java:50) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.ConnectionHandler$OutgoingMessageHandler.sendMessage(ConnectionHandler.java:408) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.ConnectionHandler$OutgoingMessageHandler.run(ConnectionHandler.java:380) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at java.lang.Thread.run(Thread.java:748) [na:1.8.0_191]
progress: [/10.35.81.88]0:0/3 0  % [/10.35.81.79]0:1/3 0  % [cassandra01-test.sofia.elex.be/10.35.81.76]0:1/3 0  % total: 0% 0.000KiB/s (avg: 2.650KiB/s)
ERROR 14:00:08,407 [Stream #3d572210-f95f-11e8-bf2d-01149b1d085c] Remote peer 10.35.81.88 failed stream session.
ERROR 14:00:08,408 [Stream #3d572210-f95f-11e8-bf2d-01149b1d085c] Streaming error occurred on session with peer 10.35.81.76
java.lang.NullPointerException: null
       at org.apache.cassandra.db.SerializationHeader$Component.access$400(SerializationHeader.java:271) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.db.SerializationHeader$Serializer.serialize(SerializationHeader.java:445) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.messages.FileMessageHeader$FileMessageHeaderSerializer.serialize(FileMessageHeader.java:216) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.messages.OutgoingFileMessage.serialize(OutgoingFileMessage.java:94) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.messages.OutgoingFileMessage$1.serialize(OutgoingFileMessage.java:52) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.messages.OutgoingFileMessage$1.serialize(OutgoingFileMessage.java:41) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.messages.StreamMessage.serialize(StreamMessage.java:50) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.ConnectionHandler$OutgoingMessageHandler.sendMessage(ConnectionHandler.java:408) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.ConnectionHandler$OutgoingMessageHandler.run(ConnectionHandler.java:380) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at java.lang.Thread.run(Thread.java:748) [na:1.8.0_191]
progress: [/10.35.81.88]0:0/3 0  % [/10.35.81.79]0:1/3 0  % [cassandra01-test.sofia.elex.be/10.35.81.76]0:1/3 0  % total: 0% 0.000KiB/s (avg: 2.648KiB/s)
WARN  14:00:08,409 [Stream #3d572210-f95f-11e8-bf2d-01149b1d085c] Stream failed
Streaming to the following hosts failed:
[/10.35.81.88, /10.35.81.79, cassandra01-test.sofia.elex.be/10.35.81.76]
ERROR 14:00:08,428 [Stream #3d572210-f95f-11e8-bf2d-01149b1d085c] Streaming error occurred on session with peer 10.35.81.79
java.lang.RuntimeException: Outgoing stream handler has been closed
       at org.apache.cassandra.streaming.ConnectionHandler.sendMessage(ConnectionHandler.java:143) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.StreamSession.maybeCompleted(StreamSession.java:771) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.StreamSession.taskCompleted(StreamSession.java:733) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.StreamTransferTask.complete(StreamTransferTask.java:87) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.StreamSession.received(StreamSession.java:667) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.StreamSession.messageReceived(StreamSession.java:528) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.ConnectionHandler$IncomingMessageHandler.run(ConnectionHandler.java:317) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at java.lang.Thread.run(Thread.java:748) [na:1.8.0_191]

In the debug.log on all nodes at this time I can see the following errors:


INFO  [STREAM-INIT-/10.35.81.76:59902] 2018-12-06 13:57:54,058 StreamResultFuture.java:116 - [Stream #ed464e90-f95e-11e8-9b44-7714c7874f55 ID#0] Creating new streaming plan for Bulk Load
INFO  [STREAM-INIT-/10.35.81.76:59902] 2018-12-06 13:57:54,068 StreamResultFuture.java:123 - [Stream #ed464e90-f95e-11e8-9b44-7714c7874f55, ID#0] Received streaming plan for Bulk Load
INFO  [STREAM-INIT-/10.35.81.76:59908] 2018-12-06 13:57:54,068 StreamResultFuture.java:123 - [Stream #ed464e90-f95e-11e8-9b44-7714c7874f55, ID#0] Received streaming plan for Bulk Load
INFO  [STREAM-IN-/10.35.81.76:59908] 2018-12-06 13:57:54,083 StreamResultFuture.java:173 - [Stream #ed464e90-f95e-11e8-9b44-7714c7874f55 ID#0] Prepare completed. Receiving 3 files(3.610GiB), sending 0 files(0.000KiB)
ERROR [STREAM-IN-/10.35.81.76:59908] 2018-12-06 13:57:54,168 StreamSession.java:593 - [Stream #ed464e90-f95e-11e8-9b44-7714c7874f55] Streaming error occurred on session with peer 10.35.81.76
java.net.SocketException: End-of-stream reached
       at org.apache.cassandra.streaming.messages.StreamMessage.deserialize(StreamMessage.java:71) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.ConnectionHandler$IncomingMessageHandler.run(ConnectionHandler.java:311) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at java.lang.Thread.run(Thread.java:748) [na:1.8.0_191]
ERROR [STREAM-OUT-/10.35.81.76:59902] 2018-12-06 13:57:54,168 StreamSession.java:593 - [Stream #ed464e90-f95e-11e8-9b44-7714c7874f55] Streaming error occurred on session with peer 10.35.81.76
java.io.IOException: Broken pipe
       at sun.nio.ch.FileDispatcherImpl.write0(Native Method) ~[na:1.8.0_191]
       at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47) ~[na:1.8.0_191]
       at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93) ~[na:1.8.0_191]
       at sun.nio.ch.IOUtil.write(IOUtil.java:51) ~[na:1.8.0_191]
       at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:471) ~[na:1.8.0_191]
       at org.apache.cassandra.io.util.BufferedDataOutputStreamPlus.doFlush(BufferedDataOutputStreamPlus.java:323) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.io.util.BufferedDataOutputStreamPlus.flush(BufferedDataOutputStreamPlus.java:331) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.ConnectionHandler$OutgoingMessageHandler.sendMessage(ConnectionHandler.java:409) [apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.ConnectionHandler$OutgoingMessageHandler.run(ConnectionHandler.java:380) [apache-cassandra-3.11.3.jar:3.11.3]
       at java.lang.Thread.run(Thread.java:748) [na:1.8.0_191]
INFO  [STREAM-IN-/10.35.81.76:59908] 2018-12-06 13:57:54,175 StreamResultFuture.java:187 - [Stream #ed464e90-f95e-11e8-9b44-7714c7874f55] Session with /10.35.81.76 is complete
WARN  [STREAM-IN-/10.35.81.76:59908] 2018-12-06 13:57:54,178 StreamResultFuture.java:214 - [Stream #ed464e90-f95e-11e8-9b44-7714c7874f55] Stream failed
ERROR [STREAM-OUT-/10.35.81.76:59902] 2018-12-06 13:57:54,179 StreamSession.java:593 - [Stream #ed464e90-f95e-11e8-9b44-7714c7874f55] Streaming error occurred on session with peer 10.35.81.76
java.io.IOException: Broken pipe
       at sun.nio.ch.FileDispatcherImpl.write0(Native Method) ~[na:1.8.0_191]
       at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47) ~[na:1.8.0_191]
       at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93) ~[na:1.8.0_191]
       at sun.nio.ch.IOUtil.write(IOUtil.java:51) ~[na:1.8.0_191]
       at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:471) ~[na:1.8.0_191]
       at org.apache.cassandra.io.util.BufferedDataOutputStreamPlus.doFlush(BufferedDataOutputStreamPlus.java:323) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.io.util.BufferedDataOutputStreamPlus.flush(BufferedDataOutputStreamPlus.java:331) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.ConnectionHandler$OutgoingMessageHandler.sendMessage(ConnectionHandler.java:409) [apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.ConnectionHandler$OutgoingMessageHandler.run(ConnectionHandler.java:388) [apache-cassandra-3.11.3.jar:3.11.3]
       at java.lang.Thread.run(Thread.java:748) [na:1.8.0_191]
INFO  [STREAM-INIT-/10.35.81.76:59928] 2018-12-06 14:00:08,400 StreamResultFuture.java:116 - [Stream #3d572210-f95f-11e8-bf2d-01149b1d085c ID#0] Creating new streaming plan for Bulk Load
INFO  [STREAM-INIT-/10.35.81.76:59928] 2018-12-06 14:00:08,401 StreamResultFuture.java:123 - [Stream #3d572210-f95f-11e8-bf2d-01149b1d085c, ID#0] Received streaming plan for Bulk Load
INFO  [STREAM-INIT-/10.35.81.76:59934] 2018-12-06 14:00:08,402 StreamResultFuture.java:123 - [Stream #3d572210-f95f-11e8-bf2d-01149b1d085c, ID#0] Received streaming plan for Bulk Load
INFO  [STREAM-IN-/10.35.81.76:59934] 2018-12-06 14:00:08,402 StreamResultFuture.java:173 - [Stream #3d572210-f95f-11e8-bf2d-01149b1d085c ID#0] Prepare completed. Receiving 3 files(3.610GiB), sending 0 files(0.000KiB)
ERROR [STREAM-IN-/10.35.81.76:59934] 2018-12-06 14:00:08,442 StreamSession.java:593 - [Stream #3d572210-f95f-11e8-bf2d-01149b1d085c] Streaming error occurred on session with peer 10.35.81.76
java.net.SocketException: End-of-stream reached
       at org.apache.cassandra.streaming.messages.StreamMessage.deserialize(StreamMessage.java:71) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at org.apache.cassandra.streaming.ConnectionHandler$IncomingMessageHandler.run(ConnectionHandler.java:311) ~[apache-cassandra-3.11.3.jar:3.11.3]
       at java.lang.Thread.run(Thread.java:748) [na:1.8.0_191]
INFO  [STREAM-IN-/10.35.81.76:59934] 2018-12-06 14:00:08,447 StreamResultFuture.java:187 - [Stream #3d572210-f95f-11e8-bf2d-01149b1d085c] Session with /10.35.81.76 is complete
WARN  [STREAM-IN-/10.35.81.76:59934] 2018-12-06 14:00:08,448 StreamResultFuture.java:214 - [Stream #3d572210-f95f-11e8-bf2d-01149b1d085c] Stream failed

So obviously some broken pipes errors and streams fail... but I am struggling to find out why, as no further details are shown.

I've examined the network connectivity between all hosts in the cluster and they can all reach each other at 9042 and 7000 ports.

Any suggestions would be highly appreciated !

--
Best regards
Ivan I. Iliev
System Administrator

Melexis Bulgaria Ltd.
2 Samokovsko shose Blvd.
1138 Sofia
Bulgaria

Mobile:+359 88 9221923
E-mail: 
iai@melexis.com

The contents of this e-mail are CONFIDENTIAL AND PROPRIETARY. Please read our disclaimer at http://www.melexis.com/mailpolicy.