[jira] [Commented] (CASSANDRA-14194) Chain commit log marker potential performance regression in batch commit mode

["Jason Brown (JIRA)" <ji...@apache.org>]

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

Jason Brown commented on CASSANDRA-14194:
-----------------------------------------

OK, think I'm at the bottom of this. While trunk is the only branch that is flat-out failing the unit tests due to a problem (see below), 3.0 and 3.11 utests are performing about 5-10% slower (when using batch commit log mode), but that 5-10% isn't enough to cause the test to timeout.
||3.0||3.11||trunk||
|[branch|https://github.com/jasobrown/cassandra/tree/14194-v2-3.0]|[branch|https://github.com/jasobrown/cassandra/tree/14194-v2-3.11]|[branch|https://github.com/jasobrown/cassandra/tree/14194-v2-trunk]|
|[utests & dtests|https://circleci.com/gh/jasobrown/workflows/cassandra/tree/14194-v2-3.0]|[utests & dtests|https://circleci.com/gh/jasobrown/workflows/cassandra/tree/14194-v2-3.11]|[utests & dtests|https://circleci.com/gh/jasobrown/workflows/cassandra/tree/14194-v2-trunk]|

This patch contains a set of small, subtle changes (the same across all three branches):

1) The main fix - There is a race in {{AbstractCommitLogService}} where the {{SyncRunnable}} thread where once we determine to call sync to disk (not just update the headers), we set {{syncRequested}} to false *after* calling {{commitLog.sync(true)}}. This allows us to have a race where {{commitLog.sync(true)}} begins it's marking work, but another mutation comes in, calls {{#requestExtraSync}} (which sets {{syncRequested}} to true, and calls unpark), and blocks in {{Allocation#awaitDiskSync()}}. If no other mutations come in (like in a unit test), {{AbstractCommitLogService}} will not {{commitLog.sync(true)}} (and {{CommitLogSegment#syncComplete}} will not release the blocked mutation) until the syncIntervalNanos is met - which, due to the introduction of the GroupCommitLog, is now hardcoded at 1000ms. By moving the {{syncRequested = false}} *before* the call to {{commitLog.sync(true)}} we eliminate the race.

2) related to #1, right before we choose to park the thread in {{SyncRunnable}}, we can check if {{syncRequested}} is true, and if so, avoid parking. This is a race between the sync thread completing the sync, but before it sleeps a new mutation calls {{#requestExtraSync}} (which unparks), and that mutation then gets stuck when the sync thread does park. If another mutation comes along it will unpark the sync thread, then both mutations can proceed; otherwise, the first mutation is blocked. This should only affect things like unit tests and *very* underutilized clusters. Note: I believe we've had this race since CASSANDRA-10202, but I'm not completely sure.

3) Fix a correctness problem, which, fortunately, has no practical implications - At the end of {{CommitLogSegment#sync()}} we always call {{syncComplete.signalAll()}}. {{syncComplete.signalAll()}} should only be called when we actually msync. Thus, if {{#sync()}} is called with {{flush}} = false, this could be improperly signalling any waiting threads. Luckily, {{AbstractCommitLogService}} should never be calling {{commitLog#sync(false)}} when in batch mode, so there is no improper signalling. However, for soundness of code, I'm moving the {{syncComplete.signalAll()}} call into the {{if(flush || close)}} block in {{CommitLogSegment#sync()}}.

4) {{AbstractCommitLogService#thread}} is now marked volatile. This field is not defined until the {{start()}} method (not the constructor), so we're not guaranteed visibility when the {{#requestExtraSync()}} and {{#awaitTermination()}} methods run. (NOTE: this field was final and defined in the ctor until CASSANDRA-8308, introduced c* 2.2) Admittedly, I'm not thrilled with putting yet another volatile on the commit log path (only in batch mode, in {{#requestExtraSync()}}), but ... correctness? Also, reading a volatile variable isn't much more expensive vs. a regulat LOAD instruction. wdyt? This one arguably could be backported to 2.2+, but that ticket was committed 3.5 years ago we have haven't heard anything, so maybe just 3.0+?

> Chain commit log marker potential performance regression in batch commit mode
> -----------------------------------------------------------------------------
>
>                 Key: CASSANDRA-14194
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-14194
>             Project: Cassandra
>          Issue Type: Bug
>          Components: Core, Testing
>            Reporter: Ariel Weisberg
>            Assignee: Jason Brown
>            Priority: Major
>         Attachments: jstack.txt
>
>
> CASSANDRA-13987 modified how the commit log sync thread works. I noticed that cql3.ViewTest and ViewBuilderTaskTest have been timing out, but only in CircleCI. When I jstack in CircleCI what I see is that the commit log writer thread is parked and the threads trying to append to the commit log are blocked waiting on it.
> I tested the commit before 13987 and it passed in CircleCI and then I tested with 13987 and it timed out. I suspect this may be a general performance regression and not just a CircleCI issue.
> And this is with write barriers disabled (sync thread doesn't actually sync) so it wasn't blocked in the filesystem.



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

---------------------------------------------------------------------
To unsubscribe, e-mail: commits-unsubscribe@cassandra.apache.org
For additional commands, e-mail: commits-help@cassandra.apache.org