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

Cassandra 3.0.18: BatchMessage.execute - 10x more on-heap allocations compared to 2.1.18

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Normal
    • Resolution: Duplicate
    • 3.0.23
    • Local/Other
    • None
    • Degradation - Resource Management
    • Normal
    • Normal
    • User Report
    • All
    • None

    Description

      In a 6 node loadtest cluster, we have been running with 2.1.18 a certain production-like workload constantly and sufficiently. After upgrading one node to 3.0.18 (remaining 5 still on 2.1.18 after we have seen that sort of regression described below), 3.0.18 is showing increased CPU usage, increase GC, high mutation stage pending tasks, dropped mutation messages ...

      Some spec. All 6 nodes equally sized:

      • Bare metal, 32 physical cores, 512G RAM
      • Xmx31G, G1, max pause millis = 2000ms
      • cassandra.yaml basically unchanged, thus same settings in regard to number of threads, compaction throttling etc.

      Following dashboard shows highlighted areas (CPU, suspension) with metrics for all 6 nodes and the one outlier being the node upgraded to Cassandra 3.0.18.

      Additionally we see a large increase on pending tasks in the mutation stage after the upgrade:

      And dropped mutation messages, also confirmed in the Cassandra log:

      INFO  [ScheduledTasks:1] 2019-11-15 08:24:24,780 MessagingService.java:1022 - MUTATION messages were dropped in last 5000 ms: 41552 for internal timeout and 0 for cross node timeout
INFO  [ScheduledTasks:1] 2019-11-15 08:24:25,157 StatusLogger.java:52 - Pool Name                    Active   Pending      Completed   Blocked  All Time Blocked
INFO  [ScheduledTasks:1] 2019-11-15 08:24:25,168 StatusLogger.java:56 - MutationStage                   256     81824     3360532756         0                 0

INFO  [ScheduledTasks:1] 2019-11-15 08:24:25,168 StatusLogger.java:56 - ViewMutationStage                 0         0              0         0                 0

INFO  [ScheduledTasks:1] 2019-11-15 08:24:25,168 StatusLogger.java:56 - ReadStage                         0         0       62862266         0                 0

INFO  [ScheduledTasks:1] 2019-11-15 08:24:25,169 StatusLogger.java:56 - RequestResponseStage              0         0     2176659856         0                 0

INFO  [ScheduledTasks:1] 2019-11-15 08:24:25,169 StatusLogger.java:56 - ReadRepairStage                   0         0              0         0                 0

INFO  [ScheduledTasks:1] 2019-11-15 08:24:25,169 StatusLogger.java:56 - CounterMutationStage              0         0              0         0                 0
...

      Judging from a 15min JFR session for both, 3.0.18 and 2.1.18 on a different node, high-level, it looks like the code path underneath BatchMessage.execute is producing ~ 10x more on-heap allocations in 3.0.18 compared to 2.1.18.

      Left => 3.0.18
      Right => 2.1.18

      JFRs zipped are exceeding the 60MB limit to directly attach to the ticket. I can upload them, if there is another destination available.

      Attachments

        1. screenshot-4.png
          13 kB
          Thomas Steinmaurer
        2. screenshot-3.png
          210 kB
          Thomas Steinmaurer
        3. screenshot-2.png
          220 kB
          Thomas Steinmaurer
        4. screenshot-1.png
          217 kB
          Thomas Steinmaurer
        5. mutation_stage.png
          27 kB
          Thomas Steinmaurer
        6. jfr_jmc_4-0-b2.png
          2.53 MB
          Michael Semb Wever
        7. jfr_jmc_4-0-b2_obj.png
          1.06 MB
          Michael Semb Wever
        8. jfr_jmc_3-11.png
          2.50 MB
          Michael Semb Wever
        9. jfr_jmc_3-11_obj.png
          1.12 MB
          Michael Semb Wever
        10. jfr_jmc_3-0.png
          2.44 MB
          Michael Semb Wever
        11. jfr_jmc_3-0_obj.png
          1.11 MB
          Michael Semb Wever
        12. jfr_jmc_3-0_obj_obj_alloc.png
          2.21 MB
          Michael Semb Wever
        13. jfr_jmc_2-1.png
          2.33 MB
          Michael Semb Wever
        14. jfr_jmc_2-1_obj.png
          1015 kB
          Michael Semb Wever
        15. jfr_allocations.png
          226 kB
          Thomas Steinmaurer
        16. dashboard.png
          286 kB
          Thomas Steinmaurer

        Issue Links

          duplicates

          Bug - A problem which impairs or prevents the functions of the product. CASSANDRA-16201 Reduce amount of allocations during batch statement execution

          • Normal -
          • Resolved
          relates to

          Bug - A problem which impairs or prevents the functions of the product. CASSANDRA-13929 BTree$Builder / io.netty.util.Recycler$Stack leaking memory

          • Normal -
          • Resolved

          Bug - A problem which impairs or prevents the functions of the product. CASSANDRA-16201 Reduce amount of allocations during batch statement execution

          • Normal -
          • Resolved

          Activity

            People

              Unassigned Unassigned
              tsteinmaurer Thomas Steinmaurer
              Votes:
              0 Vote for this issue
              Watchers:
              8 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: