[
https://issues.apache.org/jira/browse/HBASE-26145?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Oleg Muravskiy updated HBASE-26145:
-----------------------------------
Description:
While inserting records into HBase, I'm getting following exceptions on the
client side:
{noformat}
2021-07-27 12:07:33,986 WARN [hconnection-0x6d4081cd-shared-pool-158]
o.a.h.h.c.AsyncRequestFutureImpl - id=1, table=ris:ris-updates, attempt=1/16,
failureCount=9ops, last
exception=org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError on worker008,16020,1627053306686,
tracking started Tue Jul 27 12:07:33 UTC 2021; NOT retrying, failed=9 -- final
attempt!
2021-07-27 12:07:34,008 ERROR [Thread-4] o.a.hadoop.hbase.client.BatchErrors -
Exception occurred! Exception details:
[org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError,
org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError,
org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError,
org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError,
org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError,
org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError,
org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError,
org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError,
org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError];
Actions:
[{"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE5z\\x04P\\xF9\\xD3\\xD9\\x00\\x00\\x00\\x00","families":{"-":[{"qualifier":"mrt","vlen":117,"tag":[],"timestamp":"1627387651450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387651450"}]},"ts":"1627387651450"},
{"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE5z\\x04P\\xF9\\xD1\\xB0\\x00\\x00\\x00\\x01","families":{"-":[{"qualifier":"mrt","vlen":117,"tag":[],"timestamp":"1627387651450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387651450"}]},"ts":"1627387651450"},
{"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE5z\\x04P\\xF9\\xD2\\xD0\\x00\\x00\\x00\\x02","families":{"-":[{"qualifier":"mrt","vlen":125,"tag":[],"timestamp":"1627387651450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387651450"}]},"ts":"1627387651450"},
{"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE5z\\x06
\\x01\\x07\\xF8\\x00\\x01\\x00\\x00\\x00\\x00\\xA5\\x02\\x94g\\x00\\x01\\x00\\x00\\x00\\x03","families":{"-":[{"qualifier":"mrt","vlen":175,"tag":[],"timestamp":"1627387651450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387651450"}]},"ts":"1627387651450"},
{"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE9b\\x04P\\xF9\\xD3\\xD9\\x00\\x00\\x00\\x00","families":{"-":[{"qualifier":"mrt","vlen":125,"tag":[],"timestamp":"1627387652450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387652450"}]},"ts":"1627387652450"},
{"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE9b\\x06
\\x01\\x07\\xF8\\x00\\x01\\x00\\x00\\x00\\x00\\xA5\\x00\\x84U\\x00\\x01\\x00\\x00\\x00\\x01","families":{"-":[{"qualifier":"mrt","vlen":75,"tag":[],"timestamp":"1627387652450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387652450"}]},"ts":"1627387652450"},
{"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE9b\\x04P\\xF9\\xD1\\xB0\\x00\\x00\\x00\\x02","families":{"-":[{"qualifier":"mrt","vlen":110,"tag":[],"timestamp":"1627387652450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387652450"}]},"ts":"1627387652450"},
{"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE9b\\x06
\\x01\\x07\\xF8\\x00\\x01\\x00\\x00\\x00\\x00\\xA5\\x02\\x94g\\x00\\x01\\x00\\x00\\x00\\x03","families":{"-":[{"qualifier":"mrt","vlen":171,"tag":[],"timestamp":"1627387652450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387652450"}]},"ts":"1627387652450"},
{"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE9b\\x04P\\xF9\\xD3\\xD9\\x00\\x00\\x00\\x04","families":{"-":[{"qualifier":"mrt","vlen":115,"tag":[],"timestamp":"1627387652450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387652450"}]},"ts":"1627387652450"}]
2021-07-27 12:07:34,015 ERROR [Thread-4] n.r.g.r.a.AbstractApp - Error:
org.apache.hadoop.hbase.client.RetriesExhaustedWithDetailsException: Failed 9
actions: java.lang.ExceptionInInitializerError: 9 times, servers with issues:
worker008,16020,1627053306686
at
org.apache.hadoop.hbase.client.BatchErrors.makeException(BatchErrors.java:54)
at
org.apache.hadoop.hbase.client.AsyncRequestFutureImpl.getErrors(AsyncRequestFutureImpl.java:1196)
at org.apache.hadoop.hbase.client.HTable.batch(HTable.java:451)
at org.apache.hadoop.hbase.client.HTable.put(HTable.java:549){noformat}
There are no errors logged on the regionserver:
{noformat}
2021-07-27 12:07:32,811 INFO [RS_CLOSE_REGION-regionserver/worker008:16020-0]
handler.UnassignRegionHandler: Close 625d2ac4331542df877e44fa06489ca1
2021-07-27 12:07:32,811 INFO [RS_CLOSE_REGION-regionserver/worker008:16020-0]
regionserver.HRegion: Closing region
ris:ris-updates,\x00\x03\x00\x00\x01z\xE6/M:\x04P\xF9\xD0j\x00\x00\x00\x01,1627382439537.625d2ac4331542df877e44fa06489ca1.
2021-07-27 12:07:32,811 INFO [RS_CLOSE_REGION-regionserver/worker008:16020-0]
regionserver.HRegion: Flushing 625d2ac4331542df877e44fa06489ca1 1/1 column
families, dataSize=77.13 KB heapSize=122.04 KB
2021-07-27 12:07:33,088 INFO [RS_CLOSE_REGION-regionserver/worker008:16020-0]
regionserver.DefaultStoreFlusher: Flushed memstore data size=77.13 KB at
sequenceid=88678485 (bloomFilter=true),
to=hdfs://dune/hbase/data/ris/ris-updates/625d2ac4331542df877e44fa06489ca1/.tmp/-/2bc2db2278054d6399fdf618fca0f260
2021-07-27 12:07:33,093 INFO [RS_CLOSE_REGION-regionserver/worker008:16020-0]
regionserver.HStore: Added
hdfs://dune/hbase/data/ris/ris-updates/625d2ac4331542df877e44fa06489ca1/-/2bc2db2278054d6399fdf618fca0f260,
entries=600, sequenceid=88678485, filesize=21.4 K
2021-07-27 12:07:33,094 INFO [RS_CLOSE_REGION-regionserver/worker008:16020-0]
regionserver.HRegion: Finished flush of dataSize ~77.13 KB/78981, heapSize
~122.02 KB/124952, currentSize=0 B/0 for 625d2ac4331542df877e44fa06489ca1 in
283ms, sequenceid=88678485, compaction requested=true
2021-07-27 12:07:33,105 INFO [RS_CLOSE_REGION-regionserver/worker008:16020-0]
regionserver.HRegion: Closed
ris:ris-updates,\x00\x03\x00\x00\x01z\xE6/M:\x04P\xF9\xD0j\x00\x00\x00\x01,1627382439537.625d2ac4331542df877e44fa06489ca1.
2021-07-27 12:07:33,106 INFO [RS_CLOSE_REGION-regionserver/worker008:16020-0]
handler.UnassignRegionHandler: Closed 625d2ac4331542df877e44fa06489ca1
2021-07-27 12:07:35,413 WARN [StoreFileOpener---1] hfile.BlockCacheUtil:
Caching an already cached block:
9bcfcba754cf4084817bb6aee7ce0492.625d2ac4331542df877e44fa06489ca1_420326799.
This is harmless and can happen in rare cases (see HBASE-8547)
{noformat}
And on the master:
{noformat}
2021-07-27 12:07:32,655 INFO [PEWorker-16] procedure.MasterProcedureScheduler:
Took xlock for pid=118449, state=RUNNABLE:SPLIT_TABLE_REGION_PREPARE;
SplitTableRegionProcedure table=ris:ris-updates,
parent=625d2ac4331542df877e44fa06489ca1,
daughterA=43206debd9f16952acb6632130b64e36,
daughterB=d317ec8cb2eb18dbd3cf92cf4b5b85d9
2021-07-27 12:07:32,655 INFO [PEWorker-16] procedure.MasterProcedureScheduler:
Took xlock for pid=118449, state=RUNNABLE:SPLIT_TABLE_REGION_PREPARE;
SplitTableRegionProcedure table=ris:ris-updates,
parent=625d2ac4331542df877e44fa06489ca1,
daughterA=43206debd9f16952acb6632130b64e36,
daughterB=d317ec8cb2eb18dbd3cf92cf4b5b85d9
2021-07-27 12:07:32,655 INFO [PEWorker-16] procedure.MasterProcedureScheduler:
Took xlock for pid=118449, state=RUNNABLE:SPLIT_TABLE_REGION_PREPARE;
SplitTableRegionProcedure table=ris:ris-updates,
parent=625d2ac4331542df877e44fa06489ca1,
daughterA=43206debd9f16952acb6632130b64e36,
daughterB=d317ec8cb2eb18dbd3cf92cf4b5b85d9
2021-07-27 12:07:32,656 INFO [PEWorker-16] procedure2.ProcedureExecutor:
Initialized subprocedures=[{pid=118450, ppid=118449,
state=RUNNABLE:REGION_STATE_TRANSITION_CLOSE; TransitRegionStateProcedure
table=ris:ris-updates, region=625d2ac4331542df877e44fa06489ca1, UNASSIGN}]
2021-07-27 12:07:32,656 INFO [PEWorker-16] procedure.MasterProcedureScheduler:
Took xlock for pid=118450, ppid=118449,
state=RUNNABLE:REGION_STATE_TRANSITION_CLOSE; TransitRegionStateProcedure
table=ris:ris-updates, region=625d2ac4331542df877e44fa06489ca1, UNASSIGN
2021-07-27 12:07:32,657 INFO [PEWorker-16] assignment.RegionStateStore:
pid=118450 updating hbase:meta row=625d2ac4331542df877e44fa06489ca1,
regionState=CLOSING, regionLocation=worker008.dune.ripe.net,16020,1627053306686
2021-07-27 12:07:32,660 INFO [PEWorker-16] procedure2.ProcedureExecutor:
Initialized subprocedures=[{pid=118451, ppid=118450, state=RUNNABLE;
CloseRegionProcedure 625d2ac4331542df877e44fa06489ca1,
server=worker008.dune.ripe.net,16020,1627053306686}]
2021-07-27 12:07:33,106 INFO [PEWorker-3] assignment.RegionStateStore:
pid=118450 updating hbase:meta row=625d2ac4331542df877e44fa06489ca1,
regionState=CLOSED
2021-07-27 12:07:33,108 INFO [PEWorker-3] procedure2.ProcedureExecutor:
Finished subprocedure pid=118451, resume processing ppid=118450
2021-07-27 12:07:33,108 INFO [PEWorker-3] procedure2.ProcedureExecutor:
Finished pid=118451, ppid=118450, state=SUCCESS; CloseRegionProcedure
625d2ac4331542df877e44fa06489ca1,
server=worker008.dune.ripe.net,16020,1627053306686 in 447 msec
2021-07-27 12:07:33,109 INFO [PEWorker-7] procedure2.ProcedureExecutor:
Finished subprocedure pid=118450, resume processing ppid=118449
2021-07-27 12:07:33,109 INFO [PEWorker-7] procedure2.ProcedureExecutor:
Finished pid=118450, ppid=118449, state=SUCCESS; TransitRegionStateProcedure
table=ris:ris-updates, region=625d2ac4331542df877e44fa06489ca1, UNASSIGN in 452
msec
2021-07-27 12:07:33,118 INFO [PEWorker-10]
assignment.SplitTableRegionProcedure: pid=118449 splitting 5 storefiles,
region=625d2ac4331542df877e44fa06489ca1, threads=5
2021-07-27 12:07:35,072 INFO [PEWorker-10] procedure2.ProcedureExecutor:
Initialized subprocedures=[{pid=118452, ppid=118449,
state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE;
TransitRegionStateProcedure table=ris:ris-updates,
region=43206debd9f16952acb6632130b64e36, ASSIGN}, {pid=118453, ppid=118449,
state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE;
TransitRegionStateProcedure table=ris:ris-updates,
region=d317ec8cb2eb18dbd3cf92cf4b5b85d9, ASSIGN}]
2021-07-27 12:07:35,072 INFO [PEWorker-12] procedure.MasterProcedureScheduler:
Took xlock for pid=118453, ppid=118449,
state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE;
TransitRegionStateProcedure table=ris:ris-updates,
region=d317ec8cb2eb18dbd3cf92cf4b5b85d9, ASSIGN
2021-07-27 12:07:35,072 INFO [PEWorker-2] procedure.MasterProcedureScheduler:
Took xlock for pid=118452, ppid=118449,
state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE;
TransitRegionStateProcedure table=ris:ris-updates,
region=43206debd9f16952acb6632130b64e36, ASSIGN
2021-07-27 12:07:35,073 INFO [PEWorker-12]
assignment.TransitRegionStateProcedure: Starting pid=118453, ppid=118449,
state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE, locked=true;
TransitRegionStateProcedure table=ris:ris-updates,
region=d317ec8cb2eb18dbd3cf92cf4b5b85d9, ASSIGN; state=SPLITTING_NEW,
location=worker008.dune.ripe.net,16020,1627053306686; forceNewPlan=false,
retain=false
2021-07-27 12:07:35,073 INFO [PEWorker-2]
assignment.TransitRegionStateProcedure: Starting pid=118452, ppid=118449,
state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE, locked=true;
TransitRegionStateProcedure table=ris:ris-updates,
region=43206debd9f16952acb6632130b64e36, ASSIGN; state=SPLITTING_NEW,
location=worker008.dune.ripe.net,16020,1627053306686; forceNewPlan=false,
retain=false
2021-07-27 12:07:35,223 INFO [master2:16000] balancer.BaseLoadBalancer:
Reassigned 2 regions. 2 retained the pre-restart assignment.
2021-07-27 12:07:35,223 INFO [PEWorker-5] assignment.RegionStateStore:
pid=118453 updating hbase:meta row=d317ec8cb2eb18dbd3cf92cf4b5b85d9,
regionState=OPENING, regionLocation=worker008.dune.ripe.net,16020,1627053306686
2021-07-27 12:07:35,223 INFO [PEWorker-13] assignment.RegionStateStore:
pid=118452 updating hbase:meta row=43206debd9f16952acb6632130b64e36,
regionState=OPENING, regionLocation=worker008.dune.ripe.net,16020,1627053306686
2021-07-27 12:07:35,224 INFO [PEWorker-5] procedure2.ProcedureExecutor:
Initialized subprocedures=[{pid=118454, ppid=118453, state=RUNNABLE;
OpenRegionProcedure d317ec8cb2eb18dbd3cf92cf4b5b85d9,
server=worker008.dune.ripe.net,16020,1627053306686}]
2021-07-27 12:07:35,224 INFO [PEWorker-13] procedure2.ProcedureExecutor:
Initialized subprocedures=[{pid=118455, ppid=118452, state=RUNNABLE;
OpenRegionProcedure 43206debd9f16952acb6632130b64e36,
server=worker008.dune.ripe.net,16020,1627053306686}]
2021-07-27 12:07:35,421 INFO [PEWorker-14] assignment.RegionStateStore:
pid=118452 updating hbase:meta row=43206debd9f16952acb6632130b64e36,
regionState=OPEN, openSeqNum=88678489,
regionLocation=worker008.dune.ripe.net,16020,1627053306686
2021-07-27 12:07:35,423 INFO [PEWorker-14] procedure2.ProcedureExecutor:
Finished subprocedure pid=118455, resume processing ppid=118452
2021-07-27 12:07:35,423 INFO [PEWorker-14] procedure2.ProcedureExecutor:
Finished pid=118455, ppid=118452, state=SUCCESS; OpenRegionProcedure
43206debd9f16952acb6632130b64e36,
server=worker008.dune.ripe.net,16020,1627053306686 in 198 msec
2021-07-27 12:07:35,423 INFO [PEWorker-1] procedure2.ProcedureExecutor:
Finished pid=118452, ppid=118449, state=SUCCESS; TransitRegionStateProcedure
table=ris:ris-updates, region=43206debd9f16952acb6632130b64e36, ASSIGN in 351
msec
2021-07-27 12:07:35,666 INFO [PEWorker-11] assignment.RegionStateStore:
pid=118453 updating hbase:meta row=d317ec8cb2eb18dbd3cf92cf4b5b85d9,
regionState=OPEN, openSeqNum=88678489,
regionLocation=worker008.dune.ripe.net,16020,1627053306686
2021-07-27 12:07:35,668 INFO [PEWorker-11] procedure2.ProcedureExecutor:
Finished subprocedure pid=118454, resume processing ppid=118453
2021-07-27 12:07:35,668 INFO [PEWorker-11] procedure2.ProcedureExecutor:
Finished pid=118454, ppid=118453, state=SUCCESS; OpenRegionProcedure
d317ec8cb2eb18dbd3cf92cf4b5b85d9,
server=worker008.dune.ripe.net,16020,1627053306686 in 443 msec
2021-07-27 12:07:35,669 INFO [PEWorker-9] procedure2.ProcedureExecutor:
Finished subprocedure pid=118453, resume processing ppid=118449
2021-07-27 12:07:35,669 INFO [PEWorker-9] procedure2.ProcedureExecutor:
Finished pid=118453, ppid=118449, state=SUCCESS; TransitRegionStateProcedure
table=ris:ris-updates, region=d317ec8cb2eb18dbd3cf92cf4b5b85d9, ASSIGN in 596
msec
2021-07-27 12:07:35,669 INFO [PEWorker-15] procedure2.ProcedureExecutor:
Finished pid=118449, state=SUCCESS; SplitTableRegionProcedure
table=ris:ris-updates, parent=625d2ac4331542df877e44fa06489ca1,
daughterA=43206debd9f16952acb6632130b64e36,
daughterB=d317ec8cb2eb18dbd3cf92cf4b5b85d9 in 3.0160 sec
2021-07-27 12:09:05,065 INFO [master/master2:16000.Chore.1]
balancer.BaseLoadBalancer: Start Generate Balance plan for cluster.
2021-07-27 12:10:58,943 INFO [master:store-WAL-Roller] wal.AbstractFSWAL:
Rolled WAL
/hbase/MasterData/WALs/master2.dune.ripe.net,16000,1627034030675/master2.dune.ripe.net%2C16000%2C1627034030675.master2.dune.ripe.net%2C16000%2C1627034030675.regiongroup-0.1627386958285
with entries=60, filesize=30.97 KB; new WAL
/hbase/MasterData/WALs/master2.dune.ripe.net,16000,1627034030675/master2.dune.ripe.net%2C16000%2C1627034030675.master2.dune.ripe.net%2C16000%2C1627034030675.regiongroup-0.1627387858617
2021-07-27 12:12:00,780 INFO [master:store-Flusher] regionserver.HRegion:
Flushing 1595e783b53d99cd5eef43b6debb2682 1/1 column families, dataSize=26.98
KB heapSize=32.55 KB
2021-07-27 12:12:01,416 INFO [master:store-Flusher]
regionserver.DefaultStoreFlusher: Flushed memstore data size=26.98 KB at
sequenceid=1068044 (bloomFilter=true),
to=hdfs://dune/hbase/MasterData/data/master/store/1595e783b53d99cd5eef43b6debb2682/.tmp/proc/b47b99aa8f544dc6badd73f8450d6390
2021-07-27 12:12:01,418 INFO [master:store-Flusher]
regionserver.StoreFileReader: Loaded Delete Family Bloom (CompoundBloomFilter)
metadata for b47b99aa8f544dc6badd73f8450d6390
2021-07-27 12:12:01,421 INFO [master:store-Flusher]
regionserver.StoreFileReader: Loaded Delete Family Bloom (CompoundBloomFilter)
metadata for b47b99aa8f544dc6badd73f8450d6390
2021-07-27 12:12:01,421 INFO [master:store-Flusher] regionserver.HStore: Added
hdfs://dune/hbase/MasterData/data/master/store/1595e783b53d99cd5eef43b6debb2682/proc/b47b99aa8f544dc6badd73f8450d6390,
entries=8, sequenceid=1068044, filesize=5.8 K
2021-07-27 12:12:01,422 INFO [master:store-Flusher] regionserver.HRegion:
Finished flush of dataSize ~26.98 KB/27626, heapSize ~32.53 KB/33312,
currentSize=0 B/0 for 1595e783b53d99cd5eef43b6debb2682 in 642ms,
sequenceid=1068044, compaction requested=true
2021-07-27 12:14:05,276 INFO [master/master2:16000.Chore.2]
balancer.BaseLoadBalancer: Start Generate Balance plan for cluster.
2021-07-27 12:14:05,373 INFO [PEWorker-8] procedure.MasterProcedureScheduler:
Took xlock for pid=118456, state=RUNNABLE:GC_REGION_PREPARE; GCRegionProcedure
table=ris:ris-updates, region=625d2ac4331542df877e44fa06489ca1
2021-07-27 12:14:05,396 INFO [PEWorker-8] hbase.MetaTableAccessor: Deleted
ris:ris-updates,\x00\x03\x00\x00\x01z\xE6/M:\x04P\xF9\xD0j\x00\x00\x00\x01,1627382439537.625d2ac4331542df877e44fa06489ca1.
2021-07-27 12:14:05,397 INFO [PEWorker-8] procedure2.ProcedureExecutor:
Finished pid=118456, state=SUCCESS; GCRegionProcedure table=ris:ris-updates,
region=625d2ac4331542df877e44fa06489ca1 in 25 msec
{noformat}
was:
While inserting records into HBase, I'm getting following exceptions on the
client side:
{noformat}
2021-07-27 12:07:33,986 WARN [hconnection-0x6d4081cd-shared-pool-158]
o.a.h.h.c.AsyncRequestFutureImpl - id=1, table=ris:ris-updates, attempt=1/16,
failureCount=9ops, last
exception=org.apache.hadoop.hbase.DoNotRetryIOException: java.lang.ExceptionInI
nitializerError on worker008,16020,1627053306686, tracking started Tue Jul 27
12:07:33 UTC 2021; NOT retrying, failed=9 -- final attempt!
2021-07-27 12:07:34,008 ERROR [Thread-4] o.a.hadoop.hbase.client.BatchErrors -
Exception occurred! Exception details:
[org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError, org.a
pache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError,
org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError,
org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError,
org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError,
org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError,
org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerEr
ror, org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError,
org.apache.hadoop.hbase.DoNotRetryIOException:
java.lang.ExceptionInInitializerError];
Actions:
[{"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE5z\\x04P\\xF9\\xD3\\xD9\\x00\\x00\\x00\\x00","families":{"-":[{"qualifier":"mrt","vlen":117,"tag":[],"timestamp":"1627387651450"},{"qualifier":"source","vlen":11,"tag":[],"timest
amp":"1627387651450"}]},"ts":"1627387651450"},
{"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE5z\\x04P\\xF9\\xD1\\xB0\\x00\\x00\\x00\\x01","families":{"-":[{"qualifier":"mrt","vlen":117,"tag":[],"timestamp":"1627387651450"},{"qualifier
":"source","vlen":11,"tag":[],"timestamp":"1627387651450"}]},"ts":"1627387651450"},
{"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE5z\\x04P\\xF9\\xD2\\xD0\\x00\\x00\\x00\\x02","families":{"-":[{"qualifier":"mrt","vlen":125,"tag":[],"ti
mestamp":"1627387651450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387651450"}]},"ts":"1627387651450"},
{"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE5z\\x06
\\x01\\x07\\xF8\\x00\\x01\\x00\\x00\\x00\\x00\\xA5\\x02\\x9
4g\\x00\\x01\\x00\\x00\\x00\\x03","families":{"-":[{"qualifier":"mrt","vlen":175,"tag":[],"timestamp":"1627387651450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387651450"}]},"ts":"1627387651450"},
{"totalColumns":2,"row":"\\x00\\x03\\x0
0\\x00\\x01z\\xE7\\xDC\\xE9b\\x04P\\xF9\\xD3\\xD9\\x00\\x00\\x00\\x00","families":{"-":[{"qualifier":"mrt","vlen":125,"tag":[],"timestamp":"1627387652450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387652450"}]},"ts":"1627387652450"},
{"
totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE9b\\x06
\\x01\\x07\\xF8\\x00\\x01\\x00\\x00\\x00\\x00\\xA5\\x00\\x84U\\x00\\x01\\x00\\x00\\x00\\x01","families":{"-":[{"qualifier":"mrt","vlen":75,"tag":[],"timestamp":"1627387652450"},{"qua
lifier":"source","vlen":11,"tag":[],"timestamp":"1627387652450"}]},"ts":"1627387652450"},
{"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE9b\\x04P\\xF9\\xD1\\xB0\\x00\\x00\\x00\\x02","families":{"-":[{"qualifier":"mrt","vlen":110,"tag":
[],"timestamp":"1627387652450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387652450"}]},"ts":"1627387652450"},
{"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE9b\\x06
\\x01\\x07\\xF8\\x00\\x01\\x00\\x00\\x00\\x00\\xA5\\x
02\\x94g\\x00\\x01\\x00\\x00\\x00\\x03","families":{"-":[{"qualifier":"mrt","vlen":171,"tag":[],"timestamp":"1627387652450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387652450"}]},"ts":"1627387652450"},
{"totalColumns":2,"row":"\\x00\\x
03\\x00\\x00\\x01z\\xE7\\xDC\\xE9b\\x04P\\xF9\\xD3\\xD9\\x00\\x00\\x00\\x04","families":{"-":[{"qualifier":"mrt","vlen":115,"tag":[],"timestamp":"1627387652450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387652450"}]},"ts":"1627387652450
"}]
2021-07-27 12:07:34,015 ERROR [Thread-4] n.r.g.r.a.AbstractApp - Error:
org.apache.hadoop.hbase.client.RetriesExhaustedWithDetailsException: Failed 9
actions: java.lang.ExceptionInInitializerError: 9 times, servers with issues:
worker008,16020,1627053306686
at
org.apache.hadoop.hbase.client.BatchErrors.makeException(BatchErrors.java:54)
at
org.apache.hadoop.hbase.client.AsyncRequestFutureImpl.getErrors(AsyncRequestFutureImpl.java:1196)
at org.apache.hadoop.hbase.client.HTable.batch(HTable.java:451)
at org.apache.hadoop.hbase.client.HTable.put(HTable.java:549){noformat}
There are no errors logged on the regionserver:
{noformat}
2021-07-27 12:07:32,811 INFO [RS_CLOSE_REGION-regionserver/worker008:16020-0]
handler.UnassignRegionHandler: Close 625d2ac4331542df877e44fa06489ca1
2021-07-27 12:07:32,811 INFO [RS_CLOSE_REGION-regionserver/worker008:16020-0]
regionserver.HRegion: Closing region
ris:ris-updates,\x00\x03\x00\x00\x01z\xE6/M:\x04P\xF9\xD0j\x00\x00\x00\x01,1627382439537.625d2ac4331542df877e44fa06489ca1.
2021-07-27 12:07:32,811 INFO [RS_CLOSE_REGION-regionserver/worker008:16020-0]
regionserver.HRegion: Flushing 625d2ac4331542df877e44fa06489ca1 1/1 column
families, dataSize=77.13 KB heapSize=122.04 KB
2021-07-27 12:07:33,088 INFO [RS_CLOSE_REGION-regionserver/worker008:16020-0]
regionserver.DefaultStoreFlusher: Flushed memstore data size=77.13 KB at
sequenceid=88678485 (bloomFilter=true),
to=hdfs://dune/hbase/data/ris/ris-updates/625d2ac4331542df877
e44fa06489ca1/.tmp/-/2bc2db2278054d6399fdf618fca0f260
2021-07-27 12:07:33,093 INFO [RS_CLOSE_REGION-regionserver/worker008:16020-0]
regionserver.HStore: Added
hdfs://dune/hbase/data/ris/ris-updates/625d2ac4331542df877e44fa06489ca1/-/2bc2db2278054d6399fdf618fca0f260,
entries=600, sequenceid=88678485, files
ize=21.4 K
2021-07-27 12:07:33,094 INFO [RS_CLOSE_REGION-regionserver/worker008:16020-0]
regionserver.HRegion: Finished flush of dataSize ~77.13 KB/78981, heapSize
~122.02 KB/124952, currentSize=0 B/0 for 625d2ac4331542df877e44fa06489ca1 in
283ms, sequenceid=8867
8485, compaction requested=true
2021-07-27 12:07:33,105 INFO [RS_CLOSE_REGION-regionserver/worker008:16020-0]
regionserver.HRegion: Closed
ris:ris-updates,\x00\x03\x00\x00\x01z\xE6/M:\x04P\xF9\xD0j\x00\x00\x00\x01,1627382439537.625d2ac4331542df877e44fa06489ca1.
2021-07-27 12:07:33,106 INFO [RS_CLOSE_REGION-regionserver/worker008:16020-0]
handler.UnassignRegionHandler: Closed 625d2ac4331542df877e44fa06489ca1
2021-07-27 12:07:35,413 WARN [StoreFileOpener---1] hfile.BlockCacheUtil:
Caching an already cached block:
9bcfcba754cf4084817bb6aee7ce0492.625d2ac4331542df877e44fa06489ca1_420326799.
This is harmless and can happen in rare cases (see HBASE-8547){noformat}
And on master:
{noformat}
2021-07-27 12:07:32,655 INFO [PEWorker-16] procedure.MasterProcedureScheduler:
Took xlock for pid=118449, state=RUNNABLE:SPLIT_TABLE_REGION_PREPARE;
SplitTableRegionProcedure table=ris:ris-updates,
parent=625d2ac4331542df877e44fa06489ca1, daughterA=432
06debd9f16952acb6632130b64e36, daughterB=d317ec8cb2eb18dbd3cf92cf4b5b85d9
2021-07-27 12:07:32,655 INFO [PEWorker-16] procedure.MasterProcedureScheduler:
Took xlock for pid=118449, state=RUNNABLE:SPLIT_TABLE_REGION_PREPARE;
SplitTableRegionProcedure table=ris:ris-updates,
parent=625d2ac4331542df877e44fa06489ca1, daughterA=432
06debd9f16952acb6632130b64e36, daughterB=d317ec8cb2eb18dbd3cf92cf4b5b85d9
2021-07-27 12:07:32,655 INFO [PEWorker-16] procedure.MasterProcedureScheduler:
Took xlock for pid=118449, state=RUNNABLE:SPLIT_TABLE_REGION_PREPARE;
SplitTableRegionProcedure table=ris:ris-updates,
parent=625d2ac4331542df877e44fa06489ca1, daughterA=432
06debd9f16952acb6632130b64e36, daughterB=d317ec8cb2eb18dbd3cf92cf4b5b85d9
2021-07-27 12:07:32,656 INFO [PEWorker-16] procedure2.ProcedureExecutor:
Initialized subprocedures=[{pid=118450, ppid=118449,
state=RUNNABLE:REGION_STATE_TRANSITION_CLOSE; TransitRegionStateProcedure
table=ris:ris-updates, region=625d2ac4331542df877e44
fa06489ca1, UNASSIGN}]
2021-07-27 12:07:32,656 INFO [PEWorker-16] procedure.MasterProcedureScheduler:
Took xlock for pid=118450, ppid=118449,
state=RUNNABLE:REGION_STATE_TRANSITION_CLOSE; TransitRegionStateProcedure
table=ris:ris-updates, region=625d2ac4331542df877e44fa06489
ca1, UNASSIGN
2021-07-27 12:07:32,657 INFO [PEWorker-16] assignment.RegionStateStore:
pid=118450 updating hbase:meta row=625d2ac4331542df877e44fa06489ca1,
regionState=CLOSING, regionLocation=worker008.dune.ripe.net,16020,1627053306686
2021-07-27 12:07:32,660 INFO [PEWorker-16] procedure2.ProcedureExecutor:
Initialized subprocedures=[{pid=118451, ppid=118450, state=RUNNABLE;
CloseRegionProcedure 625d2ac4331542df877e44fa06489ca1,
server=worker008.dune.ripe.net,16020,1627053306686}]
2021-07-27 12:07:33,106 INFO [PEWorker-3] assignment.RegionStateStore:
pid=118450 updating hbase:meta row=625d2ac4331542df877e44fa06489ca1,
regionState=CLOSED
2021-07-27 12:07:33,108 INFO [PEWorker-3] procedure2.ProcedureExecutor:
Finished subprocedure pid=118451, resume processing ppid=118450
2021-07-27 12:07:33,108 INFO [PEWorker-3] procedure2.ProcedureExecutor:
Finished pid=118451, ppid=118450, state=SUCCESS; CloseRegionProcedure
625d2ac4331542df877e44fa06489ca1,
server=worker008.dune.ripe.net,16020,1627053306686 in 447 msec
2021-07-27 12:07:33,109 INFO [PEWorker-7] procedure2.ProcedureExecutor:
Finished subprocedure pid=118450, resume processing ppid=118449
2021-07-27 12:07:33,109 INFO [PEWorker-7] procedure2.ProcedureExecutor:
Finished pid=118450, ppid=118449, state=SUCCESS; TransitRegionStateProcedure
table=ris:ris-updates, region=625d2ac4331542df877e44fa06489ca1, UNASSIGN in 452
msec
2021-07-27 12:07:33,118 INFO [PEWorker-10]
assignment.SplitTableRegionProcedure: pid=118449 splitting 5 storefiles,
region=625d2ac4331542df877e44fa06489ca1, threads=5
2021-07-27 12:07:35,072 INFO [PEWorker-10] procedure2.ProcedureExecutor:
Initialized subprocedures=[{pid=118452, ppid=118449,
state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE;
TransitRegionStateProcedure table=ris:ris-updates,
region=43206debd9f16952acb6632130b64e36, ASSIGN}, {pid=118453, ppid=118449,
state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE;
TransitRegionStateProcedure table=ris:ris-updates,
region=d317ec8cb2eb18dbd3cf92cf4b5b85d9, ASSIGN}]
2021-07-27 12:07:35,072 INFO [PEWorker-12] procedure.MasterProcedureScheduler:
Took xlock for pid=118453, ppid=118449,
state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE;
TransitRegionStateProcedure table=ris:ris-updates,
region=d317ec8cb2eb18dbd3cf92cf4b5b85d9, ASSIGN
2021-07-27 12:07:35,072 INFO [PEWorker-2] procedure.MasterProcedureScheduler:
Took xlock for pid=118452, ppid=118449,
state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE;
TransitRegionStateProcedure table=ris:ris-updates,
region=43206debd9f16952acb6632130b64e36, ASSIGN
2021-07-27 12:07:35,073 INFO [PEWorker-12]
assignment.TransitRegionStateProcedure: Starting pid=118453, ppid=118449,
state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE, locked=true;
TransitRegionStateProcedure table=ris:ris-updates,
region=d317ec8cb2eb18dbd3cf92cf4b5b85d9, ASSIGN; state=SPLITTING_NEW,
location=worker008.dune.ripe.net,16020,1627053306686; forceNewPlan=false,
retain=false
2021-07-27 12:07:35,073 INFO [PEWorker-2]
assignment.TransitRegionStateProcedure: Starting pid=118452, ppid=118449,
state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE, locked=true;
TransitRegionStateProcedure table=ris:ris-updates,
region=43206debd9f16952acb6632130b64e36, ASSIGN; state=SPLITTING_NEW,
location=worker008.dune.ripe.net,16020,1627053306686; forceNewPlan=false,
retain=false
2021-07-27 12:07:35,223 INFO [master2:16000] balancer.BaseLoadBalancer:
Reassigned 2 regions. 2 retained the pre-restart assignment.
2021-07-27 12:07:35,223 INFO [PEWorker-5] assignment.RegionStateStore:
pid=118453 updating hbase:meta row=d317ec8cb2eb18dbd3cf92cf4b5b85d9,
regionState=OPENING, regionLocation=worker008.dune.ripe.net,16020,1627053306686
2021-07-27 12:07:35,223 INFO [PEWorker-13] assignment.RegionStateStore:
pid=118452 updating hbase:meta row=43206debd9f16952acb6632130b64e36,
regionState=OPENING, regionLocation=worker008.dune.ripe.net,16020,1627053306686
2021-07-27 12:07:35,224 INFO [PEWorker-5] procedure2.ProcedureExecutor:
Initialized subprocedures=[{pid=118454, ppid=118453, state=RUNNABLE;
OpenRegionProcedure d317ec8cb2eb18dbd3cf92cf4b5b85d9,
server=worker008.dune.ripe.net,16020,1627053306686}]
2021-07-27 12:07:35,224 INFO [PEWorker-13] procedure2.ProcedureExecutor:
Initialized subprocedures=[{pid=118455, ppid=118452, state=RUNNABLE;
OpenRegionProcedure 43206debd9f16952acb6632130b64e36,
server=worker008.dune.ripe.net,16020,1627053306686}]
2021-07-27 12:07:35,421 INFO [PEWorker-14] assignment.RegionStateStore:
pid=118452 updating hbase:meta row=43206debd9f16952acb6632130b64e36,
regionState=OPEN, openSeqNum=88678489,
regionLocation=worker008.dune.ripe.net,16020,1627053306686
2021-07-27 12:07:35,423 INFO [PEWorker-14] procedure2.ProcedureExecutor:
Finished subprocedure pid=118455, resume processing ppid=118452
2021-07-27 12:07:35,423 INFO [PEWorker-14] procedure2.ProcedureExecutor:
Finished pid=118455, ppid=118452, state=SUCCESS; OpenRegionProcedure
43206debd9f16952acb6632130b64e36,
server=worker008.dune.ripe.net,16020,1627053306686 in 198 msec
2021-07-27 12:07:35,423 INFO [PEWorker-1] procedure2.ProcedureExecutor:
Finished pid=118452, ppid=118449, state=SUCCESS; TransitRegionStateProcedure
table=ris:ris-updates, region=43206debd9f16952acb6632130b64e36, ASSIGN in 351
msec
2021-07-27 12:07:35,666 INFO [PEWorker-11] assignment.RegionStateStore:
pid=118453 updating hbase:meta row=d317ec8cb2eb18dbd3cf92cf4b5b85d9,
regionState=OPEN, openSeqNum=88678489,
regionLocation=worker008.dune.ripe.net,16020,1627053306686
2021-07-27 12:07:35,668 INFO [PEWorker-11] procedure2.ProcedureExecutor:
Finished subprocedure pid=118454, resume processing ppid=118453
2021-07-27 12:07:35,668 INFO [PEWorker-11] procedure2.ProcedureExecutor:
Finished pid=118454, ppid=118453, state=SUCCESS; OpenRegionProcedure
d317ec8cb2eb18dbd3cf92cf4b5b85d9,
server=worker008.dune.ripe.net,16020,1627053306686 in 443 msec
2021-07-27 12:07:35,669 INFO [PEWorker-9] procedure2.ProcedureExecutor:
Finished subprocedure pid=118453, resume processing ppid=118449
2021-07-27 12:07:35,669 INFO [PEWorker-9] procedure2.ProcedureExecutor:
Finished pid=118453, ppid=118449, state=SUCCESS; TransitRegionStateProcedure
table=ris:ris-updates, region=d317ec8cb2eb18dbd3cf92cf4b5b85d9, ASSIGN in 596
msec
2021-07-27 12:07:35,669 INFO [PEWorker-15] procedure2.ProcedureExecutor:
Finished pid=118449, state=SUCCESS; SplitTableRegionProcedure
table=ris:ris-updates, parent=625d2ac4331542df877e44fa06489ca1,
daughterA=43206debd9f16952acb6632130b64e36,
daughterB=d317ec8cb2eb18dbd3cf92cf4b5b85d9 in 3.0160 sec
2021-07-27 12:09:05,065 INFO [master/master2:16000.Chore.1]
balancer.BaseLoadBalancer: Start Generate Balance plan for cluster.
2021-07-27 12:10:58,943 INFO [master:store-WAL-Roller] wal.AbstractFSWAL:
Rolled WAL
/hbase/MasterData/WALs/master2.dune.ripe.net,16000,1627034030675/master2.dune.ripe.net%2C16000%2C1627034030675.master2.dune.ripe.net%2C16000%2C1627034030675.regiongroup-0.1627386958285
with entries=60, filesize=30.97 KB; new WAL
/hbase/MasterData/WALs/master2.dune.ripe.net,16000,1627034030675/master2.dune.ripe.net%2C16000%2C1627034030675.master2.dune.ripe.net%2C16000%2C1627034030675.regiongroup-0.1627387858617
2021-07-27 12:12:00,780 INFO [master:store-Flusher] regionserver.HRegion:
Flushing 1595e783b53d99cd5eef43b6debb2682 1/1 column families, dataSize=26.98
KB heapSize=32.55 KB
2021-07-27 12:12:01,416 INFO [master:store-Flusher]
regionserver.DefaultStoreFlusher: Flushed memstore data size=26.98 KB at
sequenceid=1068044 (bloomFilter=true),
to=hdfs://dune/hbase/MasterData/data/master/store/1595e783b53d99cd5eef43b6debb2682/.tmp/proc/b47b99aa8f544dc6badd73f8450d6390
2021-07-27 12:12:01,418 INFO [master:store-Flusher]
regionserver.StoreFileReader: Loaded Delete Family Bloom (CompoundBloomFilter)
metadata for b47b99aa8f544dc6badd73f8450d6390
2021-07-27 12:12:01,421 INFO [master:store-Flusher]
regionserver.StoreFileReader: Loaded Delete Family Bloom (CompoundBloomFilter)
metadata for b47b99aa8f544dc6badd73f8450d6390
2021-07-27 12:12:01,421 INFO [master:store-Flusher] regionserver.HStore: Added
hdfs://dune/hbase/MasterData/data/master/store/1595e783b53d99cd5eef43b6debb2682/proc/b47b99aa8f544dc6badd73f8450d6390,
entries=8, sequenceid=1068044, filesize=5.8 K
2021-07-27 12:12:01,422 INFO [master:store-Flusher] regionserver.HRegion:
Finished flush of dataSize ~26.98 KB/27626, heapSize ~32.53 KB/33312,
currentSize=0 B/0 for 1595e783b53d99cd5eef43b6debb2682 in 642ms,
sequenceid=1068044, compaction requested=true
2021-07-27 12:14:05,276 INFO [master/master2:16000.Chore.2]
balancer.BaseLoadBalancer: Start Generate Balance plan for cluster.
2021-07-27 12:14:05,373 INFO [PEWorker-8] procedure.MasterProcedureScheduler:
Took xlock for pid=118456, state=RUNNABLE:GC_REGION_PREPARE; GCRegionProcedure
table=ris:ris-updates, region=625d2ac4331542df877e44fa06489ca1
2021-07-27 12:14:05,396 INFO [PEWorker-8] hbase.MetaTableAccessor: Deleted
ris:ris-updates,\x00\x03\x00\x00\x01z\xE6/M:\x04P\xF9\xD0j\x00\x00\x00\x01,1627382439537.625d2ac4331542df877e44fa06489ca1.
2021-07-27 12:14:05,397 INFO [PEWorker-8] procedure2.ProcedureExecutor:
Finished pid=118456, state=SUCCESS; GCRegionProcedure table=ris:ris-updates,
region=625d2ac4331542df877e44fa06489ca1 in 25 mse{noformat}
> Update fails with DoNotRetryIOException while the region is being split
> -----------------------------------------------------------------------
>
> Key: HBASE-26145
> URL: https://issues.apache.org/jira/browse/HBASE-26145
> Project: HBase
> Issue Type: Bug
> Affects Versions: 2.4.4
> Environment: We are running HBase compiled from the release 2.4.4 tag
> with hadoop3 profile enabled, no other changes:
> JVM Version Red Hat, Inc. 1.8.0_292-25.292-b10 JVM vendor and version
> HBase Version 2.4.4-H3, revision=Unknown HBase version and revision
> HBase Compiled Fri Jul 23 08:21:49 UTC 2021, giioper When HBase version was
> compiled and by whom
> HBase Source Checksum
> 148222e0d18db5336d86bb2fda0d12a164bcbd710cd7181a98467a5bf41fa55648d7bf626d0fc32551d62986b82a7ce214c917c0f8ab6293702610c2034660d3
> HBase source SHA512 checksum
> Hadoop Version 3.2.2, revision=7a3bc90b05f257c8ace2f76d74264906f0f7a932
> Hadoop version and revision
> Hadoop Compiled 2021-01-03T12:14Z, hexiaoqiao When Hadoop version was
> compiled and by whom
> Hadoop Source Checksum 5a8f564f46624254b27f6a33126ff4 Hadoop source MD5
> checksum
> ZooKeeper Client Version 3.5.7,
> revision=f0fdd52973d373ffd9c86b81d99842dc2c7f660e ZooKeeper client version
> and revision hash
> ZooKeeper Client Compiled 02/10/2020 11:30 GMT When ZooKeeper client version
> was compiled
> ZooKeeper Quorum zookeeper1:2181
> zookeeper2:2181
> zookeeper3:2181
> zookeeper4:2181
> zookeeper5:2181 Addresses of all registered ZK servers. For more, see zk dump.
> ZooKeeper Base Path /hbase Root node of this cluster in ZK.
> Cluster Key zookeeper1:2181
> zookeeper2:2181
> zookeeper3:2181
> zookeeper4:2181
> zookeeper5:2181:/hbase Key to add this cluster as a peer for replication. Use
> 'help "add_peer"' in the shell for details.
> HBase Root Directory hdfs://dune/hbase Location of HBase home directory
> HMaster Start Time Fri Jul 23 09:53:50 UTC 2021 Date stamp of when this
> HMaster was started
> HMaster Active Time Fri Jul 23 09:53:52 UTC 2021 Date stamp of when this
> HMaster became active
> HBase Cluster ID 6cd0faae-6cf3-4888-87e0-e977a45faeaf Unique identifier
> generated for each HBase cluster
> Load average 156.28 Average number of regions per regionserver. Naive
> computation.
> Coprocessors [] Coprocessors currently loaded by the master
> LoadBalancer org.apache.hadoop.hbase.master.balancer.StochasticLoadBalancer
> LoadBalancer to be used in the Master
> Reporter: Oleg Muravskiy
> Priority: Major
>
> While inserting records into HBase, I'm getting following exceptions on the
> client side:
> {noformat}
> 2021-07-27 12:07:33,986 WARN [hconnection-0x6d4081cd-shared-pool-158]
> o.a.h.h.c.AsyncRequestFutureImpl - id=1, table=ris:ris-updates,
> attempt=1/16, failureCount=9ops, last
> exception=org.apache.hadoop.hbase.DoNotRetryIOException:
> java.lang.ExceptionInInitializerError on worker008,16020,1627053306686,
> tracking started Tue Jul 27 12:07:33 UTC 2021; NOT retrying, failed=9 --
> final attempt!
> 2021-07-27 12:07:34,008 ERROR [Thread-4] o.a.hadoop.hbase.client.BatchErrors
> - Exception occurred! Exception details:
> [org.apache.hadoop.hbase.DoNotRetryIOException:
> java.lang.ExceptionInInitializerError,
> org.apache.hadoop.hbase.DoNotRetryIOException:
> java.lang.ExceptionInInitializerError,
> org.apache.hadoop.hbase.DoNotRetryIOException:
> java.lang.ExceptionInInitializerError,
> org.apache.hadoop.hbase.DoNotRetryIOException:
> java.lang.ExceptionInInitializerError,
> org.apache.hadoop.hbase.DoNotRetryIOException:
> java.lang.ExceptionInInitializerError,
> org.apache.hadoop.hbase.DoNotRetryIOException:
> java.lang.ExceptionInInitializerError,
> org.apache.hadoop.hbase.DoNotRetryIOException:
> java.lang.ExceptionInInitializerError,
> org.apache.hadoop.hbase.DoNotRetryIOException:
> java.lang.ExceptionInInitializerError,
> org.apache.hadoop.hbase.DoNotRetryIOException:
> java.lang.ExceptionInInitializerError];
> Actions:
> [{"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE5z\\x04P\\xF9\\xD3\\xD9\\x00\\x00\\x00\\x00","families":{"-":[{"qualifier":"mrt","vlen":117,"tag":[],"timestamp":"1627387651450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387651450"}]},"ts":"1627387651450"},
>
> {"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE5z\\x04P\\xF9\\xD1\\xB0\\x00\\x00\\x00\\x01","families":{"-":[{"qualifier":"mrt","vlen":117,"tag":[],"timestamp":"1627387651450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387651450"}]},"ts":"1627387651450"},
>
> {"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE5z\\x04P\\xF9\\xD2\\xD0\\x00\\x00\\x00\\x02","families":{"-":[{"qualifier":"mrt","vlen":125,"tag":[],"timestamp":"1627387651450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387651450"}]},"ts":"1627387651450"},
> {"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE5z\\x06
> \\x01\\x07\\xF8\\x00\\x01\\x00\\x00\\x00\\x00\\xA5\\x02\\x94g\\x00\\x01\\x00\\x00\\x00\\x03","families":{"-":[{"qualifier":"mrt","vlen":175,"tag":[],"timestamp":"1627387651450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387651450"}]},"ts":"1627387651450"},
>
> {"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE9b\\x04P\\xF9\\xD3\\xD9\\x00\\x00\\x00\\x00","families":{"-":[{"qualifier":"mrt","vlen":125,"tag":[],"timestamp":"1627387652450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387652450"}]},"ts":"1627387652450"},
> {"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE9b\\x06
> \\x01\\x07\\xF8\\x00\\x01\\x00\\x00\\x00\\x00\\xA5\\x00\\x84U\\x00\\x01\\x00\\x00\\x00\\x01","families":{"-":[{"qualifier":"mrt","vlen":75,"tag":[],"timestamp":"1627387652450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387652450"}]},"ts":"1627387652450"},
>
> {"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE9b\\x04P\\xF9\\xD1\\xB0\\x00\\x00\\x00\\x02","families":{"-":[{"qualifier":"mrt","vlen":110,"tag":[],"timestamp":"1627387652450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387652450"}]},"ts":"1627387652450"},
> {"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE9b\\x06
> \\x01\\x07\\xF8\\x00\\x01\\x00\\x00\\x00\\x00\\xA5\\x02\\x94g\\x00\\x01\\x00\\x00\\x00\\x03","families":{"-":[{"qualifier":"mrt","vlen":171,"tag":[],"timestamp":"1627387652450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387652450"}]},"ts":"1627387652450"},
>
> {"totalColumns":2,"row":"\\x00\\x03\\x00\\x00\\x01z\\xE7\\xDC\\xE9b\\x04P\\xF9\\xD3\\xD9\\x00\\x00\\x00\\x04","families":{"-":[{"qualifier":"mrt","vlen":115,"tag":[],"timestamp":"1627387652450"},{"qualifier":"source","vlen":11,"tag":[],"timestamp":"1627387652450"}]},"ts":"1627387652450"}]
> 2021-07-27 12:07:34,015 ERROR [Thread-4] n.r.g.r.a.AbstractApp - Error:
> org.apache.hadoop.hbase.client.RetriesExhaustedWithDetailsException: Failed 9
> actions: java.lang.ExceptionInInitializerError: 9 times, servers with issues:
> worker008,16020,1627053306686
> at
> org.apache.hadoop.hbase.client.BatchErrors.makeException(BatchErrors.java:54)
> at
> org.apache.hadoop.hbase.client.AsyncRequestFutureImpl.getErrors(AsyncRequestFutureImpl.java:1196)
> at org.apache.hadoop.hbase.client.HTable.batch(HTable.java:451)
> at
> org.apache.hadoop.hbase.client.HTable.put(HTable.java:549){noformat}
> There are no errors logged on the regionserver:
> {noformat}
> 2021-07-27 12:07:32,811 INFO
> [RS_CLOSE_REGION-regionserver/worker008:16020-0]
> handler.UnassignRegionHandler: Close 625d2ac4331542df877e44fa06489ca1
> 2021-07-27 12:07:32,811 INFO
> [RS_CLOSE_REGION-regionserver/worker008:16020-0] regionserver.HRegion:
> Closing region
> ris:ris-updates,\x00\x03\x00\x00\x01z\xE6/M:\x04P\xF9\xD0j\x00\x00\x00\x01,1627382439537.625d2ac4331542df877e44fa06489ca1.
> 2021-07-27 12:07:32,811 INFO
> [RS_CLOSE_REGION-regionserver/worker008:16020-0] regionserver.HRegion:
> Flushing 625d2ac4331542df877e44fa06489ca1 1/1 column families, dataSize=77.13
> KB heapSize=122.04 KB
> 2021-07-27 12:07:33,088 INFO
> [RS_CLOSE_REGION-regionserver/worker008:16020-0]
> regionserver.DefaultStoreFlusher: Flushed memstore data size=77.13 KB at
> sequenceid=88678485 (bloomFilter=true),
> to=hdfs://dune/hbase/data/ris/ris-updates/625d2ac4331542df877e44fa06489ca1/.tmp/-/2bc2db2278054d6399fdf618fca0f260
> 2021-07-27 12:07:33,093 INFO
> [RS_CLOSE_REGION-regionserver/worker008:16020-0] regionserver.HStore: Added
> hdfs://dune/hbase/data/ris/ris-updates/625d2ac4331542df877e44fa06489ca1/-/2bc2db2278054d6399fdf618fca0f260,
> entries=600, sequenceid=88678485, filesize=21.4 K
> 2021-07-27 12:07:33,094 INFO
> [RS_CLOSE_REGION-regionserver/worker008:16020-0] regionserver.HRegion:
> Finished flush of dataSize ~77.13 KB/78981, heapSize ~122.02 KB/124952,
> currentSize=0 B/0 for 625d2ac4331542df877e44fa06489ca1 in 283ms,
> sequenceid=88678485, compaction requested=true
> 2021-07-27 12:07:33,105 INFO
> [RS_CLOSE_REGION-regionserver/worker008:16020-0] regionserver.HRegion: Closed
> ris:ris-updates,\x00\x03\x00\x00\x01z\xE6/M:\x04P\xF9\xD0j\x00\x00\x00\x01,1627382439537.625d2ac4331542df877e44fa06489ca1.
> 2021-07-27 12:07:33,106 INFO
> [RS_CLOSE_REGION-regionserver/worker008:16020-0]
> handler.UnassignRegionHandler: Closed 625d2ac4331542df877e44fa06489ca1
> 2021-07-27 12:07:35,413 WARN [StoreFileOpener---1] hfile.BlockCacheUtil:
> Caching an already cached block:
> 9bcfcba754cf4084817bb6aee7ce0492.625d2ac4331542df877e44fa06489ca1_420326799.
> This is harmless and can happen in rare cases (see HBASE-8547)
> {noformat}
> And on the master:
> {noformat}
> 2021-07-27 12:07:32,655 INFO [PEWorker-16]
> procedure.MasterProcedureScheduler: Took xlock for pid=118449,
> state=RUNNABLE:SPLIT_TABLE_REGION_PREPARE; SplitTableRegionProcedure
> table=ris:ris-updates, parent=625d2ac4331542df877e44fa06489ca1,
> daughterA=43206debd9f16952acb6632130b64e36,
> daughterB=d317ec8cb2eb18dbd3cf92cf4b5b85d9
> 2021-07-27 12:07:32,655 INFO [PEWorker-16]
> procedure.MasterProcedureScheduler: Took xlock for pid=118449,
> state=RUNNABLE:SPLIT_TABLE_REGION_PREPARE; SplitTableRegionProcedure
> table=ris:ris-updates, parent=625d2ac4331542df877e44fa06489ca1,
> daughterA=43206debd9f16952acb6632130b64e36,
> daughterB=d317ec8cb2eb18dbd3cf92cf4b5b85d9
> 2021-07-27 12:07:32,655 INFO [PEWorker-16]
> procedure.MasterProcedureScheduler: Took xlock for pid=118449,
> state=RUNNABLE:SPLIT_TABLE_REGION_PREPARE; SplitTableRegionProcedure
> table=ris:ris-updates, parent=625d2ac4331542df877e44fa06489ca1,
> daughterA=43206debd9f16952acb6632130b64e36,
> daughterB=d317ec8cb2eb18dbd3cf92cf4b5b85d9
> 2021-07-27 12:07:32,656 INFO [PEWorker-16] procedure2.ProcedureExecutor:
> Initialized subprocedures=[{pid=118450, ppid=118449,
> state=RUNNABLE:REGION_STATE_TRANSITION_CLOSE; TransitRegionStateProcedure
> table=ris:ris-updates, region=625d2ac4331542df877e44fa06489ca1, UNASSIGN}]
> 2021-07-27 12:07:32,656 INFO [PEWorker-16]
> procedure.MasterProcedureScheduler: Took xlock for pid=118450, ppid=118449,
> state=RUNNABLE:REGION_STATE_TRANSITION_CLOSE; TransitRegionStateProcedure
> table=ris:ris-updates, region=625d2ac4331542df877e44fa06489ca1, UNASSIGN
> 2021-07-27 12:07:32,657 INFO [PEWorker-16] assignment.RegionStateStore:
> pid=118450 updating hbase:meta row=625d2ac4331542df877e44fa06489ca1,
> regionState=CLOSING,
> regionLocation=worker008.dune.ripe.net,16020,1627053306686
> 2021-07-27 12:07:32,660 INFO [PEWorker-16] procedure2.ProcedureExecutor:
> Initialized subprocedures=[{pid=118451, ppid=118450, state=RUNNABLE;
> CloseRegionProcedure 625d2ac4331542df877e44fa06489ca1,
> server=worker008.dune.ripe.net,16020,1627053306686}]
> 2021-07-27 12:07:33,106 INFO [PEWorker-3] assignment.RegionStateStore:
> pid=118450 updating hbase:meta row=625d2ac4331542df877e44fa06489ca1,
> regionState=CLOSED
> 2021-07-27 12:07:33,108 INFO [PEWorker-3] procedure2.ProcedureExecutor:
> Finished subprocedure pid=118451, resume processing ppid=118450
> 2021-07-27 12:07:33,108 INFO [PEWorker-3] procedure2.ProcedureExecutor:
> Finished pid=118451, ppid=118450, state=SUCCESS; CloseRegionProcedure
> 625d2ac4331542df877e44fa06489ca1,
> server=worker008.dune.ripe.net,16020,1627053306686 in 447 msec
> 2021-07-27 12:07:33,109 INFO [PEWorker-7] procedure2.ProcedureExecutor:
> Finished subprocedure pid=118450, resume processing ppid=118449
> 2021-07-27 12:07:33,109 INFO [PEWorker-7] procedure2.ProcedureExecutor:
> Finished pid=118450, ppid=118449, state=SUCCESS; TransitRegionStateProcedure
> table=ris:ris-updates, region=625d2ac4331542df877e44fa06489ca1, UNASSIGN in
> 452 msec
> 2021-07-27 12:07:33,118 INFO [PEWorker-10]
> assignment.SplitTableRegionProcedure: pid=118449 splitting 5 storefiles,
> region=625d2ac4331542df877e44fa06489ca1, threads=5
> 2021-07-27 12:07:35,072 INFO [PEWorker-10] procedure2.ProcedureExecutor:
> Initialized subprocedures=[{pid=118452, ppid=118449,
> state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE;
> TransitRegionStateProcedure table=ris:ris-updates,
> region=43206debd9f16952acb6632130b64e36, ASSIGN}, {pid=118453, ppid=118449,
> state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE;
> TransitRegionStateProcedure table=ris:ris-updates,
> region=d317ec8cb2eb18dbd3cf92cf4b5b85d9, ASSIGN}]
> 2021-07-27 12:07:35,072 INFO [PEWorker-12]
> procedure.MasterProcedureScheduler: Took xlock for pid=118453, ppid=118449,
> state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE;
> TransitRegionStateProcedure table=ris:ris-updates,
> region=d317ec8cb2eb18dbd3cf92cf4b5b85d9, ASSIGN
> 2021-07-27 12:07:35,072 INFO [PEWorker-2]
> procedure.MasterProcedureScheduler: Took xlock for pid=118452, ppid=118449,
> state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE;
> TransitRegionStateProcedure table=ris:ris-updates,
> region=43206debd9f16952acb6632130b64e36, ASSIGN
> 2021-07-27 12:07:35,073 INFO [PEWorker-12]
> assignment.TransitRegionStateProcedure: Starting pid=118453, ppid=118449,
> state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE, locked=true;
> TransitRegionStateProcedure table=ris:ris-updates,
> region=d317ec8cb2eb18dbd3cf92cf4b5b85d9, ASSIGN; state=SPLITTING_NEW,
> location=worker008.dune.ripe.net,16020,1627053306686; forceNewPlan=false,
> retain=false
> 2021-07-27 12:07:35,073 INFO [PEWorker-2]
> assignment.TransitRegionStateProcedure: Starting pid=118452, ppid=118449,
> state=RUNNABLE:REGION_STATE_TRANSITION_GET_ASSIGN_CANDIDATE, locked=true;
> TransitRegionStateProcedure table=ris:ris-updates,
> region=43206debd9f16952acb6632130b64e36, ASSIGN; state=SPLITTING_NEW,
> location=worker008.dune.ripe.net,16020,1627053306686; forceNewPlan=false,
> retain=false
> 2021-07-27 12:07:35,223 INFO [master2:16000] balancer.BaseLoadBalancer:
> Reassigned 2 regions. 2 retained the pre-restart assignment.
> 2021-07-27 12:07:35,223 INFO [PEWorker-5] assignment.RegionStateStore:
> pid=118453 updating hbase:meta row=d317ec8cb2eb18dbd3cf92cf4b5b85d9,
> regionState=OPENING,
> regionLocation=worker008.dune.ripe.net,16020,1627053306686
> 2021-07-27 12:07:35,223 INFO [PEWorker-13] assignment.RegionStateStore:
> pid=118452 updating hbase:meta row=43206debd9f16952acb6632130b64e36,
> regionState=OPENING,
> regionLocation=worker008.dune.ripe.net,16020,1627053306686
> 2021-07-27 12:07:35,224 INFO [PEWorker-5] procedure2.ProcedureExecutor:
> Initialized subprocedures=[{pid=118454, ppid=118453, state=RUNNABLE;
> OpenRegionProcedure d317ec8cb2eb18dbd3cf92cf4b5b85d9,
> server=worker008.dune.ripe.net,16020,1627053306686}]
> 2021-07-27 12:07:35,224 INFO [PEWorker-13] procedure2.ProcedureExecutor:
> Initialized subprocedures=[{pid=118455, ppid=118452, state=RUNNABLE;
> OpenRegionProcedure 43206debd9f16952acb6632130b64e36,
> server=worker008.dune.ripe.net,16020,1627053306686}]
> 2021-07-27 12:07:35,421 INFO [PEWorker-14] assignment.RegionStateStore:
> pid=118452 updating hbase:meta row=43206debd9f16952acb6632130b64e36,
> regionState=OPEN, openSeqNum=88678489,
> regionLocation=worker008.dune.ripe.net,16020,1627053306686
> 2021-07-27 12:07:35,423 INFO [PEWorker-14] procedure2.ProcedureExecutor:
> Finished subprocedure pid=118455, resume processing ppid=118452
> 2021-07-27 12:07:35,423 INFO [PEWorker-14] procedure2.ProcedureExecutor:
> Finished pid=118455, ppid=118452, state=SUCCESS; OpenRegionProcedure
> 43206debd9f16952acb6632130b64e36,
> server=worker008.dune.ripe.net,16020,1627053306686 in 198 msec
> 2021-07-27 12:07:35,423 INFO [PEWorker-1] procedure2.ProcedureExecutor:
> Finished pid=118452, ppid=118449, state=SUCCESS; TransitRegionStateProcedure
> table=ris:ris-updates, region=43206debd9f16952acb6632130b64e36, ASSIGN in 351
> msec
> 2021-07-27 12:07:35,666 INFO [PEWorker-11] assignment.RegionStateStore:
> pid=118453 updating hbase:meta row=d317ec8cb2eb18dbd3cf92cf4b5b85d9,
> regionState=OPEN, openSeqNum=88678489,
> regionLocation=worker008.dune.ripe.net,16020,1627053306686
> 2021-07-27 12:07:35,668 INFO [PEWorker-11] procedure2.ProcedureExecutor:
> Finished subprocedure pid=118454, resume processing ppid=118453
> 2021-07-27 12:07:35,668 INFO [PEWorker-11] procedure2.ProcedureExecutor:
> Finished pid=118454, ppid=118453, state=SUCCESS; OpenRegionProcedure
> d317ec8cb2eb18dbd3cf92cf4b5b85d9,
> server=worker008.dune.ripe.net,16020,1627053306686 in 443 msec
> 2021-07-27 12:07:35,669 INFO [PEWorker-9] procedure2.ProcedureExecutor:
> Finished subprocedure pid=118453, resume processing ppid=118449
> 2021-07-27 12:07:35,669 INFO [PEWorker-9] procedure2.ProcedureExecutor:
> Finished pid=118453, ppid=118449, state=SUCCESS; TransitRegionStateProcedure
> table=ris:ris-updates, region=d317ec8cb2eb18dbd3cf92cf4b5b85d9, ASSIGN in 596
> msec
> 2021-07-27 12:07:35,669 INFO [PEWorker-15] procedure2.ProcedureExecutor:
> Finished pid=118449, state=SUCCESS; SplitTableRegionProcedure
> table=ris:ris-updates, parent=625d2ac4331542df877e44fa06489ca1,
> daughterA=43206debd9f16952acb6632130b64e36,
> daughterB=d317ec8cb2eb18dbd3cf92cf4b5b85d9 in 3.0160 sec
> 2021-07-27 12:09:05,065 INFO [master/master2:16000.Chore.1]
> balancer.BaseLoadBalancer: Start Generate Balance plan for cluster.
> 2021-07-27 12:10:58,943 INFO [master:store-WAL-Roller] wal.AbstractFSWAL:
> Rolled WAL
> /hbase/MasterData/WALs/master2.dune.ripe.net,16000,1627034030675/master2.dune.ripe.net%2C16000%2C1627034030675.master2.dune.ripe.net%2C16000%2C1627034030675.regiongroup-0.1627386958285
> with entries=60, filesize=30.97 KB; new WAL
> /hbase/MasterData/WALs/master2.dune.ripe.net,16000,1627034030675/master2.dune.ripe.net%2C16000%2C1627034030675.master2.dune.ripe.net%2C16000%2C1627034030675.regiongroup-0.1627387858617
> 2021-07-27 12:12:00,780 INFO [master:store-Flusher] regionserver.HRegion:
> Flushing 1595e783b53d99cd5eef43b6debb2682 1/1 column families, dataSize=26.98
> KB heapSize=32.55 KB
> 2021-07-27 12:12:01,416 INFO [master:store-Flusher]
> regionserver.DefaultStoreFlusher: Flushed memstore data size=26.98 KB at
> sequenceid=1068044 (bloomFilter=true),
> to=hdfs://dune/hbase/MasterData/data/master/store/1595e783b53d99cd5eef43b6debb2682/.tmp/proc/b47b99aa8f544dc6badd73f8450d6390
> 2021-07-27 12:12:01,418 INFO [master:store-Flusher]
> regionserver.StoreFileReader: Loaded Delete Family Bloom
> (CompoundBloomFilter) metadata for b47b99aa8f544dc6badd73f8450d6390
> 2021-07-27 12:12:01,421 INFO [master:store-Flusher]
> regionserver.StoreFileReader: Loaded Delete Family Bloom
> (CompoundBloomFilter) metadata for b47b99aa8f544dc6badd73f8450d6390
> 2021-07-27 12:12:01,421 INFO [master:store-Flusher] regionserver.HStore:
> Added
> hdfs://dune/hbase/MasterData/data/master/store/1595e783b53d99cd5eef43b6debb2682/proc/b47b99aa8f544dc6badd73f8450d6390,
> entries=8, sequenceid=1068044, filesize=5.8 K
> 2021-07-27 12:12:01,422 INFO [master:store-Flusher] regionserver.HRegion:
> Finished flush of dataSize ~26.98 KB/27626, heapSize ~32.53 KB/33312,
> currentSize=0 B/0 for 1595e783b53d99cd5eef43b6debb2682 in 642ms,
> sequenceid=1068044, compaction requested=true
> 2021-07-27 12:14:05,276 INFO [master/master2:16000.Chore.2]
> balancer.BaseLoadBalancer: Start Generate Balance plan for cluster.
> 2021-07-27 12:14:05,373 INFO [PEWorker-8]
> procedure.MasterProcedureScheduler: Took xlock for pid=118456,
> state=RUNNABLE:GC_REGION_PREPARE; GCRegionProcedure table=ris:ris-updates,
> region=625d2ac4331542df877e44fa06489ca1
> 2021-07-27 12:14:05,396 INFO [PEWorker-8] hbase.MetaTableAccessor: Deleted
> ris:ris-updates,\x00\x03\x00\x00\x01z\xE6/M:\x04P\xF9\xD0j\x00\x00\x00\x01,1627382439537.625d2ac4331542df877e44fa06489ca1.
> 2021-07-27 12:14:05,397 INFO [PEWorker-8] procedure2.ProcedureExecutor:
> Finished pid=118456, state=SUCCESS; GCRegionProcedure table=ris:ris-updates,
> region=625d2ac4331542df877e44fa06489ca1 in 25 msec
> {noformat}
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
