[
https://issues.apache.org/jira/browse/HBASE-21601?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16757873#comment-16757873
]
Sergey Shelukhin commented on HBASE-21601:
------------------------------------------
There are no retries that I see or any way to reuse the record on high level...
I think there might be a race condition in asyncwal. It's possible that the
record is written correctly, but not removed correctly from ring buffer, or
something. So then the buffers of the WALEdit (which is itself somewhat
difficult to track) get reused, and AsyncWAL writes the record again with some
random data from other requests.
I looked at the code a bit but it will take a while to understand, so for now
I'm going to mitigate it by skipping such records. Given that this record is
bogus, and the lengths are intact, for this scenario it's safe to do so.
However, it's possible I guess to have a bug where skipping such record would
lead to data loss. Regardless, failure to split the WAL will lead to even more
data loss in this case so it should be ok to handle errors where the structure
is correct but cells are corrupted.
I cannot share the WAL data, but I'm attaching the debug logging I've added
that shows the WALKey and cell length of two records, which I think should be
sufficient - there's nothing more to see from the file itself, it's just a
valid WAL file with records as follows:
The data in the first record in the logs, in every cell, is valid, and it's
followed by more valid WALKey-s with various number of valid cells. I included
one cell prefix as an example.
The data in the 2nd one is invalid in every cell, and looks like fragments of
our real data (values we insert), randomly cut and pasted into the buffers. I
tried to search for substrings from these invalid values in the rest of the
file, but cannot find them, so they are from some different requests.
> HBase (asyncwal?) can write a corrupted record - step 1, skip such records
> --------------------------------------------------------------------------
>
> Key: HBASE-21601
> URL: https://issues.apache.org/jira/browse/HBASE-21601
> Project: HBase
> Issue Type: Bug
> Reporter: Sergey Shelukhin
> Assignee: Sergey Shelukhin
> Priority: Major
>
> {noformat}
> 2018-12-13 17:01:12,208 ERROR [RS_LOG_REPLAY_OPS-regionserver/...]
> executor.EventHandler: Caught throwable while processing event RS_LOG_REPLAY
> java.lang.RuntimeException: java.lang.NegativeArraySizeException
> at
> org.apache.hadoop.hbase.wal.WALSplitter$PipelineController.checkForErrors(WALSplitter.java:846)
> at
> org.apache.hadoop.hbase.wal.WALSplitter$OutputSink.finishWriting(WALSplitter.java:1203)
> at
> org.apache.hadoop.hbase.wal.WALSplitter$LogRecoveredEditsOutputSink.finishWritingAndClose(WALSplitter.java:1267)
> at
> org.apache.hadoop.hbase.wal.WALSplitter.splitLogFile(WALSplitter.java:349)
> at
> org.apache.hadoop.hbase.wal.WALSplitter.splitLogFile(WALSplitter.java:196)
> at
> org.apache.hadoop.hbase.regionserver.SplitLogWorker.splitLog(SplitLogWorker.java:178)
> at
> org.apache.hadoop.hbase.regionserver.SplitLogWorker.lambda$new$0(SplitLogWorker.java:90)
> at
> org.apache.hadoop.hbase.regionserver.handler.WALSplitterHandler.process(WALSplitterHandler.java:70)
> at
> org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:104)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: java.lang.NegativeArraySizeException
> at org.apache.hadoop.hbase.CellUtil.cloneFamily(CellUtil.java:113)
> at
> org.apache.hadoop.hbase.wal.WALSplitter$LogRecoveredEditsOutputSink.filterCellByStore(WALSplitter.java:1542)
> at
> org.apache.hadoop.hbase.wal.WALSplitter$LogRecoveredEditsOutputSink.appendBuffer(WALSplitter.java:1586)
> at
> org.apache.hadoop.hbase.wal.WALSplitter$LogRecoveredEditsOutputSink.append(WALSplitter.java:1560)
> at
> org.apache.hadoop.hbase.wal.WALSplitter$WriterThread.writeBuffer(WALSplitter.java:1085)
> at
> org.apache.hadoop.hbase.wal.WALSplitter$WriterThread.doRun(WALSplitter.java:1077)
> at
> org.apache.hadoop.hbase.wal.WALSplitter$WriterThread.run(WALSplitter.java:1047)
> {noformat}
> Unfortunately I cannot share the file.
> The issue appears to be straightforward - for whatever reason the family
> length is negative. Not sure how such a cell got created, I suspect the file
> was corrupted.
> {code}
> byte[] output = new byte[cell.getFamilyLength()];
> {code}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
