[
https://issues.apache.org/jira/browse/NIFI-13885?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17946087#comment-17946087
]
Ravikumar M edited comment on NIFI-13885 at 4/21/25 10:28 AM:
--------------------------------------------------------------
We got the same issue in 2.0.0-M2, this version is already using [JetBrains
Xodus|https://github.com/JetBrains/xodus] , we didn't see any delay or failure
for API request processing in the cluster here. But we are still hitting with
this problem twice now where it impacted us. [~joewitt] Is there any solution
for this?
{code:java}
2025-04-15 13:45:42,352 INFO [Clustering Tasks Thread-3]
o.a.n.c.c.ClusterProtocolHeartbeater Heartbeat created at
2025-04-15T12:45:42.259Z and sent to
nifi-1.nifi-hs.pipercx.svc.cluster.local:1025 at
2025-04-15T12:45:42.352338719Z; determining Cluster Coordinator took 4 millis;
DNS lookup for coordinator took 0 millis; connecting to coordinator took 0
millis; sending heartbeat took 45 millis; receiving first byte from response
took 43 millis; receiving full response took 44 millis; total time was 93
millis 2025-04-15 13:45:44,495 WARN [Heartbeat Monitor Thread-1]
o.a.n.c.c.node.NodeClusterCoordinator Requesting that
nifi-0.nifi-hs.pipercx.svc.cluster.local:8443 reconnect to the cluster due to:
Node has a Revision Update Count of 213336 but local value is only 213335. Node
appears not to have the appropriate set of Component Revisions 2025-04-15
13:45:44,495 INFO [Heartbeat Monitor Thread-1]
o.a.n.c.c.node.NodeClusterCoordinator Event Reported for
nifi-0.nifi-hs.pipercx.svc.cluster.local:8443 -- Requesting that node connect
to cluster 2025-04-15 13:45:44,506 INFO [Heartbeat Monitor Thread-1]
o.a.n.c.c.node.NodeClusterCoordinator Status of
nifi-0.nifi-hs.pipercx.svc.cluster.local:8443 changed from
NodeConnectionStatus[nodeId=nifi-0.nifi-hs.pipercx.svc.cluster.local:8443,
state=CONNECTED, updateId=4347] to
NodeConnectionStatus[nodeId=nifi-0.nifi-hs.pipercx.svc.cluster.local:8443,
state=CONNECTING, updateId=4351] 2025-04-15 13:45:44,565 WARN [Heartbeat
Monitor Thread-1] o.a.n.c.c.node.NodeClusterCoordinator Requesting that
nifi-2.nifi-hs.pipercx.svc.cluster.local:8443 reconnect to the cluster due to:
Node has a Revision Update Count of 213336 but local value is only 213335. Node
appears not to have the appropriate set of Component Revisions 2025-04-15
13:45:44,565 INFO [Heartbeat Monitor Thread-1]
o.a.n.c.c.node.NodeClusterCoordinator Event Reported for
nifi-2.nifi-hs.pipercx.svc.cluster.local:8443 -- Requesting that node connect
to cluster 2025-04-15 13:45:44,571 INFO [Heartbeat Monitor Thread-1]
o.a.n.c.c.node.NodeClusterCoordinator Status of
nifi-2.nifi-hs.pipercx.svc.cluster.local:8443 changed from
NodeConnectionStatus[nodeId=nifi-2.nifi-hs.pipercx.svc.cluster.local:8443,
state=CONNECTED, updateId=4350] to
NodeConnectionStatus[nodeId=nifi-2.nifi-hs.pipercx.svc.cluster.local:8443,
state=CONNECTING, updateId=4352] 2025-04-15 13:45:44,650 INFO [Heartbeat
Monitor Thread-1] o.a.n.c.c.h.AbstractHeartbeatMonitor Finished processing 3
heartbeats in 155 millis{code}
Coordinator Logs
|{{{}nifi{}}}{{{}@nifi{}}}{{{}--{}}}{{{}1{}}}{{{}:/opt/nifi/nifi-current$ cat
logs/nifi-app.log \| grep -i {}}}{{"2025-04-15 13:45:44,495"}} {{-color -B40
-A10}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}15{}}}{{{},{}}}{{{}549{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}100{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
b2388556-ad48-48a3-aeac-005f27e8fd68 (type=HEARTBEAT, length={}}}{{{}4463{}}}
{{{}bytes) from
nifi{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{95}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}16{}}}{{{},{}}}{{{}920{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}99{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
2a29e615{}}}{{{}8155{}}}{{{}-4b32-a013-b3868a78db26 (type=HEARTBEAT,
length=-{}}}{{{}4467{}}} {{{}bytes) from
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{96}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}16{}}}{{{},{}}}{{{}921{}}} {{INFO
[Clustering Tasks Thread-{}}}\\{{{}3{}}}\\{{{}]
o.a.n.c.c.ClusterProtocolHeartbeater Heartbeat created at
}}{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}16{}}}{{{}.818Z
and sent to
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}1025{}}} {{at
}}{{{}2025{}}}{{{}{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}16{}}}{{{}.921728227Z;
determining Cluster Coordinator took {}}}{{4}} {{millis; DNS lookup }}{{for}}
{{coordinator took }}{{0}} {{millis; connecting to coordinator took }}{{1}}
{{millis; sending heartbeat took }}{{52}} {{millis; receiving first }}{{byte}}
{{from response took }}{{45}} {{millis; receiving full response took }}{{45}}
{{millis; total time was }}{{102}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}19{}}}{{{},{}}}{{{}492{}}} {{INFO
[Heartbeat Monitor Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.c.c.h.AbstractHeartbeatMonitor Finished processing }}{{3}} {{heartbeats
in }}{{6720}} {{nanos}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}20{}}}{{{},{}}}{{{}170{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}97{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
e55f44ab-3b42-447b-8b32-4a66fa751461 (type=HEARTBEAT, length={}}}{{{}4464{}}}
{{{}bytes) from
nifi{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{98}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}20{}}}{{{},{}}}{{{}619{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}3{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
1a300ccf-51e7-4ab3-a9cf-155f42dc8065 (type=HEARTBEAT, length={}}}{{{}4463{}}}
{{{}bytes) from
nifi{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{56}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}22{}}}{{{},{}}}{{{}023{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}2{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
3f782d5b-f28b-45b2-ad4f-ef1bb8170af9 (type=HEARTBEAT, length={}}}{{{}4467{}}}
{{{}bytes) from
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{91}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}22{}}}{{{},{}}}{{{}024{}}} {{INFO
[Clustering Tasks Thread-{}}}\\{{{}3{}}}\\{{{}]
o.a.n.c.c.ClusterProtocolHeartbeater Heartbeat created at
}}{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}21{}}}{{{}.928Z
and sent to
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}1025{}}} {{at
}}{{{}2025{}}}{{{}{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}22{}}}{{{}.024649024Z;
determining Cluster Coordinator took {}}}{{4}} {{millis; DNS lookup }}{{for}}
{{coordinator took }}{{0}} {{millis; connecting to coordinator took }}{{0}}
{{millis; sending heartbeat took }}{{48}} {{millis; receiving first }}{{byte}}
{{from response took }}{{44}} {{millis; receiving full response took }}{{44}}
{{millis; total time was }}{{96}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}24{}}}{{{},{}}}{{{}383{}}} {{INFO
[NiFi Web Server-{}}}\\{{{}394987{}}}\\{{{}] o.a.n.c.s.StandardProcessScheduler
Stopping AttributesToJSON[id=36af30fe-514a-1b3c-bc34-7060ecebe453]}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}24{}}}{{{},{}}}{{{}383{}}} {{INFO
[NiFi Web Server-{}}}\\{{{}394987{}}}\\{{{}]
o.a.n.controller.StandardProcessorNode Stopping processor:
AttributesToJSON[id=36af30fe-514a-1b3c-bc34-7060ecebe453]}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}24{}}}{{{},{}}}{{{}401{}}} {{INFO
[Timer-Driven Process Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.c.s.TimerDrivenSchedulingAgent Stopped scheduling
AttributesToJSON[id=36af30fe-514a-1b3c-bc34-7060ecebe453] to run}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}24{}}}{{{},{}}}{{{}401{}}} {{INFO
[Timer-Driven Process Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.controller.StandardProcessorNode
AttributesToJSON[id=36af30fe-514a-1b3c-bc34-7060ecebe453] has completely
stopped. Completing any associatedFutures.}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}24{}}}{{{},{}}}{{{}493{}}} {{INFO
[Heartbeat Monitor Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.c.c.h.AbstractHeartbeatMonitor Finished processing }}{{3}} {{heartbeats
in }}{{3939}} {{nanos}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}25{}}}{{{},{}}}{{{}237{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
76a02ca9{}}}{{{}8080{}}}{{{}--{}}}{{{}4984{}}}{{{}-97d2-871918100aab
(type=HEARTBEAT, length={}}}{{{}4464{}}} {{{}bytes) from
nifi{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{56}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}25{}}}{{{},{}}}{{{}581{}}} {{{}INFO
[Flow Service Tasks Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.p.FlowConfigurationArchiveManager Removing old archive file
./data/archive/20250415T130804+0100_flow.json.gz to reduce storage usage.
currentSize={}}}{{{}517922067{}}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}25{}}}{{{},{}}}{{{}587{}}} {{{}INFO
[Flow Service Tasks Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.nifi.controller.StandardFlowService Saved flow controller
org.apache.nifi.controller.FlowController{}}}{{{}@303ac720{}}} {{// Another
save pending = false}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}25{}}}{{{},{}}}{{{}681{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}7{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
0be1922d-509e-4e74-8af9-cf55d0811e1c (type=HEARTBEAT, length={}}}{{{}4463{}}}
{{{}bytes) from
nifi{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{50}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}27{}}}{{{},{}}}{{{}128{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}5{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
ad1693f3-ca19-4b12-86bc-703eca8bd35a (type=HEARTBEAT, length={}}}{{{}4467{}}}
{{{}bytes) from
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{92}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}27{}}}{{{},{}}}{{{}128{}}} {{INFO
[Clustering Tasks Thread-{}}}\\{{{}3{}}}\\{{{}]
o.a.n.c.c.ClusterProtocolHeartbeater Heartbeat created at
}}{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}27{}}}{{{}.030Z
and sent to
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}1025{}}} {{at
}}{{{}2025{}}}{{{}{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}27{}}}{{{}.128952987Z;
determining Cluster Coordinator took {}}}{{4}} {{millis; DNS lookup }}{{for}}
{{coordinator took }}{{0}} {{millis; connecting to coordinator took }}{{0}}
{{millis; sending heartbeat took }}{{50}} {{millis; receiving first }}{{byte}}
{{from response took }}{{44}} {{millis; receiving full response took }}{{44}}
{{millis; total time was }}{{98}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}29{}}}{{{},{}}}{{{}493{}}} {{INFO
[Heartbeat Monitor Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.c.c.h.AbstractHeartbeatMonitor Finished processing }}{{3}} {{heartbeats
in }}{{3050}} {{nanos}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}30{}}}{{{},{}}}{{{}300{}}} {{INFO
[Checkpoint FlowFile Repository] o.a.n.c.r.WriteAheadFlowFileRepository
Initiating checkpoint of FlowFile Repository}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}30{}}}{{{},{}}}{{{}302{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}4{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
e376e72a{}}}{{{}4161{}}}{{{}-445b-{}}}{{{}8419{}}}{{{}-fcb747045743
(type=HEARTBEAT, length=-{}}}{{{}4464{}}} {{{}bytes) from
nifi{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{54}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}30{}}}{{{},{}}}{{{}785{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}6{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
1f26252e{}}}{{{}1817{}}}{{{}-4c36-86a7-f39cbbdefdd4 (type=HEARTBEAT,
length=-{}}}{{{}4463{}}} {{{}bytes) from
nifi{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{92}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}31{}}}{{{},{}}}{{{}095{}}} {{INFO
[Checkpoint FlowFile Repository] o.a.n.wali.SequentialAccessWriteAheadLog
Checkpointed Write-Ahead Log with }}{{99466}} {{Records and }}{{445}} {{Swap
Files in }}{{795}} {{milliseconds (Stop-the-world time = }}{{12}}
{{milliseconds), max Transaction ID }}{{326649836}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}31{}}}{{{},{}}}{{{}095{}}} {{INFO
[Checkpoint FlowFile Repository] o.a.n.c.r.WriteAheadFlowFileRepository
Successfully checkpointed FlowFile Repository with }}{{99466}} {{records in
}}{{795}} {{milliseconds}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}31{}}}{{{},{}}}{{{}347{}}} {{INFO
[FileSystemRepository Workers Thread-{}}}\\{{{}3{}}}\\{{{}]
o.a.n.c.repository.FileSystemRepository Successfully archived }}{{1}}
{{Resource Claims }}{{for}} {{Container }}{{default}} {{in }}{{0}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}32{}}}{{{},{}}}{{{}189{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}8{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
a87f2b35-48d6-435f-bb55-af12d4024655 (type=HEARTBEAT, length={}}}{{{}4467{}}}
{{{}bytes) from
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{49}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}32{}}}{{{},{}}}{{{}189{}}} {{INFO
[Clustering Tasks Thread-{}}}\\{{{}3{}}}\\{{{}]
o.a.n.c.c.ClusterProtocolHeartbeater Heartbeat created at
}}{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}32{}}}{{{}.135Z
and sent to
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}1025{}}} {{at
}}{{{}2025{}}}{{{}{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}32{}}}{{{}.189869356Z;
determining Cluster Coordinator took {}}}{{4}} {{millis; DNS lookup }}{{for}}
{{coordinator took }}{{0}} {{millis; connecting to coordinator took }}{{0}}
{{millis; sending heartbeat took }}{{49}} {{millis; receiving first }}{{byte}}
{{from response took }}{{1}} {{millis; receiving full response took }}{{1}}
{{millis; total time was }}{{54}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}34{}}}{{{},{}}}{{{}493{}}} {{INFO
[Heartbeat Monitor Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.c.c.h.AbstractHeartbeatMonitor Finished processing }}{{3}} {{heartbeats
in }}{{3509}} {{nanos}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}35{}}}{{{},{}}}{{{}405{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}9{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
6a6f87f4-8fd0-4f17-a8f6-9f3554b4a287 (type=HEARTBEAT, length={}}}{{{}4464{}}}
{{{}bytes) from
nifi{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{92}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}35{}}}{{{},{}}}{{{}893{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}12{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
d733ba82-e963-402f-9ecc-75a0c7571fe1 (type=HEARTBEAT, length={}}}{{{}4463{}}}
{{{}bytes) from
nifi{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{96}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}37{}}}{{{},{}}}{{{}248{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}11{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
5be72afd-516c{}}}{{{}4150{}}}{{{}--{}}}{{{}8343{}}}{{{}-a35a0ace4c4f
(type=HEARTBEAT, length={}}}{{{}4467{}}} {{{}bytes) from
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{46}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}37{}}}{{{},{}}}{{{}251{}}} {{INFO
[Clustering Tasks Thread-{}}}\\{{{}3{}}}\\{{{}]
o.a.n.c.c.ClusterProtocolHeartbeater Heartbeat created at
}}{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}37{}}}{{{}.196Z
and sent to
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}1025{}}} {{at
}}{{{}2025{}}}{{{}{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}37{}}}{{{}.251287657Z;
determining Cluster Coordinator took {}}}{{4}} {{millis; DNS lookup }}{{for}}
{{coordinator took }}{{0}} {{millis; connecting to coordinator took }}{{1}}
{{millis; sending heartbeat took }}{{5}} {{millis; receiving first }}{{byte}}
{{from response took }}{{44}} {{millis; receiving full response took }}{{44}}
{{millis; total time was }}{{54}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}37{}}}{{{},{}}}{{{}631{}}} {{{}INFO
[Flow Service Tasks Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.p.FlowConfigurationArchiveManager Removing old archive file
./data/archive/20250415T130823+0100_flow.json.gz to reduce storage usage.
currentSize={}}}{{{}517833849{}}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}37{}}}{{{},{}}}{{{}637{}}} {{{}INFO
[Flow Service Tasks Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.nifi.controller.StandardFlowService Saved flow controller
org.apache.nifi.controller.FlowController{}}}{{{}@303ac720{}}} {{// Another
save pending = false}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}39{}}}{{{},{}}}{{{}495{}}} {{INFO
[Heartbeat Monitor Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.c.c.h.AbstractHeartbeatMonitor Finished processing }}{{3}} {{heartbeats
in }}{{4421}} {{nanos}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}40{}}}{{{},{}}}{{{}466{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}17{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
b90f7075-7f46-44db-b78d-888298a81486 (type=HEARTBEAT, length={}}}{{{}4464{}}}
{{{}bytes) from
nifi{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{51}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}40{}}}{{{},{}}}{{{}965{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}13{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
731bb68d-f72d{}}}{{{}4777{}}}{{{}-b2c1-1a63430577d7 (type=HEARTBEAT,
length=-{}}}{{{}4463{}}} {{{}bytes) from
nifi{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{54}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}42{}}}{{{},{}}}{{{}351{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}10{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
34f3ab04-bc52-49b2-a850-68f99bc7b4fd (type=HEARTBEAT, length={}}}{{{}4467{}}}
{{{}bytes) from
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{88}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}42{}}}{{{},{}}}{{{}352{}}} {{INFO
[Clustering Tasks Thread-{}}}\\{{{}3{}}}\\{{{}]
o.a.n.c.c.ClusterProtocolHeartbeater Heartbeat created at
}}{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}42{}}}{{{}.259Z
and sent to
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}1025{}}} {{at
}}{{{}2025{}}}{{{}{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}42{}}}{{{}.352338719Z;
determining Cluster Coordinator took {}}}{{4}} {{millis; DNS lookup }}{{for}}
{{coordinator took }}{{0}} {{millis; connecting to coordinator took }}{{0}}
{{millis; sending heartbeat took }}{{45}} {{millis; receiving first }}{{byte}}
{{from response took }}{{43}} {{millis; receiving full response took }}{{44}}
{{millis; total time was }}{{93}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}495{}}} {{{}WARN
[Heartbeat Monitor Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.c.c.node.NodeClusterCoordinator Requesting that
nifi{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}}
{{reconnect to the cluster due to: Node has a Revision Update Count of
}}{{213336}} {{but local value is only }}{{{}213335{}}}{{{}. Node appears not
to have the appropriate set of Component Revisions{}}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}495{}}} {{INFO
[Heartbeat Monitor Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.c.c.node.NodeClusterCoordinator Event Reported }}{{for}}
{{{}nifi{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}}
{{-- Requesting that node connect to cluster}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}506{}}} {{{}INFO
[Heartbeat Monitor Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.c.c.node.NodeClusterCoordinator Status of
nifi{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}}
{{changed from
NodeConnectionStatus[nodeId=nifi-{}}}\\{{{}0{}}}\\{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}\\{{{}8443{}}}\\{{{},
state=CONNECTED, updateId={}}}\\{{{}4347{}}}\\{{{}] to
NodeConnectionStatus[nodeId=nifi-{}}}\\{{{}0{}}}\\{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}\\{{{}8443{}}}\\{{{},
state=CONNECTING, updateId={}}}\\{{{}4351{}}}\\{{{}]}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}565{}}} {{{}WARN
[Heartbeat Monitor Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.c.c.node.NodeClusterCoordinator Requesting that
nifi{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}}
{{reconnect to the cluster due to: Node has a Revision Update Count of
}}{{213336}} {{but local value is only }}{{{}213335{}}}{{{}. Node appears not
to have the appropriate set of Component Revisions{}}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}565{}}} {{INFO
[Heartbeat Monitor Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.c.c.node.NodeClusterCoordinator Event Reported }}{{for}}
{{{}nifi{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}}
{{-- Requesting that node connect to cluster}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}571{}}} {{{}INFO
[Heartbeat Monitor Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.c.c.node.NodeClusterCoordinator Status of
nifi{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}}
{{changed from
NodeConnectionStatus[nodeId=nifi-{}}}\\{{{}2{}}}\\{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}\\{{{}8443{}}}\\{{{},
state=CONNECTED, updateId={}}}\\{{{}4350{}}}\\{{{}] to
NodeConnectionStatus[nodeId=nifi-{}}}\\{{{}2{}}}\\{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}\\{{{}8443{}}}\\{{{},
state=CONNECTING, updateId={}}}\\{{{}4352{}}}\\{{{}]}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}650{}}} {{INFO
[Heartbeat Monitor Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.c.c.h.AbstractHeartbeatMonitor Finished processing }}{{3}} {{heartbeats
in }}{{155}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}847{}}} {{INFO
[NiFi Web Server-{}}}\\{{{}394965{}}}\\{{{}] o.a.n.c.s.StandardProcessScheduler
Starting AttributesToJSON[id=36af30fe-514a-1b3c-bc34-7060ecebe453]}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}847{}}} {{INFO
[NiFi Web Server-{}}}\\{{{}394965{}}}\\{{{}]
o.a.n.controller.StandardProcessorNode Starting
AttributesToJSON[id=36af30fe-514a-1b3c-bc34-7060ecebe453]}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}899{}}} {{INFO
[Timer-Driven Process Thread-{}}}\\{{{}1{}}}\\{{{}]
o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled
AttributesToJSON[id=36af30fe-514a-1b3c-bc34-7060ecebe453] to run with }}{{1}}
{{threads}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}45{}}}{{{},{}}}{{{}572{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}15{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
1142ddef-fb53{}}}{{{}4206{}}}{{{}-96a9-c48e5407ea2c (type=HEARTBEAT,
length=-{}}}{{{}4628{}}} {{{}bytes) from
nifi{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{95}} {{millis}}
{{{}2025{}}}{{{}-{-}{-}{}}}{{{}04{}}}{{{{}}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}46{}}}{{{},{}}}{{{}073{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\\{{{}16{}}}\\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
29bd245e-55e4-467a-aa78-5a79cc19fe9f (type=HEARTBEAT, length={}}}{{{}4627{}}}
{{{}bytes) from
nifi{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{93}} {{millis}}
{{{}nifi{}}}{{{}@nifi{}}}{{{}-{}}}{{{}1{}}}{{{}:/opt/nifi/nifi-current${}}}|
was (Author: JIRAUSER307668):
We got the same issue in 2.0.0-M2, this version is already using [JetBrains
Xodus|https://github.com/JetBrains/xodus] , we didn't see any delay or failure
for API request processing in the cluster here. But we are still hitting with
this problem twice now where it impacted us. Is there any solution for this?
{code:java}
2025-04-15 13:45:42,352 INFO [Clustering Tasks Thread-3]
o.a.n.c.c.ClusterProtocolHeartbeater Heartbeat created at
2025-04-15T12:45:42.259Z and sent to
nifi-1.nifi-hs.pipercx.svc.cluster.local:1025 at
2025-04-15T12:45:42.352338719Z; determining Cluster Coordinator took 4 millis;
DNS lookup for coordinator took 0 millis; connecting to coordinator took 0
millis; sending heartbeat took 45 millis; receiving first byte from response
took 43 millis; receiving full response took 44 millis; total time was 93
millis 2025-04-15 13:45:44,495 WARN [Heartbeat Monitor Thread-1]
o.a.n.c.c.node.NodeClusterCoordinator Requesting that
nifi-0.nifi-hs.pipercx.svc.cluster.local:8443 reconnect to the cluster due to:
Node has a Revision Update Count of 213336 but local value is only 213335. Node
appears not to have the appropriate set of Component Revisions 2025-04-15
13:45:44,495 INFO [Heartbeat Monitor Thread-1]
o.a.n.c.c.node.NodeClusterCoordinator Event Reported for
nifi-0.nifi-hs.pipercx.svc.cluster.local:8443 -- Requesting that node connect
to cluster 2025-04-15 13:45:44,506 INFO [Heartbeat Monitor Thread-1]
o.a.n.c.c.node.NodeClusterCoordinator Status of
nifi-0.nifi-hs.pipercx.svc.cluster.local:8443 changed from
NodeConnectionStatus[nodeId=nifi-0.nifi-hs.pipercx.svc.cluster.local:8443,
state=CONNECTED, updateId=4347] to
NodeConnectionStatus[nodeId=nifi-0.nifi-hs.pipercx.svc.cluster.local:8443,
state=CONNECTING, updateId=4351] 2025-04-15 13:45:44,565 WARN [Heartbeat
Monitor Thread-1] o.a.n.c.c.node.NodeClusterCoordinator Requesting that
nifi-2.nifi-hs.pipercx.svc.cluster.local:8443 reconnect to the cluster due to:
Node has a Revision Update Count of 213336 but local value is only 213335. Node
appears not to have the appropriate set of Component Revisions 2025-04-15
13:45:44,565 INFO [Heartbeat Monitor Thread-1]
o.a.n.c.c.node.NodeClusterCoordinator Event Reported for
nifi-2.nifi-hs.pipercx.svc.cluster.local:8443 -- Requesting that node connect
to cluster 2025-04-15 13:45:44,571 INFO [Heartbeat Monitor Thread-1]
o.a.n.c.c.node.NodeClusterCoordinator Status of
nifi-2.nifi-hs.pipercx.svc.cluster.local:8443 changed from
NodeConnectionStatus[nodeId=nifi-2.nifi-hs.pipercx.svc.cluster.local:8443,
state=CONNECTED, updateId=4350] to
NodeConnectionStatus[nodeId=nifi-2.nifi-hs.pipercx.svc.cluster.local:8443,
state=CONNECTING, updateId=4352] 2025-04-15 13:45:44,650 INFO [Heartbeat
Monitor Thread-1] o.a.n.c.c.h.AbstractHeartbeatMonitor Finished processing 3
heartbeats in 155 millis{code}
Coordinator Logs
|{{{}nifi{}}}{{{}@nifi{}}}{{{}--{}}}{{{}1{}}}{{{}:/opt/nifi/nifi-current$ cat
logs/nifi-app.log \| grep -i {}}}{{"2025-04-15 13:45:44,495"}} {{-color -B40
-A10}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}15{}}}{{{},{}}}{{{}549{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}100{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
b2388556-ad48-48a3-aeac-005f27e8fd68 (type=HEARTBEAT, length={}}}{{{}4463{}}}
{{{}bytes) from
nifi-{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{95}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}16{}}}{{{},{}}}{{{}920{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}99{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
2a29e615-{}}}{{{}8155{}}}{{{}-4b32-a013-b3868a78db26 (type=HEARTBEAT,
length=-{}}}{{{}4467{}}} {{{}bytes) from
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{96}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}16{}}}{{{},{}}}{{{}921{}}} {{INFO
[Clustering Tasks Thread-{}}}\{{{}3{}}}\{{{}]
o.a.n.c.c.ClusterProtocolHeartbeater Heartbeat created at
}}{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}16{}}}{{{}.818Z
and sent to
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}1025{}}} {{at
}}{{{}2025{}}}{{{}-{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}16{}}}{{{}.921728227Z;
determining Cluster Coordinator took {}}}{{4}} {{millis; DNS lookup }}{{for}}
{{coordinator took }}{{0}} {{millis; connecting to coordinator took }}{{1}}
{{millis; sending heartbeat took }}{{52}} {{millis; receiving first }}{{byte}}
{{from response took }}{{45}} {{millis; receiving full response took }}{{45}}
{{millis; total time was }}{{102}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}19{}}}{{{},{}}}{{{}492{}}} {{INFO
[Heartbeat Monitor Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.c.c.h.AbstractHeartbeatMonitor Finished processing }}{{3}} {{heartbeats
in }}{{6720}} {{nanos}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}20{}}}{{{},{}}}{{{}170{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}97{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
e55f44ab-3b42-447b-8b32-4a66fa751461 (type=HEARTBEAT, length={}}}{{{}4464{}}}
{{{}bytes) from
nifi-{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{98}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}20{}}}{{{},{}}}{{{}619{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}3{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
1a300ccf-51e7-4ab3-a9cf-155f42dc8065 (type=HEARTBEAT, length={}}}{{{}4463{}}}
{{{}bytes) from
nifi-{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{56}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}22{}}}{{{},{}}}{{{}023{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}2{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
3f782d5b-f28b-45b2-ad4f-ef1bb8170af9 (type=HEARTBEAT, length={}}}{{{}4467{}}}
{{{}bytes) from
nifi-{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{91}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}22{}}}{{{},{}}}{{{}024{}}} {{INFO
[Clustering Tasks Thread-{}}}\{{{}3{}}}\{{{}]
o.a.n.c.c.ClusterProtocolHeartbeater Heartbeat created at
}}{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}21{}}}{{{}.928Z
and sent to
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}1025{}}} {{at
}}{{{}2025{}}}{{{}-{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}22{}}}{{{}.024649024Z;
determining Cluster Coordinator took {}}}{{4}} {{millis; DNS lookup }}{{for}}
{{coordinator took }}{{0}} {{millis; connecting to coordinator took }}{{0}}
{{millis; sending heartbeat took }}{{48}} {{millis; receiving first }}{{byte}}
{{from response took }}{{44}} {{millis; receiving full response took }}{{44}}
{{millis; total time was }}{{96}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}24{}}}{{{},{}}}{{{}383{}}} {{INFO
[NiFi Web Server-{}}}\{{{}394987{}}}\{{{}] o.a.n.c.s.StandardProcessScheduler
Stopping AttributesToJSON[id=36af30fe-514a-1b3c-bc34-7060ecebe453]}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}24{}}}{{{},{}}}{{{}383{}}} {{INFO
[NiFi Web Server-{}}}\{{{}394987{}}}\{{{}]
o.a.n.controller.StandardProcessorNode Stopping processor:
AttributesToJSON[id=36af30fe-514a-1b3c-bc34-7060ecebe453]}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}24{}}}{{{},{}}}{{{}401{}}} {{INFO
[Timer-Driven Process Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.c.s.TimerDrivenSchedulingAgent Stopped scheduling
AttributesToJSON[id=36af30fe-514a-1b3c-bc34-7060ecebe453] to run}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}24{}}}{{{},{}}}{{{}401{}}} {{INFO
[Timer-Driven Process Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.controller.StandardProcessorNode
AttributesToJSON[id=36af30fe-514a-1b3c-bc34-7060ecebe453] has completely
stopped. Completing any associatedFutures.}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}24{}}}{{{},{}}}{{{}493{}}} {{INFO
[Heartbeat Monitor Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.c.c.h.AbstractHeartbeatMonitor Finished processing }}{{3}} {{heartbeats
in }}{{3939}} {{nanos}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}25{}}}{{{},{}}}{{{}237{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}1{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
76a02ca9-{}}}{{{}8080{}}}{{{}--{}}}{{{}4984{}}}{{{}-97d2-871918100aab
(type=HEARTBEAT, length={}}}{{{}4464{}}} {{{}bytes) from
nifi{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{56}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}25{}}}{{{},{}}}{{{}581{}}} {{{}INFO
[Flow Service Tasks Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.p.FlowConfigurationArchiveManager Removing old archive file
./data/archive/20250415T130804+0100_flow.json.gz to reduce storage usage.
currentSize={}}}{{{}517922067{}}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}25{}}}{{{},{}}}{{{}587{}}} {{{}INFO
[Flow Service Tasks Thread-{}}}\{{{}1{}}}\{{{}]
o.a.nifi.controller.StandardFlowService Saved flow controller
org.apache.nifi.controller.FlowController{}}}{{{}@303ac720{}}} {{// Another
save pending = false}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}25{}}}{{{},{}}}{{{}681{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}7{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
0be1922d-509e-4e74-8af9-cf55d0811e1c (type=HEARTBEAT, length={}}}{{{}4463{}}}
{{{}bytes) from
nifi-{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{50}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}27{}}}{{{},{}}}{{{}128{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}5{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
ad1693f3-ca19-4b12-86bc-703eca8bd35a (type=HEARTBEAT, length={}}}{{{}4467{}}}
{{{}bytes) from
nifi-{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{92}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}27{}}}{{{},{}}}{{{}128{}}} {{INFO
[Clustering Tasks Thread-{}}}\{{{}3{}}}\{{{}]
o.a.n.c.c.ClusterProtocolHeartbeater Heartbeat created at
}}{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}27{}}}{{{}.030Z
and sent to
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}1025{}}} {{at
}}{{{}2025{}}}{{{}-{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}27{}}}{{{}.128952987Z;
determining Cluster Coordinator took {}}}{{4}} {{millis; DNS lookup }}{{for}}
{{coordinator took }}{{0}} {{millis; connecting to coordinator took }}{{0}}
{{millis; sending heartbeat took }}{{50}} {{millis; receiving first }}{{byte}}
{{from response took }}{{44}} {{millis; receiving full response took }}{{44}}
{{millis; total time was }}{{98}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}29{}}}{{{},{}}}{{{}493{}}} {{INFO
[Heartbeat Monitor Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.c.c.h.AbstractHeartbeatMonitor Finished processing }}{{3}} {{heartbeats
in }}{{3050}} {{nanos}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}30{}}}{{{},{}}}{{{}300{}}} {{INFO
[Checkpoint FlowFile Repository] o.a.n.c.r.WriteAheadFlowFileRepository
Initiating checkpoint of FlowFile Repository}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}30{}}}{{{},{}}}{{{}302{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}4{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
e376e72a-{}}}{{{}4161{}}}{{{}-445b-{}}}{{{}8419{}}}{{{}-fcb747045743
(type=HEARTBEAT, length=-{}}}{{{}4464{}}} {{{}bytes) from
nifi{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{54}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}30{}}}{{{},{}}}{{{}785{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}6{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
1f26252e-{}}}{{{}1817{}}}{{{}-4c36-86a7-f39cbbdefdd4 (type=HEARTBEAT,
length=-{}}}{{{}4463{}}} {{{}bytes) from
nifi{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{92}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}31{}}}{{{},{}}}{{{}095{}}} {{INFO
[Checkpoint FlowFile Repository] o.a.n.wali.SequentialAccessWriteAheadLog
Checkpointed Write-Ahead Log with }}{{99466}} {{Records and }}{{445}} {{Swap
Files in }}{{795}} {{milliseconds (Stop-the-world time = }}{{12}}
{{milliseconds), max Transaction ID }}{{326649836}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}31{}}}{{{},{}}}{{{}095{}}} {{INFO
[Checkpoint FlowFile Repository] o.a.n.c.r.WriteAheadFlowFileRepository
Successfully checkpointed FlowFile Repository with }}{{99466}} {{records in
}}{{795}} {{milliseconds}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}31{}}}{{{},{}}}{{{}347{}}} {{INFO
[FileSystemRepository Workers Thread-{}}}\{{{}3{}}}\{{{}]
o.a.n.c.repository.FileSystemRepository Successfully archived }}{{1}}
{{Resource Claims }}{{for}} {{Container }}{{default}} {{in }}{{0}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}32{}}}{{{},{}}}{{{}189{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}8{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
a87f2b35-48d6-435f-bb55-af12d4024655 (type=HEARTBEAT, length={}}}{{{}4467{}}}
{{{}bytes) from
nifi-{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{49}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}32{}}}{{{},{}}}{{{}189{}}} {{INFO
[Clustering Tasks Thread-{}}}\{{{}3{}}}\{{{}]
o.a.n.c.c.ClusterProtocolHeartbeater Heartbeat created at
}}{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}32{}}}{{{}.135Z
and sent to
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}1025{}}} {{at
}}{{{}2025{}}}{{{}-{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}32{}}}{{{}.189869356Z;
determining Cluster Coordinator took {}}}{{4}} {{millis; DNS lookup }}{{for}}
{{coordinator took }}{{0}} {{millis; connecting to coordinator took }}{{0}}
{{millis; sending heartbeat took }}{{49}} {{millis; receiving first }}{{byte}}
{{from response took }}{{1}} {{millis; receiving full response took }}{{1}}
{{millis; total time was }}{{54}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}34{}}}{{{},{}}}{{{}493{}}} {{INFO
[Heartbeat Monitor Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.c.c.h.AbstractHeartbeatMonitor Finished processing }}{{3}} {{heartbeats
in }}{{3509}} {{nanos}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}35{}}}{{{},{}}}{{{}405{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}9{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
6a6f87f4-8fd0-4f17-a8f6-9f3554b4a287 (type=HEARTBEAT, length={}}}{{{}4464{}}}
{{{}bytes) from
nifi-{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{92}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}35{}}}{{{},{}}}{{{}893{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}12{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
d733ba82-e963-402f-9ecc-75a0c7571fe1 (type=HEARTBEAT, length={}}}{{{}4463{}}}
{{{}bytes) from
nifi-{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{96}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}37{}}}{{{},{}}}{{{}248{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}11{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
5be72afd-516c-{}}}{{{}4150{}}}{{{}--{}}}{{{}8343{}}}{{{}-a35a0ace4c4f
(type=HEARTBEAT, length={}}}{{{}4467{}}} {{{}bytes) from
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{46}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}37{}}}{{{},{}}}{{{}251{}}} {{INFO
[Clustering Tasks Thread-{}}}\{{{}3{}}}\{{{}]
o.a.n.c.c.ClusterProtocolHeartbeater Heartbeat created at
}}{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}37{}}}{{{}.196Z
and sent to
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}1025{}}} {{at
}}{{{}2025{}}}{{{}-{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}37{}}}{{{}.251287657Z;
determining Cluster Coordinator took {}}}{{4}} {{millis; DNS lookup }}{{for}}
{{coordinator took }}{{0}} {{millis; connecting to coordinator took }}{{1}}
{{millis; sending heartbeat took }}{{5}} {{millis; receiving first }}{{byte}}
{{from response took }}{{44}} {{millis; receiving full response took }}{{44}}
{{millis; total time was }}{{54}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}37{}}}{{{},{}}}{{{}631{}}} {{{}INFO
[Flow Service Tasks Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.p.FlowConfigurationArchiveManager Removing old archive file
./data/archive/20250415T130823+0100_flow.json.gz to reduce storage usage.
currentSize={}}}{{{}517833849{}}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}37{}}}{{{},{}}}{{{}637{}}} {{{}INFO
[Flow Service Tasks Thread-{}}}\{{{}1{}}}\{{{}]
o.a.nifi.controller.StandardFlowService Saved flow controller
org.apache.nifi.controller.FlowController{}}}{{{}@303ac720{}}} {{// Another
save pending = false}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}39{}}}{{{},{}}}{{{}495{}}} {{INFO
[Heartbeat Monitor Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.c.c.h.AbstractHeartbeatMonitor Finished processing }}{{3}} {{heartbeats
in }}{{4421}} {{nanos}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}40{}}}{{{},{}}}{{{}466{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}17{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
b90f7075-7f46-44db-b78d-888298a81486 (type=HEARTBEAT, length={}}}{{{}4464{}}}
{{{}bytes) from
nifi-{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{51}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}40{}}}{{{},{}}}{{{}965{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}13{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
731bb68d-f72d-{}}}{{{}4777{}}}{{{}-b2c1-1a63430577d7 (type=HEARTBEAT,
length=-{}}}{{{}4463{}}} {{{}bytes) from
nifi{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{54}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}42{}}}{{{},{}}}{{{}351{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}10{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
34f3ab04-bc52-49b2-a850-68f99bc7b4fd (type=HEARTBEAT, length={}}}{{{}4467{}}}
{{{}bytes) from
nifi-{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{88}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}42{}}}{{{},{}}}{{{}352{}}} {{INFO
[Clustering Tasks Thread-{}}}\{{{}3{}}}\{{{}]
o.a.n.c.c.ClusterProtocolHeartbeater Heartbeat created at
}}{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}42{}}}{{{}.259Z
and sent to
nifi{}}}{{{}1{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}1025{}}} {{at
}}{{{}2025{}}}{{{}-{}}}{{{}04{}}}{{{}-15T12:{}}}{{{}45{}}}{{{}:{}}}{{{}42{}}}{{{}.352338719Z;
determining Cluster Coordinator took {}}}{{4}} {{millis; DNS lookup }}{{for}}
{{coordinator took }}{{0}} {{millis; connecting to coordinator took }}{{0}}
{{millis; sending heartbeat took }}{{45}} {{millis; receiving first }}{{byte}}
{{from response took }}{{43}} {{millis; receiving full response took }}{{44}}
{{millis; total time was }}{{93}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}495{}}} {{{}WARN
[Heartbeat Monitor Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.c.c.node.NodeClusterCoordinator Requesting that
nifi-{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}}
{{reconnect to the cluster due to: Node has a Revision Update Count of
}}{{213336}} {{but local value is only }}{{{}213335{}}}{{{}. Node appears not
to have the appropriate set of Component Revisions{}}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}495{}}} {{INFO
[Heartbeat Monitor Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.c.c.node.NodeClusterCoordinator Event Reported }}{{for}}
{{{}nifi-{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}}
{{-- Requesting that node connect to cluster}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}506{}}} {{{}INFO
[Heartbeat Monitor Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.c.c.node.NodeClusterCoordinator Status of
nifi-{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}}
{{changed from
NodeConnectionStatus[nodeId=nifi-{}}}\{{{}0{}}}\{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}\{{{}8443{}}}\{{{},
state=CONNECTED, updateId={}}}\{{{}4347{}}}\{{{}] to
NodeConnectionStatus[nodeId=nifi-{}}}\{{{}0{}}}\{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}\{{{}8443{}}}\{{{},
state=CONNECTING, updateId={}}}\{{{}4351{}}}\{{{}]}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}565{}}} {{{}WARN
[Heartbeat Monitor Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.c.c.node.NodeClusterCoordinator Requesting that
nifi-{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}}
{{reconnect to the cluster due to: Node has a Revision Update Count of
}}{{213336}} {{but local value is only }}{{{}213335{}}}{{{}. Node appears not
to have the appropriate set of Component Revisions{}}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}565{}}} {{INFO
[Heartbeat Monitor Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.c.c.node.NodeClusterCoordinator Event Reported }}{{for}}
{{{}nifi-{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}}
{{-- Requesting that node connect to cluster}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}571{}}} {{{}INFO
[Heartbeat Monitor Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.c.c.node.NodeClusterCoordinator Status of
nifi-{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}}
{{changed from
NodeConnectionStatus[nodeId=nifi-{}}}\{{{}2{}}}\{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}\{{{}8443{}}}\{{{},
state=CONNECTED, updateId={}}}\{{{}4350{}}}\{{{}] to
NodeConnectionStatus[nodeId=nifi-{}}}\{{{}2{}}}\{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}\{{{}8443{}}}\{{{},
state=CONNECTING, updateId={}}}\{{{}4352{}}}\{{{}]}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}650{}}} {{INFO
[Heartbeat Monitor Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.c.c.h.AbstractHeartbeatMonitor Finished processing }}{{3}} {{heartbeats
in }}{{155}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}847{}}} {{INFO
[NiFi Web Server-{}}}\{{{}394965{}}}\{{{}] o.a.n.c.s.StandardProcessScheduler
Starting AttributesToJSON[id=36af30fe-514a-1b3c-bc34-7060ecebe453]}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}847{}}} {{INFO
[NiFi Web Server-{}}}\{{{}394965{}}}\{{{}]
o.a.n.controller.StandardProcessorNode Starting
AttributesToJSON[id=36af30fe-514a-1b3c-bc34-7060ecebe453]}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}44{}}}{{{},{}}}{{{}899{}}} {{INFO
[Timer-Driven Process Thread-{}}}\{{{}1{}}}\{{{}]
o.a.n.c.s.TimerDrivenSchedulingAgent Scheduled
AttributesToJSON[id=36af30fe-514a-1b3c-bc34-7060ecebe453] to run with }}{{1}}
{{threads}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}45{}}}{{{},{}}}{{{}572{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}15{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
1142ddef-fb53-{}}}{{{}4206{}}}{{{}-96a9-c48e5407ea2c (type=HEARTBEAT,
length=-{}}}{{{}4628{}}} {{{}bytes) from
nifi{}}}{{{}2{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{95}} {{millis}}
{{{}2025{}}}{{{}--{}}}{{{}04{}}}{{{}{}}}{{{}15{}}}
{{{}13{}}}{{{}:{}}}{{{}45{}}}{{{}:{}}}{{{}46{}}}{{{},{}}}{{{}073{}}} {{{}INFO
[Process Cluster Protocol Request-{}}}\{{{}16{}}}\{{{}]
o.a.n.c.p.impl.SocketProtocolListener Finished processing request
29bd245e-55e4-467a-aa78-5a79cc19fe9f (type=HEARTBEAT, length={}}}{{{}4627{}}}
{{{}bytes) from
nifi-{}}}{{{}0{}}}{{{}.nifi-hs.pipercx.svc.cluster.local:{}}}{{{}8443{}}} {{in
}}{{93}} {{millis}}
{{{}nifi{}}}{{{}@nifi{}}}{{{}-{}}}{{{}1{}}}{{{}:/opt/nifi/nifi-current${}}}|
> NiFi revision manager and heartbeat validation conflicts leading to
> reconnection request
> ----------------------------------------------------------------------------------------
>
> Key: NIFI-13885
> URL: https://issues.apache.org/jira/browse/NIFI-13885
> Project: Apache NiFi
> Issue Type: Bug
> Affects Versions: 1.23.0, 1.24.0, 1.23.2
> Reporter: Shubham Sharma
> Priority: Critical
> Attachments: hkl25073070_jstack.tar.gz, hkl25073177_jstack.tar.gz
>
>
> With a 5 node NiFi cluster deployment we observed a critical issue where
> reconnection requests are getting generated frequently due to difference in
> local coordinator's and given node's revisionUpdateCounter, affecting
> workflow lifecycle.
> *User Log summary*
> *User request to update controller service on random node(test01)*
> {code:java}
> 2024-10-14 18:44:55,927 INFO [NiFi Web Server-151009]
> o.a.n.w.s.NiFiAuthenticationFilter Authentication Success [test-app]
> 10.10.21.9 PUT
> https://test01.dvl:9443/nifi-api/controller-services/7f2fe434-8d01-3d6e-83f5-87d47e6e9598{code}
>
> *User request forwarded immediately to coordinator(test02)*
>
> {code:java}
> 2024-10-14 18:44:55,929 INFO [NiFi Web Server-1414436]
> o.a.n.w.s.NiFiAuthenticationFilter Authentication Success [test-app]
> 10.10.21.9 PUT
> https://test02:9443/nifi-api/controller-services/7f2fe434-8d01-3d6e-83f5-87d47e6e9598
> {code}
>
> *Delay to complete request as shown here in coordinator (test02)*
> {code:java}
> 2024-10-14 18:46:17,952 INFO [NiFi Web Server-1414436]
> o.a.n.w.s.NiFiAuthenticationFilter Authentication Success [test-app]
> 10.10.21.9 GET
> https://test02:9443/nifi-api/controller-services/7f2fe434-8d01-3d6e-83f5-87d47e6e9598{code}
>
> *App Log analysis*
> Added a log statement at the end of updateRevision function in
> NaiveRevisionManager for printing updated value of revisionUpdateCounter.
>
> *Coordinator app log summary*
> On main node test01 it took around 48 seconds to process above request for
> updating disabled controller service via restAPI and update
> revisionUpdateCounter to *3081375*
>
> *2024-10-14 18:45:43,455* INFO [NiFi Web Server-151009]
> o.a.n.web.revision.NaiveRevisionManager ---- Updated revision using [[61,
> ${clientid}, 7f2fe434-8d01-3d6e-83f5-87d47e6e9598]], revisionList [[61,
> ${clientid}, 7f2fe434-8d01-3d6e-83f5-87d47e6e9598]], revisionUpdateCounter
> *3081375*
>
> *Coordinator (test02)received its own heartbeat*
>
> *2024-10-14 18:45:47,143* INFO [Process Cluster Protocol Request-62]
> o.a.n.c.c.h.ClusterProtocolHeartbeatMonitor ----- Received new heartbeat from
> test02:9443, revisionId {*}3081374{*}, activethreadCount 79 ,
> connectionStatus CONNECTED -----
>
> *Received test01 node's heartbeat request to coordinator BUT with updated
> revisionID*
> *2024-10-14 18:45:57,724* INFO [Process Cluster Protocol Request-91]
> o.a.n.c.c.h.ClusterProtocolHeartbeatMonitor ----- Received new heartbeat from
> test01:9443, revisionId {*}3081375{*}, activethreadCount 73 ,
> connectionStatus CONNECTED -----
>
> *Scheduled Heartbeat validation gets triggered but due to above mismatch it
> requested reconnection for test01*
> *2024-10-14 18:46:07,654* WARN [Heartbeat Monitor Thread-1]
> o.a.n.c.c.node.NodeClusterCoordinator ----- Requesting that {*}test01{*}:9443
> reconnect to the cluster due to: Node has a Revision Update Count of
> *3081375* but local value is only {*}3081374{*}. Node appears not to have the
> appropriate set of Component Revisions -----
>
> *During reconnection request on test01 node, ie. going under reconnection and
> synchronisation process, finally coordinator received updated revision
> counter*
> *2024-10-14 18:46:11,238* INFO [NiFi Web Server-1414436]
> o.a.n.web.revision.NaiveRevisionManager ---- Updated revision using [[61,
> ${clientid}, 7f2fe434-8d01-3d6e-83f5-87d47e6e9598]], revisionList [[61,
> ${clientid}, 7f2fe434-8d01-3d6e-83f5-87d47e6e9598]], revisionUpdateCounter
> *3081375*
>
> *And next heartbeat* *sent by coordinator (test02) to itself* *containing
> updated revision counter*
> *2024-10-14 18:46:17,213* INFO [Process Cluster Protocol Request-2]
> o.a.n.c.c.h.ClusterProtocolHeartbeatMonitor ----- Received new heartbeat from
> {*}test02{*}:9443, revisionId {*}3081375{*}, activethreadCount 111 ,
> connectionStatus CONNECTED -----
>
> This reconnection attempts is happening frequently and affecting workflow
> request.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
