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:33:14 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:32 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; 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 not something that garnered particular scrutiny.

Note I guess that mis-estimating this particular CF is not a big issue since it is empty anyway,
but I'm not a huge fan of band-aiding the issue with debug logging, since once the noise dies
down we may find other cases (there are other non empty CFs in our logs I need to look at)
where it may really be a warning that the wrong memtable (not expected to be empty) is being
metered.

This is all related to CASSANDRA-6944, CASSANDRA-6945 and CASSANDRA-7401.

CASSANDRA-6945 certainly seems to be responsible for these odd cases being metered more often
(which I don't believe was the intent).



was (Author: graham sanderson):
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; 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.

Note I guess that mis-estimating this particular CF is not a big issue since it is empty anyway,
but I'm not a huge fan of band-aiding the issue with debug logging, since once the noise dies
down we may find other cases (there are other non empty CFs in our logs I need to look at)
where it may really be a warning that the wrong memtable (not expected to be empty) is being
metered.

This is all related to CASSANDRA-6944, CASSANDRA-6945 and CASSANDRA-7401.

CASSANDRA-6945 certainly seems to be responsible for these odd cases being metered more often
(which I don't believe was the intent).


> 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