HBase PE randomRead test takes 40 minutes while write takes 1 minute

TheFixer — Thu, 27 Oct 2022 04:58:11 GMT

Hello and thank you for reading

I Have created a randomRead test and it took 40 minutes while randomWrite took 5 minutes

is that normal ?

below is the output for Write and read operations

Write test output

hbase org.apache.hadoop.hbase.PerformanceEvaluation --nomapred randomWrite 1

2022-10-26 13:32:53,776 INFO [main] hbase.PerformanceEvaluation: RandomWriteTest test run options={"addColumns":true,"autoFlush":false,"blockEncoding":"NONE","blockSize":65536,"bloomType":"ROW","bufferSize":2097152,"caching":30,"cmdName":"randomWrite","columns":1,"compression":"NONE","cycles":1,"families":1,"filterAll":false,"flushCommits":true,"inMemoryCF":false,"inMemoryCompaction":"NONE","measureAfter":0,"multiGet":0,"noOfTags":1,"nomapred":true,"numClientThreads":1,"oneCon":false,"perClientRunRows":1048576,"period":104857,"presplitRegions":0,"randomSleep":0,"replicas":1,"reportLatency":false,"sampleRate":1.0,"size":1.0,"splitPolicy":null,"startRow":0,"tableName":"TestTable","totalRows":1048576,"traceRate":0.0,"useTags":false,"valueRandom":false,"valueSize":1000,"valueZipf":false,"writeToWAL":true} 2022-10-26 13:32:55,782 INFO [TestClient-0] hbase.PerformanceEvaluation: Timed test starting in thread TestClient-0 2022-10-26 13:33:01,805 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/104857/1048576, latency mean=56.41, min=2.00, max=349333.00, stdDev=2107.78, 95th=12.00, 99th=20.00 2022-10-26 13:33:07,446 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/209714/1048576, latency mean=54.59, min=2.00, max=349333.00, stdDev=2039.15, 95th=13.00, 99th=20.00 2022-10-26 13:33:12,944 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/314571/1048576, latency mean=53.54, min=2.00, max=349333.00, stdDev=1960.14, 95th=13.00, 99th=19.00 2022-10-26 13:33:19,271 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/419428/1048576, latency mean=54.98, min=2.00, max=349333.00, stdDev=1974.94, 95th=14.00, 99th=21.00 2022-10-26 13:33:25,871 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/524285/1048576, latency mean=56.68, min=2.00, max=349333.00, stdDev=2043.48, 95th=14.00, 99th=21.00 2022-10-26 13:33:31,179 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/629142/1048576, latency mean=55.13, min=2.00, max=349333.00, stdDev=2005.58, 95th=14.00, 99th=21.00 2022-10-26 13:33:36,663 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/733999/1048576, latency mean=56.11, min=2.00, max=349333.00, stdDev=2027.17, 95th=14.00, 99th=21.00 2022-10-26 13:33:41,989 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/838856/1048576, latency mean=55.46, min=2.00, max=349333.00, stdDev=2012.56, 95th=13.00, 99th=21.00 2022-10-26 13:33:48,815 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/943713/1048576, latency mean=53.09, min=2.00, max=335883.00, stdDev=1945.38, 95th=15.00, 99th=22.00 2022-10-26 13:33:55,022 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/1048570/1048576, latency mean=54.34, min=2.00, max=335883.00, stdDev=1953.04, 95th=15.00, 99th=22.00 2022-10-26 13:33:55,070 INFO [TestClient-0] hbase.PerformanceEvaluation: Test : RandomWriteTest, Thread : TestClient-0 2022-10-26 13:33:55,106 INFO [TestClient-0] hbase.PerformanceEvaluation: Latency (us) : mean=54.34, min=2.00, max=335883.00, stdDev=1953.04, 50th=10.00, 75th=11.00, 95th=15.00, 99th=22.00, 99.9th=58.00, 99.99th=84513.36, 99.999th=208397.71 2022-10-26 13:33:55,106 INFO [TestClient-0] hbase.PerformanceEvaluation: Num measures (latency) : 1048575 2022-10-26 13:33:55,129 INFO [TestClient-0] hbase.PerformanceEvaluation: Mean = 54.34 Min = 2.00 Max = 335883.00 StdDev = 1953.04 50th = 10.00 75th = 11.00 95th = 15.00 99th = 22.00 99.9th = 58.00 99.99th = 84513.36 99.999th = 208397.71 2022-10-26 13:33:55,130 INFO [TestClient-0] hbase.PerformanceEvaluation: ValueSize (bytes) : mean=0.00, min=0.00, max=0.00, stdDev=0.00, 50th=0.00, 75th=0.00, 95th=0.00, 99th=0.00, 99.9th=0.00, 99.99th=0.00, 99.999th=0.00 2022-10-26 13:33:55,130 INFO [TestClient-0] hbase.PerformanceEvaluation: Num measures (ValueSize): 0 2022-10-26 13:33:55,130 INFO [TestClient-0] hbase.PerformanceEvaluation: Mean = 0.00 Min = 0.00 Max = 0.00 StdDev = 0.00 50th = 0.00 75th = 0.00 95th = 0.00 99th = 0.00 99.9th = 0.00 99.99th = 0.00 99.999th = 0.00 2022-10-26 13:33:55,135 INFO [TestClient-0] hbase.PerformanceEvaluation: Finished class org.apache.hadoop.hbase.PerformanceEvaluation$RandomWriteTest in 59348ms at offset 0 for 1048576 rows (17.39 MB/s) 2022-10-26 13:33:55,135 INFO [TestClient-0] hbase.PerformanceEvaluation: Finished TestClient-0 in 59348ms over 1048576 rows 2022-10-26 13:33:55,137 INFO [main] hbase.PerformanceEvaluation: [RandomWriteTest] Min: 59348ms Max: 59348ms Avg: 59348ms

