cassandra-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Joost van de Wijgerd <jwijg...@gmail.com>
Subject Re: Cassandra 1.0 hangs during GC
Date Mon, 23 Jul 2012 16:12:07 GMT
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 <nkovshov@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" <aaron@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

Mime
View raw message