[
https://issues.apache.org/jira/browse/NIFI-16297?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Alexander Bij updated NIFI-16297:
---------------------------------
Description:
h2. Summary
NIFI-14014 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{}}},
{{{}connectionAnalyticsMetricsRegistry{}}}, and {{clusterMetricsRegistry.}}
Every metric in all three registries shares the exact same {{instance}} label
value, computed once per scrape.
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.
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.
was:
h2. Summary
NIFI-14014 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 (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.
> 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.10.0, 2.11.0
> Reporter: Alexander Bij
> Priority: Minor
>
> h2. Summary
> NIFI-14014 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{}}},
> {{{}connectionAnalyticsMetricsRegistry{}}}, and {{clusterMetricsRegistry.}}
> Every metric in all three registries shares the exact same {{instance}} label
> value, computed once per scrape.
> 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.
> 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.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
