cassandra-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Marco Gasparini <marco.gaspar...@competitoor.com>
Subject too many logDroppedMessages and StatusLogger
Date Fri, 08 Mar 2019 08:27:16 GMT
Hi all,

I cannot understand why I get the following logs, they appear every day at
not fixed period of time. I saw them every 2 minutes or every 10 seconds, I
cannot find any pattern.
I took this very example here during an heavy workload of writes and reads
but I get them also during a very little workload and without any active
compaction/repair/streaming process and no high cpu/memory/iowait usage.

2019-03-08 01:49:47,868 INFO  [ScheduledTasks:1] MessagingService.java:1246
> logDroppedMessages READ messages were dropped in last 5000 ms: 0 internal
> and 1 cross node. Mean internal dropped latency: 6357 ms and Mean
> cross-node dropped latency: 6556 ms
> 2019-03-08 01:49:47,868 INFO  [ScheduledTasks:1] StatusLogger.java:47 log
> Pool Name                    Active   Pending      Completed   Blocked  All
> Time Blocked
> 2019-03-08 01:49:47,870 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> MutationStage                     0         0       17641121         0
>            0
> 2019-03-08 01:49:47,870 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> ViewMutationStage                 0         0              0         0
>            0
> 2019-03-08 01:49:47,870 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> ReadStage                         0         0        6851090         0
>            0
> 2019-03-08 01:49:47,870 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> RequestResponseStage              0         0       13646587         0
>            0
> 2019-03-08 01:49:47,870 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> ReadRepairStage                   0         0         352884         0
>            0
> 2019-03-08 01:49:47,870 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> CounterMutationStage              0         0              0         0
>            0
> 2019-03-08 01:49:47,870 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> MiscStage                         0         0              0         0
>            0
> 2019-03-08 01:49:47,870 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> CompactionExecutor                0         0         882478         0
>            0
> 2019-03-08 01:49:47,871 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> MemtableReclaimMemory             0         0           4101         0
>            0
> 2019-03-08 01:49:47,871 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> PendingRangeCalculator            0         0              7         0
>            0
> 2019-03-08 01:49:47,871 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> GossipStage                       0         0        4399705         0
>            0
> 2019-03-08 01:49:47,871 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> SecondaryIndexManagement          0         0              0         0
>            0
> 2019-03-08 01:49:47,871 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> HintsDispatcher                   0         0           2165         0
>            0
> 2019-03-08 01:49:47,871 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> MigrationStage                    0         0             50         0
>            0
> 2019-03-08 01:49:47,871 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> MemtablePostFlush                 0         0           4393         0
>            0
> 2019-03-08 01:49:47,872 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> PerDiskMemtableFlushWriter_0         0         0           4097         0
>                0
> 2019-03-08 01:49:47,872 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> ValidationExecutor                0         0           1565         0
>            0
> 2019-03-08 01:49:47,872 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> Sampler                           0         0              0         0
>            0
> 2019-03-08 01:49:47,872 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> MemtableFlushWriter               0         0           4101         0
>            0
> 2019-03-08 01:49:47,872 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> InternalResponseStage             0         0         121813         0
>            0
> 2019-03-08 01:49:47,872 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> AntiEntropyStage                  0         0           6997         0
>            0
> 2019-03-08 01:49:47,873 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> CacheCleanupExecutor              0         0             33         0
>            0
> 2019-03-08 01:49:47,873 INFO  [ScheduledTasks:1] StatusLogger.java:51 log
> Native-Transport-Requests         4         0      364526951         0
>            0
> 2019-03-08 01:49:47,873 INFO  [ScheduledTasks:1] StatusLogger.java:61 log
> CompactionManager                 0         0
> 2019-03-08 01:49:47,873 INFO  [ScheduledTasks:1] StatusLogger.java:73 log
> MessagingService                n/a       2/0
> 2019-03-08 01:49:47,873 INFO  [ScheduledTasks:1] StatusLogger.java:83 log
> Cache Type                     Size                 Capacity
>  KeysToSave
> 2019-03-08 01:49:47,873 INFO  [ScheduledTasks:1] StatusLogger.java:85 log
> KeyCache                  104856992                104857600
>       all
> 2019-03-08 01:49:47,873 INFO  [ScheduledTasks:1] StatusLogger.java:91 log
> RowCache                          0                        0
>       all
> 2019-03-08 01:49:47,873 INFO  [ScheduledTasks:1] StatusLogger.java:98 log
> Table                       Memtable ops,data
> 2019-03-08 01:49:47,873 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_distributed.parent_repair_history                 0,0
> 2019-03-08 01:49:47,873 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_distributed.repair_history                 0,0
> 2019-03-08 01:49:47,873 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_distributed.view_build_status                 0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.compaction_history               3,781
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.schema_aggregates                  0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.schema_triggers                    0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.size_estimates             2535,100788
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.paxos                              0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.views_builds_in_progress                 0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.batches                            0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.schema_keyspaces                   0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.sstable_activity              129,3974
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.batchlog                           0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.schema_columns                     0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.hints                              0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.IndexInfo                          0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.schema_columnfamilies                 0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.schema_functions                   0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.built_views                        0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.peer_events                        0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.range_xfers                        0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.peers                              0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.transferred_ranges                 0,0
> 2019-03-08 01:49:47,874 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.schema_usertypes                   0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.local                              0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.available_ranges                   0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system.prepared_statements                 0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_schema.columns                     0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_schema.types                       0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_schema.indexes                     0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_schema.keyspaces                   0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_schema.dropped_columns                 0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_schema.aggregates                  0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_schema.triggers                    0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_schema.tables                      0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_schema.views                       0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_schema.functions                   0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> web_history.web_pages_history      2851,402270519
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> _kibana.doc                               0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> scratchboard.job_ids_scratches     156810,13026241
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> elastic_admin.metadata                    0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_auth.roles                         0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_auth.role_members                  0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_auth.resource_role_permissons_index                 0,0
> 2019-03-08 01:49:47,875 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_auth.role_permissions                 0,0
> 2019-03-08 01:49:47,876 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_traces.sessions                    0,0
> 2019-03-08 01:49:47,876 INFO  [ScheduledTasks:1] StatusLogger.java:101 log
> system_traces.events                      0,0


I have a 5 nodes cluster running Cassandra 3.11.3.5. During high workload I
got 500k reads and about 1M writes (inserts and/or deletes) in about 2.5
hours, after that the workload goes down.

any help is very appreciate.

Regards
Marco

Mime
View raw message