cassandra-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Marco Gasparini <marco.gaspar...@competitoor.com>
Subject Re: too many logDroppedMessages and StatusLogger
Date Tue, 12 Mar 2019 07:33:06 GMT
thanks for the answer Nate,

my queries are more like the following:
select f1,f2,f3, bigtxt from  mytable  where f1= ? and f2= ? limit 10;
insert into mytable (f1,f2,f3,bigtxt) values (?,?,?,?)

actually I have a text field (bigtxt) that could be > 1MB.

Marco

Il giorno lun 11 mar 2019 alle ore 22:21 Nate McCall <zznate.m@gmail.com>
ha scritto:

> Are you using queries with a large number of arguments to an IN clause
> on a partition key? If so, the coordinator has to:
> - hold open the client request
> - unwind the IN clause into individual statements
> - scatter/gathering those statements around the cluster (each at the
> requested consistency level!)
> - pull it all back together and send it out
>
> In extreme cases, this can flood internode messaging and make things
> look slow even when the system is near idle.
>
> On Fri, Mar 8, 2019 at 9:27 PM Marco Gasparini
> <marco.gasparini@competitoor.com> wrote:
> >
> > 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
> >
> >
> >
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: user-unsubscribe@cassandra.apache.org
> For additional commands, e-mail: user-help@cassandra.apache.org
>
>

Mime
View raw message