You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cassandra.apache.org by "Alex Efimov (Jira)" <ji...@apache.org> on 2019/09/04 14:05:00 UTC
[jira] [Commented] (CASSANDRA-15276) SSTableLoader failes if
loading large table
[ https://issues.apache.org/jira/browse/CASSANDRA-15276?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16922516#comment-16922516 ]
Alex Efimov commented on CASSANDRA-15276:
-----------------------------------------
I can confirm the issue. And it happens on quite a small amount of data (50 Mb in my case.)
{code:java}
progress: [/172.0.30.173]0:1/2 6 % total: 6% 228.754KiB/s (avg: 228.754KiB/s)
progress: [/172.0.30.173]0:1/2 26 % total: 26% 531.535KiB/s (avg: 397.567KiB/s)
progress: [/172.0.30.173]0:1/2 46 % total: 46% 426.074KiB/s (avg: 409.262KiB/s)
ERROR 13:56:16,649 [Stream #a10affb0-cf1b-11e9-b329-0f37ec112982] Streaming error occurred on session with peer 172.0.30.173
java.net.SocketException: End-of-stream reached
at org.apache.cassandra.streaming.messages.StreamMessage.deserialize(StreamMessage.java:71) ~[apache-cassandra-3.11.4.jar:3.11.4]
at org.apache.cassandra.streaming.ConnectionHandler$IncomingMessageHandler.run(ConnectionHandler.java:311) ~[apache-cassandra-3.11.4.jar:3.11.4]
at java.lang.Thread.run(Thread.java:748) [na:1.8.0_212]
progress: [/172.0.30.173]0:1/2 66 % total: 66% 462.619KiB/s (avg: 423.893KiB/s)
progress: [/172.0.30.173]0:1/2 85 % total: 85% 514.001KiB/s (avg: 441.729KiB/s)
progress: [/172.0.30.173]0:2/2 100% total: 100% 451.664KiB/s (avg: 443.107KiB/s)
progress: [/172.0.30.173]0:2/2 100% total: 100% 0.000KiB/s (avg: 443.098KiB/s)
WARN 13:57:05,525 [Stream #a10affb0-cf1b-11e9-b329-0f37ec112982] Stream failed
Streaming to the following hosts failed:
[/172.0.30.173]
java.util.concurrent.ExecutionException: org.apache.cassandra.streaming.StreamException: Stream failed
at com.google.common.util.concurrent.AbstractFuture$Sync.getValue(AbstractFuture.java:299)
at com.google.common.util.concurrent.AbstractFuture$Sync.get(AbstractFuture.java:286)
at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:116)
at org.apache.cassandra.tools.BulkLoader.load(BulkLoader.java:98)
at org.apache.cassandra.tools.BulkLoader.main(BulkLoader.java:48)
Caused by: org.apache.cassandra.streaming.StreamException: Stream failed
at org.apache.cassandra.streaming.management.StreamEventJMXNotifier.onFailure(StreamEventJMXNotifier.java:88)
at com.google.common.util.concurrent.Futures$6.run(Futures.java:1310)
at com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute(MoreExecutors.java:457)
at com.google.common.util.concurrent.ExecutionList.executeListener(ExecutionList.java:156)
at com.google.common.util.concurrent.ExecutionList.execute(ExecutionList.java:145)
at com.google.common.util.concurrent.AbstractFuture.setException(AbstractFuture.java:202)
at org.apache.cassandra.streaming.StreamResultFuture.maybeComplete(StreamResultFuture.java:215)
at org.apache.cassandra.streaming.StreamResultFuture.handleSessionComplete(StreamResultFuture.java:191)
at org.apache.cassandra.streaming.StreamSession.closeSession(StreamSession.java:481)
at org.apache.cassandra.streaming.StreamSession.onError(StreamSession.java:571)
at org.apache.cassandra.streaming.ConnectionHandler$IncomingMessageHandler.run(ConnectionHandler.java:324)
at java.lang.Thread.run(Thread.java:748)
Exception in thread "main" org.apache.cassandra.tools.BulkLoadException: java.util.concurrent.ExecutionException: org.apache.cassandra.streaming.StreamException: Stream failed
at org.apache.cassandra.tools.BulkLoader.load(BulkLoader.java:114)
at org.apache.cassandra.tools.BulkLoader.main(BulkLoader.java:48)
Caused by: java.util.concurrent.ExecutionException: org.apache.cassandra.streaming.StreamException: Stream failed
at com.google.common.util.concurrent.AbstractFuture$Sync.getValue(AbstractFuture.java:299)
at com.google.common.util.concurrent.AbstractFuture$Sync.get(AbstractFuture.java:286)
at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:116)
at org.apache.cassandra.tools.BulkLoader.load(BulkLoader.java:98)
... 1 more
Caused by: org.apache.cassandra.streaming.StreamException: Stream failed
at org.apache.cassandra.streaming.management.StreamEventJMXNotifier.onFailure(StreamEventJMXNotifier.java:88)
at com.google.common.util.concurrent.Futures$6.run(Futures.java:1310)
at com.google.common.util.concurrent.MoreExecutors$DirectExecutor.execute(MoreExecutors.java:457)
at com.google.common.util.concurrent.ExecutionList.executeListener(ExecutionList.java:156)
at com.google.common.util.concurrent.ExecutionList.execute(ExecutionList.java:145)
at com.google.common.util.concurrent.AbstractFuture.setException(AbstractFuture.java:202)
at org.apache.cassandra.streaming.StreamResultFuture.maybeComplete(StreamResultFuture.java:215)
at org.apache.cassandra.streaming.StreamResultFuture.handleSessionComplete(StreamResultFuture.java:191)
at org.apache.cassandra.streaming.StreamSession.closeSession(StreamSession.java:481)
at org.apache.cassandra.streaming.StreamSession.onError(StreamSession.java:571)
at org.apache.cassandra.streaming.ConnectionHandler$IncomingMessageHandler.run(ConnectionHandler.java:324)
at java.lang.Thread.run(Thread.java:748)
{code}
> 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
(v8.3.2#803003)
---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@cassandra.apache.org
For additional commands, e-mail: commits-help@cassandra.apache.org