Howmuch memory do you have on the machine. Seems like you have 8G reserved for the Cassandra java process, If this is all the memory on the machine you might be swapping. Also which jvm do you use?
kind regards Joost On Mon, Jul 23, 2012 at 10:07 AM, Nikolay Kоvshov <nkovs...@yandex.ru> wrote: > 21th I have mirgated to cassandra 1.1.2 but see no improvement > > cat /var/log/cassandra/Earth1.log | grep "GC for" > INFO [ScheduledTasks:1] 2012-05-22 17:42:48,445 GCInspector.java (line 123) > GC for ParNew: 345 ms for 1 collections, 82451888 used; max is 8464105472 > INFO [ScheduledTasks:1] 2012-05-23 02:47:13,911 GCInspector.java (line 123) > GC for ParNew: 312 ms for 1 collections, 110617416 used; max is 8464105472 > INFO [ScheduledTasks:1] 2012-05-23 11:57:54,317 GCInspector.java (line 123) > GC for ParNew: 298 ms for 1 collections, 98161920 used; max is 8464105472 > INFO [ScheduledTasks:1] 2012-07-02 08:52:37,019 GCInspector.java (line 123) > GC for ParNew: 196886 ms for 1 collections, 2310058496 used; max is 8464105472 > INFO [ScheduledTasks:1] 2012-07-16 17:41:25,940 GCInspector.java (line 123) > GC for ParNew: 200146 ms for 1 collections, 2345987088 used; max is 8464105472 > === Migrated from 1.0.0 to 1.1.2 > INFO [ScheduledTasks:1] 2012-07-21 09:05:08,280 GCInspector.java (line 122) > GC for ParNew: 282 ms for 1 collections, 466406864 used; max is 8464105472 > INFO [ScheduledTasks:1] 2012-07-21 12:38:43,132 GCInspector.java (line 122) > GC for ParNew: 233 ms for 1 collections, 405269504 used; max is 8464105472 > INFO [ScheduledTasks:1] 2012-07-22 02:29:09,596 GCInspector.java (line 122) > GC for ParNew: 253 ms for 1 collections, 389700768 used; max is 8464105472 > INFO [ScheduledTasks:1] 2012-07-22 17:45:46,357 GCInspector.java (line 122) > GC for ParNew: 57391 ms for 1 collections, 400083984 used; max is 8464105472 > > Memory and yaml memory-related settings are default > I do not do deletes > I have 2 CF's and no secondary indexes > > LiveRatio's: > INFO [pool-1-thread-1] 2012-06-09 02:36:07,759 Memtable.java (line 177) > CFS(Keyspace='Keyspace1', ColumnFamily='PSS') liveRatio is 1.0 (just-counted > was 1.0). calculation took 85ms for 6236 columns > INFO [MemoryMeter:1] 2012-07-21 09:04:47,614 Memtable.java (line 213) > CFS(Keyspace='Keyspace1', ColumnFamily='Standard1') liveRatio is 1.0 > (just-counted was 1.0). calculation took 8ms for 1 columns > INFO [MemoryMeter:1] 2012-07-21 09:04:51,012 Memtable.java (line 213) > CFS(Keyspace='Keyspace1', ColumnFamily='PSS') liveRatio is 1.0 (just-counted > was 1.0). calculation took 99ms for 1094 columns > INFO [MemoryMeter:1] 2012-07-21 09:04:51,331 Memtable.java (line 213) > CFS(Keyspace='Keyspace1', ColumnFamily='Standard1') liveRatio is 1.0 > (just-counted was 1.0). calculation took 80ms for 242 columns > INFO [MemoryMeter:1] 2012-07-21 09:04:51,856 Memtable.java (line 213) > CFS(Keyspace='Keyspace1', ColumnFamily='PSS') liveRatio is 1.0 (just-counted > was 1.0). calculation took 505ms for 2678 columns > INFO [MemoryMeter:1] 2012-07-21 09:04:52,881 Memtable.java (line 213) > CFS(Keyspace='Keyspace1', ColumnFamily='PSS') liveRatio is 1.0 (just-counted > was 1.0). calculation took 776ms for 5236 columns > INFO [MemoryMeter:1] 2012-07-21 09:04:52,945 Memtable.java (line 213) > CFS(Keyspace='Keyspace1', ColumnFamily='Standard1') liveRatio is 1.0 > (just-counted was 1.0). calculation took 64ms for 389 columns > INFO [MemoryMeter:1] 2012-07-21 09:04:55,162 Memtable.java (line 213) > CFS(Keyspace='Keyspace1', ColumnFamily='PSS') liveRatio is 1.0 (just-counted > was 1.0). calculation took 1378ms for 8948 columns > INFO [MemoryMeter:1] 2012-07-21 09:04:55,304 Memtable.java (line 213) > CFS(Keyspace='Keyspace1', ColumnFamily='Standard1') liveRatio is 1.0 > (just-counted was 1.0). calculation took 140ms for 1082 columns > INFO [MemoryMeter:1] 2012-07-21 09:05:08,439 Memtable.java (line 213) > CFS(Keyspace='Keyspace1', ColumnFamily='Standard1') liveRatio is > 2.5763038186160894 (just-counted was 2.5763038186160894). calculation took > 8796ms for 102193 columns > > 18.07.2012, 07:51, "aaron morton" <aa...@thelastpickle.com>: >> Assuming all the memory and yaml settings default that does not sound right. >> The first thought would be the memory meter not counting correctly... >> Do you do a lot of deletes ? >> Do you have a lot of CF's and/or secondary indexes ? >> Can you see log lines about the "liveRatio" for your cf's ? >> I would upgrade to 1.0.10 before getting too carried away though. >> Cheers >> >> ----------------- >> Aaron Morton >> Freelance Developer >> @aaronmorton >> http://www.thelastpickle.com >> >> On 17/07/2012, at 8:14 PM, Nikolay Kоvshov wrote: >> >>> This is a cluster of 2 nodes, each having 8G of operating memory, >>> replicationfactor=2 >>> Write/read pressure is quite low and almost never exceeds 10/second >>> >>> From time to time (2-3 times in a month) I see GC activity in logs and for >>> this time cassandra stops responding to requests which results in a timeout >>> in upper-layer application. Total time of unavailability can be over 5 >>> minues (like in the following case) >>> >>> What can I do with that? Wiil it become much worse when my cluster grows up? >>> >>> INFO [GossipTasks:1] 2012-07-16 13:10:50,055 Gossiper.java (line 736) >>> InetAddress /10.220.50.9 is now dead. >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,056 GCInspector.java (line >>> 123) GC for ParNew: 391383 ms for 1 collections, 2025808488 used; max is >>> 8464105472 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,067 StatusLogger.java (line >>> 50) Pool Name Active Pending Blocked >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,071 StatusLogger.java (line >>> 65) ReadStage 0 0 0 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,071 StatusLogger.java (line >>> 65) RequestResponseStage 0 0 0 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,072 StatusLogger.java (line >>> 65) ReadRepairStage 0 0 0 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,072 StatusLogger.java (line >>> 65) MutationStage 0 0 0 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,073 StatusLogger.java (line >>> 65) ReplicateOnWriteStage 0 0 0 >>> INFO [GossipStage:1] 2012-07-16 13:10:50,074 Gossiper.java (line 722) >>> InetAddress /10.220.50.9 is now UP >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,075 StatusLogger.java (line >>> 65) GossipStage 1 59 0 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,075 StatusLogger.java (line >>> 65) AntiEntropyStage 0 0 0 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,076 StatusLogger.java (line >>> 65) MigrationStage 0 0 0 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,076 StatusLogger.java (line >>> 65) StreamStage 0 0 0 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,077 StatusLogger.java (line >>> 65) MemtablePostFlusher 0 0 0 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,077 StatusLogger.java (line >>> 65) FlushWriter 0 0 0 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,077 StatusLogger.java (line >>> 65) MiscStage 0 0 0 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,078 StatusLogger.java (line >>> 65) InternalResponseStage 0 0 0 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,078 StatusLogger.java (line >>> 65) HintedHandoff 0 0 0 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,079 StatusLogger.java (line >>> 69) CompactionManager n/a 0 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,079 StatusLogger.java (line >>> 81) MessagingService n/a 0,0 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,080 StatusLogger.java (line >>> 85) ColumnFamily Memtable ops,data Row cache size/cap Key >>> cache size/cap >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,080 StatusLogger.java (line >>> 88) Keyspace1.PSS 36712,343842617 0/0 >>> 97995/1000000 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,085 StatusLogger.java (line >>> 88) Keyspace1.Standard1 128679,162567721 0/0 >>> 0/1000000 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,085 StatusLogger.java (line >>> 88) system.NodeIdInfo 0,0 0/0 >>> 0/1 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,086 StatusLogger.java (line >>> 88) system.IndexInfo 0,0 0/0 >>> 0/1 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,086 StatusLogger.java (line >>> 88) system.LocationInfo 0,0 0/0 >>> 1/2 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,086 StatusLogger.java (line >>> 88) system.Migrations 0,0 0/0 >>> 3/3 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,087 StatusLogger.java (line >>> 88) system.HintsColumnFamily 1,528 0/0 >>> 0/1 >>> INFO [ScheduledTasks:1] 2012-07-16 13:10:50,087 StatusLogger.java (line >>> 88) system.Schema 0,0 0/0 >>> 2/3 >>> -------- Завершение пересылаемого сообщения -------- -- Joost van de Wijgerd Visseringstraat 21B 1051KH Amsterdam +31624111401 joost.van.de.wijgerd@Skype http://www.linkedin.com/in/jwijgerd
