cassandra-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "graham sanderson (JIRA)" <j...@apache.org>
Subject [jira] [Comment Edited] (CASSANDRA-7467) flood of "setting live ratio to maximum of 64" from repair
Date Wed, 06 Aug 2014 23:12:15 GMT

    [ https://issues.apache.org/jira/browse/CASSANDRA-7467?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14088437#comment-14088437
] 

graham sanderson edited comment on CASSANDRA-7467 at 8/6/14 11:12 PM:
----------------------------------------------------------------------

I can see where many of them are coming from on 2.0.9 (before this change to debug level)
- we just upgraded from 2.0.5

{code}
2014-08-06 04:02:34,026 INFO  [MemoryMeter:1] 2014-08-06 04:02:34,026 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:02:34,069 INFO  [MemoryMeter:1] 2014-08-06 04:02:34,069 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:02:34,117 INFO  [InternalResponseStage:87] 2014-08-06 04:02:34,117 ColumnFamilyStore.java
(line 794) Enqueuing flush of Memtable-schema_triggers@1406319171(0/0 serialized/live bytes,
3 ops)
2014-08-06 04:02:34,118 INFO  [FlushWriter:41] 2014-08-06 04:02:34,118 Memtable.java (line
363) Writing Memtable-schema_triggers@1406319171(0/0 serialized/live bytes, 3 ops)
2014-08-06 04:02:34,124 INFO  [FlushWriter:41] 2014-08-06 04:02:34,124 Memtable.java (line
403) Completed flushing /data/6/cassandra/system/schema_triggers/system-schema_triggers-jb-60-Data.db
(129 bytes) for commitlog position ReplayPosition(segmentId=1407287842775, position=7415363)
2014-08-06 04:02:34,126 INFO  [CompactionExecutor:185] 2014-08-06 04:02:34,126 CompactionTask.java
(line 115) Compacting [SSTableReader(path='/data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-59-Data.db'),
SSTableReader(path='/data/6/cassandra/system/schema_triggers/system-schema_triggers-jb-60-Data.db'),
SSTableReader(path='/data/6/cassandra/system/schema_triggers/system-schema_triggers-jb-58-Data.db'),
SSTableReader(path='/data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-57-Data.db')]
2014-08-06 04:02:34,796 INFO  [MemoryMeter:1] 2014-08-06 04:02:34,796 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:02:34,844 INFO  [MemoryMeter:1] 2014-08-06 04:02:34,844 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:02:34,896 INFO  [InternalResponseStage:88] 2014-08-06 04:02:34,896 ColumnFamilyStore.java
(line 794) Enqueuing flush of Memtable-schema_triggers@349252843(0/0 serialized/live bytes,
3 ops)
2014-08-06 04:02:34,897 INFO  [FlushWriter:38] 2014-08-06 04:02:34,897 Memtable.java (line
363) Writing Memtable-schema_triggers@349252843(0/0 serialized/live bytes, 3 ops)
2014-08-06 04:02:34,903 INFO  [FlushWriter:38] 2014-08-06 04:02:34,903 Memtable.java (line
403) Completed flushing /data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-61-Data.db
(129 bytes) for commitlog position ReplayPosition(segmentId=1407287842775, position=7995460)
2014-08-06 04:12:47,723 INFO  [MemoryMeter:1] 2014-08-06 04:12:47,723 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:12:47,749 INFO  [MemoryMeter:1] 2014-08-06 04:12:47,749 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:12:47,815 INFO  [InternalResponseStage:101] 2014-08-06 04:12:47,815 ColumnFamilyStore.java
(line 794) Enqueuing flush of Memtable-schema_triggers@1809531694(0/0 serialized/live bytes,
3 ops)
2014-08-06 04:12:47,816 INFO  [FlushWriter:48] 2014-08-06 04:12:47,816 Memtable.java (line
363) Writing Memtable-schema_triggers@1809531694(0/0 serialized/live bytes, 3 ops)
2014-08-06 04:12:47,821 INFO  [FlushWriter:48] 2014-08-06 04:12:47,821 Memtable.java (line
403) Completed flushing /data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-62-Data.db
(129 bytes) for commitlog position ReplayPosition(segmentId=1407287842777, position=23729801)
2014-08-06 04:12:49,257 INFO  [MemoryMeter:1] 2014-08-06 04:12:49,257 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:12:49,301 INFO  [MemoryMeter:1] 2014-08-06 04:12:49,301 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:12:49,349 INFO  [InternalResponseStage:103] 2014-08-06 04:12:49,349 ColumnFamilyStore.java
(line 794) Enqueuing flush of Memtable-schema_triggers@91416114(0/0 serialized/live bytes,
3 ops)
2014-08-06 04:12:49,350 INFO  [FlushWriter:48] 2014-08-06 04:12:49,350 Memtable.java (line
363) Writing Memtable-schema_triggers@91416114(0/0 serialized/live bytes, 3 ops)
2014-08-06 04:12:49,357 INFO  [FlushWriter:48] 2014-08-06 04:12:49,357 Memtable.java (line
403) Completed flushing /data/6/cassandra/system/schema_triggers/system-schema_triggers-jb-63-Data.db
(129 bytes) for commitlog position ReplayPosition(segmentId=1407287842777, position=25231718)
2014-08-06 04:13:33,224 INFO  [MemoryMeter:1] 2014-08-06 04:13:33,224 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:13:33,250 INFO  [MemoryMeter:1] 2014-08-06 04:13:33,250 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:13:33,324 INFO  [InternalResponseStage:106] 2014-08-06 04:13:33,324 ColumnFamilyStore.java
(line 794) Enqueuing flush of Memtable-schema_triggers@157617667(0/0 serialized/live bytes,
3 ops)
2014-08-06 04:13:33,325 INFO  [FlushWriter:51] 2014-08-06 04:13:33,325 Memtable.java (line
363) Writing Memtable-schema_triggers@157617667(0/0 serialized/live bytes, 3 ops)
2014-08-06 04:13:33,330 INFO  [FlushWriter:51] 2014-08-06 04:13:33,330 Memtable.java (line
403) Completed flushing /data/6/cassandra/system/schema_triggers/system-schema_triggers-jb-64-Data.db
(129 bytes) for commitlog position ReplayPosition(segmentId=1407287842778, position=4977305)
2014-08-06 04:13:33,332 INFO  [CompactionExecutor:213] 2014-08-06 04:13:33,332 CompactionTask.java
(line 115) Compacting [SSTableReader(path='/data/6/cassandra/system/schema_triggers/system-schema_triggers-jb-64-Data.db'),
SSTableReader(path='/data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-61-Data.db'),
SSTableReader(path='/data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-62-Data.db'),
SSTableReader(path='/data/6/cassandra/system/schema_triggers/system-schema_triggers-jb-63-Data.db')]
2014-08-06 04:13:46,756 INFO  [MemoryMeter:1] 2014-08-06 04:13:46,756 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:13:46,771 INFO  [MemoryMeter:1] 2014-08-06 04:13:46,771 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:13:46,892 INFO  [InternalResponseStage:108] 2014-08-06 04:13:46,892 ColumnFamilyStore.java
(line 794) Enqueuing flush of Memtable-schema_triggers@1625969376(0/0 serialized/live bytes,
3 ops)
2014-08-06 04:13:46,896 INFO  [FlushWriter:51] 2014-08-06 04:13:46,896 Memtable.java (line
363) Writing Memtable-schema_triggers@1625969376(0/0 serialized/live bytes, 3 ops)
2014-08-06 04:13:46,903 INFO  [FlushWriter:51] 2014-08-06 04:13:46,903 Memtable.java (line
403) Completed flushing /data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-65-Data.db
(129 bytes) for commitlog position ReplayPosition(segmentId=1407287842778, position=9486910)
2014-08-06 04:19:31,886 INFO  [MemoryMeter:1] 2014-08-06 04:19:31,886 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:19:31,934 INFO  [MemoryMeter:1] 2014-08-06 04:19:31,934 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 1ms for 0 cells
2014-08-06 04:19:31,987 INFO  [InternalResponseStage:110] 2014-08-06 04:19:31,987 ColumnFamilyStore.java
(line 794) Enqueuing flush of Memtable-schema_triggers@431225069(0/0 serialized/live bytes,
3 ops)
2014-08-06 04:19:31,989 INFO  [FlushWriter:58] 2014-08-06 04:19:31,989 Memtable.java (line
363) Writing Memtable-schema_triggers@431225069(0/0 serialized/live bytes, 3 ops)
2014-08-06 04:19:31,994 INFO  [FlushWriter:58] 2014-08-06 04:19:31,994 Memtable.java (line
403) Completed flushing /data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-66-Data.db
(129 bytes) for commitlog position ReplayPosition(segmentId=1407287842781, position=17483747)
2014-08-06 04:19:32,434 INFO  [MemoryMeter:1] 2014-08-06 04:19:32,434 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:19:32,480 INFO  [MemoryMeter:1] 2014-08-06 04:19:32,480 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:19:32,529 INFO  [InternalResponseStage:111] 2014-08-06 04:19:32,529 ColumnFamilyStore.java
(line 794) Enqueuing flush of Memtable-schema_triggers@928567559(0/0 serialized/live bytes,
3 ops)
2014-08-06 04:19:32,535 INFO  [FlushWriter:55] 2014-08-06 04:19:32,535 Memtable.java (line
363) Writing Memtable-schema_triggers@928567559(0/0 serialized/live bytes, 3 ops)
2014-08-06 04:19:32,540 INFO  [FlushWriter:55] 2014-08-06 04:19:32,540 Memtable.java (line
403) Completed flushing /data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-67-Data.db
(129 bytes) for commitlog position ReplayPosition(segmentId=1407287842781, position=18159774)
{code}

