[
https://issues.apache.org/jira/browse/HBASE-30346?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
ASF GitHub Bot updated HBASE-30346:
-----------------------------------
Labels: pull-request-available (was: )
> NPE in AbstractFSWAL WAL-roll debug logging aborts RegionServer when
> DFSOutputStream#getPipeline() legitimately returns null
> ----------------------------------------------------------------------------------------------------------------------------
>
> Key: HBASE-30346
> URL: https://issues.apache.org/jira/browse/HBASE-30346
> Project: HBase
> Issue Type: Bug
> Components: regionserver, wal
> Affects Versions: 3.0.0, 4.0.0-alpha-1, 2.6.7
> Reporter: Aman Poonia
> Assignee: Aman Poonia
> Priority: Major
> Labels: pull-request-available
>
> *Symptom*
> RegionServers abort during WAL log rolling with:
> {code:java}
> java.lang.NullPointerException: Cannot read the array length because
> "array" is null
> at java.base/java.util.Arrays.stream(Arrays.java:5533)
> at
> org.apache.hadoop.hbase.regionserver.wal.AbstractFSWAL.rollWriterInternal(AbstractFSWAL.java:926)
> at
> org.apache.hadoop.hbase.regionserver.wal.AbstractFSWAL.rollWriter(AbstractFSWAL.java:950)
> at
> org.apache.hadoop.hbase.wal.AbstractWALRoller$RollController.rollWal(AbstractWALRoller.java:305)
> at
> org.apache.hadoop.hbase.wal.AbstractWALRoller.run(AbstractWALRoller.java:211)
> {code}
> followed by {{AbstractWALRoller}} catching the exception, logging {{"Log
> rolling failed"}}, and calling {{abort(...)}} on the RegionServer — a full RS
> self-abort, WAL
> splitting, and reassignment of every region the RS was carrying. Observed 9
> times over a 68.8h window on a production cluster carrying 300–450+ regions
> per affected RS,
> driving the two longest region-in-transition episodes in that window.
> *Root cause*
> {{AbstractFSWAL.rollWriterInternal(boolean force)}} logs the newly-rolled
> WAL's DataNode pipeline for debugging, _after_ the roll has already succeeded
> ({{replaceWriter}} has
> already installed the new writer):
> {code:java}
> if (LOG.isDebugEnabled()) {
> LOG.debug("Create new " + implClassName + " writer with pipeline: "
> + FanOutOneBlockAsyncDFSOutputHelper
>
> .getDataNodeInfo(Arrays.stream(getPipeline()).collect(Collectors.toList())));
> }
> {code}
> {{getPipeline()}} on the sync WAL path ({{FSHLog#getPipeline()}}) delegates
> directly to Hadoop's {{DFSOutputStream#getPipeline()}}, which can
> legitimately return {{null}}:
> {code:java}
> // returns the list of targets, if any, that is being currently used.
> @VisibleForTesting
> public synchronized DatanodeInfo[] getPipeline() {
> if (getStreamer().streamerClosed()) {
> return null;
> }
> DatanodeInfo[] currentNodes = getStreamer().getNodes();
> if (currentNodes == null) {
> return null;
> }
> ...
> }
> {code}
> This is a documented, expected condition ("if any"), not an error: the
> underlying {{DataStreamer}} has no current pipeline before the first block is
> allocated, between blocks
> ({{DataStreamer#endBlock()}} resets {{nodes}} to {{null}}), or on a
> transient failed block-create retry. There is no non-null alternative
> accessor on
> {{DFSOutputStream}}/{{DataStreamer}}.
> {{Arrays.stream(null)}} throws NPE (unlike {{Arrays.toString(null)}}, which
> returns the string {{"null"}}). Because the debug-log statement sits inside a
> try block explicitly
> commented "Any exception from here on is catastrophic, non-recoverable, so
> we currently abort," the NPE is treated as a genuine roll failure and
> propagates to
> {{AbstractWALRoller}}, which aborts the RegionServer — even though the roll
> itself had already succeeded and only the diagnostic log line failed to
> format.
> *Regression*
> Introduced by HBASE-28775 ("Change the output of DatanodeInfo in the log to
> the hostname of the datanode", commit 53944cfc930a), which replaced the
> previously null-tolerant
> {{Arrays.toString(getPipeline())}} with the null-intolerant
> {{Arrays.stream(getPipeline()).collect(Collectors.toList())}} fed into
> {{FanOutOneBlockAsyncDFSOutputHelper#getDataNodeInfo}}. Confirmed present,
> unfixed, on {{master}} and {{branch-3}}.
> *Scope / why the fix is safe*
> Audited every consumer of {{WAL#getPipeline()}}:
> * All logging call sites in {{AbstractFSWAL}}/{{FSHLog}} except the one
> above already use {{Arrays.toString(getPipeline())}}, which is null-tolerant.
> * The only functional (non-logging) consumer,
> {{AsyncFSWAL#getLogReplication()}}, already calls through
> {{AsyncFSWAL#getPipeline()}}, which already null-guards its output
> ({{output != null ? output.getPipeline() : new DatanodeInfo[0]}}).
> * {{FSHLog#getPipeline()}} is the only implementation that still propagates
> Hadoop's null, and it is the only call site ({{AbstractFSWAL.java:926}}) that
> is null-intolerant.
> It is a pure logging feed with no functional consumer on the sync path.
> *Note:* the abort-on-roll-failure design itself ({{AbstractWALRoller}},
> HBASE-1132) is correct and intentionally not touched by this fix — a genuine
> roll failure should still
> abort the RS so its WALs can be split and recovered.
> *Proposed fix*
> Normalize {{FSHLog#getPipeline()}} to never return null, matching the
> contract {{AsyncFSWAL}} already honors:
> {code:java}
> DatanodeInfo[] getPipeline() {
> if (this.hdfs_out != null) {
> if (this.hdfs_out.getWrappedStream() instanceof DFSOutputStream) {
> DatanodeInfo[] pipeline =
> ((DFSOutputStream) this.hdfs_out.getWrappedStream()).getPipeline();
> if (pipeline != null) {
> return pipeline;
> }
> }
> }
> return new DatanodeInfo[0];
> }
> {code}
> This fixes the defect at its source for every current and future caller,
> rather than patching only the one call site that happens to be
> null-intolerant today.
> *Test plan*
> Added
> {{TestFSHLog#testGetPipelineDoesNotReturnNullWhenUnderlyingStreamerHasNone}}:
> mocks {{DFSOutputStream#getPipeline()}} to return null, injects it as
> {{FSHLog#hdfs_out}},
> and asserts {{FSHLog#getPipeline()}} returns a non-null, empty array
> instead of propagating the null. Verified this test fails against the pre-fix
> code with
> {{AssertionError: getPipeline() must never return null}} and passes with
> the fix.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
