Sönke Liebau created NIFI-16547:
-----------------------------------
Summary: Cluster protocol sockets are created without a connect
timeout
Key: NIFI-16547
URL: https://issues.apache.org/jira/browse/NIFI-16547
Project: Apache NiFi
Issue Type: Bug
Components: Core Framework
Affects Versions: 2.7.2
Environment: Observed with NiFi running on Kubernetes, affects any
environment though.
Reporter: Sönke Liebau
Assignee: Sönke Liebau
h3. Description
The code in `SocketUtils.createSocket` creates new sockets with `new
Socket(host, port)` which tries connecting the socket to the target host
immediately.
The problem is, that this initial connection is not governed by the timeouts
configurable via `nifi.cluster.node.read.timeout` or
`nifi.cluster.node.connection.timeout`. Those are only applied later. The
timeout for this initial connection is controlled by the kernel's SYN timeout,
which is about 130 seconds with Linux defaults. This is not really relevant for
any connection attempts that are actively rejected, but if packets are silently
DROPed by a firewall or something like that along the way, this will "hang" for
about 2 minutes.
This can be problematic in places, where this is called in a synchroneous
context and blocks subsequent code. One such example is
`notifyNodeStatusChange` which is called from the HeartbeatMonitor and fans out
to all nodes. If one of those connects hangs, it blocks the heartbeat monitor
for 120 seconds. While it waits, the coordinator processes no heartbeats at
all, so nodes that are joining or rejoining stay CONNECTING:
On the client side of things, the same SocketUtils is used for heartbeats and
connection requests. A node whose heartbeat goes to an address that drops
packets blocks its heartbeat thread for the full connect timeout and gets
disconnected for lack of heartbeat, although it is healthy.
We saw this create issues on NiFi clusters running on Kubernetes during rolling
restarts. Nodes address each other by pod DNS name, and after a pod has exited
its old IP can still be used for a while (DNS and JVM caching, or a name that
was resolved just before the pod went away). Depending on the CNI
implementation, a connect to the IP of an exited pod is silently dropped
instead of rejected, so it hangs until the kernel gives up.
h3. Symptoms
We saw several issues over time during rolling restarts, that we think might be
tied to this issue.
- Nodes unable to rejoin for a long time.
- API returning 409 because coordinator is not CONNECTED
- Healthy nodes being disconnected
h3. Suggested fix
The fix should be fairly simple, replace the `new` calls with creating an
unconnected socket and then calling connect(new InetSocketAddress(host, port),
timeout), with nifi.cluster.node.connection.timeout as the timeout. I think
there may be some Exception handling to tweak, but that should do away with the
super long timeouts.
I ran a test with an image with that fix vs a vanilla image and had Claude
compare behavior across a few rolling restart on K8s for both. Results are
shown below - but this should not be treated as gospel, rather indications.
|| ||Stock||Fixed||
|Rollout duration|5:21|3:42|
|Restart until API answers 200 on all nodes again|5:23 (322 s)|3:33 (212 s)|
|Kill → that node back (CONNECTED + API 200), n2 / n1 / n0|302 / 255 / 105
s|109 / 88 / 50 s|
|Running nodes disconnected for lack of heartbeat|3|0|
|NiFi shutdown time, n2 / n1 / n0|0 / 93 / 57 s|0 / 0 / 0 s|
|Time other, running nodes refused the API with 409|~95 s each on n1 and n2|~12
s, only on the node rejoining|
|Longest heartbeat-monitor stall|5 s|5 s|
What changed with the fix:
* Running nodes keep working. On stock, every coordinator handover got running
nodes disconnected, and the API returned 409 on all three nodes for two windows
(about 96 s and 74 s). In those windows even reading the cluster state and
processor state failed everywhere. With the fix there were no such disconnects,
and while one node restarted the other two answered normally.
* Shutdown takes 0 s. On stock, shutdowns waited 57–93 s for a heartbeat stuck
on the old coordinator's address. Faster shutdowns are a big part of why the
whole rollout got 1:40 shorter.
--
This message was sent by Atlassian Jira
(v10.3.26#10030026)
