2 node cluster, Machines with 16GB, redhat 5 64Bit, 8 cores
network topology , CF 3
5 Column familes with 25 writes per second each, zero reads
on load test (written in Hector) we get some MutationStage Pending in system.log / nodetool tpstats
hitting this errors every 2-10 minutes
At the very same time of high MutationStage (pending) the client is getting also timeout
We also noticed that it keeps running large minor compaction - that consume alot of time
which limit we reached: network/IO/number of nodes/configuration ?
High MutationStage
(3 posts) (2 voices)-
Posted 2 months ago #
-
INFO [ScheduledTasks:1] 2013-03-06 15:12:21,713 GCInspector.java (line 122) GC for ParNew: 722 ms for 2 collections, 3449664536 used; max is 4125097984
INFO [OptionalTasks:1] 2013-03-06 15:12:21,943 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='company', ColumnFamily='txattr') (estimated 83552647 bytes)
INFO [OptionalTasks:1] 2013-03-06 15:12:21,944 ColumnFamilyStore.java (line 659) Enqueuing flush of Memtable-txattr@1400354514(27446113/83552647 serialized/live bytes, 38050 ops)
INFO [ScheduledTasks:1] 2013-03-06 15:12:35,296 GCInspector.java (line 122) GC for ConcurrentMarkSweep: 1550 ms for 2 collections, 2058484368 used; max is 4125097984
INFO [FlushWriter:5] 2013-03-06 15:12:35,973 Memtable.java (line 305) Completed flushing /opt/cassandra/lib/data/company/txctx/company-txctx-hf-39-Data.db (9959461 bytes) for commitlog position ReplayPosition(segmentId=1362567378287, position=3422613)
INFO [FlushWriter:5] 2013-03-06 15:12:35,975 Memtable.java (line 264) Writing Memtable-txtier@699572157(28137242/167650082 serialized/live bytes, 15474 ops)
INFO [OptionalTasks:1] 2013-03-06 15:12:35,975 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='company', ColumnFamily='txwu') (estimated 83013911 bytes)
INFO [ScheduledTasks:1] 2013-03-06 15:12:36,352 GCInspector.java (line 122) GC for ParNew: 417 ms for 2 collections, 2689840136 used; max is 4125097984
INFO [ScheduledTasks:1] 2013-03-06 15:12:37,356 GCInspector.java (line 122) GC for ParNew: 497 ms for 2 collections, 2581031264 used; max is 4125097984
INFO [OptionalTasks:1] 2013-03-06 15:12:38,053 ColumnFamilyStore.java (line 659) Enqueuing flush of Memtable-txwu@1733440143(20321642/109106975 serialized/live bytes, 38050 ops)
INFO [ScheduledTasks:1] 2013-03-06 15:12:38,610 GCInspector.java (line 122) GC for ParNew: 594 ms for 2 collections, 2723066120 used; max is 4125097984
INFO [ScheduledTasks:1] 2013-03-06 15:12:39,614 GCInspector.java (line 122) GC for ParNew: 243 ms for 1 collections, 3349962224 used; max is 4125097984
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,298 MessagingService.java (line 673) 2 MUTATION messages dropped in last 5000ms
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,301 StatusLogger.java (line 57) Pool Name Active Pending Blocked
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,308 StatusLogger.java (line 72) ReadStage 0 0 0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,308 StatusLogger.java (line 72) RequestResponseStage 0 0 0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,309 StatusLogger.java (line 72) ReadRepairStage 0 0 0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,309 StatusLogger.java (line 72) MutationStage 64 369 0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,309 StatusLogger.java (line 72) ReplicateOnWriteStage 0 0 0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,310 StatusLogger.java (line 72) GossipStage 0 0 0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,310 StatusLogger.java (line 72) AntiEntropyStage 0 0 0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,310 StatusLogger.java (line 72) MigrationStage 0 0 0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,311 StatusLogger.java (line 72) StreamStage 0 0 0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,311 StatusLogger.java (line 72) MemtablePostFlusher 1 5 0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,312 StatusLogger.java (line 72) FlushWriter 1 5 1
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,312 StatusLogger.java (line 72) MiscStage 0 0 0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,312 StatusLogger.java (line 72) commitlog_archiver 0 0 0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,313 StatusLogger.java (line 72) InternalResponseStage 0 0 0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,313 StatusLogger.java (line 72) HintedHandoff 0 0 0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,314 StatusLogger.java (line 77) CompactionManager 3 4
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,314 StatusLogger.java (line 89) MessagingService n/a 36,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,315 StatusLogger.java (line 99) Cache Type Size Capacity KeysToSave Provider
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,315 StatusLogger.java (line 100) KeyCache 125 2184533 all
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,315 StatusLogger.java (line 106) RowCache 0 0 all org.apache.cassandra.cache.SerializingCacheProvider
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,316 StatusLogger.java (line 113) ColumnFamily Memtable ops,data
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,316 StatusLogger.java (line 116) system.NodeIdInfo 0,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,316 StatusLogger.java (line 116) system.IndexInfo 0,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,317 StatusLogger.java (line 116) system.LocationInfo 0,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,317 StatusLogger.java (line 116) system.Versions 0,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,317 StatusLogger.java (line 116) system.schema_keyspaces 0,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,317 StatusLogger.java (line 116) system.Migrations 0,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,318 StatusLogger.java (line 116) system.schema_columnfamilies 0,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,318 StatusLogger.java (line 116) system.schema_columns 0,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,318 StatusLogger.java (line 116) system.HintsColumnFamily 687,76357816
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,318 StatusLogger.java (line 116) system.Schema 0,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,319 StatusLogger.java (line 116) OpsCenter.events_timeline 0,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,319 StatusLogger.java (line 116) OpsCenter.pdps 426,60560
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,319 StatusLogger.java (line 116) OpsCenter.settings 0,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,319 StatusLogger.java (line 116) OpsCenter.rollups7200 0,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,320 StatusLogger.java (line 116) OpsCenter.rollups60 1358,335766
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,320 StatusLogger.java (line 116) OpsCenter.events 0,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,320 StatusLogger.java (line 116) OpsCenter.rollups300 428,142167
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,320 StatusLogger.java (line 116) OpsCenter.rollups86400 0,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,321 StatusLogger.java (line 116) company.txmetric 49050,35996029
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,321 StatusLogger.java (line 116) company.txattr 9500,30080972
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,321 StatusLogger.java (line 116) company.txctx 13500,40387725
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,321 StatusLogger.java (line 116) company.txtier 47550,84303564
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,322 StatusLogger.java (line 116) company.objects 0,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,322 StatusLogger.java (line 116) company.txwu 0,0
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,322 StatusLogger.java (line 116) company.periods 360,10119
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,322 StatusLogger.java (line 116) company.attributes 900,5820
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,323 StatusLogger.java (line 116) company.tiers 9924,86081
INFO [ScheduledTasks:1] 2013-03-06 15:12:40,323 StatusLogger.java (line 116) company.applications 122,3112
INFO [FlushWriter:5] 2013-03-06 15:12:40,716 Memtable.java (line 305) Completed flushing /opt/cassandra/lib/data/company/txtier/company-txtier-hf-23-Data.db (8991230 bytes) for commitlog position ReplayPosition(segmentId=1362567378287, position=3422613)
INFO [FlushWriter:5] 2013-03-06 15:12:40,718 Memtable.java (line 264) Writing Memtable-HintsColumnFamily@908436622(111743540/139679425 serialized/live bytes, 1472 ops)
INFO [ScheduledTasks:1] 2013-03-06 15:12:42,752 GCInspector.java (line 122) GC for ParNew: 437 ms for 2 collections, 3344201360 used; max is 4125097984
INFO [OptionalTasks:1] 2013-03-06 15:12:42,812 MeteredFlusher.java (line 62) flushing high-traffic column family CFS(Keyspace='company', ColumnFamily='txtier') (estimated 107011538 bytes)
INFO [MemoryMeter:1] 2013-03-06 15:12:42,911 Memtable.java (line 213) CFS(Keyspace='company', ColumnFamily='txmetric') liveRatio is 5.817172512218668 (just-counted was 4.962854126542127). calculation took 28767ms for 104046 columns
INFO [OptionalTasks:1] 2013-03-06 15:12:43,403 ColumnFamilyStore.java (line 659) Enqueuing flush of Memtable-txtier@1666775274(18083059/107744260 serialized/live bytes, 64050 ops)
INFO [CompactionExecutor:84] 2013-03-06 15:12:43,458 CompactionTask.java (line 221) Compacted to [/opt/cassandra/lib/data/company/txwu/company-txwu-hf-36-Data.db,/opt/cassandra/lib/data/company/txwu/company-txwu-hf-39-Data.db,]. 62,913,763 to 62,910,862 (~99% of original) bytes for 2 keys at 0.990989MB/s. Time: 60,542ms.
INFO [CompactionExecutor:84] 2013-03-06 15:12:43,478 CompactionTask.java (line 109) Compacting [SSTableReader(path='/opt/cassandra/lib/data/company/txwu/company-txwu-hf-37-Data.db'), SSTableReader(path='/opt/cassandra/lib/data/company/txwu/company-txwu-hf-38-Data.db'), SSTableReader(path='/opt/cassandra/lib/data/company/txwu/company-txwu-hf-36-Data.db'), SSTableReader(path='/opt/cassandra/lib/data/company/txwu/company-txwu-hf-40-Data.db')]
INFO [CompactionExecutor:84] 2013-03-06 15:12:43,482 CompactionController.java (line 172) Compacting large row company/txwu:2013-03-6-13:10-wu (169764814 bytes) incrementally
INFO [ScheduledTasks:1] 2013-03-06 15:12:57,975 GCInspector.java (line 122) GC for ConcurrentMarkSweep: 1693 ms for 2 collections, 2375045832 used; max is 4125097984
Posted 2 months ago # -
What version of DSE are you using?
Posted 2 months ago #
Reply
You must log in to post.
