GC logging is not in system.log. But in the following file. JVM_OPTS="$JVM_OPTS -Xloggc:/var/log/cassandra/gc-`date +%s`.log"
At least, no GC logs are shown in your post. On Tue, Jun 18, 2013 at 5:05 PM, Joel Samuelsson <samuelsson.j...@gmail.com>wrote: > Can't find any promotion failure. > > In system.log this is what I get: > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,490 GCInspector.java (line > 122) GC for ParNew: 145189 ms for 1 collections, 225905072 used; max is > 4114612224 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,490 StatusLogger.java (line > 57) Pool Name Active Pending Blocked > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,491 StatusLogger.java (line > 72) ReadStage 0 0 0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,492 StatusLogger.java (line > 72) RequestResponseStage 0 0 0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,492 StatusLogger.java (line > 72) ReadRepairStage 0 0 0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,492 StatusLogger.java (line > 72) MutationStage 0 0 0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,493 StatusLogger.java (line > 72) ReplicateOnWriteStage 0 0 0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,493 StatusLogger.java (line > 72) GossipStage 0 0 0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,493 StatusLogger.java (line > 72) AntiEntropyStage 0 0 0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,494 StatusLogger.java (line > 72) MigrationStage 0 0 0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,494 StatusLogger.java (line > 72) StreamStage 0 0 0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,494 StatusLogger.java (line > 72) MemtablePostFlusher 0 0 0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,495 StatusLogger.java (line > 72) FlushWriter 0 0 0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,495 StatusLogger.java (line > 72) MiscStage 0 0 0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,499 StatusLogger.java (line > 72) commitlog_archiver 0 0 0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,499 StatusLogger.java (line > 72) InternalResponseStage 0 0 0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,499 StatusLogger.java (line > 72) HintedHandoff 0 0 0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,500 StatusLogger.java (line > 77) CompactionManager 0 0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,500 StatusLogger.java (line > 89) MessagingService n/a 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,500 StatusLogger.java (line > 99) Cache Type Size Capacity KeysToSave Provider > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,504 StatusLogger.java (line > 100) KeyCache 12129 2184533 all > > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,505 StatusLogger.java (line > 106) RowCache 0 0 all > org.apache.cassandra.cache.SerializingCacheProvider > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,505 StatusLogger.java (line > 113) ColumnFamily Memtable ops,data > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,505 StatusLogger.java (line > 116) system.NodeIdInfo 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,505 StatusLogger.java (line > 116) system.IndexInfo 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,505 StatusLogger.java (line > 116) system.LocationInfo 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,506 StatusLogger.java (line > 116) system.Versions 3,103 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,506 StatusLogger.java (line > 116) system.schema_keyspacees 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,506 StatusLogger.java (line > 116) system.Migrations 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,506 StatusLogger.java (line > 116) system.schema_columnfamilies 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,506 StatusLogger.java (line > 116) system.schema_columns 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,507 StatusLogger.java (line > 116) system.HintsColumnFamily 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,507 StatusLogger.java (line > 116) system.Schema 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,507 StatusLogger.java (line > 116) Keyspace.cf01 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,507 StatusLogger.java (line > 116) Keyspace.cf02 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,507 StatusLogger.java (line > 116) Keyspace.cf03 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,508 StatusLogger.java (line > 116) Keyspace.cf04 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,508 StatusLogger.java (line > 116) Keyspace.cf05 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,508 StatusLogger.java (line > 116) Keyspace.cf06 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,508 StatusLogger.java (line > 116) Keyspace.cf07 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,508 StatusLogger.java (line > 116) Keyspace.cf08 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,508 StatusLogger.java (line > 116) Keyspace.cf09 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,509 StatusLogger.java (line > 116) Keyspace.cf10 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,509 StatusLogger.java (line > 116) Keyspace.cf11 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,509 StatusLogger.java (line > 116) Keyspace.cf12 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,509 StatusLogger.java (line > 116) Keyspace.cf13 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,509 StatusLogger.java (line > 116) Keyspace.cf14 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,510 StatusLogger.java (line > 116) Keyspace.cf15 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,510 StatusLogger.java (line > 116) Keyspace.cf16 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,510 StatusLogger.java (line > 116) Keyspace.cf17 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,510 StatusLogger.java (line > 116) Keyspace.cf18 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,510 StatusLogger.java (line > 116) Keyspace.cf19 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,511 StatusLogger.java (line > 116) Keyspace.cf20 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,511 StatusLogger.java (line > 116) Keyspace.cf21 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,511 StatusLogger.java (line > 116) Keyspace.cf22 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,511 StatusLogger.java (line > 116) Keyspace.cf23 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,511 StatusLogger.java (line > 116) Keyspace.cf24 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,512 StatusLogger.java (line > 116) Keyspace.cf25 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,512 StatusLogger.java (line > 116) Keyspace.cf26 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,512 StatusLogger.java (line > 116) StressKeyspace.StressStandard 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,512 StatusLogger.java (line > 116) testing_Keyspace.cf01 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,512 StatusLogger.java (line > 116) testing_Keyspace.cf02 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,513 StatusLogger.java (line > 116) testing_Keyspace.cf03 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,513 StatusLogger.java (line > 116) testing_Keyspace.cf04 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,513 StatusLogger.java (line > 116) testing_Keyspace.cf05 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,513 StatusLogger.java (line > 116) testing_Keyspace.cf06 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,513 StatusLogger.java (line > 116) testing_Keyspace.cf07 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,514 StatusLogger.java (line > 116) testing_Keyspace.cf08 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,514 StatusLogger.java (line > 116) testing_Keyspace.cf09 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,514 StatusLogger.java (line > 116) testing_Keyspace.cf10 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,514 StatusLogger.java (line > 116) testing_Keyspace.cf11 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,514 StatusLogger.java (line > 116) testing_Keyspace.cf12 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,515 StatusLogger.java (line > 116) testing_Keyspace.cf13 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,515 StatusLogger.java (line > 116) testing_Keyspace.cf14 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,515 StatusLogger.java (line > 116) testing_Keyspace.cf15 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,515 StatusLogger.java (line > 116) testing_Keyspace.cf16 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,515 StatusLogger.java (line > 116) testing_Keyspace.cf17 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,516 StatusLogger.java (line > 116) testing_Keyspace.cf18 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,516 StatusLogger.java (line > 116) testing_Keyspace.cf19 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,516 StatusLogger.java (line > 116) testing_Keyspace.cf20 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,516 StatusLogger.java (line > 116) testing_Keyspace.cf21 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,517 StatusLogger.java (line > 116) testing_Keyspace.cf22 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,517 StatusLogger.java (line > 116) OpsCenter.rollups7200 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,517 StatusLogger.java (line > 116) OpsCenter.rollups86400 0,0 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,517 StatusLogger.java (line > 116) OpsCenter.rollups60 13745,3109686 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,517 StatusLogger.java (line > 116) OpsCenter.events 18,826 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,518 StatusLogger.java (line > 116) OpsCenter.rollups300 2516,570931 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,519 StatusLogger.java (line > 116) OpsCenter.pdps 9072,160850 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,519 StatusLogger.java (line > 116) OpsCenter.events_timeline 3,86 > INFO [ScheduledTasks:1] 2013-06-17 08:13:47,520 StatusLogger.java (line > 116) OpsCenter.settings 0,0 > > And from gc-1371454124.log I get: > 2013-06-17T08:11:22.300+0000: 2551.288: [GC 870971K->216494K(4018176K), > 145.1887460 secs] > > > 2013/6/18 Takenori Sato <ts...@cloudian.com> > >> Find "promotion failure". Bingo if it happened at the time. >> >> Otherwise, post the relevant portion of the log here. Someone may find a >> hint. >> >> >> On Mon, Jun 17, 2013 at 5:51 PM, Joel Samuelsson < >> samuelsson.j...@gmail.com> wrote: >> >>> Just got a very long GC again. What am I to look for in the logging I >>> just enabled? >>> >>> >>> 2013/6/17 Joel Samuelsson <samuelsson.j...@gmail.com> >>> >>>> > If you are talking about 1.2.x then I also have memory problems on >>>> the idle cluster: java memory constantly slow grows up to limit, then spend >>>> long time for GC. I never seen such behaviour for 1.0.x and 1.1.x, where >>>> on idle cluster java memory stay on the same value. >>>> >>>> No I am running Cassandra 1.1.8. >>>> >>>> > Can you paste you gc config? >>>> >>>> I believe the relevant configs are these: >>>> # GC tuning options >>>> JVM_OPTS="$JVM_OPTS -XX:+UseParNewGC" >>>> JVM_OPTS="$JVM_OPTS -XX:+UseConcMarkSweepGC" >>>> JVM_OPTS="$JVM_OPTS -XX:+CMSParallelRemarkEnabled" >>>> JVM_OPTS="$JVM_OPTS -XX:SurvivorRatio=8" >>>> JVM_OPTS="$JVM_OPTS -XX:MaxTenuringThreshold=1" >>>> JVM_OPTS="$JVM_OPTS -XX:CMSInitiatingOccupancyFraction=75" >>>> JVM_OPTS="$JVM_OPTS -XX:+UseCMSInitiatingOccupancyOnly" >>>> >>>> I haven't changed anything in the environment config up until now. >>>> >>>> > Also can you take a heap dump at 2 diff points so that we can >>>> compare it? >>>> >>>> I can't access the machine at all during the stop-the-world freezes. >>>> Was that what you wanted me to try? >>>> >>>> > Uncomment the followings in "cassandra-env.sh". >>>> Done. Will post results as soon as I get a new stop-the-world gc. >>>> >>>> > If you are unable to find a JIRA, file one >>>> >>>> Unless this turns out to be a problem on my end, I will. >>>> >>> >>> >> >