Read test output

hbase org.apache.hadoop.hbase.PerformanceEvaluation --nomapred randomRead 1

2022-10-26 13:37:22,748 INFO [main] hbase.PerformanceEvaluation: RandomReadTest test run options={"addColumns":true,"autoFlush":false,"blockEncoding":"NONE","blockSize":65536,"bloomType":"ROW","bufferSize":2097152,"caching":30,"cmdName":"randomRead","columns":1,"compression":"NONE","cycles":1,"families":1,"filterAll":false,"flushCommits":true,"inMemoryCF":false,"inMemoryCompaction":"NONE","measureAfter":0,"multiGet":0,"noOfTags":1,"nomapred":true,"numClientThreads":1,"oneCon":false,"perClientRunRows":1048576,"period":104857,"presplitRegions":0,"randomSleep":0,"replicas":1,"reportLatency":false,"sampleRate":1.0,"size":1.0,"splitPolicy":null,"startRow":0,"tableName":"TestTable","totalRows":1048576,"traceRate":0.0,"useTags":false,"valueRandom":false,"valueSize":1000,"valueZipf":false,"writeToWAL":true} 2022-10-26 13:42:29,630 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/104857/1048576, latency mean=2902.60, min=1223.00, max=640739.00, stdDev=6929.21, 95th=8863.10, 99th=16757.84 2022-10-26 13:46:10,281 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/209714/1048576, latency mean=2502.58, min=1209.00, max=705993.00, stdDev=5867.28, 95th=4658.25, 99th=14318.00 2022-10-26 13:49:37,036 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/314571/1048576, latency mean=2324.93, min=1206.00, max=705993.00, stdDev=5236.88, 95th=3405.00, 99th=13056.56 2022-10-26 13:53:50,501 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/419428/1048576, latency mean=2347.49, min=1175.00, max=1397390.00, stdDev=6757.86, 95th=3457.00, 99th=13465.00 2022-10-26 13:58:10,615 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/524285/1048576, latency mean=2375.16, min=1175.00, max=1588850.00, stdDev=7580.45, 95th=3656.00, 99th=14012.00 2022-10-26 14:02:39,164 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/629142/1048576, latency mean=2409.69, min=1175.00, max=1397390.00, stdDev=7883.84, 95th=3900.00, 99th=14984.97 2022-10-26 14:07:29,432 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/733999/1048576, latency mean=2463.48, min=1174.00, max=1305424.00, stdDev=8435.93, 95th=4363.00, 99th=15973.98 2022-10-26 14:12:20,392 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/838856/1048576, latency mean=2498.55, min=1174.00, max=1297436.00, stdDev=8546.64, 95th=4896.00, 99th=16571.98 2022-10-26 14:17:02,351 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/943713/1048576, latency mean=2526.95, min=1174.00, max=1444174.00, stdDev=9834.51, 95th=5040.95, 99th=16944.00 2022-10-26 14:21:53,530 INFO [TestClient-0] hbase.PerformanceEvaluation: 0/1048570/1048576, latency mean=2556.04, min=1175.00, max=1444174.00, stdDev=9846.08, 95th=5592.00, 99th=17257.00 2022-10-26 14:21:53,543 INFO [TestClient-0] hbase.PerformanceEvaluation: Test : RandomReadTest, Thread : TestClient-0 2022-10-26 14:21:53,606 INFO [TestClient-0] hbase.PerformanceEvaluation: Latency (us) : mean=2556.04, min=1175.00, max=1444174.00, stdDev=9846.08, 50th=1771.00, 75th=1996.00, 95th=5592.00, 99th=17257.00, 99.9th=31161.00, 99.99th=465459.98, 99.999th=1230909.40 2022-10-26 14:21:53,606 INFO [TestClient-0] hbase.PerformanceEvaluation: Num measures (latency) : 1048575 2022-10-26 14:21:53,654 INFO [TestClient-0] hbase.PerformanceEvaluation: Mean = 2556.04 Min = 1175.00 Max = 1444174.00 StdDev = 9846.08 50th = 1771.00 75th = 1996.00 95th = 5592.00 99th = 17257.00 99.9th = 31161.00 99.99th = 465459.98 99.999th = 1230909.40 2022-10-26 14:21:53,654 INFO [TestClient-0] hbase.PerformanceEvaluation: ValueSize (bytes) : mean=0.00, min=0.00, max=0.00, stdDev=0.00, 50th=0.00, 75th=0.00, 95th=0.00, 99th=0.00, 99.9th=0.00, 99.99th=0.00, 99.999th=0.00 2022-10-26 14:21:53,654 INFO [TestClient-0] hbase.PerformanceEvaluation: Num measures (ValueSize): 0 2022-10-26 14:21:53,655 INFO [TestClient-0] hbase.PerformanceEvaluation: Mean = 0.00 Min = 0.00 Max = 0.00 StdDev = 0.00 50th = 0.00 75th = 0.00 95th = 0.00 99th = 0.00 99.9th = 0.00 99.99th = 0.00 99.999th = 0.00 2022-10-26 14:21:53,784 INFO [TestClient-0] hbase.PerformanceEvaluation: Finished class org.apache.hadoop.hbase.PerformanceEvaluation$RandomReadTest in 2668961ms at offset 0 for 1048576 rows (0.39 MB/s) 2022-10-26 14:21:53,785 INFO [TestClient-0] hbase.PerformanceEvaluation: Finished TestClient-0 in 2668961ms over 1048576 rows 2022-10-26 14:21:53,786 INFO [main] hbase.PerformanceEvaluation: [RandomReadTest] Summary of timings (ms): [2668961] 2022-10-26 14:21:53,788 INFO [main] hbase.PerformanceEvaluation: [RandomReadTest] Min: 2668961ms Max: 2668961ms Avg: 2668961ms

