hbase-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "stack (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (HBASE-9022) TestHLogSplit.testIOEOnOutputThread fails
Date Fri, 26 Jul 2013 19:07:49 GMT

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

stack commented on HBASE-9022:
------------------------------

It failed a few times over night including here http://54.241.6.143/job/HBase-0.95-Hadoop-2/696/org.apache.hbase$hbase-server/testReport/junit/org.apache.hadoop.hbase.regionserver.wal/TestHLogSplitCompressed/testIOEOnOutputThread/

The debugging shows that we open a writer AFTER the clean up has run (probably because loaded
cluster and the thread gets scheduled later):

Here is section for the above logs:

{{monospaced}}
...
2013-07-26 05:02:48,439 DEBUG [WriterThread-1] wal.HLogSplitter$LogRecoveredEditsOutputSink(1202):
Creating writer path=/hbase/t1/ccc/recovered.edits/0000000000000000002.temp region=ccc
2013-07-26 05:02:48,440 FATAL [WriterThread-1] wal.HLogSplitter$LogRecoveredEditsOutputSink(1236):
 Got while writing log entry to log
java.io.IOException: Injected
	at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter$LogRecoveredEditsOutputSink.append(HLogSplitter.java:1227)
	at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter$WriterThread.writeBuffer(HLogSplitter.java:829)
	at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter$WriterThread.doRun(HLogSplitter.java:821)
	at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter$WriterThread.run(HLogSplitter.java:791)
2013-07-26 05:02:48,440 ERROR [WriterThread-1] wal.HLogSplitter$WriterThread(793): Exiting
thread
java.io.IOException: Injected
	at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter$LogRecoveredEditsOutputSink.append(HLogSplitter.java:1227)
	at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter$WriterThread.writeBuffer(HLogSplitter.java:829)
	at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter$WriterThread.doRun(HLogSplitter.java:821)
	at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter$WriterThread.run(HLogSplitter.java:791)
2013-07-26 05:02:48,441 DEBUG [Thread-298] wal.HLogSplitter$LogRecoveredEditsOutputSink(1032):
{color:red}Submitting close of /hbase/t1/ccc/recovered.edits/0000000000000000002.temp{color}
2013-07-26 05:02:48,443 INFO  [IPC Server handler 6 on 60581] namenode.FSNamesystem$DefaultAuditLogger(5567):
allowed=true	ugi=ec2-user (auth:SIMPLE)	ip=/127.0.0.1	cmd=mkdirs	src=/hbase/t1/bbb/recovered.edits
dst=null	perm=ec2-user:supergroup:rwxr-xr-x
2013-07-26 05:02:48,445 INFO  [IPC Server handler 9 on 60581] namenode.FSNamesystem$DefaultAuditLogger(5567):
allowed=true	ugi=ec2-user (auth:SIMPLE)	ip=/127.0.0.1	cmd=getfileinfo	src=/hbase/t1/bbb/recovered.edits/0000000000000000001.temp
dst=null	perm=null
2013-07-26 05:02:48,447 DEBUG [WriterThread-2] wal.HLogSplitter$LogRecoveredEditsOutputSink(1202):
Creating writer path=/hbase/t1/bbb/recovered.edits/0000000000000000001.temp region=bbb
2013-07-26 05:02:48,447 FATAL [WriterThread-2] wal.HLogSplitter$LogRecoveredEditsOutputSink(1236):
 Got while writing log entry to log
java.io.IOException: Injected
	at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter$LogRecoveredEditsOutputSink.append(HLogSplitter.java:1227)
	at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter$WriterThread.writeBuffer(HLogSplitter.java:829)
	at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter$WriterThread.doRun(HLogSplitter.java:821)
	at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter$WriterThread.run(HLogSplitter.java:791)
2013-07-26 05:02:48,447 ERROR [WriterThread-2] wal.HLogSplitter$WriterThread(793): Exiting
thread
java.io.IOException: Injected
	at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter$LogRecoveredEditsOutputSink.append(HLogSplitter.java:1227)
	at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter$WriterThread.writeBuffer(HLogSplitter.java:829)
	at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter$WriterThread.doRun(HLogSplitter.java:821)
	at org.apache.hadoop.hbase.regionserver.wal.HLogSplitter$WriterThread.run(HLogSplitter.java:791)
2013-07-26 05:02:48,456 DEBUG [split-log-closeStream-1] wal.HLogSplitter$LogRecoveredEditsOutputSink$2(1036):
Closing /hbase/t1/ccc/recovered.edits/0000000000000000002.temp
2013-07-26 05:02:48,458 INFO  [split-log-closeStream-1] wal.HLogSplitter$LogRecoveredEditsOutputSink$2(1044):
Closed wap /hbase/t1/ccc/recovered.edits/0000000000000000002.temp (wrote 0 edits in 0ms)
...

{{monospaced}}

So we schedule a writer thread.  It opens a recovered.edits writer per region encountered.
 The close happens after first region recovered.edits writer is opened but before the second
region is encountered.
                
> TestHLogSplit.testIOEOnOutputThread fails
> -----------------------------------------
>
>                 Key: HBASE-9022
>                 URL: https://issues.apache.org/jira/browse/HBASE-9022
>             Project: HBase
>          Issue Type: Bug
>            Reporter: stack
>         Attachments: 9022.addthreaddumping-part2.txt, 9022.addthreaddumping.txt, 9022.txt,
9022.txt, 9022.txt, 9022.yet-more-logging2.txt, 9022.yet-more-logging.txt
>
>
> https://builds.apache.org/job/PreCommit-HBASE-Build/6428//testReport/org.apache.hadoop.hbase.regionserver.wal/TestHLogSplit/testIOEOnOutputThread/

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira

Mime
View raw message