cassandra-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Michał Szczygieł (JIRA) <j...@apache.org>
Subject [jira] [Commented] (CASSANDRA-12182) redundant StatusLogger print out when both dropped message and long GC event happen
Date Fri, 03 Nov 2017 23:08:02 GMT

    [ https://issues.apache.org/jira/browse/CASSANDRA-12182?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16238548#comment-16238548
] 

Michał Szczygieł commented on CASSANDRA-12182:
----------------------------------------------

You're right (obviously). Feel free to remove {{InMemoryAppender#getEvents}} from my latest
patch and replace it with direct field access. But please don't use previous patch, because
test would incorrectly fail when time ranges are not connected ({{Range.intersect}} would
throw {{IllegalArgumentException}} in such case). utests for the latest patch: [https://circleci.com/gh/mszczygiel/cassandra/4]


> redundant StatusLogger print out when both dropped message and long GC event happen
> -----------------------------------------------------------------------------------
>
>                 Key: CASSANDRA-12182
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-12182
>             Project: Cassandra
>          Issue Type: Bug
>            Reporter: Wei Deng
>            Assignee: Michał Szczygieł
>            Priority: Minor
>              Labels: lhf
>         Attachments: 12182-trunk.txt, 12182-trunk.txt, 12182-trunk.txt
>
>
> I was stress testing a C* 3.0 environment and it appears that when the CPU is running
low, HINT and MUTATION messages will start to get dropped, and the GC thread can also get
some really long-running GC, and I'd get some redundant log entries in system.log like the
following:
> {noformat}
> WARN  [Service Thread] 2016-07-12 22:48:45,748  GCInspector.java:282 - G1 Young Generation
GC in 522ms.  G1 Eden Space: 68157440 -> 0; G1 Old Gen: 3376113224 -> 3468387912; G1
Survivor Space: 24117248 -> 0; 
> INFO  [Service Thread] 2016-07-12 22:48:45,763  StatusLogger.java:52 - Pool Name    
               Active   Pending      Completed   Blocked  All Time Blocked
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,775  MessagingService.java:983 - MUTATION
messages were dropped in last 5000 ms: 419 for internal timeout and 0 for cross node timeout
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,776  MessagingService.java:983 - HINT messages
were dropped in last 5000 ms: 89 for internal timeout and 0 for cross node timeout
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,776  StatusLogger.java:52 - Pool Name  
                 Active   Pending      Completed   Blocked  All Time Blocked
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,798  StatusLogger.java:56 - MutationStage
                   32      4194       32997234         0                 0
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,798  StatusLogger.java:56 - ViewMutationStage
                0         0              0         0                 0
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,799  StatusLogger.java:56 - ReadStage  
                      0         0            940         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,800  StatusLogger.java:56 - MutationStage
                   32      4363       32997333         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,801  StatusLogger.java:56 - ViewMutationStage
                0         0              0         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,801  StatusLogger.java:56 - ReadStage    
                    0         0            940         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,802  StatusLogger.java:56 - RequestResponseStage
             0         0       11094437         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,802  StatusLogger.java:56 - ReadRepairStage
                  0         0              5         0                 0
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,803  StatusLogger.java:56 - RequestResponseStage
             4         0       11094509         0                 0
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,807  StatusLogger.java:56 - ReadRepairStage
                  0         0              5         0                 0
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,808  StatusLogger.java:56 - CounterMutationStage
             0         0              0         0                 0
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,809  StatusLogger.java:56 - MiscStage  
                      0         0              0         0                 0
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,809  StatusLogger.java:56 - CompactionExecutor
               2        62           1234         0                 0
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,810  StatusLogger.java:56 - MemtableReclaimMemory
            0         0             79         0                 0
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,810  StatusLogger.java:56 - PendingRangeCalculator
           0         0              3         0                 0
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,819  StatusLogger.java:56 - GossipStage
                      0         0           5214         0                 0
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,820  StatusLogger.java:56 - SecondaryIndexManagement
         0         0              3         0                 0
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,820  StatusLogger.java:56 - HintsDispatcher
                  1         2             36         0                 0
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,821  StatusLogger.java:56 - MigrationStage
                   0         0              0         0                 0
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,822  StatusLogger.java:56 - MemtablePostFlush
                1         3            115         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,830  StatusLogger.java:56 - CounterMutationStage
             0         0              0         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,831  StatusLogger.java:56 - MiscStage    
                    0         0              0         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,831  StatusLogger.java:56 - CompactionExecutor
               2        62           1234         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,832  StatusLogger.java:56 - MemtableReclaimMemory
            0         0             79         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,832  StatusLogger.java:56 - PendingRangeCalculator
           0         0              3         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,833  StatusLogger.java:56 - GossipStage  
                    0         0           5214         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,839  StatusLogger.java:56 - SecondaryIndexManagement
         0         0              3         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,840  StatusLogger.java:56 - HintsDispatcher
                  1         2             36         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,843  StatusLogger.java:56 - MigrationStage
                   0         0              0         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,844  StatusLogger.java:56 - MemtablePostFlush
                1         3            115         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,844  StatusLogger.java:56 - ValidationExecutor
               0         0              0         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,845  StatusLogger.java:56 - Sampler      
                    0         0              0         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,846  StatusLogger.java:56 - MemtableFlushWriter
              2         2             79         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,846  StatusLogger.java:56 - InternalResponseStage
            0         0        1978269         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,847  StatusLogger.java:56 - AntiEntropyStage
                 0         0              0         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,847  StatusLogger.java:56 - CacheCleanupExecutor
             0         0              0         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,848  StatusLogger.java:56 - Native-Transport-Requests
      128       133        5903870         8           1534827
> INFO  [Service Thread] 2016-07-12 22:48:45,848  StatusLogger.java:66 - CompactionManager
                2        18
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,870  StatusLogger.java:56 - ValidationExecutor
               0         0              0         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,872  StatusLogger.java:78 - MessagingService
               n/a      0/16
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,884  StatusLogger.java:56 - Sampler    
                      0         0              0         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,885  StatusLogger.java:88 - Cache Type   
                 Size                 Capacity               KeysToSave
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,885  StatusLogger.java:56 - MemtableFlushWriter
              2         2             79         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,886  StatusLogger.java:90 - KeyCache     
                14240                104857600                      all
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,887  StatusLogger.java:56 - InternalResponseStage
            0         0        1978269         0                 0
> INFO  [Service Thread] 2016-07-12 22:48:45,887  StatusLogger.java:96 - RowCache     
                    0                        0                      all
> INFO  [ScheduledTasks:1] 2016-07-12 22:48:45,888  StatusLogger.java:56 - AntiEntropyStage
                 0         0              0         0                 0
> {noformat}
> This makes the log entries harder to read. If we can make StatusLogger code to be single
entry and subsequent call will just give up and print out a log like "StatusLogger is busy",
that should help to make the log clean.



--
This message was sent by Atlassian JIRA
(v6.4.14#64029)

---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@cassandra.apache.org
For additional commands, e-mail: commits-help@cassandra.apache.org


Mime
View raw message