Re: HBase PE randomRead test takes 40 minutes while write takes 1 minute

rki_ — Fri, 28 Oct 2022 08:23:28 GMT

Hi @TheFixer ,

During read, hbase has to fetch the blocks from other slave nodes if the locality of the regions are not good and this can contribute to latency as the block in not local to the client (Hbase ) and has to go over the network to fetch those provided the disks are fast enough.

So you may want to run a major compaction on that table to see if that improves the read performance.

Further, when the reads are performed the 1st time on a table that is written recently, the blocks are not cached in memory. So subsequent reads should give good performance comparatively as the blocks will be cache in the BlockCache.

Re: HBase PE randomRead test takes 40 minutes while write takes 1 minute

TheFixer — Sat, 29 Oct 2022 03:19:20 GMT

Hello @rki_ ,

Thank you very much for your replay

I didn't specify any table for this test, so it should default to TestTable

Re: HBase PE randomRead test takes 40 minutes while write takes 1 minute

rki_ — Sat, 29 Oct 2022 07:04:12 GMT

You can also try to split the table at the time of creation or split it now so that not all requests go to the same Region server which thereby creates a hotspot and might be a bottleneck.

question HBase PE randomRead test takes 40 minutes while write takes 1 minute in Support Questions

HBase PE randomRead test takes 40 minutes while write takes 1 minute

Re: HBase PE randomRead test takes 40 minutes while write takes 1 minute

Re: HBase PE randomRead test takes 40 minutes while write takes 1 minute

Re: HBase PE randomRead test takes 40 minutes while write takes 1 minute