You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cassandra.apache.org by "Roman Danko (JIRA)" <ji...@apache.org> on 2019/08/13 11:33:00 UTC
[jira] [Updated] (CASSANDRA-15276) SSTableLoader failes if loading
large table
[ https://issues.apache.org/jira/browse/CASSANDRA-15276?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Roman Danko updated CASSANDRA-15276:
------------------------------------
Description:
I'm trying to restore backups created by Opscenter. I restore to fresh cluster, so it is necessary to use sstableloader. Backups are created from DSE cluster version 6.7.3, restored to 6.7.4. Restore procedure hangs on large tables(190GB).
Cluster is tunned and configured to withstand higher load, than normaly. Maintanance features like nodesync and compactions are throttled to minimum. All configuration changes are:
* disabled noderepair
* nodesync: rate_in_kb: 64 #originaly 8192
* compaction_throughput_mb_per_sec: 1
* concurrent_compactors: 1
* memtable_allocation_type: offheap_objects
* memtable_space_in_mb: 2048
* max_heapsize_mb: 32786
* streaming_keep_alive_period_in_secs: 72000
* streaming_socket_timeout_in_ms: 86400000 #tested, but dse 6.7.4 won't start up with this setting
* dse_cassandra_streaming_connections_per_host: 3 #originaly 1
Logs from system.log
{code:java}
INFO [STREAM-INIT-/10.132.16.10:38620] 2019-08-12 14:16:51,722 StreamResultFuture.java:129 - [Stream #ccaadb30-bd0b-11e9-b05b-75f1a4f2840d, ID#0] Received streaming plan for Bulk Load
INFO [STREAM-IN-/10.132.16.10:38620] 2019-08-12 14:16:51,741 StreamResultFuture.java:194 - [Stream #ccaadb30-bd0b-11e9-b05b-75f1a4f2840d ID#0] Prepare completed. Receiving 17 files(191.218GiB), sending 0 files(0.000KiB)
ERROR [STREAM-IN-/10.132.16.10:38620] 2019-08-12 14:18:00,640 StreamSession.java:650 - [Stream #ccaadb30-bd0b-11e9-b05b-75f1a4f2840d] Streaming error occurred on session with peer 10.132.16.10
java.net.SocketException: End-of-stream reached
at org.apache.cassandra.streaming.messages.StreamMessage.deserialize(StreamMessage.java:107)
at org.apache.cassandra.streaming.ConnectionHandler$IncomingMessageHandler.run(ConnectionHandler.java:318)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(Thread.java:748)
INFO [STREAM-IN-/10.132.16.10:38620] 2019-08-12 14:18:00,648 StreamResultFuture.java:208 - [Stream #ccaadb30-bd0b-11e9-b05b-75f1a4f2840d] Session with /10.132.16.10 is complete
WARN [STREAM-IN-/10.132.16.10:38620] 2019-08-12 14:18:00,650 StreamResultFuture.java:235 - [Stream #ccaadb30-bd0b-11e9-b05b-75f1a4f2840d] Stream failed
INFO [STREAM-INIT-/10.132.16.8:44336] 2019-08-12 14:21:48,227 StreamResultFuture.java:122 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7 ID#0] Creating new streaming plan for Bulk Load
INFO [STREAM-INIT-/10.132.16.8:44336] 2019-08-12 14:21:48,229 StreamResultFuture.java:129 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7, ID#0] Received streaming plan for Bulk Load
INFO [STREAM-INIT-/10.132.16.8:44342] 2019-08-12 14:21:48,230 StreamResultFuture.java:129 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7, ID#0] Received streaming plan for Bulk Load
INFO [STREAM-IN-/10.132.16.8:44342] 2019-08-12 14:21:48,243 StreamResultFuture.java:194 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7 ID#0] Prepare completed. Receiving 13 files(185.643GiB), sending 0 files(0.000KiB)
INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 14:24:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 0B (0B/s), 0% was inconsistent.
INFO [STREAM-INIT-/10.132.16.9:48802] 2019-08-12 14:27:12,562 StreamResultFuture.java:122 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08 ID#0] Creating new streaming plan for Bulk Load
INFO [STREAM-INIT-/10.132.16.9:48802] 2019-08-12 14:27:12,564 StreamResultFuture.java:129 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08, ID#0] Received streaming plan for Bulk Load
INFO [STREAM-INIT-/10.132.16.9:48806] 2019-08-12 14:27:12,565 StreamResultFuture.java:129 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08, ID#0] Received streaming plan for Bulk Load
INFO [STREAM-IN-/10.132.16.9:48806] 2019-08-12 14:27:12,582 StreamResultFuture.java:194 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08 ID#0] Prepare completed. Receiving 15 files(188.633GiB), sending 0 files(0.000KiB)
INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 14:34:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 29MB (50kB/s), 0% was inconsistent.
INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 14:44:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 98MB (168kB/s), 0% was inconsistent.
INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 14:54:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 20MB (35kB/s), 0% was inconsistent.
INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 15:04:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 0B (0B/s), 0% was inconsistent.
ERROR [STREAM-IN-/10.132.16.8:44342] 2019-08-12 15:14:36,634 StreamSession.java:650 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7] Streaming error occurred on session with peer 10.132.16.8
java.net.SocketException: End-of-stream reached
at org.apache.cassandra.streaming.messages.StreamMessage.deserialize(StreamMessage.java:107)
at org.apache.cassandra.streaming.ConnectionHandler$IncomingMessageHandler.run(ConnectionHandler.java:318)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(Thread.java:748)
INFO [STREAM-IN-/10.132.16.8:44342] 2019-08-12 15:14:36,640 StreamResultFuture.java:208 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7] Session with /10.132.16.8 is complete
WARN [STREAM-IN-/10.132.16.8:44342] 2019-08-12 15:14:36,641 StreamResultFuture.java:235 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7] Stream failed
INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 15:14:42,739 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 37MB (63kB/s), 0% was inconsistent.
INFO [GCInspector:1] 2019-08-12 15:21:11,323 GCInspector.java:313 - G1 Young Generation GC in 201ms. G1 Old Gen: 3516715984 -> 3535248344; G1 Survivor Space: 394264576 -> 427819008; G1 Eden Space: 20216545280 -> 0
INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 15:24:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 59MB (100kB/s), 0% was inconsistent.
INFO [GCInspector:1] 2019-08-12 15:27:41,343 GCInspector.java:313 - G1 Young Generation GC in 232ms. G1 Old Gen: 3562767320 -> 3585796048; G1 Survivor Space: 503316480 -> 545259520; G1 Eden Space: 20107493376 -> 0
INFO [GCInspector:1] 2019-08-12 15:31:55,093 GCInspector.java:313 - G1 Young Generation GC in 238ms. G1 Old Gen: 3597089752 -> 3617499096; G1 Survivor Space: 587202560 -> 612368384; G1 Eden Space: 20023607296 -> 0
INFO [GCInspector:1] 2019-08-12 15:34:05,240 GCInspector.java:313 - G1 Young Generation GC in 234ms. G1 Old Gen: 3617499096 -> 3632501208; G1 Survivor Space: 612368384 -> 662700032; G1 Eden Space: 19998441472 -> 0
INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 15:34:42,739 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 24MB (42kB/s), 0% was inconsistent.
ERROR [STREAM-IN-/10.132.16.9:48806] 2019-08-12 15:35:32,089 StreamSession.java:650 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08] Streaming error occurred on session with peer 10.132.16.9
java.net.SocketException: End-of-stream reached
at org.apache.cassandra.streaming.messages.StreamMessage.deserialize(StreamMessage.java:107)
at org.apache.cassandra.streaming.ConnectionHandler$IncomingMessageHandler.run(ConnectionHandler.java:318)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(Thread.java:748)
INFO [STREAM-IN-/10.132.16.9:48806] 2019-08-12 15:35:32,094 StreamResultFuture.java:208 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08] Session with /10.132.16.9 is complete
WARN [STREAM-IN-/10.132.16.9:48806] 2019-08-12 15:35:32,095 StreamResultFuture.java:235 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08] Stream failed
{code}
I suspected that sstableloader may ignore parameter streaming_keep_alive_period_in_secs, because streams seems to consistently fails after short aproximately 1hour interval.
was:
I'm trying to restore backups created by Opscenter. I restore to fresh cluster, so it is necessary to use sstableloader. Backups are created from DSE cluster version 6.7.3, restored to 6.7.4. Restore procedure hangs on large tables(190GB).
Cluster is tunned and configured to withstand higher load, than normaly. Maintanance features like nodesync and compactions are throttled to minimum. All configuration changes are:
*
disabled noderepair
*
nodesync: rate_in_kb: 64 #originaly 8192
*
compaction_throughput_mb_per_sec: 1
*
concurrent_compactors: 1
*
memtable_allocation_type: offheap_objects
*
memtable_space_in_mb: 2048
*
max_heapsize_mb: 32786
*
streaming_keep_alive_period_in_secs: 72000
*
streaming_socket_timeout_in_ms: 86400000 #tested, but dse 6.7.4 won't start up with this setting
*
dse_cassandra_streaming_connections_per_host: 3 #originaly 1
Logs from system.log
{code:java}
INFO [STREAM-INIT-/10.132.16.10:38620] 2019-08-12 14:16:51,722 StreamResultFuture.java:129 - [Stream #ccaadb30-bd0b-11e9-b05b-75f1a4f2840d, ID#0] Received streaming plan for Bulk Load
INFO [STREAM-IN-/10.132.16.10:38620] 2019-08-12 14:16:51,741 StreamResultFuture.java:194 - [Stream #ccaadb30-bd0b-11e9-b05b-75f1a4f2840d ID#0] Prepare completed. Receiving 17 files(191.218GiB), sending 0 files(0.000KiB)
ERROR [STREAM-IN-/10.132.16.10:38620] 2019-08-12 14:18:00,640 StreamSession.java:650 - [Stream #ccaadb30-bd0b-11e9-b05b-75f1a4f2840d] Streaming error occurred on session with peer 10.132.16.10
java.net.SocketException: End-of-stream reached
at org.apache.cassandra.streaming.messages.StreamMessage.deserialize(StreamMessage.java:107)
at org.apache.cassandra.streaming.ConnectionHandler$IncomingMessageHandler.run(ConnectionHandler.java:318)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(Thread.java:748)
INFO [STREAM-IN-/10.132.16.10:38620] 2019-08-12 14:18:00,648 StreamResultFuture.java:208 - [Stream #ccaadb30-bd0b-11e9-b05b-75f1a4f2840d] Session with /10.132.16.10 is complete
WARN [STREAM-IN-/10.132.16.10:38620] 2019-08-12 14:18:00,650 StreamResultFuture.java:235 - [Stream #ccaadb30-bd0b-11e9-b05b-75f1a4f2840d] Stream failed
INFO [STREAM-INIT-/10.132.16.8:44336] 2019-08-12 14:21:48,227 StreamResultFuture.java:122 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7 ID#0] Creating new streaming plan for Bulk Load
INFO [STREAM-INIT-/10.132.16.8:44336] 2019-08-12 14:21:48,229 StreamResultFuture.java:129 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7, ID#0] Received streaming plan for Bulk Load
INFO [STREAM-INIT-/10.132.16.8:44342] 2019-08-12 14:21:48,230 StreamResultFuture.java:129 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7, ID#0] Received streaming plan for Bulk Load
INFO [STREAM-IN-/10.132.16.8:44342] 2019-08-12 14:21:48,243 StreamResultFuture.java:194 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7 ID#0] Prepare completed. Receiving 13 files(185.643GiB), sending 0 files(0.000KiB)
INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 14:24:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 0B (0B/s), 0% was inconsistent.
INFO [STREAM-INIT-/10.132.16.9:48802] 2019-08-12 14:27:12,562 StreamResultFuture.java:122 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08 ID#0] Creating new streaming plan for Bulk Load
INFO [STREAM-INIT-/10.132.16.9:48802] 2019-08-12 14:27:12,564 StreamResultFuture.java:129 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08, ID#0] Received streaming plan for Bulk Load
INFO [STREAM-INIT-/10.132.16.9:48806] 2019-08-12 14:27:12,565 StreamResultFuture.java:129 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08, ID#0] Received streaming plan for Bulk Load
INFO [STREAM-IN-/10.132.16.9:48806] 2019-08-12 14:27:12,582 StreamResultFuture.java:194 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08 ID#0] Prepare completed. Receiving 15 files(188.633GiB), sending 0 files(0.000KiB)
INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 14:34:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 29MB (50kB/s), 0% was inconsistent.
INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 14:44:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 98MB (168kB/s), 0% was inconsistent.
INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 14:54:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 20MB (35kB/s), 0% was inconsistent.
INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 15:04:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 0B (0B/s), 0% was inconsistent.
ERROR [STREAM-IN-/10.132.16.8:44342] 2019-08-12 15:14:36,634 StreamSession.java:650 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7] Streaming error occurred on session with peer 10.132.16.8
java.net.SocketException: End-of-stream reached
at org.apache.cassandra.streaming.messages.StreamMessage.deserialize(StreamMessage.java:107)
at org.apache.cassandra.streaming.ConnectionHandler$IncomingMessageHandler.run(ConnectionHandler.java:318)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(Thread.java:748)
INFO [STREAM-IN-/10.132.16.8:44342] 2019-08-12 15:14:36,640 StreamResultFuture.java:208 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7] Session with /10.132.16.8 is complete
WARN [STREAM-IN-/10.132.16.8:44342] 2019-08-12 15:14:36,641 StreamResultFuture.java:235 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7] Stream failed
INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 15:14:42,739 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 37MB (63kB/s), 0% was inconsistent.
INFO [GCInspector:1] 2019-08-12 15:21:11,323 GCInspector.java:313 - G1 Young Generation GC in 201ms. G1 Old Gen: 3516715984 -> 3535248344; G1 Survivor Space: 394264576 -> 427819008; G1 Eden Space: 20216545280 -> 0
INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 15:24:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 59MB (100kB/s), 0% was inconsistent.
INFO [GCInspector:1] 2019-08-12 15:27:41,343 GCInspector.java:313 - G1 Young Generation GC in 232ms. G1 Old Gen: 3562767320 -> 3585796048; G1 Survivor Space: 503316480 -> 545259520; G1 Eden Space: 20107493376 -> 0
INFO [GCInspector:1] 2019-08-12 15:31:55,093 GCInspector.java:313 - G1 Young Generation GC in 238ms. G1 Old Gen: 3597089752 -> 3617499096; G1 Survivor Space: 587202560 -> 612368384; G1 Eden Space: 20023607296 -> 0
INFO [GCInspector:1] 2019-08-12 15:34:05,240 GCInspector.java:313 - G1 Young Generation GC in 234ms. G1 Old Gen: 3617499096 -> 3632501208; G1 Survivor Space: 612368384 -> 662700032; G1 Eden Space: 19998441472 -> 0
INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 15:34:42,739 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 24MB (42kB/s), 0% was inconsistent.
ERROR [STREAM-IN-/10.132.16.9:48806] 2019-08-12 15:35:32,089 StreamSession.java:650 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08] Streaming error occurred on session with peer 10.132.16.9
java.net.SocketException: End-of-stream reached
at org.apache.cassandra.streaming.messages.StreamMessage.deserialize(StreamMessage.java:107)
at org.apache.cassandra.streaming.ConnectionHandler$IncomingMessageHandler.run(ConnectionHandler.java:318)
at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
at java.lang.Thread.run(Thread.java:748)
INFO [STREAM-IN-/10.132.16.9:48806] 2019-08-12 15:35:32,094 StreamResultFuture.java:208 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08] Session with /10.132.16.9 is complete
WARN [STREAM-IN-/10.132.16.9:48806] 2019-08-12 15:35:32,095 StreamResultFuture.java:235 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08] Stream failed
{code}
I suspected that sstableloader may ignore parameter streaming_keep_alive_period_in_secs, because streams seems to consistently fails after short aproximately 1hour interval.
> SSTableLoader failes if loading large table
> -------------------------------------------
>
> Key: CASSANDRA-15276
> URL: https://issues.apache.org/jira/browse/CASSANDRA-15276
> Project: Cassandra
> Issue Type: Bug
> Components: Legacy/Tools
> Reporter: Roman Danko
> Priority: Normal
>
> I'm trying to restore backups created by Opscenter. I restore to fresh cluster, so it is necessary to use sstableloader. Backups are created from DSE cluster version 6.7.3, restored to 6.7.4. Restore procedure hangs on large tables(190GB).
> Cluster is tunned and configured to withstand higher load, than normaly. Maintanance features like nodesync and compactions are throttled to minimum. All configuration changes are:
> * disabled noderepair
> * nodesync: rate_in_kb: 64 #originaly 8192
> * compaction_throughput_mb_per_sec: 1
> * concurrent_compactors: 1
> * memtable_allocation_type: offheap_objects
> * memtable_space_in_mb: 2048
> * max_heapsize_mb: 32786
> * streaming_keep_alive_period_in_secs: 72000
> * streaming_socket_timeout_in_ms: 86400000 #tested, but dse 6.7.4 won't start up with this setting
> * dse_cassandra_streaming_connections_per_host: 3 #originaly 1
> Logs from system.log
>
> {code:java}
> INFO [STREAM-INIT-/10.132.16.10:38620] 2019-08-12 14:16:51,722 StreamResultFuture.java:129 - [Stream #ccaadb30-bd0b-11e9-b05b-75f1a4f2840d, ID#0] Received streaming plan for Bulk Load
> INFO [STREAM-IN-/10.132.16.10:38620] 2019-08-12 14:16:51,741 StreamResultFuture.java:194 - [Stream #ccaadb30-bd0b-11e9-b05b-75f1a4f2840d ID#0] Prepare completed. Receiving 17 files(191.218GiB), sending 0 files(0.000KiB)
> ERROR [STREAM-IN-/10.132.16.10:38620] 2019-08-12 14:18:00,640 StreamSession.java:650 - [Stream #ccaadb30-bd0b-11e9-b05b-75f1a4f2840d] Streaming error occurred on session with peer 10.132.16.10
> java.net.SocketException: End-of-stream reached
> at org.apache.cassandra.streaming.messages.StreamMessage.deserialize(StreamMessage.java:107)
> at org.apache.cassandra.streaming.ConnectionHandler$IncomingMessageHandler.run(ConnectionHandler.java:318)
> at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
> at java.lang.Thread.run(Thread.java:748)
> INFO [STREAM-IN-/10.132.16.10:38620] 2019-08-12 14:18:00,648 StreamResultFuture.java:208 - [Stream #ccaadb30-bd0b-11e9-b05b-75f1a4f2840d] Session with /10.132.16.10 is complete
> WARN [STREAM-IN-/10.132.16.10:38620] 2019-08-12 14:18:00,650 StreamResultFuture.java:235 - [Stream #ccaadb30-bd0b-11e9-b05b-75f1a4f2840d] Stream failed
> INFO [STREAM-INIT-/10.132.16.8:44336] 2019-08-12 14:21:48,227 StreamResultFuture.java:122 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7 ID#0] Creating new streaming plan for Bulk Load
> INFO [STREAM-INIT-/10.132.16.8:44336] 2019-08-12 14:21:48,229 StreamResultFuture.java:129 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7, ID#0] Received streaming plan for Bulk Load
> INFO [STREAM-INIT-/10.132.16.8:44342] 2019-08-12 14:21:48,230 StreamResultFuture.java:129 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7, ID#0] Received streaming plan for Bulk Load
> INFO [STREAM-IN-/10.132.16.8:44342] 2019-08-12 14:21:48,243 StreamResultFuture.java:194 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7 ID#0] Prepare completed. Receiving 13 files(185.643GiB), sending 0 files(0.000KiB)
> INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 14:24:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 0B (0B/s), 0% was inconsistent.
> INFO [STREAM-INIT-/10.132.16.9:48802] 2019-08-12 14:27:12,562 StreamResultFuture.java:122 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08 ID#0] Creating new streaming plan for Bulk Load
> INFO [STREAM-INIT-/10.132.16.9:48802] 2019-08-12 14:27:12,564 StreamResultFuture.java:129 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08, ID#0] Received streaming plan for Bulk Load
> INFO [STREAM-INIT-/10.132.16.9:48806] 2019-08-12 14:27:12,565 StreamResultFuture.java:129 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08, ID#0] Received streaming plan for Bulk Load
> INFO [STREAM-IN-/10.132.16.9:48806] 2019-08-12 14:27:12,582 StreamResultFuture.java:194 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08 ID#0] Prepare completed. Receiving 15 files(188.633GiB), sending 0 files(0.000KiB)
> INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 14:34:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 29MB (50kB/s), 0% was inconsistent.
> INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 14:44:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 98MB (168kB/s), 0% was inconsistent.
> INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 14:54:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 20MB (35kB/s), 0% was inconsistent.
> INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 15:04:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 0B (0B/s), 0% was inconsistent.
> ERROR [STREAM-IN-/10.132.16.8:44342] 2019-08-12 15:14:36,634 StreamSession.java:650 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7] Streaming error occurred on session with peer 10.132.16.8
> java.net.SocketException: End-of-stream reached
> at org.apache.cassandra.streaming.messages.StreamMessage.deserialize(StreamMessage.java:107)
> at org.apache.cassandra.streaming.ConnectionHandler$IncomingMessageHandler.run(ConnectionHandler.java:318)
> at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
> at java.lang.Thread.run(Thread.java:748)
> INFO [STREAM-IN-/10.132.16.8:44342] 2019-08-12 15:14:36,640 StreamResultFuture.java:208 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7] Session with /10.132.16.8 is complete
> WARN [STREAM-IN-/10.132.16.8:44342] 2019-08-12 15:14:36,641 StreamResultFuture.java:235 - [Stream #7dfbc520-bd0c-11e9-9cf8-d3315f3fffd7] Stream failed
> INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 15:14:42,739 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 37MB (63kB/s), 0% was inconsistent.
> INFO [GCInspector:1] 2019-08-12 15:21:11,323 GCInspector.java:313 - G1 Young Generation GC in 201ms. G1 Old Gen: 3516715984 -> 3535248344; G1 Survivor Space: 394264576 -> 427819008; G1 Eden Space: 20216545280 -> 0
> INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 15:24:42,740 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 59MB (100kB/s), 0% was inconsistent.
> INFO [GCInspector:1] 2019-08-12 15:27:41,343 GCInspector.java:313 - G1 Young Generation GC in 232ms. G1 Old Gen: 3562767320 -> 3585796048; G1 Survivor Space: 503316480 -> 545259520; G1 Eden Space: 20107493376 -> 0
> INFO [GCInspector:1] 2019-08-12 15:31:55,093 GCInspector.java:313 - G1 Young Generation GC in 238ms. G1 Old Gen: 3597089752 -> 3617499096; G1 Survivor Space: 587202560 -> 612368384; G1 Eden Space: 20023607296 -> 0
> INFO [GCInspector:1] 2019-08-12 15:34:05,240 GCInspector.java:313 - G1 Young Generation GC in 234ms. G1 Old Gen: 3617499096 -> 3632501208; G1 Survivor Space: 612368384 -> 662700032; G1 Eden Space: 19998441472 -> 0
> INFO [NodeSyncMaintenanceTasks:1] 2019-08-12 15:34:42,739 NodeSyncMaintenanceTasks.java:172 - In last 10m: validated 24MB (42kB/s), 0% was inconsistent.
> ERROR [STREAM-IN-/10.132.16.9:48806] 2019-08-12 15:35:32,089 StreamSession.java:650 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08] Streaming error occurred on session with peer 10.132.16.9
> java.net.SocketException: End-of-stream reached
> at org.apache.cassandra.streaming.messages.StreamMessage.deserialize(StreamMessage.java:107)
> at org.apache.cassandra.streaming.ConnectionHandler$IncomingMessageHandler.run(ConnectionHandler.java:318)
> at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
> at java.lang.Thread.run(Thread.java:748)
> INFO [STREAM-IN-/10.132.16.9:48806] 2019-08-12 15:35:32,094 StreamResultFuture.java:208 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08] Session with /10.132.16.9 is complete
> WARN [STREAM-IN-/10.132.16.9:48806] 2019-08-12 15:35:32,095 StreamResultFuture.java:235 - [Stream #3f501c30-bd0d-11e9-9641-6d81d6b3fb08] Stream failed
> {code}
>
> I suspected that sstableloader may ignore parameter streaming_keep_alive_period_in_secs, because streams seems to consistently fails after short aproximately 1hour interval.
>
--
This message was sent by Atlassian JIRA
(v7.6.14#76016)
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@cassandra.apache.org
For additional commands, e-mail: commits-help@cassandra.apache.org