We hit an unexpected slowdown on the first reconciliation of a primary and traced it back to how activation-conditioned dependents get their informers started.
WorkflowReconcileExecutor.handleReconcile is synchronized (WorkflowReconcileExecutor.java:54) and calls registerOrDeregisterEventSourceBasedOnActivation at line 95. For a dependent with an activation condition, that ends up in EventSourceManager.dynamicallyRegisterEventSource -> eventSource.start() (EventSourceManager.java:256) -> InformerManager.start (:79), which blocks until the informer's initial LIST has synced. Since the executor's monitor is held the whole time, all the other dependents queue up behind it, so the first reconciliation ends up paying the sum of every activation-conditioned informer's sync time instead of overlapping them.
What made us fairly confident this isn't intended: EventSourceManager already moves eventSource.start() outside its own synchronized block (lines 252-256, with the "lock striping" comment). The intent is clearly that a blocking start shouldn't sit under a lock, it's just that the workflow executor happens to hold a different one across the same call.
Here's what we saw. JFR from one first reconciliation:
pool-10-thread-2 parked 978 ms
InformerManager.start() line: 79
EventSourceManager.dynamicallyRegisterEventSource(EventSource) line: 256
AbstractWorkflowExecutor.registerOrDeregisterEventSourceBasedOnActivation(...) line: 197
WorkflowReconcileExecutor.handleReconcile(DependentResourceNode) line: 95
pool-10-thread-5 blocked 967 ms on WorkflowReconcileExecutor monitor, previousOwner = pool-10-thread-2
pool-10-thread-4 blocked 966 ms on WorkflowReconcileExecutor monitor, previousOwner = pool-10-thread-5
That reconciliation took 2879 ms; with the same informers syncing quickly it was 136 ms. In our case the syncs are slow because those informers use informerListLimit, which stops the API server from answering the LIST from its watch cache, but anything that makes an initial LIST slow would do the same, so we suspect others could run into this without ever touching that setting.
Two pontential ideas here:
- Register activation-conditioned event sources eagerly at controller start when the condition doesn't need a primary to evaluate (ours are just configuration checks). The sync then happens at startup, in parallel, covered by
cacheSyncTimeout, and never during a reconciliation. This is the one we'd prefer, since it takes the cost off the reconciliation path completely.
- Start dynamically registered event sources outside the executor's monitor. The registration bookkeeping needs the lock, the blocking
start() doesn't. This lets the syncs overlap, though the first reconciliation still waits for the slowest one.
Happy to put up a PR for whichever shape you prefer.
On option 1: we had a look and there's no notion of a primary-independent activation condition today, Condition.isMet always takes the primary. Though CRDPresentActivationCondition ignores it completely and caches globally, so it seems like the common case. Would you be open to something explicit for it, like a marker interface or a requiresPrimary() default, so those can be registered eagerly at startup?
We hit an unexpected slowdown on the first reconciliation of a primary and traced it back to how activation-conditioned dependents get their informers started.
WorkflowReconcileExecutor.handleReconcileissynchronized(WorkflowReconcileExecutor.java:54) and callsregisterOrDeregisterEventSourceBasedOnActivationat line 95. For a dependent with an activation condition, that ends up inEventSourceManager.dynamicallyRegisterEventSource->eventSource.start()(EventSourceManager.java:256) ->InformerManager.start(:79), which blocks until the informer's initial LIST has synced. Since the executor's monitor is held the whole time, all the other dependents queue up behind it, so the first reconciliation ends up paying the sum of every activation-conditioned informer's sync time instead of overlapping them.What made us fairly confident this isn't intended:
EventSourceManageralready moveseventSource.start()outside its ownsynchronizedblock (lines 252-256, with the "lock striping" comment). The intent is clearly that a blocking start shouldn't sit under a lock, it's just that the workflow executor happens to hold a different one across the same call.Here's what we saw. JFR from one first reconciliation:
That reconciliation took 2879 ms; with the same informers syncing quickly it was 136 ms. In our case the syncs are slow because those informers use
informerListLimit, which stops the API server from answering the LIST from its watch cache, but anything that makes an initial LIST slow would do the same, so we suspect others could run into this without ever touching that setting.Two pontential ideas here:
cacheSyncTimeout, and never during a reconciliation. This is the one we'd prefer, since it takes the cost off the reconciliation path completely.start()doesn't. This lets the syncs overlap, though the first reconciliation still waits for the slowest one.Happy to put up a PR for whichever shape you prefer.
On option 1: we had a look and there's no notion of a primary-independent activation condition today, Condition.isMet always takes the primary. Though CRDPresentActivationCondition ignores it completely and caches globally, so it seems like the common case. Would you be open to something explicit for it, like a marker interface or a requiresPrimary() default, so those can be registered eagerly at startup?