Alexander Bij created NIFI-16297:
------------------------------------
Summary: jvm/cluster/connection-analytics Prometheus metrics still
permanently retain a stale pre-cluster-join instance ID series
Key: NIFI-16297
URL: https://issues.apache.org/jira/browse/NIFI-16297
Project: Apache NiFi
Issue Type: Bug
Components: Core Framework
Affects Versions: 2.11.0, 2.10.0
Reporter: Alexander Bij
h2. Summary
NIFI-14014 ("Metrics endpoints may return data for 'dead' instance IDs", fixed
in 2.1.0) described this exact problem: a node's Prometheus \{{instance}} label
starts as a temporary, per-process value and later switches to the node's
persisted cluster UUID once it joins the cluster; any scrape that lands before
that switch leaves a permanent, frozen series behind under the old value.
NIFI-14014's fix (prefer \{{node.getId()}} over
\{{controllerFacade.getInstanceId()}} once available) only changed *which*
identifier is used *after* the transition -- it did not stop metrics from being
recorded under the temporary identifier *before* the transition, and it did not
address the actual root cause: the registries these metrics live in are
long-lived singletons that are never cleared. As a result, the symptom
NIFI-14014 was meant to fix can still occur today.
This affects \{{jvmMetricsRegistry}} (\{{nifi_jvm_*}} metrics),
\{{connectionAnalyticsMetricsRegistry}}, and \{{clusterMetricsRegistry}}
(\{{cluster_*}} metrics) -- every metric in all three registries shares the
exact same \{{instance}} label value, computed once per scrape.
*Simple mental model:* \{{populateFlowMetrics()}} only runs on-demand, in
direct response to an HTTP \{{GET}} on the metrics endpoint -- it is not a
background/scheduled job. So the bug requires a race: it only manifests if
something actually *calls* \{{GET /nifi-api/flow/metrics/prometheus}} during
the narrow window between process start and the node finishing its cluster-join
handshake. If no request lands in that window, the registries stay empty until
the first scrape, which by then already observes the final, stable node UUID,
and no stale series is ever created. If a request *does* land in that window,
whatever \{{instance}} value it observes is written into the singleton registry
and never removed. A typical Prometheus scrape interval (15-60s) makes this a
fairly low-probability race, but any tighter polling against this same endpoint
right at container/process start -- e.g. a Kubernetes readiness or liveness
probe pointed at it -- makes hitting this window far more likely.
h2. Root cause
{code:java}
// StandardNiFiServiceFacade.java, inside populateFlowMetrics()
final NodeIdentifier node = controllerFacade.getNodeId();
final String instId = StringUtils.isEmpty(controllerFacade.getInstanceId()) ?
"" : controllerFacade.getInstanceId();
final String instanceId = node == null ? instId : node.getId();
{code}
* Before a clustered node completes its first connection handshake,
\{{controllerFacade.getNodeId()}} is \{{null}}, so \{{instanceId}} falls back
to \{{controllerFacade.getInstanceId()}} (i.e. \{{FlowController.instanceId}}
-- effectively a standalone-mode value, itself sourced from whichever node is
currently cluster coordinator).
* Once the handshake completes, \{{getNodeId()}} becomes non-null and
\{{instanceId}} permanently switches to the node's *persisted* cluster UUID
(\{{node.getId()}}), which is stable for the rest of that process's life
(stored via local \{{StateManager}} state, unaffected by later
disconnects/reconnects/coordinator elections).
* This one-time transition happens on every node start in a clustered
deployment. Any scrape landing in the (typically brief, but non-zero) window
before the transition permanently registers \{{instance=<temporary-id>}} in
\{{jvmMetricsRegistry}}, \{{connectionAnalyticsMetricsRegistry}}, and
\{{clusterMetricsRegistry}} -- and because none of these three registries are
ever cleared or recreated, that series is never removed. It sits frozen at
whatever value it had during that startup window, returned on every subsequent
scrape for the life of the process, alongside the correct, continuously-updated
series under the real node UUID.
Unlike [connected_nodes churn on cluster_connected_node_count|NIFI-16296]
(fixed by removing a churning label), this leak is bounded to (at most) one
stale series per node process restart, not continuous flapping during
steady-state operation -- but it is real and reproducible on every clustered
node startup, and directly reopens the exact symptom NIFI-14014 was filed to
close.
h2. Why NIFI-14014 didn't fully fix this
NIFI-14014's own description matches this symptom precisely: "If metrics
endpoints are queried before the instance ID transitions, various Gauges (JVM,
cluster, and storage metrics) register with the initial instance identifier.
When the metrics endpoints are subsequently called after the clustered instance
ID is set, the system returns data for both the outdated instance ID and the
new one, creating duplicate metric streams." The fix (PR #9528) only reordered
which identifier source is *preferred*; it never addressed why a stale
identifier's data persists forever once recorded -- i.e. it didn't touch the
singleton/never-cleared registry lifecycle, which is the actual root cause (the
same root cause behind NIFI-8272, NIFI-11899, and NIFI-16296).
h2. Steps to reproduce
# Start (or restart) a NiFi node configured to join a cluster.
# As early as possible during that node's startup -- before it has completed
its initial connect handshake -- scrape \{{GET
/nifi-api/flow/metrics/prometheus}} on that node (a tight polling loop from
just after process start works; a Kubernetes readiness/liveness probe pointed
at this endpoint reproduces this reliably in practice). Observe
\{{nifi_jvm_heap_used}} (or any \{{nifi_jvm_*}}/\{{cluster_*}} metric) reported
under some \{{instance=<uuid-A>}}.
# Wait for the node to finish joining the cluster, then scrape again. Observe
the same metrics now reported under a *different* \{{instance=<uuid-B>}} (the
persisted cluster node UUID).
# Continue scraping indefinitely -- observe that \{{instance=<uuid-A>}}'s
series for every metric in \{{jvmMetricsRegistry}},
\{{connectionAnalyticsMetricsRegistry}}, and \{{clusterMetricsRegistry}}
remains present, frozen at its last-recorded values, for the remaining lifetime
of the process.
h2. Suggested fix
Extend the pattern already established by NIFI-11899 to the three registries
that were left out of it: make \{{jvmMetricsRegistry}},
\{{connectionAnalyticsMetricsRegistry}}, and \{{clusterMetricsRegistry}} fresh,
locally-scoped instances created inside \{{populateFlowMetrics()}} on every
invocation, exactly like \{{nifiMetricsRegistry}} and
\{{bulletinMetricsRegistry}} already are, rather than permanent instance
fields. This is a more general and durable fix than special-casing the startup
window (e.g. suppressing metrics until \{{instanceId}} settles), since it also
protects against any other future source of \{{instance}} (or other label)
churn in these registries, not just this one known transition.
h2. Impact
Any dashboard or alert built on \{{nifi_jvm_*}}, \{{cluster_*}}, or
connection-analytics metrics that aggregates or filters by \{{instance}} can
pick up a permanent, frozen "ghost" series per node restart in a clustered
deployment, in addition to the correct live series -- directly re-opening the
"dead instance ID" symptom NIFI-14014 was filed to eliminate.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
