[CASSANDRA-7701] Infinite flush loop

• Type: Bug
• Status: Resolved
• Priority: Normal
• Resolution: Not A Problem
• Fix Version/s: 2.1.0
• Severity: Normal
• Assignee: Unassigned
• Reporter: Brandon Williams
• Created: 05/Aug/14 20:51
• Updated: 16/Apr/19 09:31
• Resolved: 05/Aug/14 21:04

Description

If you run the repro from CASSANDRA-7695, you can get an infinite flush loop:

NFO  20:46:34 Compacting [SSTableReader(path='/var/lib/cassandra/data/cass_test/put_test-3252eb901cde11e4a736517bcdb23258/cass_test-put_test-ka-1442-Data.db'), SSTableReader(path='/var/lib/cassandra/data/cass_test/put_test-3252eb901cde11e4a736517bcdb23258/cass_test-put_test-ka-1443-Data.db'), SSTableReader(path='/var/lib/cassandra/data/cass_test/put_test-3252eb901cde11e4a736517bcdb23258/cass_test-put_test-ka-1440-Data.db'), SSTableReader(path='/var/lib/cassandra/data/cass_test/put_test-3252eb901cde11e4a736517bcdb23258/cass_test-put_test-ka-1441-Data.db')]
INFO  20:46:34 Enqueuing flush of compactions_in_progress: 180 (0%) on-heap, 0 (0%) off-heap
INFO  20:46:34 Writing Memtable-compactions_in_progress@842537816(0 serialized bytes, 1 ops, 0%/0% of on/off-heap limit)
INFO  20:46:34 Completed flushing /var/lib/cassandra/data/system/compactions_in_progress-55080ab05d9c388690a4acb25fe1f77b/system-compactions_in_progress-ka-954-Data.db (42 bytes) for commitlog position ReplayPosition(segmentId=1407269935245, position=12803233)
INFO  20:46:34 Compacted 4 sstables to [/var/lib/cassandra/data/cass_test/put_test-3252eb901cde11e4a736517bcdb23258/cass_test-put_test-ka-1444,].  9,664 bytes to 2,416 (~25% of original) in 37ms = 0.062272MB/s.  4 total partitions merged to 1.  Partition merge counts were {4:1, }
INFO  20:46:35 Enqueuing flush of put_test: 87040444 (33%) on-heap, 0 (0%) off-heap
INFO  20:46:35 Writing Memtable-put_test@418061108(512021 serialized bytes, 356 ops, 33%/0% of on/off-heap limit)
INFO  20:46:35 Completed flushing /var/lib/cassandra/data/cass_test/put_test-3252eb901cde11e4a736517bcdb23258/cass_test-put_test-ka-1445-Data.db (2416 bytes) for commitlog position ReplayPosition(segmentId=1407269935247, position=30214640)
INFO  20:46:37 Enqueuing flush of put_test: 87040444 (33%) on-heap, 0 (0%) off-heap
INFO  20:46:37 Writing Memtable-put_test@1715686331(512021 serialized bytes, 348 ops, 33%/0% of on/off-heap limit)
INFO  20:46:37 Completed flushing /var/lib/cassandra/data/cass_test/put_test-3252eb901cde11e4a736517bcdb23258/cass_test-put_test-ka-1446-Data.db (2416 bytes) for commitlog position ReplayPosition(segmentId=1407269935250, position=19460288)
INFO  20:46:39 Enqueuing flush of put_test: 87040444 (33%) on-heap, 0 (0%) off-heap
INFO  20:46:39 Writing Memtable-put_test@295716698(512021 serialized bytes, 344 ops, 33%/0% of on/off-heap limit)
INFO  20:46:39 Completed flushing /var/lib/cassandra/data/cass_test/put_test-3252eb901cde11e4a736517bcdb23258/cass_test-put_test-ka-1447-Data.db (2416 bytes) for commitlog position ReplayPosition(segmentId=1407269935253, position=7681712)
INFO  20:46:39 Enqueuing flush of compactions_in_progress: 1333 (0%) on-heap, 0 (0%) off-heap
INFO  20:46:39 Writing Memtable-compactions_in_progress@833384128(143 serialized bytes, 9 ops, 0%/0% of on/off-heap limit)
INFO  20:46:39 Completed flushing /var/lib/cassandra/data/system/compactions_in_progress-55080ab05d9c388690a4acb25fe1f77b/system-compactions_in_progress-ka-955-Data.db (166 bytes) for commitlog position ReplayPosition(segmentId=1407269935253, position=8194154)
INFO  20:46:39 Compacting [SSTableReader(path='/var/lib/cassandra/data/cass_test/put_test-3252eb901cde11e4a736517bcdb23258/cass_test-put_test-ka-1447-Data.db'), SSTableReader(path='/var/lib/cassandra/data/cass_test/put_test-3252eb901cde11e4a736517bcdb23258/cass_test-put_test-ka-1446-Data.db'), SSTableReader(path='/var/lib/cassandra/data/cass_test/put_test-3252eb901cde11e4a736517bcdb23258/cass_test-put_test-ka-1445-Data.db'), SSTableReader(path='/var/lib/cassandra/data/cass_test/put_test-3252eb901cde11e4a736517bcdb23258/cass_test-put_test-ka-1444-Data.db')]
INFO  20:46:39 Compacting [SSTableReader(path='/var/lib/cassandra/data/system/compactions_in_progress-55080ab05d9c388690a4acb25fe1f77b/system-compactions_in_progress-ka-952-Data.db'), SSTableReader(path='/var/lib/cassandra/data/system/compactions_in_progress-55080ab05d9c388690a4acb25fe1f77b/system-compactions_in_progress-ka-955-Data.db'), SSTableReader(path='/var/lib/cassandra/data/system/compactions_in_progress-55080ab05d9c388690a4acb25fe1f77b/system-compactions_in_progress-ka-953-Data.db'), SSTableReader(path='/var/lib/cassandra/data/system/compactions_in_progress-55080ab05d9c388690a4acb25fe1f77b/system-compactions_in_progress-ka-954-Data.db')]
INFO  20:46:39 Enqueuing flush of compactions_in_progress: 180 (0%) on-heap, 0 (0%) off-heap
INFO  20:46:39 Writing Memtable-compactions_in_progress@1180400490(0 serialized bytes, 1 ops, 0%/0% of on/off-heap limit)
INFO  20:46:39 Compacted 4 sstables to [/var/lib/cassandra/data/system/compactions_in_progress-55080ab05d9c388690a4acb25fe1f77b/system-compactions_in_progress-ka-956,].  462 bytes to 166 (~35% of original) in 44ms = 0.003598MB/s.  5 total partitions merged to 1.  Partition merge counts were {1:3, 2:1, }
INFO  20:46:39 Completed flushing /var/lib/cassandra/data/system/compactions_in_progress-55080ab05d9c388690a4acb25fe1f77b/system-compactions_in_progress-ka-957-Data.db (42 bytes) for commitlog position ReplayPosition(segmentId=1407269935253, position=12803233)
INFO  20:46:39 Compacted 4 sstables to [/var/lib/cassandra/data/cass_test/put_test-3252eb901cde11e4a736517bcdb23258/cass_test-put_test-ka-1448,].  9,664 bytes to 2,416 (~25% of original) in 68ms = 0.033883MB/s.  4 total partitions merged to 1.  Partition merge counts were {4:1, }
INFO  20:46:40 Enqueuing flush of put_test: 87040444 (33%) on-heap, 0 (0%) off-heap
INFO  20:46:40 Writing Memtable-put_test@553655581(512021 serialized bytes, 358 ops, 33%/0% of on/off-heap limit)
INFO  20:46:40 Completed flushing /var/lib/cassandra/data/cass_test/put_test-3252eb901cde11e4a736517bcdb23258/cass_test-put_test-ka-1449-Data.db (2416 bytes) for commitlog position ReplayPosition(segmentId=1407269935255, position=32775200)
INFO  20:46:42 Enqueuing flush of put_test: 87040444 (33%) on-heap, 0 (0%) off-heap
INFO  20:46:42 Writing Memtable-put_test@1630754028(512021 serialized bytes, 354 ops, 34%/0% of on/off-heap limit)
INFO  20:46:42 Completed flushing /var/lib/cassandra/data/cass_test/put_test-3252eb901cde11e4a736517bcdb23258/cass_test-put_test-ka-1450-Data.db (2416 bytes) for commitlog position ReplayPosition(segmentId=1407269935258, position=23557184)

This keeps going long after the run is complete. Restarting the node stops the loop.