Support Questions

Find answers, ask questions, and share your expertise
Announcements
Celebrating as our community reaches 100,000 members! Thank you!

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

avatar
New Contributor

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

 

 

 

 

3 REPLIES 3

avatar
Super Collaborator

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.

avatar
New Contributor

Hello @rki_ ,


Thank you very much for your replay

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

 

Screen Shot 2022-10-29 at 12.13.27.png

 

Screen Shot 2022-10-29 at 12.17.10.png

avatar
Super Collaborator

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.