So these particular flushes happen as a result of 3 mystery ops in this CF (it isn't the only
one, but an obvious choice)... note these ops appeared as of 2.0.5, but the metering of the
memtable did not happen frequently - maybe once every few weeks, so sort of lost in noise.

In relation to all this, CASSANDRA-6944, CASSANDRA-6945 and CASSANDRA-7401, I still think
it is a bug (or at least unintended) that we end up metering empty memtables, so I dislike
the band-aid of turning these to debug (though it would make my inbox happier in the short
term) - Whilst empty memtables were sometimes metered before CASSANDRA-6945, that change made
it happen it seems on every flush (I presume these particular memtables are being flushed
due to other more pressing activity in the system). I'm not sure it is clear what the semantics
are supposed to be now when the metering occurs after the active memtable has been switched.

In any case, In the meanwhile, I will look at where these 3 (phantom) ops are coming from
since they seem to be in every memtable




was (Author: graham sanderson):
I can see where many of them are coming from (prior to this change but with 2.0.9 they started
appearing)

{code}
2014-08-06 04:02:34,026 INFO  [MemoryMeter:1] 2014-08-06 04:02:34,026 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:02:34,069 INFO  [MemoryMeter:1] 2014-08-06 04:02:34,069 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:02:34,117 INFO  [InternalResponseStage:87] 2014-08-06 04:02:34,117 ColumnFamilyStore.java
(line 794) Enqueuing flush of Memtable-schema_triggers@1406319171(0/0 serialized/live bytes,
3 ops)
2014-08-06 04:02:34,118 INFO  [FlushWriter:41] 2014-08-06 04:02:34,118 Memtable.java (line
363) Writing Memtable-schema_triggers@1406319171(0/0 serialized/live bytes, 3 ops)
2014-08-06 04:02:34,124 INFO  [FlushWriter:41] 2014-08-06 04:02:34,124 Memtable.java (line
403) Completed flushing /data/6/cassandra/system/schema_triggers/system-schema_triggers-jb-60-Data.db
(129 bytes) for commitlog position ReplayPosition(segmentId=1407287842775, position=7415363)
2014-08-06 04:02:34,126 INFO  [CompactionExecutor:185] 2014-08-06 04:02:34,126 CompactionTask.java
(line 115) Compacting [SSTableReader(path='/data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-59-Data.db'),
SSTableReader(path='/data/6/cassandra/system/schema_triggers/system-schema_triggers-jb-60-Data.db'),
SSTableReader(path='/data/6/cassandra/system/schema_triggers/system-schema_triggers-jb-58-Data.db'),
SSTableReader(path='/data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-57-Data.db')]
2014-08-06 04:02:34,796 INFO  [MemoryMeter:1] 2014-08-06 04:02:34,796 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:02:34,844 INFO  [MemoryMeter:1] 2014-08-06 04:02:34,844 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:02:34,896 INFO  [InternalResponseStage:88] 2014-08-06 04:02:34,896 ColumnFamilyStore.java
(line 794) Enqueuing flush of Memtable-schema_triggers@349252843(0/0 serialized/live bytes,
3 ops)
2014-08-06 04:02:34,897 INFO  [FlushWriter:38] 2014-08-06 04:02:34,897 Memtable.java (line
363) Writing Memtable-schema_triggers@349252843(0/0 serialized/live bytes, 3 ops)
2014-08-06 04:02:34,903 INFO  [FlushWriter:38] 2014-08-06 04:02:34,903 Memtable.java (line
403) Completed flushing /data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-61-Data.db
(129 bytes) for commitlog position ReplayPosition(segmentId=1407287842775, position=7995460)
2014-08-06 04:12:47,723 INFO  [MemoryMeter:1] 2014-08-06 04:12:47,723 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:12:47,749 INFO  [MemoryMeter:1] 2014-08-06 04:12:47,749 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:12:47,815 INFO  [InternalResponseStage:101] 2014-08-06 04:12:47,815 ColumnFamilyStore.java
(line 794) Enqueuing flush of Memtable-schema_triggers@1809531694(0/0 serialized/live bytes,
3 ops)
2014-08-06 04:12:47,816 INFO  [FlushWriter:48] 2014-08-06 04:12:47,816 Memtable.java (line
363) Writing Memtable-schema_triggers@1809531694(0/0 serialized/live bytes, 3 ops)
2014-08-06 04:12:47,821 INFO  [FlushWriter:48] 2014-08-06 04:12:47,821 Memtable.java (line
403) Completed flushing /data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-62-Data.db
(129 bytes) for commitlog position ReplayPosition(segmentId=1407287842777, position=23729801)
2014-08-06 04:12:49,257 INFO  [MemoryMeter:1] 2014-08-06 04:12:49,257 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:12:49,301 INFO  [MemoryMeter:1] 2014-08-06 04:12:49,301 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:12:49,349 INFO  [InternalResponseStage:103] 2014-08-06 04:12:49,349 ColumnFamilyStore.java
(line 794) Enqueuing flush of Memtable-schema_triggers@91416114(0/0 serialized/live bytes,
3 ops)
2014-08-06 04:12:49,350 INFO  [FlushWriter:48] 2014-08-06 04:12:49,350 Memtable.java (line
363) Writing Memtable-schema_triggers@91416114(0/0 serialized/live bytes, 3 ops)
2014-08-06 04:12:49,357 INFO  [FlushWriter:48] 2014-08-06 04:12:49,357 Memtable.java (line
403) Completed flushing /data/6/cassandra/system/schema_triggers/system-schema_triggers-jb-63-Data.db
(129 bytes) for commitlog position ReplayPosition(segmentId=1407287842777, position=25231718)
2014-08-06 04:13:33,224 INFO  [MemoryMeter:1] 2014-08-06 04:13:33,224 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:13:33,250 INFO  [MemoryMeter:1] 2014-08-06 04:13:33,250 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:13:33,324 INFO  [InternalResponseStage:106] 2014-08-06 04:13:33,324 ColumnFamilyStore.java
(line 794) Enqueuing flush of Memtable-schema_triggers@157617667(0/0 serialized/live bytes,
3 ops)
2014-08-06 04:13:33,325 INFO  [FlushWriter:51] 2014-08-06 04:13:33,325 Memtable.java (line
363) Writing Memtable-schema_triggers@157617667(0/0 serialized/live bytes, 3 ops)
2014-08-06 04:13:33,330 INFO  [FlushWriter:51] 2014-08-06 04:13:33,330 Memtable.java (line
403) Completed flushing /data/6/cassandra/system/schema_triggers/system-schema_triggers-jb-64-Data.db
(129 bytes) for commitlog position ReplayPosition(segmentId=1407287842778, position=4977305)
2014-08-06 04:13:33,332 INFO  [CompactionExecutor:213] 2014-08-06 04:13:33,332 CompactionTask.java
(line 115) Compacting [SSTableReader(path='/data/6/cassandra/system/schema_triggers/system-schema_triggers-jb-64-Data.db'),
SSTableReader(path='/data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-61-Data.db'),
SSTableReader(path='/data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-62-Data.db'),
SSTableReader(path='/data/6/cassandra/system/schema_triggers/system-schema_triggers-jb-63-Data.db')]
2014-08-06 04:13:46,756 INFO  [MemoryMeter:1] 2014-08-06 04:13:46,756 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:13:46,771 INFO  [MemoryMeter:1] 2014-08-06 04:13:46,771 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:13:46,892 INFO  [InternalResponseStage:108] 2014-08-06 04:13:46,892 ColumnFamilyStore.java
(line 794) Enqueuing flush of Memtable-schema_triggers@1625969376(0/0 serialized/live bytes,
3 ops)
2014-08-06 04:13:46,896 INFO  [FlushWriter:51] 2014-08-06 04:13:46,896 Memtable.java (line
363) Writing Memtable-schema_triggers@1625969376(0/0 serialized/live bytes, 3 ops)
2014-08-06 04:13:46,903 INFO  [FlushWriter:51] 2014-08-06 04:13:46,903 Memtable.java (line
403) Completed flushing /data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-65-Data.db
(129 bytes) for commitlog position ReplayPosition(segmentId=1407287842778, position=9486910)
2014-08-06 04:19:31,886 INFO  [MemoryMeter:1] 2014-08-06 04:19:31,886 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:19:31,934 INFO  [MemoryMeter:1] 2014-08-06 04:19:31,934 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 1ms for 0 cells
2014-08-06 04:19:31,987 INFO  [InternalResponseStage:110] 2014-08-06 04:19:31,987 ColumnFamilyStore.java
(line 794) Enqueuing flush of Memtable-schema_triggers@431225069(0/0 serialized/live bytes,
3 ops)
2014-08-06 04:19:31,989 INFO  [FlushWriter:58] 2014-08-06 04:19:31,989 Memtable.java (line
363) Writing Memtable-schema_triggers@431225069(0/0 serialized/live bytes, 3 ops)
2014-08-06 04:19:31,994 INFO  [FlushWriter:58] 2014-08-06 04:19:31,994 Memtable.java (line
403) Completed flushing /data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-66-Data.db
(129 bytes) for commitlog position ReplayPosition(segmentId=1407287842781, position=17483747)
2014-08-06 04:19:32,434 INFO  [MemoryMeter:1] 2014-08-06 04:19:32,434 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:19:32,480 INFO  [MemoryMeter:1] 2014-08-06 04:19:32,480 Memtable.java (line
481) CFS(Keyspace='system', ColumnFamily='schema_triggers') liveRatio is 64.0 (just-counted
was 64.0).  calculation took 0ms for 0 cells
2014-08-06 04:19:32,529 INFO  [InternalResponseStage:111] 2014-08-06 04:19:32,529 ColumnFamilyStore.java
(line 794) Enqueuing flush of Memtable-schema_triggers@928567559(0/0 serialized/live bytes,
3 ops)
2014-08-06 04:19:32,535 INFO  [FlushWriter:55] 2014-08-06 04:19:32,535 Memtable.java (line
363) Writing Memtable-schema_triggers@928567559(0/0 serialized/live bytes, 3 ops)
2014-08-06 04:19:32,540 INFO  [FlushWriter:55] 2014-08-06 04:19:32,540 Memtable.java (line
403) Completed flushing /data/1/cassandra/system/schema_triggers/system-schema_triggers-jb-67-Data.db
(129 bytes) for commitlog position ReplayPosition(segmentId=1407287842781, position=18159774)
{code}

