You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cassandra.apache.org by "Zhu Han (JIRA)" <ji...@apache.org> on 2011/07/30 09:56:09 UTC

[jira] [Created] (CASSANDRA-2976) Severe bug on commit log replay

Severe bug on commit log replay
-------------------------------

                 Key: CASSANDRA-2976
                 URL: https://issues.apache.org/jira/browse/CASSANDRA-2976
             Project: Cassandra
          Issue Type: Bug
          Components: Core
    Affects Versions: 0.6.13
            Reporter: Zhu Han


For 0.6, the replay order of commit log is determined by modify time(mtime) of commit log files. The roll and update of a new log segment can be finished under 1ms if the log device is backed up by BBU or it is a SSD with super capacitor. So the last log segment and previous segment can have the same mtime.

While File#listFiles() does not guarantee the order of return files, after sorting by mtime, it is possible that the new log segment are replayed before old log segment.  This can causes data loss!

Here is the output of log,  you can observe from the timestamp in the commit log file names that new log segment are replayed before old segment...

 INFO [main] 2011-07-30 01:21:07,569 CommitLog.java (line 171) Replaying /var/lib/cassandra/commitlog/CommitLog-1311959800795.log, /var/lib/cassandra/commitlog/CommitLog-1310661748573.log, /var/lib/cassandra/commitlog/CommitLog-1311838097776.log
 INFO [main] 2011-07-30 01:21:07,571 CommitLog.java (line 286) Finished reading /var/lib/cassandra/commitlog/CommitLog-1311959800795.log
 INFO [main] 2011-07-30 01:21:15,813 CommitLog.java (line 286) Finished reading /var/lib/cassandra/commitlog/CommitLog-1310661748573.log
 INFO [main] 2011-07-30 01:21:15,865 CommitLog.java (line 286) Finished reading /var/lib/cassandra/commitlog/CommitLog-1311838097776.log
 INFO [main] 2011-07-30 01:21:15,926 CommitLog.java (line 174) Log replay complete



I have not checked 0.7.x and 0.8.x, I suppose they both have the same problem.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] [Commented] (CASSANDRA-2976) Severe bug on commit log replay

Posted by "Zhu Han (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/CASSANDRA-2976?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13073146#comment-13073146 ] 

Zhu Han commented on CASSANDRA-2976:
------------------------------------

For file system with coarse time resolution, e.g. ext3 with 1s resolution, this problem can be reproduced much easily...

> Severe bug on commit log replay
> -------------------------------
>
>                 Key: CASSANDRA-2976
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-2976
>             Project: Cassandra
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 0.6.13
>            Reporter: Zhu Han
>   Original Estimate: 4h
>  Remaining Estimate: 4h
>
> For 0.6, the replay order of commit log is determined by modify time(mtime) of commit log files. The roll and update of a new log segment can be finished under 1ms if the log device is backed up by BBU or it is a SSD with super capacitor. So the last log segment and previous segment can have the same mtime.
> While File#listFiles() does not guarantee the order of return files, after sorting by mtime, it is possible that the new log segment are replayed before old log segment.  This can causes data loss!
> Here is the output of log,  you can observe from the timestamp in the commit log file names that new log segment are replayed before old segment...
>  INFO [main] 2011-07-30 01:21:07,569 CommitLog.java (line 171) Replaying /var/lib/cassandra/commitlog/CommitLog-1311959800795.log, /var/lib/cassandra/commitlog/CommitLog-1310661748573.log, /var/lib/cassandra/commitlog/CommitLog-1311838097776.log
>  INFO [main] 2011-07-30 01:21:07,571 CommitLog.java (line 286) Finished reading /var/lib/cassandra/commitlog/CommitLog-1311959800795.log
>  INFO [main] 2011-07-30 01:21:15,813 CommitLog.java (line 286) Finished reading /var/lib/cassandra/commitlog/CommitLog-1310661748573.log
>  INFO [main] 2011-07-30 01:21:15,865 CommitLog.java (line 286) Finished reading /var/lib/cassandra/commitlog/CommitLog-1311838097776.log
>  INFO [main] 2011-07-30 01:21:15,926 CommitLog.java (line 174) Log replay complete
> I have not checked 0.7.x and 0.8.x, I suppose they both have the same problem.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] [Commented] (CASSANDRA-2976) Severe bug on commit log replay

Posted by "Zhu Han (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/CASSANDRA-2976?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13073171#comment-13073171 ] 

Zhu Han commented on CASSANDRA-2976:
------------------------------------

Oh, I just forgot the conflict resolution is still applied during log replay...

Yes, this issue can be closed as the order of log replay does not matter.

> Severe bug on commit log replay
> -------------------------------
>
>                 Key: CASSANDRA-2976
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-2976
>             Project: Cassandra
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 0.6.13
>            Reporter: Zhu Han
>   Original Estimate: 4h
>  Remaining Estimate: 4h
>
> For 0.6, the replay order of commit log is determined by modify time(mtime) of commit log files. The roll and update of a new log segment can be finished under 1ms if the log device is backed up by BBU or it is a SSD with super capacitor. So the last log segment and previous segment can have the same mtime.
> While File#listFiles() does not guarantee the order of return files, after sorting by mtime, it is possible that the new log segment are replayed before old log segment.  This can causes data loss!
> Here is the output of log,  you can observe from the timestamp in the commit log file names that new log segment are replayed before old segment...
>  INFO [main] 2011-07-30 01:21:07,569 CommitLog.java (line 171) Replaying /var/lib/cassandra/commitlog/CommitLog-1311959800795.log, /var/lib/cassandra/commitlog/CommitLog-1310661748573.log, /var/lib/cassandra/commitlog/CommitLog-1311838097776.log
>  INFO [main] 2011-07-30 01:21:07,571 CommitLog.java (line 286) Finished reading /var/lib/cassandra/commitlog/CommitLog-1311959800795.log
>  INFO [main] 2011-07-30 01:21:15,813 CommitLog.java (line 286) Finished reading /var/lib/cassandra/commitlog/CommitLog-1310661748573.log
>  INFO [main] 2011-07-30 01:21:15,865 CommitLog.java (line 286) Finished reading /var/lib/cassandra/commitlog/CommitLog-1311838097776.log
>  INFO [main] 2011-07-30 01:21:15,926 CommitLog.java (line 174) Log replay complete
> I have not checked 0.7.x and 0.8.x, I suppose they both have the same problem.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] [Commented] (CASSANDRA-2976) Severe bug on commit log replay

Posted by "Jonathan Ellis (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/CASSANDRA-2976?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13073167#comment-13073167 ] 

Jonathan Ellis commented on CASSANDRA-2976:
-------------------------------------------

Looks like a non-problem to me -- I'm not sure why it bothers to sort at all (probably so that if replay is aborted you end up with data from roughly the order it was received in) but the conflict resolution is such that the same result will be arrived at no matter the order in which updates are applied.

It's also worth pointing out that each CL segment is replayed independently, there is no "this must be the last segment, skip the rest" logic anywhere.

> Severe bug on commit log replay
> -------------------------------
>
>                 Key: CASSANDRA-2976
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-2976
>             Project: Cassandra
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 0.6.13
>            Reporter: Zhu Han
>   Original Estimate: 4h
>  Remaining Estimate: 4h
>
> For 0.6, the replay order of commit log is determined by modify time(mtime) of commit log files. The roll and update of a new log segment can be finished under 1ms if the log device is backed up by BBU or it is a SSD with super capacitor. So the last log segment and previous segment can have the same mtime.
> While File#listFiles() does not guarantee the order of return files, after sorting by mtime, it is possible that the new log segment are replayed before old log segment.  This can causes data loss!
> Here is the output of log,  you can observe from the timestamp in the commit log file names that new log segment are replayed before old segment...
>  INFO [main] 2011-07-30 01:21:07,569 CommitLog.java (line 171) Replaying /var/lib/cassandra/commitlog/CommitLog-1311959800795.log, /var/lib/cassandra/commitlog/CommitLog-1310661748573.log, /var/lib/cassandra/commitlog/CommitLog-1311838097776.log
>  INFO [main] 2011-07-30 01:21:07,571 CommitLog.java (line 286) Finished reading /var/lib/cassandra/commitlog/CommitLog-1311959800795.log
>  INFO [main] 2011-07-30 01:21:15,813 CommitLog.java (line 286) Finished reading /var/lib/cassandra/commitlog/CommitLog-1310661748573.log
>  INFO [main] 2011-07-30 01:21:15,865 CommitLog.java (line 286) Finished reading /var/lib/cassandra/commitlog/CommitLog-1311838097776.log
>  INFO [main] 2011-07-30 01:21:15,926 CommitLog.java (line 174) Log replay complete
> I have not checked 0.7.x and 0.8.x, I suppose they both have the same problem.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira

        

[jira] [Resolved] (CASSANDRA-2976) Severe bug on commit log replay

Posted by "Zhu Han (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/CASSANDRA-2976?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Zhu Han resolved CASSANDRA-2976.
--------------------------------

    Resolution: Won't Fix

It is not necessary to maintain the order during log replay, as conflict resolution assures the eventual consistency.

> Severe bug on commit log replay
> -------------------------------
>
>                 Key: CASSANDRA-2976
>                 URL: https://issues.apache.org/jira/browse/CASSANDRA-2976
>             Project: Cassandra
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 0.6.13
>            Reporter: Zhu Han
>   Original Estimate: 4h
>  Remaining Estimate: 4h
>
> For 0.6, the replay order of commit log is determined by modify time(mtime) of commit log files. The roll and update of a new log segment can be finished under 1ms if the log device is backed up by BBU or it is a SSD with super capacitor. So the last log segment and previous segment can have the same mtime.
> While File#listFiles() does not guarantee the order of return files, after sorting by mtime, it is possible that the new log segment are replayed before old log segment.  This can causes data loss!
> Here is the output of log,  you can observe from the timestamp in the commit log file names that new log segment are replayed before old segment...
>  INFO [main] 2011-07-30 01:21:07,569 CommitLog.java (line 171) Replaying /var/lib/cassandra/commitlog/CommitLog-1311959800795.log, /var/lib/cassandra/commitlog/CommitLog-1310661748573.log, /var/lib/cassandra/commitlog/CommitLog-1311838097776.log
>  INFO [main] 2011-07-30 01:21:07,571 CommitLog.java (line 286) Finished reading /var/lib/cassandra/commitlog/CommitLog-1311959800795.log
>  INFO [main] 2011-07-30 01:21:15,813 CommitLog.java (line 286) Finished reading /var/lib/cassandra/commitlog/CommitLog-1310661748573.log
>  INFO [main] 2011-07-30 01:21:15,865 CommitLog.java (line 286) Finished reading /var/lib/cassandra/commitlog/CommitLog-1311838097776.log
>  INFO [main] 2011-07-30 01:21:15,926 CommitLog.java (line 174) Log replay complete
> I have not checked 0.7.x and 0.8.x, I suppose they both have the same problem.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira