Member since
10-24-2022
3
Posts
0
Kudos Received
0
Solutions
10-28-2022
08:46 PM
Hello and thanks for reading I have an issue with hadoop hbase while trying to find the issue I can see below memstore flush logs for all tables and its non stop MemstoreFlusherChore requesting flush of table 1. because K has an old edit so flush to free WALs after random delay 65889ms 022-10-29 12:22:13,176 INFO [regionserver/uhn-hw-fores201b:16020.Chore.1] regionserver.HRegionServer: MemstoreFlusherChore requesting flush of table 1. because K has an old edit so flush to free WALs after random delay 65889ms
2022-10-29 12:22:13,177 INFO [regionserver/uhn-hw-fores201b:16020.Chore.1] regionserver.HRegionServer: MemstoreFlusherChore requesting flush of tabl 2 . because K has an old edit so flush to free WALs after random delay 181952ms
2022-10-29 12:22:13,177 INFO [regionserver/uhn-hw-fores201b:16020.Chore.1] regionserver.HRegionServer: MemstoreFlusherChore requesting flush of table 3 . because K has an old edit so flush to free WALs after random delay 150462ms
2022-10-29 12:22:13,177 INFO [regionserver/uhn-hw-fores201b:16020.Chore.1] regionserver.HRegionServer: MemstoreFlusherChore requesting flush of table 4 . because K has an old edit so flush to free WALs after random delay 161958ms This error seems complex because no documentation about error below is random logs from same node 2022-10-29 12:21:46,170 INFO [MemStoreFlusher.1] regionserver.HRegion: Finished flush of dataSize ~6.68 MB/7002393, heapSize ~19.57 MB/20517200, currentSize=0 B/0 for ad1bd353d9ae0c52e30a935c5d06ecfa in 335ms, sequenceid=25141679, compaction requested=true 2022-10-29 12:22:02,679 INFO [MemStoreFlusher.1] regionserver.HRegion: Flushing 1/1 column families, dataSize=2.79 MB heapSize=7.22 MB Tasks:
===========================================================
Task: Compacting K in table .
Status: RUNNING:Compacting store K
Running for 11449s
Task: Compacting K in region.
Status: RUNNING:Compacting store K
Running for 168s
Task: Compacting K in region.
Status: RUNNING:Compacting store K
Running for 159s
Task: Compacting K in region.
Status: RUNNING:Compacting store K
Running for 72s RS Queue:
===========================================================
Compaction/Split Queue summary: compactionQueue=(longCompactions=111975:shortCompactions=35811), splitQueue=0
Compaction/Split Queue dump:
LargeCompation Queue: Below is the worker node data I tried to find any configuration for WAL, but seems it has been depricated HBase Version 2.0.0.3.0.1.0-187, revision=e9fcf450949102de5069b257a6dee469b8f5aab3 Hadoop Version 3.1.1.3.0.1.0-187, revision=2820e4d6fc7ec31ac42187083ed5933c823e9784
... View more
Labels:
- Labels:
-
Apache Hadoop
-
Apache HBase
10-28-2022
08:19 PM
Hello @rki_ , Thank you very much for your replay I didn't specify any table for this test, so it should default to TestTable
... View more
10-26-2022
09:57 PM
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
... View more
Labels:
- Labels:
-
Apache HBase