In relation to this, CASSANDRA-6944, CASSANDRA-6945 and CASSANDRA-7401...

I still think it is a bug (or at least unintended) that we end up metering empty memtables,
so I dislike the band-aid of turning these to debug (though it would make my inbox happier
in the short term) - Whilst empty memtables were sometimes metered before CASSANDRA-6945,
that change made it happen it seems on every flush (I presume these particular memtables are
being flushed due to other more pressing activity in the system). I'm not sure it is clear
what the semantics are supposed to be now when the metering occurs after the active memtable
has been switched.

In any case, In the meanwhile, I will look at where these 3 (phantom) ops are coming from
since they seem to be in every memtable



> flood of "setting live ratio to maximum of 64" from repair
> ----------------------------------------------------------
>
>                 Key: CASSANDRA-7467
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-7467
>             Project: Cassandra
>          Issue Type: Bug
>          Components: Core
>            Reporter: Jackson Chung
>            Assignee: Aleksey Yeschenko
>             Fix For: 2.0.10
>
>
> we are on 2.0.8
> running with repair -pr -local <KS>, all nodes on i2.2x (60G ram);, with setting
8G of heap. Using java 8. (key cache size is 1G)
> On occasion, when repair is run, the C* that run the repair, or another node in the cluster,
or both, run into a bad state with the system.log just printing ""setting live ratio to maximum
of 64"  forever every split seconds. It usually happens when repairing one of the larger/wider
CF. 
>  WARN [MemoryMeter:1] 2014-06-28 09:13:24,540 Memtable.java (line 470) setting live ratio
to maximum of 64.0 instead of Infinity
>  INFO [MemoryMeter:1] 2014-06-28 09:13:24,540 Memtable.java (line 481) CFS(Keyspace='RIQ',
ColumnFamily='MemberTimeline') liveRatio is 64.0 (just-counted was 64.0).  calculation took
0ms for 0 cells
> 		Table: MemberTimeline
> 		SSTable count: 13
> 		Space used (live), bytes: 17644018786
> ...
> 		Compacted partition minimum bytes: 30
> 		Compacted partition maximum bytes: 464228842
> 		Compacted partition mean bytes: 54578
> Just to give an idea of how bad this is, the log file is set to rotate 50 times with
21M each. In less than 15 minutes, all the logs are filled up with just that log. C* is not
responding, and can't be killed normally. Only way is to kill -9



--
This message was sent by Atlassian JIRA
(v6.2#6252)

Mime
View raw message