You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cassandra.apache.org by "Sylvain Lebresne (JIRA)" <ji...@apache.org> on 2016/07/15 14:17:20 UTC
[jira] [Updated] (CASSANDRA-12182) redundant StatusLogger print out
when both dropped message and long GC event happen
[ https://issues.apache.org/jira/browse/CASSANDRA-12182?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Sylvain Lebresne updated CASSANDRA-12182:
-----------------------------------------
Labels: lhf (was: )
> 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
> Priority: Minor
> Labels: lhf
>
> 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.3.4#6332)