You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cassandra.apache.org by "graham sanderson (JIRA)" <ji...@apache.org> on 2014/08/07 01:12:15 UTC
[jira] [Comment Edited] (CASSANDRA-7467) flood of "setting live
ratio to maximum of 64" from repair
[ 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)