[HBASE-10158] Add sync rate histogram to HLogPE

• Type: Sub-task
• Status: Closed
• Priority: Major
• Resolution: Implemented
• Fix Version/s: 0.99.0
• Component/s: Performance, wal
• Assignee: Michael Stack
• Reporter: Michael Stack
• Created: 13/Dec/13 17:46
• Updated: 21/Feb/15 23:33
• Resolved: 11/Apr/14 23:38

Description

HLogPE emits a few metrics that help comparing WAL implementations – sync and append counts. This patch adds a histogram around time between sync calls to ensure implementations are not clumping sync invocations. Helps comparing implementations.

It also makes it so the just committed HBASE-8755 code calls postSync and postAppend methods.

eclark Mind reviewing? Also, are these additions actually needed? Could I dump the metrics we already collect if I only did proper startup invocation; i.e. use our metrics rather than these yammer ones?

Here is what the output looks like on a run of HLogPE:

...
2013-12-13 09:41:15,641 INFO  [StoreOpener-a77539a833048fa441d3195c853cf6ea-1] hfile.CacheConfig: Allocating LruBlockCache with maximum size 395 M
2013-12-13 09:41:15,652 INFO  [StoreOpener-a77539a833048fa441d3195c853cf6ea-1] compactions.CompactionConfiguration: size [134217728, 9223372036854775807); files [3, 10); ratio 1.200000; off-peak ratio 5.000000; throttle point 2684354560; delete expired; major period 604800000, major jitter 0.500000
2013-12-13 09:41:15,662 INFO  [StoreOpener-a77539a833048fa441d3195c853cf6ea-1] util.ChecksumType: Checksum using org.apache.hadoop.util.PureJavaCrc32
2013-12-13 09:41:15,663 INFO  [StoreOpener-a77539a833048fa441d3195c853cf6ea-1] util.ChecksumType: Checksum can use org.apache.hadoop.util.PureJavaCrc32C
2013-12-13 09:41:15,666 DEBUG [main] regionserver.HRegion: Found 0 recovered edits file(s) under file:/Users/stack/checkouts/trunk/target/test-data/a62eb348-138b-4275-b33a-12ebb12c20b9/HLogPerformanceEvaluation/data/default/HLogPerformanceEvaluation/a77539a833048fa441d3195c853cf6ea
2013-12-13 09:41:15,669 INFO  [main] regionserver.HRegion: Onlined a77539a833048fa441d3195c853cf6ea; next sequenceid=1
12/13/13 9:42:15 AM ============================================================
org.apache.hadoop.hbase.regionserver.wal.HLogPerformanceEvaluation:
  appendMeter:
             count = 1173705160
         mean rate = 19180.80 bytes/ms
     1-minute rate = 16437.82 bytes/ms
     5-minute rate = 12716.38 bytes/ms
    15-minute rate = 11783.97 bytes/ms

  syncMeter:
             count = 1726060
         mean rate = 28.20 syncs/ms
     1-minute rate = 24.16 syncs/ms
     5-minute rate = 18.68 syncs/ms
    15-minute rate = 17.30 syncs/ms


org.apache.hadoop.hbase.regionserver.wal.HLogPerformanceEvaluation.nanos-between-syncs:
  syncHistogram:
               min = 13000.00
               max = 32438000.00
              mean = 34754.07
            stddev = 38993.58
            median = 29000.00
              75% <= 37000.00
              95% <= 56000.00
              98% <= 84420.00
              99% <= 99000.00
            99.9% <= 267709.00



2013-12-13 09:42:25,040 INFO  [t0] wal.HLogPerformanceEvaluation: t0 took 69.369s 28831.320ops/s
2013-12-13 09:42:25,040 INFO  [main] wal.HLogPerformanceEvaluation: Summary: threads=1, iterations=2000000, syncInterval=0 took 69.369s 28831.320ops/s
...

Issue Links

• is part of: HBASE-10156 FSHLog Refactor (WAS -> Fix up the HBASE-8755 slowdown when low contention)