[
https://issues.apache.org/jira/browse/HBASE-29802?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=18050350#comment-18050350
]
Duo Zhang commented on HBASE-29802:
-----------------------------------
This is one of the NPE log.
https://nightlies.apache.org/hbase/HBase-Flaky-Tests/master/24757/hbase-mapreduce/target/surefire-reports/org.apache.hadoop.hbase.snapshot.TestSecureExportSnapshot-output.txt
Skimmed the code, this.buf can only be null when we close the output, i.e,
shutdown the WAL or roll the WAL writer, but for the latter one, we have
fencing to make sure not write to a close writer. For the former case, there is
no WAL closing related logs, and since isAbort is false, we will do close
region first and then shutdown the WAL, so should not happen too.
Need to dig more in the future.
> NPE when shutting down mini cluster cause tests hang
> ----------------------------------------------------
>
> Key: HBASE-29802
> URL: https://issues.apache.org/jira/browse/HBASE-29802
> Project: HBase
> Issue Type: Bug
> Components: mapreduce, test
> Reporter: Duo Zhang
> Priority: Major
>
> Found this in a timeout run for TestSecureExportSnapshot
> {noformat}
> 2026-01-02T22:53:58,988 INFO [RegionServerTracker-0] master.HMaster(3360):
> ***** STOPPING master '59fad5da8b71,38027,1767393931926' *****
> 2026-01-02T22:53:58,988 INFO [RegionServerTracker-0] master.HMaster(3362):
> STOPPED: Cluster shutdown set; onlineServer=0
> 2026-01-02T22:53:58,988 INFO [M:0;59fad5da8b71:38027]
> hbase.HBaseServerBase(457): Close async cluster connection
> 2026-01-02T22:53:58,988 INFO [M:0;59fad5da8b71:38027]
> hbase.HBaseServerBase(440): Shutdown chores and chore service
> 2026-01-02T22:53:58,988 DEBUG [M:0;59fad5da8b71:38027]
> cleaner.LogCleaner(212): Cancelling LogCleaner
> 2026-01-02T22:53:58,989 DEBUG [M:0;59fad5da8b71:38027]
> cleaner.HFileCleaner(335): Stopping file delete threads
> 2026-01-02T22:53:58,989 WARN [OldWALsCleaner-0] cleaner.LogCleaner(200):
> Interrupted while cleaning old WALs, will try to clean it next round. Exiting.
> 2026-01-02T22:53:58,989 DEBUG
> [master/59fad5da8b71:0:becomeActiveMaster-HFileCleaner.large.0-1767393935168]
> cleaner.HFileCleaner(306): Exit
> Thread[master/59fad5da8b71:0:becomeActiveMaster-HFileCleaner.large.0-1767393935168,5,FailOnTimeoutGroup]
> 2026-01-02T22:53:58,989 DEBUG
> [master/59fad5da8b71:0:becomeActiveMaster-HFileCleaner.small.0-1767393935174]
> cleaner.HFileCleaner(306): Exit
> Thread[master/59fad5da8b71:0:becomeActiveMaster-HFileCleaner.small.0-1767393935174,5,FailOnTimeoutGroup]
> 2026-01-02T22:53:58,989 INFO [M:0;59fad5da8b71:38027]
> hbase.ChoreService(370): Chore service for: master/59fad5da8b71:0 had
> [ScheduledChore name=FlushedSequenceIdFlusher, period=10800000,
> unit=MILLISECONDS] on shutdown
> 2026-01-02T22:53:58,989 INFO [M:0;59fad5da8b71:38027]
> hbase.HBaseServerBase(450): Shutdown executor service
> 2026-01-02T22:53:58,989 DEBUG [M:0;59fad5da8b71:38027] master.HMaster(1813):
> Stopping service threads
> 2026-01-02T22:53:58,989 INFO [M:0;59fad5da8b71:38027]
> procedure2.RemoteProcedureDispatcher(119): Stopping procedure remote
> dispatcher
> 2026-01-02T22:53:58,989 INFO [M:0;59fad5da8b71:38027]
> procedure2.ProcedureExecutor(723): Stopping
> 2026-01-02T22:53:58,990 INFO [M:0;59fad5da8b71:38027]
> region.RegionProcedureStore(110): Stopping the Region Procedure Store,
> isAbort=false
> 2026-01-02T22:53:58,991 DEBUG [Time-limited test-EventThread]
> zookeeper.ZKWatcher(609): master:38027-0x100734ba5eb0000,
> quorum=127.0.0.1:59100, baseZNode=/hbase Received ZooKeeper Event,
> type=NodeDeleted, state=SyncConnected, path=/hbase/master
> 2026-01-02T22:53:58,992 DEBUG [Time-limited test-EventThread]
> zookeeper.ZKWatcher(609): master:38027-0x100734ba5eb0000,
> quorum=127.0.0.1:59100, baseZNode=/hbase Received ZooKeeper Event,
> type=NodeChildrenChanged, state=SyncConnected, path=/hbase
> 2026-01-02T22:53:58,992 DEBUG [M:0;59fad5da8b71:38027] zookeeper.ZKUtil(347):
> master:38027-0x100734ba5eb0000, quorum=127.0.0.1:59100, baseZNode=/hbase
> Unable to get data of znode /hbase/master because node does not exist (not an
> error)
> 2026-01-02T22:53:58,992 WARN [M:0;59fad5da8b71:38027]
> master.ActiveMasterManager(344): Failed get of master address:
> java.io.IOException: Can't get master address from ZooKeeper; znode data ==
> null
> 2026-01-02T22:53:58,993 INFO [M:0;59fad5da8b71:38027]
> master.ServerManager(1148): Writing .lastflushedseqids file at:
> hdfs://localhost:44733/user/jenkins/test-data/eb9fcf01-d40e-546d-7f81-2198b3d62cff/.lastflushedseqids
> 2026-01-02T22:53:58,994 DEBUG [normalizer-worker-0]
> normalizer.RegionNormalizerWorker(193): interrupt detected. terminating.
> 2026-01-02T22:53:59,019 INFO [Block report processor]
> blockmanagement.BlockManager(3777): BLOCK* addStoredBlock: 127.0.0.1:37189 is
> added to blk_1073742422_1598 (size=307)
> 2026-01-02T22:53:59,019 INFO [Block report processor]
> blockmanagement.BlockManager(3777): BLOCK* addStoredBlock: 127.0.0.1:38631 is
> added to blk_1073742422_1598 (size=307)
> 2026-01-02T22:53:59,020 INFO [Block report processor]
> blockmanagement.BlockManager(3777): BLOCK* addStoredBlock: 127.0.0.1:40115 is
> added to blk_1073742422_1598 (size=307)
> 2026-01-02T22:53:59,020 INFO [M:0;59fad5da8b71:38027]
> assignment.AssignmentManager(409): Stopping assignment manager
> 2026-01-02T22:53:59,021 INFO [M:0;59fad5da8b71:38027]
> region.MasterRegion(264): Closing local region {ENCODED =>
> 1595e783b53d99cd5eef43b6debb2682, NAME =>
> 'master:store,,1.1595e783b53d99cd5eef43b6debb2682.', STARTKEY => '', ENDKEY
> => ''}, isAbort=false
> 2026-01-02T22:53:59,021 DEBUG [M:0;59fad5da8b71:38027]
> regionserver.HRegion(1725): Closing 1595e783b53d99cd5eef43b6debb2682,
> disabling compactions & flushes
> 2026-01-02T22:53:59,042 INFO [M:0;59fad5da8b71:38027]
> regionserver.HRegion(1758): Closing region
> master:store,,1.1595e783b53d99cd5eef43b6debb2682.
> 2026-01-02T22:53:59,042 DEBUG [M:0;59fad5da8b71:38027]
> regionserver.HRegion(1779): Time limited wait for close lock on
> master:store,,1.1595e783b53d99cd5eef43b6debb2682.
> 2026-01-02T22:53:59,042 DEBUG [M:0;59fad5da8b71:38027]
> regionserver.HRegion(1846): Acquired close lock on
> master:store,,1.1595e783b53d99cd5eef43b6debb2682. after waiting 0 ms
> 2026-01-02T22:53:59,043 DEBUG [M:0;59fad5da8b71:38027]
> regionserver.HRegion(1856): Updates disabled for region
> master:store,,1.1595e783b53d99cd5eef43b6debb2682.
> 2026-01-02T22:53:59,043 INFO [M:0;59fad5da8b71:38027]
> regionserver.HRegion(2969): Flushing 1595e783b53d99cd5eef43b6debb2682 4/4
> column families, dataSize=1013.53 KB heapSize=1.19 MB
> 2026-01-02T22:53:59,043 ERROR
> [AsyncFSWAL-0-hdfs://localhost:44733/user/jenkins/test-data/eb9fcf01-d40e-546d-7f81-2198b3d62cff/MasterData-prefix:59fad5da8b71,38027,1767393931926]
> server.NIOServerCnxnFactory(85): Thread
> Thread[AsyncFSWAL-0-hdfs://localhost:44733/user/jenkins/test-data/eb9fcf01-d40e-546d-7f81-2198b3d62cff/MasterData-prefix:59fad5da8b71,38027,1767393931926,5,FailOnTimeoutGroup]
> died
> java.lang.NullPointerException: Cannot invoke
> "org.apache.hbase.thirdparty.io.netty.buffer.ByteBuf.readableBytes()" because
> "this.buf" is null
> at
> org.apache.hadoop.hbase.io.asyncfs.FanOutOneBlockAsyncDFSOutput.buffered(FanOutOneBlockAsyncDFSOutput.java:414)
> at
> org.apache.hadoop.hbase.regionserver.wal.AsyncProtobufLogWriter.append(AsyncProtobufLogWriter.java:134)
> at
> org.apache.hadoop.hbase.regionserver.wal.AsyncFSWAL.doAppend(AsyncFSWAL.java:181)
> at
> org.apache.hadoop.hbase.regionserver.wal.AsyncFSWAL.doAppend(AsyncFSWAL.java:100)
> at
> org.apache.hadoop.hbase.regionserver.wal.AbstractFSWAL.appendEntry(AbstractFSWAL.java:1333)
> at
> org.apache.hadoop.hbase.regionserver.wal.AbstractFSWAL.appendAndSync(AbstractFSWAL.java:1724)
> at
> org.apache.hadoop.hbase.regionserver.wal.AbstractFSWAL.consume(AbstractFSWAL.java:1832)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
> at
> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
> at java.base/java.lang.Thread.run(Thread.java:840)
> {noformat}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
