Anshu Singh created NIFI-16479:
----------------------------------
Summary: Copy request (POST /process-groups/{id}/copy) holds the
NiFiServiceFacadeLock write lock, blocking all API requests on the node
Key: NIFI-16479
URL: https://issues.apache.org/jira/browse/NIFI-16479
Project: Apache NiFi
Issue Type: Bug
Components: Core Framework
Affects Versions: 2.12.0, 2.11.0, 2.10.0, 2.9.0, 2.8.0, 2.7.0, 2.6.0
Environment: 3-node NiFi cluster (NiFi 2.6.0 lab, issue also observed
on NiFi 2.8.0), Java 21, 4 vCPU / 16 GB RAM per node, 8 GB heap, external
ZooKeeper, nifi.cluster.node.read.timeout=20 sec. Flow: ~3,000 process groups,
~15,000 processors, parameter contexts with inheritance (one context bound to
every process group, 1,645 parameters reachable).
Reporter: Anshu Singh
h3. Summary
Copying components in the UI (Ctrl+C, which calls {{POST
/nifi-api/process-groups/\{id\}/copy}}) runs
{{StandardNiFiServiceFacade.copyComponents}} while holding the node-wide
*write* lock of {{NiFiServiceFacadeLock}}. Every other API call on that node
has to wait until the copy finishes. This includes the UI polling calls
{{/flow/current-user}}, {{/flow/status}}, {{/flow/controller/bulletins}} and
{{/flow/process-groups/\{id\}}}. In a cluster, the other nodes replicate those
GETs to the copying node, hit {{nifi.cluster.node.read.timeout}}, and the UI
shows:
{noformat}
Invalid State
Current User Entity not expected
[org.apache.nifi.web.client.api.WebClientServiceException: Request execution
failed HTTP Method [GET] URI
[https://<copying-node>:8443/nifi-api/flow/current-user]]
{noformat}
With large parameter contexts a single copy can take more than a minute, so the
whole cluster UI becomes unusable for that time.
The {{copy*}} write-lock pointcut and {{copyComponents}} are unchanged in
2.12.0 and on main (verified in source). Line numbers below are from 2.8.0.
h3. Why this looks unintended
* {{NiFiServiceFacadeLock}} applies the write lock by method-name pointcut:
{{execution(* copy*(..))}} -> {{proceedWithWriteLock}}. The same pointcut
already exists in 1.x, where {{copy*}} matched {{copySnippet}}, which does
create components and calls {{controllerFacade.save()}}.
* NIFI-13976 (PR #9535) added the new {{copyComponents}} method for the 2.x
copy/paste endpoints. {{NiFiServiceFacadeLock}} was not changed, so
{{copyComponents}} inherited the write lock only because of its name.
* {{copyComponents}} (StandardNiFiServiceFacade, 2.8.0 ~line 5295) only reads.
It calls {{processGroupDAO.getProcessGroup}},
{{NiFiRegistryFlowMapper.mapProcessGroup}} and
{{NiFiRegistryFlowMapper.mapParameterContexts}}, then builds a
{{CopyResponseEntity}}. It does not save the flow, does not claim or update
revisions, and does not modify components.
* The mutating counterpart, {{pasteComponents}} (~line 6317), does not match
any {{NiFiServiceFacadeLock}} pointcut (there is no {{paste*}}). It is
protected by {{revisionManager.updateRevision}} and process group locks. So the
write lock on copy does not protect paste either.
* Download Flow Definition ({{getCurrentFlowSnapshotByGroupId}}, a {{get*}}
method, so *read* lock) already runs the same {{mapParameterContexts}} mapping
under the read lock.
h3. Evidence
Thread dump of the copying node during the stall (NiFi 2.8.0). One writer and
five UI requests are parked on the same lock:
{noformat}
"NiFi Web Server-104441" ... runnable
java.lang.Thread.State: RUNNABLE
at
org.apache.nifi.parameter.StandardParameterReferenceManager.getReferencedControllerServiceData(StandardParameterReferenceManager.java:125)
at
org.apache.nifi.registry.flow.mapping.NiFiRegistryFlowMapper.mapParameterContexts(NiFiRegistryFlowMapper.java:876)
at
org.apache.nifi.web.StandardNiFiServiceFacade.copyComponents(StandardNiFiServiceFacade.java:5361)
at
org.apache.nifi.web.NiFiServiceFacadeLock.proceedWithWriteLock(NiFiServiceFacadeLock.java:179)
at
org.apache.nifi.web.NiFiServiceFacadeLock.copyLock(NiFiServiceFacadeLock.java:78)
at
org.apache.nifi.web.api.ProcessGroupResource.copy(ProcessGroupResource.java:409)
"NiFi Web Server-106846" ... waiting on condition
- parking to wait for <0x000000060ce26018> (a
java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)
at
org.apache.nifi.web.NiFiServiceFacadeLock.proceedWithReadLock(NiFiServiceFacadeLock.java:158)
at
org.apache.nifi.web.api.FlowResource.getControllerStatus(FlowResource.java:1505)
(same for FlowResource.getBulletins, getFlow, getCurrentUser,
getRegistryClients)
{noformat}
Log on another node (the requester) during the same window:
{noformat}
WARN [Replicate Request Thread-4625] o.a.n.c.c.h.r.ThreadPoolRequestReplicator
Failed to replicate request GET /nifi-api/flow/current-user to al2023-node5:8443
org.apache.nifi.web.client.api.WebClientServiceException: Request execution
failed HTTP Method [GET] URI
[https://al2023-node5:8443/nifi-api/flow/current-user]
Caused by: java.net.http.HttpTimeoutException: request timed out
{noformat}
Lock timing measured with {{<logger
name="org.apache.nifi.web.NiFiServiceFacadeLock" level="DEBUG"/>}} (lab, NiFi
2.6.0):
||Scenario||copyComponents write-lock hold||Effect||
|~16.5k processors, 1,600 small contexts, copy 1 top-level group|2.0 s|reads
waited 1.4-1.6 s, no errors|
|same, plus a shared 100-parameter context inherited by all groups, copy all 13
top-level groups|71.2 s|47 reads waited more than 15 s (max 69.8 s); 31 of 373
UI requests failed with 409/500 WebClientServiceException|
|3,005 groups, ~14.7k processors, 11 contexts (1,645 parameters) bound to all
groups, copy *one* group, no other load|50-82 s|UI on the other nodes shows
"Invalid State" for about 1 minute and recovers when the copy ends|
Raising {{nifi.cluster.node.read.timeout}} to 300 s,
{{nifi.web.request.timeout}} to 420 s and the thread counts to 1000/150 only
hides the error. UI requests then hang for about 80 s instead of failing.
h3. Steps to reproduce
# 3-node cluster with {{nifi.cluster.node.read.timeout=20 sec}}.
# Create ~3,000 nested process groups with ~15,000 processors. Bind one
parameter context to every group; that context inherits ~10 contexts with
100-200 parameters each.
# Open the UI on node A. On node B, select one top-level process group and
press Ctrl+C.
# Within 20 s, node A's UI shows "Invalid State ... WebClientServiceException
... node B" until the copy on node B completes.
h3. Expected
Copying is read-only and should not block other readers. It should take the
read lock (as Download Flow Definition does), so only flow modifications wait
for it.
h3. Suggested fix
Restrict the write-lock pointcut to {{copySnippet}} and let {{copyComponents}}
use {{proceedWithReadLock}}. Alternatives: an explicit read pointcut for
{{copyComponents}}, or renaming the facade method so it no longer matches
{{copy*}}.
h3. Related
The cost of the copy itself (mapping the whole parent group, and a full-flow
scan per parameter) is tracked separately in <TICKET-2-KEY>.
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
