stack created HBASE-19371:
-----------------------------

             Summary: Running WALPerformanceEvaluation against asyncfswal 
throws exceptions
                 Key: HBASE-19371
                 URL: https://issues.apache.org/jira/browse/HBASE-19371
             Project: HBase
          Issue Type: Bug
            Reporter: stack


Was trying to do a perf eval on asyncfswal. I ran w/ these args:

 Performance counter stats for '/home/stack/hbase/bin/hbase --config 
/home/stack/conf_hbase org.apache.hadoop.hbase.wal.WALPerformanceEvaluation 
-path /user/stack/logs/ -verify -threads 25 -iterations 1000000 -keySize 50 
-valueSize 100 -syncInterval 10':

The verify fails on all runs:

Exception in thread "main" java.lang.IllegalStateException: Counted=12390228, 
expected=25000000
  at 
org.apache.hadoop.hbase.wal.WALPerformanceEvaluation.run(WALPerformanceEvaluation.java:368)
                                                                                
                            at 
org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:76)
  at 
org.apache.hadoop.hbase.wal.WALPerformanceEvaluation.innerMain(WALPerformanceEvaluation.java:597)
                                                                                
                      at 
org.apache.hadoop.hbase.wal.WALPerformanceEvaluation.main(WALPerformanceEvaluation.java:601)

I need to fix test or figure what is wrong in asyncfswal.

Also seeing these when I run w/ one thread only:

2017-11-28 21:25:49,952 WARN  [AsyncFSWAL-1-1] wal.AsyncFSWAL: RingBufferTruck 
with unexpected type: EMPTY

Log has a spew of them.

Has stuff like this too:

2017-11-28 21:25:40,065 WARN  [Close-WAL-Writer-3] wal.AsyncProtobufLogWriter: 
normal close failed, try recover                                                
                                           java.io.IOException: stream already 
broken                                                                          
                                                                                
        at 
org.apache.hadoop.hbase.io.asyncfs.FanOutOneBlockAsyncDFSOutput.endBlock(FanOutOneBlockAsyncDFSOutput.java:510)
                                                                                
        at 
org.apache.hadoop.hbase.io.asyncfs.FanOutOneBlockAsyncDFSOutput.lambda$close$12(FanOutOneBlockAsyncDFSOutput.java:550)
                                                                                
 at 
org.apache.hadoop.hbase.shaded.io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:163)
  at 
org.apache.hadoop.hbase.shaded.io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:403)
                                                                      at 
org.apache.hadoop.hbase.shaded.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:462)
  at 
org.apache.hadoop.hbase.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:858)
                                                                            at 
org.apache.hadoop.hbase.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:138)
  at java.lang.Thread.run(Thread.java:748)

Starts out spewing EMPTY here:

2017-11-28 21:16:52,051 INFO  [main] regionserver.HRegion: Setting 
FlushNonSloppyStoresFirstPolicy for the 
region=WALPerformanceEvaluation:0,,1511932610787.deca03e0ca447fa25d02fe9cd6e31aa4.
2017-11-28 21:16:52,058 DEBUG [main] regionserver.HRegion: Found 0 recovered 
edits file(s) under 
hdfs://ve0524.halxg.cloudera.com:8020/user/stack/logs/data/WALPerformanceEvaluation/0/deca03e0ca447fa25d02fe9cd6e31aa4
2017-11-28 21:16:52,068 DEBUG [main] regionserver.FlushLargeStoresPolicy: No 
hbase.hregion.percolumnfamilyflush.size.lower.bound set in description of table 
WALPerformanceEvaluation:0, use config (134217728) instead
2017-11-28 21:16:52,084 DEBUG [main] wal.WALSplitter: Wrote 
file=hdfs://ve0524.halxg.cloudera.com:8020/user/stack/logs/data/WALPerformanceEvaluation/0/deca03e0ca447fa25d02fe9cd6e31aa4/recovered.edits/2.seqid,
 newSeqId=2, maxSeqId=0
2017-11-28 21:16:52,084 INFO  [main] regionserver.HRegion: Onlined 
deca03e0ca447fa25d02fe9cd6e31aa4; next sequenceid=2
2017-11-28 21:16:52,185 WARN  [AsyncFSWAL-1-1] wal.AsyncFSWAL: RingBufferTruck 
with unexpected type: EMPTY
2017-11-28 21:16:52,185 WARN  [AsyncFSWAL-1-1] wal.AsyncFSWAL: RingBufferTruck 
with unexpected type: EMPTY
2017-11-28 21:16:52,185 WARN  [AsyncFSWAL-1-1] wal.AsyncFSWAL: RingBufferTruck 
with unexpected type: EMPTY
2017-11-28 21:16:52,185 WARN  [AsyncFSWAL-1-1] wal.AsyncFSWAL: RingBufferTruck 
with unexpected type: EMPTY
2017-11-28 21:16:52,185 WARN  [AsyncFSWAL-1-1] wal.AsyncFSWAL: RingBufferTruck 
with unexpected type: EMPTY
2017-11-28 21:16:52,185 WARN  [AsyncFSWAL-1-1] wal.AsyncFSWAL: RingBufferTruck 
with unexpected type: EMPTY
2017-11-28 21:16:52,185 WARN  [AsyncFSWAL-1-1] wal.AsyncFSWAL: RingBufferTruck 
with unexpected type: EMPTY
...

This is tip of branch-2 minus the commit of the change to the ringbuffer (I'd 
not pulled in that change).

[~Apache9] in case you've seen it before else I'll dig in sir.





--
This message was sent by Atlassian JIRA
(v6.4.14#64029)

Reply via email to