incubator-cassandra-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Michael Theroux <mthero...@yahoo.com>
Subject Re: Cassandra Messages Dropped
Date Tue, 18 Sep 2012 03:46:27 GMT
Thanks for the response.

We are on version 1.1.2.  We don't see the MutationStage back up.  The dump from the messages
dropped error doesn't show a backup, but also watching "nodetool tpstats" doesn't show any
backup there.

nodetool info also shows we have over a gig of available memory on the JVM heap of each node.

The earliest GCInspector traces I see before one of the more recent incidents in which messages
were dropped are:

	INFO [ScheduledTasks:1] 2012-09-18 02:25:53,928 GCInspector.java (line 122) GC for ParNew:
396 ms for 1 collections, 2064505088 used; max is 4253024256
 
	NFO [ScheduledTasks:1] 2012-09-18 02:25:55,929 GCInspector.java (line 122) GC for ParNew:
485 ms for 1 collections, 1961875064 used; max is 4253024256
 
	INFO [ScheduledTasks:1] 2012-09-18 02:25:57,930 GCInspector.java (line 122) GC for ParNew:
265 ms for 1 collections, 1968074096 used; max is 4253024256

But this was 45 minutes before messages were dropped.

It's appreciated,
-Mike
 
On Sep 17, 2012, at 11:27 PM, aaron morton wrote:

>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,839 StatusLogger.java (line 72) MemtablePostFlusher
              1         5         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,840 StatusLogger.java (line 72) FlushWriter
                      1         5         0
> Looks suspiciously like 
> http://mail-archives.apache.org/mod_mbox/cassandra-user/201209.mbox/%3C9FB0E801-B1ED-41C4-9939-BAFBDDF15FD9@thelastpickle.com%3E
> 
> What version are you on ? 
> 
> Are there any ERROR log messages before this ? 
> 
> Are you seeing MutationStage back up ? 
> 
> Are you see log messages from GCInspector ?
> 
> Cheers
> 
> -----------------
> Aaron Morton
> Freelance Developer
> @aaronmorton
> http://www.thelastpickle.com
> 
> On 18/09/2012, at 2:16 AM, Michael Theroux <mtheroux2@yahoo.com> wrote:
> 
>> Hello,
>> 
>> While under load, we have occasionally been seeing "messages dropped" errors in our
cassandra log.  Doing some research, I understand this is part of Cassandra's design to shed
load, and we should look at the tpstats-like output to determine what should be done to resolve
the situation.  Typically, you will see lots of messages blocked or pending, and that might
be an indicator that a specific part of hardware needs to be improved/tuned/upgraded.  
>> 
>> However, looking at the output we are getting, I'm finding it difficult to see what
needs to be tuned, as it looks to me cassandra is handling the load within the mutation stage:
>> 
>> NFO [ScheduledTasks:1] 2012-09-17 06:28:03,266 MessagingService.java (line 658) 119
MUTATION messages dropped in last 5000ms
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,645 StatusLogger.java (line 57) Pool
Name                    Active   Pending   Blocked
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,836 StatusLogger.java (line 72) ReadStage
                        3         3         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,837 StatusLogger.java (line 72) RequestResponseStage
             0         0         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,837 StatusLogger.java (line 72) ReadRepairStage
                  0         0         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,837 StatusLogger.java (line 72) MutationStage
                    0         0         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,838 StatusLogger.java (line 72) ReplicateOnWriteStage
            0         0         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,838 StatusLogger.java (line 72) GossipStage
                      0         0         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,839 StatusLogger.java (line 72) AntiEntropyStage
                 0         0         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,839 StatusLogger.java (line 72) MigrationStage
                   0         0         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,839 StatusLogger.java (line 72) StreamStage
                      0         0         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,839 StatusLogger.java (line 72) MemtablePostFlusher
              1         5         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,840 StatusLogger.java (line 72) FlushWriter
                      1         5         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,840 StatusLogger.java (line 72) MiscStage
                        0         0         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,840 StatusLogger.java (line 72) commitlog_archiver
               0         0         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,841 StatusLogger.java (line 72) InternalResponseStage
            0         0         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,841 StatusLogger.java (line 72) AntiEntropySessions
              0         0         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,851 StatusLogger.java (line 72) HintedHandoff
                    0         0         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,851 StatusLogger.java (line 77) CompactionManager
                0         0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,852 StatusLogger.java (line 89) MessagingService
               n/a       0,0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,852 StatusLogger.java (line 99) Cache
Type                     Size                 Capacity               KeysToSave          
                                              Provider
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,853 StatusLogger.java (line 100) KeyCache
                   2184533                  2184533                      all             
                                                   
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,853 StatusLogger.java (line 106) RowCache
                         0                        0                      all             
org.apache.cassandra.cache.SerializingCacheProvider
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,853 StatusLogger.java (line 113) ColumnFamily
               Memtable ops,data
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,853 StatusLogger.java (line 116) system.NodeIdInfo
                        0,0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,854 StatusLogger.java (line 116) system.IndexInfo
                         0,0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,854 StatusLogger.java (line 116) system.LocationInfo
                      0,0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,854 StatusLogger.java (line 116) system.Versions
                          0,0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,855 StatusLogger.java (line 116) system.schema_keyspaces
                  0,0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,855 StatusLogger.java (line 116) system.Migrations
                        0,0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,855 StatusLogger.java (line 116) system.schema_columnfamilies
                0,0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,856 StatusLogger.java (line 116) system.schema_columns
                    0,0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,856 StatusLogger.java (line 116) system.HintsColumnFamily
                 0,0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,856 StatusLogger.java (line 116) system.Schema
                            0,0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,857 StatusLogger.java (line 116) prod.comp
                          0,0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,857 StatusLogger.java (line 116) prod.byp
                     224,61863
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,857 StatusLogger.java (line 116) prod.byn
                     30,6106
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,857 StatusLogger.java (line 116) prod.p
                    3354,3792954
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,858 StatusLogger.java (line 116) prod.rel
               788,153294
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,858 StatusLogger.java (line 116) prod.i
                       46,271517
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,859 StatusLogger.java (line 116) prod.users
                    18489,5650405
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,859 StatusLogger.java (line 116) prod.caches
                      40,7512998
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,859 StatusLogger.java (line 116) prod.sessions
                 8085,13063121
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,859 StatusLogger.java (line 116) prod.content
                            0,0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,860 StatusLogger.java (line 116) prod.enr
                 436,341190
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,860 StatusLogger.java (line 116) prod.byt
                23800,9880339
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,861 StatusLogger.java (line 116) prod.aliases
                 63603,10475769
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,861 StatusLogger.java (line 116) prod.ran
                   1500,329387
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,861 StatusLogger.java (line 116) prod.cmap
                       0,0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,861 StatusLogger.java (line 116) prod.pmap
               73032,61237450
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,862 StatusLogger.java (line 116) prod.pic
                  5421,4438066
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,862 StatusLogger.java (line 116) prod.watchdog
                           0,0
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,863 StatusLogger.java (line 116) prod.s
                        31,40924
>> INFO [ScheduledTasks:1] 2012-09-17 06:28:03,863 StatusLogger.java (line 116) prod.m
                21690,64262284
>> 
>> 
>> We are using a write consistency level of LOCAL_QUROUM over a six node cluster. 
Any observations are welcome,
>> 
>> Thanks,
>> -Mike
> 


Mime
View raw message