Uploaded image for project: 'Cassandra'
  1. Cassandra
  2. CASSANDRA-15276

SSTableLoader failes if loading large table

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Triage Needed
    • Normal
    • Resolution: Unresolved
    • None
    • Legacy/Tools
    • None
    • All
    • None

    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 

       

      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

       

      I suspected that sstableloader may ignore parameter streaming_keep_alive_period_in_secs, because streams seems to consistently fails after short aproximately 1hour interval.

       

      Attachments

        Activity

          People

            Unassigned Unassigned
            elcomtik Roman Danko
            Votes:
            1 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

              Created:
              Updated: