[
https://issues.apache.org/jira/browse/HBASE-3481?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12987965#action_12987965
]
Todd Lipcon commented on HBASE-3481:
------------------------------------
BTW, think I ran into another ramification of this bug. I had a region split,
but even after the parent was closed, it remained in the {{lastSeqWritten}}
map in HLog. So, my log shows:
2011-01-27 11:34:21,784 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too
many hlogs: logs=46, maxlogs=32; forcing flush of 5 regions(s):
1064fef659ccf634bfb6dbd24a3d3e32, 2e84570f830560a49276e236ebfb53ed,
61b89db95b24fbc6cabf6661cfbc9534, 6f219526af6c8a9e180324bd5d03a08b, d7e912ab428
2011-01-27 11:34:21,784 WARN org.apache.hadoop.hbase.regionserver.LogRoller:
Failed to schedule flush of d7e912ab428b25dbb388edda934591a0r=null,
requester=null
2011-01-27 11:34:45,904 INFO org.apache.hadoop.hbase.regionserver.wal.HLog: Too
many hlogs: logs=47, maxlogs=32; forcing flush of 1 regions(s):
d7e912ab428b25dbb388edda934591a0
2011-01-27 11:34:45,934 WARN org.apache.hadoop.hbase.regionserver.LogRoller:
Failed to schedule flush of d7e912ab428b25dbb388edda934591a0r=null,
requester=null
...
and I ended up with hundreds of HLogs. This was with a mixed put/ICV workload
> max seq id in flushed file can be larger than its correct value causing data
> loss during recovery
> -------------------------------------------------------------------------------------------------
>
> Key: HBASE-3481
> URL: https://issues.apache.org/jira/browse/HBASE-3481
> Project: HBase
> Issue Type: Bug
> Reporter: Kannan Muthukkaruppan
> Assignee: ryan rawson
> Priority: Blocker
> Fix For: 0.90.1, 0.92.0
>
> Attachments: HBASE-3481.txt
>
>
> [While doing some cluster kill tests, I noticed some missing data after log
> recovery. Upon investigating further, and pretty printing contents of HFiles
> and recovered logs, this is my analysis of the situation/bug. Please confirm
> the theory and pitch in with suggestions.]
> When memstores are flushed, the max sequence id recorded in the HFile should
> be the max sequence id of all KVs in the memstore. However, we seem to simply
> obtain the current sequence id from the HRegion, and stamp the HFile's
> MAX_SEQ_ID with it.
> From HRegion.java:
> {code}
> sequenceId = (wal == null)? myseqid: wal.startCacheFlush();
> {code}
> where, startCacheFlush() is:
> {code}
> public long startCacheFlush() {
> this.cacheFlushLock.lock();
> return obtainSeqNum();
> }
> {code}
> where, obtainSeqNum() is simply:
> {code}
> private long obtainSeqNum() {
> return this.logSeqNum.incrementAndGet();
> }
> {code}
> So let's say a memstore contains edits with sequence number 1..10.
> Meanwhile, say more Puts come along, and are going through this flow (in
> pseudo-code)
> {code}
> 1. HLog.append();
> 1.1 obtainSeqNum()
> 1.2 writeToWAL()
> 2 updateMemStore()
> {code}
> So it is possible that the sequence number has already been incremented to
> say 15 if there are 5 more outstanding puts. Say the writeToWAL() is still in
> progress for these puts. In this case, none of these edits (11..15) would
> have been written to memstore yet.
> At this point if a cache flush of the memstore happens, then we'll record its
> MAX_SEQ_ID as 16 in the store file instead of 10 (because that's what
> obtainSeqNum() would return as the next sequence number to use, right?).
> Assume that the edits 11..15 eventually complete. And so HLogs do contain the
> data for edits 11..15.
> Now, at this point if the region server were to crash, and we run log
> recovery, the splits all go through correctly, and a correct recovered.edits
> file is generated with the edits 11..15.
> Next, when the region is opened, the HRegion notes that one of the store file
> says MAX_SEQ_ID is 16. So, when it replays the recovered.edits file, it
> skips replaying edits 11..15. Or in other words, data loss.
> ----
--
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.
