[HBASE-15014] Fix filterCellByStore in WALsplitter is awful for performance

• Type: Bug
• Status: Resolved
• Priority: Critical
• Resolution: Fixed
• Affects Version/s: 1.2.0
• Fix Version/s: 1.2.0, 1.3.0, 2.0.0
• Component/s: MTTR, Recovery, wal
• Assignee: Elliott Neil Clark
• Reporter: Elliott Neil Clark
• Created: 18/Dec/15 21:09
• Updated: 22/Dec/15 11:53
• Resolved: 22/Dec/15 07:08

Description

Testing the latest 1.2 I see this when there is a regionserver that crashes.

Thread 921 (RS_LOG_REPLAY_OPS-hbase2698:16020-0-Writer-1):
  State: RUNNABLE
  Blocked count: 6354
  Waited count: 6249
  Stack:
    org.apache.hadoop.hbase.KeyValue.equals(KeyValue.java:1128)
    java.util.ArrayList.indexOf(ArrayList.java:317)
    java.util.ArrayList.contains(ArrayList.java:300)
    java.util.ArrayList.batchRemove(ArrayList.java:720)
    java.util.ArrayList.removeAll(ArrayList.java:690)
    org.apache.hadoop.hbase.wal.WALSplitter$LogRecoveredEditsOutputSink.filterCellByStore(WALSplitter.java:1529)
    org.apache.hadoop.hbase.wal.WALSplitter$LogRecoveredEditsOutputSink.append(WALSplitter.java:1557)
    org.apache.hadoop.hbase.wal.WALSplitter$WriterThread.writeBuffer(WALSplitter.java:1113)
    org.apache.hadoop.hbase.wal.WALSplitter$WriterThread.doRun(WALSplitter.java:1105)
    org.apache.hadoop.hbase.wal.WALSplitter$WriterThread.run(WALSplitter.java:1075)
Thread 920 (RS_LOG_REPLAY_OPS-hbase2698:16020-0-Writer-0):
  State: TIMED_WAITING
  Blocked count: 17560
  Waited count: 19695
  Stack:
    java.lang.Object.wait(Native Method)
    org.apache.hadoop.hbase.wal.WALSplitter$WriterThread.doRun(WALSplitter.java:1093)
    org.apache.hadoop.hbase.wal.WALSplitter$WriterThread.run(WALSplitter.java:1075)
Thread 919 (RS_LOG_REPLAY_OPS-hbase2698:16020-0):
  State: TIMED_WAITING
  Blocked count: 115
  Waited count: 976
  Stack:
    java.lang.Object.wait(Native Method)
    org.apache.hadoop.hbase.wal.WALSplitter$EntryBuffers.appendEntry(WALSplitter.java:944)
    org.apache.hadoop.hbase.wal.WALSplitter.splitLogFile(WALSplitter.java:365)
    org.apache.hadoop.hbase.wal.WALSplitter.splitLogFile(WALSplitter.java:236)
    org.apache.hadoop.hbase.regionserver.SplitLogWorker$1.exec(SplitLogWorker.java:104)
    org.apache.hadoop.hbase.regionserver.handler.WALSplitterHandler.process(WALSplitterHandler.java:72)
    org.apache.hadoop.hbase.executor.EventHandler.run(EventHandler.java:128)
    java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    java.lang.Thread.run(Thread.java:745)

This has been going on for >10 mins.