Wei Deng created CASSANDRA-12182:
------------------------------------
Summary: 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
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)
