cassandra-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Michael Kjellman (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (CASSANDRA-5241) Fix forceBlockingFlush
Date Sat, 16 Feb 2013 18:31:12 GMT

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

Michael Kjellman commented on CASSANDRA-5241:
---------------------------------------------

i reverted this (and also #5151, but I had run that in production for a week..) and things
have gone back to "normal" so far, which is what I would expect. All of the compactions/flushes
were all on the system table as far as i can tell.

{code}
INFO [InternalResponseStage:1] 2013-02-15 16:34:47,544 ColumnFamilyStore.java (line 631) Enqueuing
flush of Memtable-schema_columnfamilies@857773834(29769/104976 serialized/live bytes, 449
ops)
 INFO [FlushWriter:2] 2013-02-15 16:34:47,544 Memtable.java (line 453) Writing Memtable-schema_columnfamilies@857773834(29769/104976
serialized/live bytes, 449 ops)
 INFO [FlushWriter:2] 2013-02-15 16:34:48,594 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_columnfamilies/system-schema_columnfamilies-ib-2544-Data.db
(6450 bytes) for commitlog position ReplayPosition(segmentId=1360972349957, position=33437754)
 INFO [InternalResponseStage:1] 2013-02-15 16:34:48,596 ColumnFamilyStore.java (line 631)
Enqueuing flush of Memtable-schema_columns@1895125890(4160/22541 serialized/live bytes, 48
ops)
 INFO [FlushWriter:1] 2013-02-15 16:34:48,597 Memtable.java (line 453) Writing Memtable-schema_columns@1895125890(4160/22541
serialized/live bytes, 48 ops)
 INFO [FlushWriter:1] 2013-02-15 16:34:49,120 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_columns/system-schema_columns-ib-2508-Data.db (1111 bytes) for
commitlog position ReplayPosition(segmentId=1360972349957, position=33443208)
 INFO [InternalResponseStage:4] 2013-02-15 16:34:49,218 ColumnFamilyStore.java (line 631)
Enqueuing flush of Memtable-schema_keyspaces@1421427252(613/5719 serialized/live bytes, 15
ops)
 INFO [FlushWriter:2] 2013-02-15 16:34:49,219 Memtable.java (line 453) Writing Memtable-schema_keyspaces@1421427252(613/5719
serialized/live bytes, 15 ops)
 INFO [FlushWriter:2] 2013-02-15 16:34:49,763 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_keyspaces/system-schema_keyspaces-ib-2461-Data.db (380 bytes)
for commitlog position ReplayPosition(segmentId=1360972349957, position=33488931)
 INFO [InternalResponseStage:4] 2013-02-15 16:34:49,765 ColumnFamilyStore.java (line 631)
Enqueuing flush of Memtable-schema_columnfamilies@135054804(29769/104976 serialized/live bytes,
449 ops)
 INFO [FlushWriter:1] 2013-02-15 16:34:49,765 Memtable.java (line 453) Writing Memtable-schema_columnfamilies@135054804(29769/104976
serialized/live bytes, 449 ops)
 INFO [FlushWriter:1] 2013-02-15 16:34:50,373 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_columnfamilies/system-schema_columnfamilies-ib-2545-Data.db
(6450 bytes) for commitlog position ReplayPosition(segmentId=1360972349957, position=33492822)
 INFO [CompactionExecutor:3] 2013-02-15 16:34:50,374 CompactionTask.java (line 110) Compacting
[SSTableReader(path='/data/cassandra/system/schema_columnfamilies/system-schema_columnfamilies-ib-2545-Data.db'),
SSTableReader(path='/data/cassandra/system/schema_columnfamilies/system-schema_columnfamilies-ib-2543-Data.db'),
SSTableReader(path='/data/cassandra/system/schema_columnfamilies/system-schema_columnfamilies-ib-2544-Data.db'),
SSTableReader(path='/data/cassandra/system/schema_columnfamilies/system-schema_columnfamilies-ib-2542-Data.db')]
 INFO [InternalResponseStage:4] 2013-02-15 16:34:50,374 ColumnFamilyStore.java (line 631)
Enqueuing flush of Memtable-schema_columns@952822131(4160/22541 serialized/live bytes, 48
ops)
 INFO [FlushWriter:2] 2013-02-15 16:34:50,375 Memtable.java (line 453) Writing Memtable-schema_columns@952822131(4160/22541
serialized/live bytes, 48 ops)
 INFO [FlushWriter:2] 2013-02-15 16:34:51,467 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_columns/system-schema_columns-ib-2509-Data.db (1111 bytes) for
commitlog position ReplayPosition(segmentId=1360972349957, position=33497016)
 INFO [CompactionExecutor:3] 2013-02-15 16:34:51,552 CompactionTask.java (line 267) Compacted
4 sstables to [/data/cassandra/system/schema_columnfamilies/system-schema_columnfamilies-ib-2546,].
 30,610 bytes to 11,260 (~36% of original) in 1,178ms = 0.009116MB/s.  19 total rows, 7 unique.
 Row merge counts were {1:3, 2:0, 3:0, 4:4, }
 INFO [InternalResponseStage:1] 2013-02-15 16:34:51,840 ColumnFamilyStore.java (line 631)
Enqueuing flush of Memtable-schema_keyspaces@812842029(613/5719 serialized/live bytes, 15
ops)
 INFO [FlushWriter:1] 2013-02-15 16:34:51,840 Memtable.java (line 453) Writing Memtable-schema_keyspaces@812842029(613/5719
serialized/live bytes, 15 ops)
 INFO [FlushWriter:1] 2013-02-15 16:34:52,469 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_keyspaces/system-schema_keyspaces-ib-2462-Data.db (380 bytes)
for commitlog position ReplayPosition(segmentId=1360972349957, position=33543564)
 INFO [CompactionExecutor:1] 2013-02-15 16:34:52,470 CompactionTask.java (line 110) Compacting
[SSTableReader(path='/data/cassandra/system/schema_keyspaces/system-schema_keyspaces-ib-2460-Data.db'),
SSTableReader(path='/data/cassandra/system/schema_keyspaces/system-schema_keyspaces-ib-2461-Data.db'),
SSTableReader(path='/data/cassandra/system/schema_keyspaces/system-schema_keyspaces-ib-2462-Data.db'),
SSTableReader(path='/data/cassandra/system/schema_keyspaces/system-schema_keyspaces-ib-2459-Data.db')]
 INFO [InternalResponseStage:1] 2013-02-15 16:34:52,471 ColumnFamilyStore.java (line 631)
Enqueuing flush of Memtable-schema_columnfamilies@1702036678(29769/104976 serialized/live
bytes, 449 ops)
 INFO [FlushWriter:2] 2013-02-15 16:34:52,471 Memtable.java (line 453) Writing Memtable-schema_columnfamilies@1702036678(29769/104976
serialized/live bytes, 449 ops)
 INFO [FlushWriter:2] 2013-02-15 16:34:53,696 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_columnfamilies/system-schema_columnfamilies-ib-2547-Data.db
(6450 bytes) for commitlog position ReplayPosition(segmentId=1360972349957, position=33550747)
 INFO [InternalResponseStage:1] 2013-02-15 16:34:53,698 ColumnFamilyStore.java (line 631)
Enqueuing flush of Memtable-schema_columns@1044114603(4160/22541 serialized/live bytes, 48
ops)
 INFO [FlushWriter:1] 2013-02-15 16:34:53,699 Memtable.java (line 453) Writing Memtable-schema_columns@1044114603(4160/22541
serialized/live bytes, 48 ops)
 INFO [CompactionExecutor:1] 2013-02-15 16:34:53,864 CompactionTask.java (line 267) Compacted
4 sstables to [/data/cassandra/system/schema_keyspaces/system-schema_keyspaces-ib-2463,].
 1,670 bytes to 530 (~31% of original) in 1,394ms = 0.000363MB/s.  19 total rows, 7 unique.
 Row merge counts were {1:3, 2:0, 3:0, 4:4, }
 INFO [FlushWriter:1] 2013-02-15 16:34:54,306 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_columns/system-schema_columns-ib-2510-Data.db (1111 bytes) for
commitlog position ReplayPosition(segmentId=1360972349958, position=2773)
 INFO [CompactionExecutor:4] 2013-02-15 16:34:54,307 CompactionTask.java (line 110) Compacting
[SSTableReader(path='/data/cassandra/system/schema_columns/system-schema_columns-ib-2507-Data.db'),
SSTableReader(path='/data/cassandra/system/schema_columns/system-schema_columns-ib-2509-Data.db'),
SSTableReader(path='/data/cassandra/system/schema_columns/system-schema_columns-ib-2510-Data.db'),
SSTableReader(path='/data/cassandra/system/schema_columns/system-schema_columns-ib-2508-Data.db')]
 INFO [InternalResponseStage:2] 2013-02-15 16:34:54,399 ColumnFamilyStore.java (line 631)
Enqueuing flush of Memtable-schema_keyspaces@2087735380(613/5719 serialized/live bytes, 15
ops)
 INFO [FlushWriter:2] 2013-02-15 16:34:54,400 Memtable.java (line 453) Writing Memtable-schema_keyspaces@2087735380(613/5719
serialized/live bytes, 15 ops)
 INFO [FlushWriter:2] 2013-02-15 16:34:55,443 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_keyspaces/system-schema_keyspaces-ib-2464-Data.db (380 bytes)
for commitlog position ReplayPosition(segmentId=1360972349958, position=48584)
 INFO [CompactionExecutor:4] 2013-02-15 16:34:55,444 CompactionTask.java (line 267) Compacted
4 sstables to [/data/cassandra/system/schema_columns/system-schema_columns-ib-2511,].  8,157
bytes to 4,824 (~59% of original) in 1,136ms = 0.004050MB/s.  11 total rows, 5 unique.  Row
merge counts were {1:3, 2:0, 3:0, 4:2, }
 INFO [InternalResponseStage:2] 2013-02-15 16:34:55,445 ColumnFamilyStore.java (line 631)
Enqueuing flush of Memtable-schema_columnfamilies@68491683(29769/104976 serialized/live bytes,
449 ops)
 INFO [FlushWriter:1] 2013-02-15 16:34:55,445 Memtable.java (line 453) Writing Memtable-schema_columnfamilies@68491683(29769/104976
serialized/live bytes, 449 ops)
 INFO [FlushWriter:1] 2013-02-15 16:34:55,445 Memtable.java (line 453) Writing Memtable-schema_columnfamilies@68491683(29769/104976
serialized/live bytes, 449 ops)
 INFO [FlushWriter:1] 2013-02-15 16:34:56,028 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_columnfamilies/system-schema_columnfamilies-ib-2548-Data.db
(6450 bytes) for commitlog position ReplayPosition(segmentId=1360972349958, position=53448)
 INFO [InternalResponseStage:2] 2013-02-15 16:34:56,030 ColumnFamilyStore.java (line 631)
Enqueuing flush of Memtable-schema_columns@1584026962(4160/22541 serialized/live bytes, 48
ops)
 INFO [FlushWriter:2] 2013-02-15 16:34:56,030 Memtable.java (line 453) Writing Memtable-schema_columns@1584026962(4160/22541
serialized/live bytes, 48 ops)
 INFO [FlushWriter:2] 2013-02-15 16:34:56,588 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_columns/system-schema_columns-ib-2512-Data.db (1111 bytes) for
commitlog position ReplayPosition(segmentId=1360972349958, position=57075)
 INFO [InternalResponseStage:3] 2013-02-15 16:34:56,659 ColumnFamilyStore.java (line 631)
Enqueuing flush of Memtable-schema_keyspaces@344869448(613/5719 serialized/live bytes, 15
ops)
 INFO [FlushWriter:1] 2013-02-15 16:34:56,660 Memtable.java (line 453) Writing Memtable-schema_keyspaces@344869448(613/5719
serialized/live bytes, 15 ops)
 INFO [FlushWriter:1] 2013-02-15 16:34:57,255 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_keyspaces/system-schema_keyspaces-ib-2465-Data.db (380 bytes)
for commitlog position ReplayPosition(segmentId=1360972349958, position=101243)
 INFO [InternalResponseStage:3] 2013-02-15 16:34:57,257 ColumnFamilyStore.java (line 631)
Enqueuing flush of Memtable-schema_columnfamilies@155981751(29769/104976 serialized/live bytes,
449 ops)
 INFO [FlushWriter:2] 2013-02-15 16:34:57,257 Memtable.java (line 453) Writing Memtable-schema_columnfamilies@155981751(29769/104976
serialized/live bytes, 449 ops)
 INFO [FlushWriter:2] 2013-02-15 16:34:57,973 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_columnfamilies/system-schema_columnfamilies-ib-2549-Data.db
(6450 bytes) for commitlog position ReplayPosition(segmentId=1360972349958, position=109304)
 INFO [CompactionExecutor:3] 2013-02-15 16:34:57,974 CompactionTask.java (line 110) Compacting
[SSTableReader(path='/data/cassandra/system/schema_columnfamilies/system-schema_columnfamilies-ib-2548-Data.db'),
SSTableReader(path='/data/cassandra/system/schema_columnfamilies/system-schema_columnfamilies-ib-2547-Data.db'),
SSTableReader(path='/data/cassandra/system/schema_columnfamilies/system-schema_columnfamilies-ib-2549-Data.db'),
SSTableReader(path='/data/cassandra/system/schema_columnfamilies/system-schema_columnfamilies-ib-2546-Data.db')]
 INFO [InternalResponseStage:3] 2013-02-15 16:34:57,975 ColumnFamilyStore.java (line 631)
Enqueuing flush of Memtable-schema_columns@1378572796(4160/22541 serialized/live bytes, 48
ops)
 INFO [FlushWriter:1] 2013-02-15 16:34:57,975 Memtable.java (line 453) Writing Memtable-schema_columns@1378572796(4160/22541
serialized/live bytes, 48 ops)
 INFO [FlushWriter:1] 2013-02-15 16:34:59,100 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_columns/system-schema_columns-ib-2513-Data.db (1111 bytes) for
commitlog position ReplayPosition(segmentId=1360972349958, position=115687)
 INFO [CompactionExecutor:3] 2013-02-15 16:34:59,101 CompactionTask.java (line 267) Compacted
4 sstables to [/data/cassandra/system/schema_columnfamilies/system-schema_columnfamilies-ib-2550,].
 30,610 bytes to 11,260 (~36% of original) in 1,127ms = 0.009528MB/s.  19 total rows, 7 unique.
 Row merge counts were {1:3, 2:0, 3:0, 4:4, }
 INFO [InternalResponseStage:2] 2013-02-15 16:34:59,257 ColumnFamilyStore.java (line 631)
Enqueuing flush of Memtable-schema_keyspaces@44063083(613/5719 serialized/live bytes, 15 ops)
 INFO [FlushWriter:2] 2013-02-15 16:34:59,258 Memtable.java (line 453) Writing Memtable-schema_keyspaces@44063083(613/5719
serialized/live bytes, 15 ops)
 INFO [FlushWriter:2] 2013-02-15 16:34:59,811 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_keyspaces/system-schema_keyspaces-ib-2466-Data.db (380 bytes)
for commitlog position ReplayPosition(segmentId=1360972349958, position=163485)
 INFO [CompactionExecutor:4] 2013-02-15 16:34:59,812 CompactionTask.java (line 110) Compacting
[SSTableReader(path='/data/cassandra/system/schema_keyspaces/system-schema_keyspaces-ib-2464-Data.db'),
SSTableReader(path='/data/cassandra/system/schema_keyspaces/system-schema_keyspaces-ib-2463-Data.db'),
SSTableReader(path='/data/cassandra/system/schema_keyspaces/system-schema_keyspaces-ib-2466-Data.db'),
SSTableReader(path='/data/cassandra/system/schema_keyspaces/system-schema_keyspaces-ib-2465-Data.db')]
 INFO [InternalResponseStage:2] 2013-02-15 16:34:59,813 ColumnFamilyStore.java (line 631)
Enqueuing flush of Memtable-schema_columnfamilies@76036956(29769/104976 serialized/live bytes,
449 ops)
 INFO [FlushWriter:1] 2013-02-15 16:34:59,813 Memtable.java (line 453) Writing Memtable-schema_columnfamilies@76036956(29769/104976
serialized/live bytes, 449 ops)
 INFO [FlushWriter:1] 2013-02-15 16:35:00,988 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_columnfamilies/system-schema_columnfamilies-ib-2551-Data.db
(6450 bytes) for commitlog position ReplayPosition(segmentId=1360972349958, position=166562)
 INFO [InternalResponseStage:2] 2013-02-15 16:35:00,990 ColumnFamilyStore.java (line 631)
Enqueuing flush of Memtable-schema_columns@100939726(4160/22541 serialized/live bytes, 48
ops)
 INFO [FlushWriter:2] 2013-02-15 16:35:00,990 Memtable.java (line 453) Writing Memtable-schema_columns@100939726(4160/22541
serialized/live bytes, 48 ops)
 INFO [CompactionExecutor:4] 2013-02-15 16:35:01,089 CompactionTask.java (line 267) Compacted
4 sstables to [/data/cassandra/system/schema_keyspaces/system-schema_keyspaces-ib-2467,].
 1,670 bytes to 530 (~31% of original) in 1,277ms = 0.000396MB/s.  19 total rows, 7 unique.
 Row merge counts were {1:3, 2:0, 3:0, 4:4, }
 INFO [FlushWriter:2] 2013-02-15 16:35:01,657 Memtable.java (line 487) Completed flushing
/data/cassandra/system/schema_columns/system-schema_columns-ib-2514-Data.db (1111 bytes) for
commitlog position ReplayPosition(segmentId=1360972349958, position=171811)
{code}
                
> Fix forceBlockingFlush
> ----------------------
>
>                 Key: CASSANDRA-5241
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-5241
>             Project: Cassandra
>          Issue Type: Improvement
>            Reporter: Sylvain Lebresne
>            Assignee: Marcus Eriksson
>             Fix For: 1.2.2
>
>         Attachments: 0001-CASSANDRA-5241-wait-for-flushing-to-complete-before-.patch
>
>
> ForceBlockingFlush doesn't guarantee that after the call, every that the thread has written
prior to the call will be fully flushed. At least not in the case of concurrent flushes, because
if 2 threads flush roughly at the same time, one will have it's forceBlockingFlush call return
immediately because the memtable will be clean (even though some of the thread writes may
have not be fully flushed yet).
> I think this is very fragile and make it easy to have hard to find races and so we should
fix it. Typically a forceFlush that see a clean memtable could submit a dummy task in the
postFlushExecutor and wait for that.

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Mime
View raw message