[
https://issues.apache.org/jira/browse/HBASE-24585?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17140056#comment-17140056
]
Michael Stack commented on HBASE-24585:
---------------------------------------
Some more context. Here are exceptions before the ERROR one in the description
above:
{code}
2020-06-18 14:28:28,739 WARN [split-log-closeStream--pool7-t1]
wal.BoundedRecoveredHFilesOutputSink: Failed to get table descriptor for
hbase:meta
java.io.InterruptedIOException: Interrupted after 18 tries while maxAttempts=46
at
org.apache.hadoop.hbase.client.RpcRetryingCallerImpl.callWithRetries(RpcRetryingCallerImpl.java:173)
at
org.apache.hadoop.hbase.client.HBaseAdmin.executeCallable(HBaseAdmin.java:3007)
at
org.apache.hadoop.hbase.client.HBaseAdmin.getTableDescriptor(HBaseAdmin.java:550)
at
org.apache.hadoop.hbase.client.HBaseAdmin.getDescriptor(HBaseAdmin.java:365)
at
org.apache.hadoop.hbase.wal.BoundedRecoveredHFilesOutputSink.getTableDescriptor(BoundedRecoveredHFilesOutputSink.java:227)
at
org.apache.hadoop.hbase.wal.BoundedRecoveredHFilesOutputSink.lambda$createRecoveredHFileWriter$4(BoundedRecoveredHFilesOutputSink.java:203)
at
java.util.concurrent.ConcurrentHashMap.computeIfAbsent(ConcurrentHashMap.java:1660)
at
org.apache.hadoop.hbase.wal.BoundedRecoveredHFilesOutputSink.createRecoveredHFileWriter(BoundedRecoveredHFilesOutputSink.java:203)
at
org.apache.hadoop.hbase.wal.BoundedRecoveredHFilesOutputSink.append(BoundedRecoveredHFilesOutputSink.java:109)
at
org.apache.hadoop.hbase.wal.BoundedRecoveredHFilesOutputSink.lambda$writeRemainingEntryBuffers$3(BoundedRecoveredHFilesOutputSink.java:149)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
2020-06-18 14:28:28,739 INFO
[RS_LOG_REPLAY_OPS-regionserver/localhost:16020-1] wal.WALSplitter: Processed
10 edits across 0 regions cost 199772 ms; edits skipped=1;
WAL=file:/Users/stack/checkouts/hbase.apache.git/tmp/hbase/WALs/localhost,16020,1592514971625-splitting/localhost%2C16020%2C1592514971625.meta.1592514976169.meta,
size=3.1 K, length=3224, corrupted=false, progress failed=true
2020-06-18 14:28:28,740 INFO [split-log-closeStream--pool6-t1]
wal.BoundedRecoveredHFilesOutputSink: Failed getting hbase:meta table
descriptor from master; trying local
2020-06-18 14:28:28,740 WARN
[RS_LOG_REPLAY_OPS-regionserver/localhost:16020-1] regionserver.SplitLogWorker:
Resigning, interrupted splitting WAL
file:/Users/stack/checkouts/hbase.apache.git/tmp/hbase/WALs/localhost,16020,1592514971625-splitting/localhost%2C16020%2C1592514971625.meta.1592514976169.meta
java.io.InterruptedIOException
at
org.apache.hadoop.hbase.wal.BoundedRecoveredHFilesOutputSink.writeRemainingEntryBuffers(BoundedRecoveredHFilesOutputSink.java:163)
at
org.apache.hadoop.hbase.wal.BoundedRecoveredHFilesOutputSink.close(BoundedRecoveredHFilesOutputSink.java:136)
at org.apache.hadoop.hbase.wal.WALSplitter.splitLogFile(WALSplitter.java:391)
at org.apache.hadoop.hbase.wal.WALSplitter.splitLogFile(WALSplitter.java:215)
at
org.apache.hadoop.hbase.regionserver.SplitLogWorker.splitLog(SplitLogWorker.java:102)
at
org.apache.hadoop.hbase.regionserver.SplitWALCallable.splitWal(SplitWALCallable.java:104)
at
org.apache.hadoop.hbase.regionserver.SplitWALCallable.call(SplitWALCallable.java:86)
at
org.apache.hadoop.hbase.regionserver.SplitWALCallable.call(SplitWALCallable.java:49)
at
org.apache.hadoop.hbase.regionserver.handler.RSProcedureHandler.process(RSProcedureHandler.java:49)
at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:104)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.InterruptedException
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.reportInterruptAfterWait(AbstractQueuedSynchronizer.java:2014)
at
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2048)
at
java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at
java.util.concurrent.ExecutorCompletionService.take(ExecutorCompletionService.java:193)
at
org.apache.hadoop.hbase.wal.BoundedRecoveredHFilesOutputSink.writeRemainingEntryBuffers(BoundedRecoveredHFilesOutputSink.java:156)
... 12 more
2020-06-18 14:28:28,741 ERROR
[RS_LOG_REPLAY_OPS-regionserver/localhost:16020-1] handler.RSProcedureHandler:
Error when call RSProcedureCallable:
java.io.IOException: Failed WAL split, status=RESIGNED,
wal=file:/Users/stack/checkouts/hbase.apache.git/tmp/hbase/WALs/localhost,16020,1592514971625-splitting/localhost%2C16020%2C1592514971625.meta.1592514976169.meta
at
org.apache.hadoop.hbase.regionserver.SplitWALCallable.splitWal(SplitWALCallable.java:106)
at
org.apache.hadoop.hbase.regionserver.SplitWALCallable.call(SplitWALCallable.java:86)
at
org.apache.hadoop.hbase.regionserver.SplitWALCallable.call(SplitWALCallable.java:49)
at
org.apache.hadoop.hbase.regionserver.handler.RSProcedureHandler.process(RSProcedureHandler.java:49)
at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:104)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:748)
{code}
> If RSProcedureHandler throws exception, it aborts the hosting RS
> ----------------------------------------------------------------
>
> Key: HBASE-24585
> URL: https://issues.apache.org/jira/browse/HBASE-24585
> Project: HBase
> Issue Type: Bug
> Reporter: Michael Stack
> Priority: Major
>
> HBASE-24574 proc v2 distributed log splitting is enabled. A remote split
> fails because it was interrupted. The InterruptedException became an IOE and
> then bubbled up and out of the RSPH below causing a RS abort.
> {code}
> 2020-06-17 21:20:37,472 ERROR
> [RS_LOG_REPLAY_OPS-regionserver/localhost:16020-0]
> handler.RSProcedureHandler: Error when call RSProcedureCallable:
> java.io.IOException: Failed WAL split, status=RESIGNED,
> wal=file:/Users/stack/checkouts/hbase.apache.git/tmp/hbase/WALs/localhost,16020,1592440848604-splitting/localhost%2C16020%2C1592440848604.meta.1592440852959.meta
> at
> org.apache.hadoop.hbase.regionserver.SplitWALCallable.splitWal(SplitWALCallable.java:106)
> at
> org.apache.hadoop.hbase.regionserver.SplitWALCallable.call(SplitWALCallable.java:86)
> at
> org.apache.hadoop.hbase.regionserver.SplitWALCallable.call(SplitWALCallable.java:49)
> at
> org.apache.hadoop.hbase.regionserver.handler.RSProcedureHandler.process(RSProcedureHandler.java:49)
> at org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:104)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at java.lang.Thread.run(Thread.java:748)
> {code}
> The remote-procedure framework needs to be more resilient? Log the exception
> unless an ERROR and keep going? Otherwise, makes features like procedurev2
> distributed log splitting brittle.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)