Hi Willy, Thanks for taking the time, and sorry about the headache. You are right that the patch addresses several problems at once, and I made it worse by starting from the solution instead of the problem. Let me restart from the problem. But first, a bug report on my own patch.
1. The patch I sent has a CPU busy-loop, please drop it as it stands ==================================================================== We ran the 3.2-adapted version of this patch in production and hit this: for the whole soft-stop window, each forwarder spins one core at roughly 1e6 applet calls per second. The handler arms the drain re-check with task_schedule(appctx->t, ...). task_run_applet() does not manage ->expire, and when the handler finally takes "goto soft_close" it leaves ->expire at an already expired date. From then on the applet only ever takes the early "goto out" since EOS is set, so nothing clears it: run_tasks_from_lists() requeues the task at a past date and wake_expired_tasks() re-wakes it on every poll loop. Resetting ->expire at soft_close fixes the symptom, but the real lesson is that driving a periodic re-check from the applet task was wrong to begin with. The per-sink forward_task already exists and is already woken by the stopping broadcast (signal 0 from do_soft_stop_now()), so anything periodic belongs there. I mention it because it is a symptom of the design problem you are pointing at, not just a missing line. 2. The problem, with no solution attached ========================================= Two distinct losses happen at soft-stop with a ring-based log pipeline: (a) whatever is still in the ring when soft-stop is requested is dropped, because the forwarder closes on the first "stopping" test; (b) whatever the still-running streams produce during the soft-stop window is dropped as well, because by then no forwarder is left to read the ring. In our tests (b) dominates. At 3000 req/s the old worker needs about 180 ms to finish its last streams, and every log line emitted in that window is lost: around 3400 lines per reload. Issue #3436 has a reproducer on a vanilla build -- 268 to 358 lines lost per 3 reloads at 2000 req/s, and 0 without reloads. The requirement is just this: the last stream to finish must still get its log line out. Everything else in my patch was me working around what makes that hard, which brings me to the next point. 3. Why the patch reached into actconn ===================================== The forwarder cannot simply outlive the streams, because its own session is part of what keeps the process alive: sink_forward_session_init() -> appctx_finalize_startup() -> session_new() -> jobs++, and the poll loop exits on (jobs - unstoppable_jobs) == 0. Keeping the forwarder open past soft-stop therefore holds the worker up to hard-stop-after -- or forever when hard-stop-after is not set -- which is why the current code has to close it immediately. So the forwarder is itself part of the condition it would like to wait on, and cannot wait on it. That is the entire reason I ended up computing "is everyone else gone?" inside sink.c out of actconn. The actconn arithmetic, the log-forward exclusion and the 20 ms poll are all consequences of that one workaround. You disliked all three, and I now think all three are wrong for the same reason. 4. What I believe the right shape is ==================================== Take the forwarder out of the exit condition instead of teaching it to guess. If a live forwarder is accounted in unstoppable_jobs, then (jobs - unstoppable_jobs) == 0 becomes usable as the close signal. Strictly speaking it means "everything stoppable is done", which is a superset of the data plane, but that is the conservative side to err on, and it is computed by the core with no heuristic in sink.c, no proxy-type special case and no polling. It does widen what unstoppable_jobs counts beyond the master CLI listener; if you would rather keep that counter's meaning, a separate counter playing the same role works just as well. The other half is then missing: today the loop breaks and the process exits at that very point, so the sinks need a bounded chance to flush before it does. That is the part I would like your opinion on: whether that belongs in run_poll_loop() before the break, in a deinit-time step, or somewhere else entirely, and how you would prefer to bound it. Note this also settles the question you raised further down: at that point no stream is left to produce new messages, so "the ring is empty" is a final state rather than a race, and there is nothing left to sample or confirm. haproxy's own shutdown-time messages are the one exception, which is another reason for the flush to sit on the exit path itself. 5. Your individual points ========================= > I didn't understand that part unfortunately. What does the ring lock > have to do with this work ? Nothing, once the above is done. That paragraph was defending the sampling order of the actconn read: the drain state is read before the dispatch takes the ring lock, so a message written by a stream before it dropped out of actconn is guaranteed to be visible to that same dispatch. It is an argument that only exists because of the actconn workaround, and it disappears along with it. > You seem to be making a general case of a particular deployment > you're using. Agreed. The 20 ms poll exists because our rings are chained inside a single process (frontend -> ring -> log-forward -> log backend), so when the drain is observed the last messages can still be inside the local relay. That is a real problem, but it is my deployment's problem and should have been presented as such. With the shape in section 4 it disappears anyway: the relay's own sessions are counted in jobs, so the chain quiesces before the exit condition is met. > The term "wedge" is not clear to me here [...] That's already handled > by "timeout server" in the ring. Maybe you want a shorter one when > stopping ? You are right, it is a plain inactivity timeout, and a stopping-time variant of "timeout server" is exactly what I want; I have no reason to invent a second mechanism for it. One detail though: an explicit "ring" section gets no server timeout at all by default. sink_setup_proxy() leaves timeout.server at TICK_ETERNITY, and only the implicit rings created from a "log" directive get the 1s/5s defaults in sink_new_from_logger(). So for the stopping-time bound to be reliable it needs a sane default of its own rather than inheriting "no limit". > And if it had been established then closed ? Unchanged from today: the stream aborts, the endpoint gets SE_FL_EOS|SE_FL_ERROR and the session is torn down as usual, and since process_sink_forward() only creates sessions while !stopping, no reconnection happens. Whatever is left in the ring at that point is dropped -- the same policy question as the stuck downstream above, and the same stopping-time timeout should govern it. The not-yet-established test only avoids waiting on a connection that may never come up. I should have said so in the commit message. > what is not clear to me is how we make sure that we *do not* quit > while there are still data left there. With the patch as sent, we do not. If the downstream stops accepting, the 1 s bound gives up and drops what is left, on the grounds that holding the worker until hard-stop-after is worse. That is a policy choice I hardcoded without saying so, and it should instead be the stopping-time timeout discussed above -- configurable, and documented as "logs may be lost if the downstream is stuck". The direction I do want to guarantee is the other one: never quit early while the downstream is still accepting and messages are still being forwarded. 6. On the frontend option ========================= > What would be needed instead would be to have an option in frontends > to indicate whether or not a soft-stop should close their connections I agree, and I think it is more than orthogonal: it is a prerequisite for section 4. If a ring's server points at a log-forward section of the same process, that section holds an accepted connection which never terminates by itself and therefore keeps jobs above the floor forever. The forwarder would then be waiting for a condition that its own connection prevents from ever being met. The same applies to any raw TCP frontend, as you say -- log-forward is not special, it is simply the one I happened to hit. On the reconnect side of your sketch: today the old worker's ring cannot drain that way at all. process_sink_forward() only creates sessions while !stopping, and the applet closes on its first stopping test, so once soft-stop begins nothing reconnects anywhere. The ring contents cannot reach the new process either -- memory rings die with the worker, and file-backed rings are rotated at startup rather than resumed. So making your sketch work needs exactly the sink-side change in items 1 and 2 below: keep flushing while stopping, allow reconnection, and bound the whole thing with the stopping-time timeout. With your frontend option shutting the old chained frontend down, the reconnect would then indeed land on the new process and drain there. shut(WR) and waiting for the client rather than resetting sounds right to me, and a stopping-specific bound on top of it even more so. I would rather leave that one to you since it is about frontend soft-stop semantics in general rather than about sinks. My log-forward exclusion then goes away on its own. 7. Proposed split ================= 1. sink: on soft-stop, flush what is already in the ring before closing, without waiting for new messages. Fixes (a) only. The worker lives just long enough to write out the existing backlog, bounded by (2); no new exit condition. 2. sink: bound that stopping-time flush with a stopping-specific timeout rather than a hardcoded delay. 3. core + sink: keep the forwarder alive until the stoppable data plane is done, per section 4. Fixes (b). Needs your call on the hook point. 4. (yours) frontend option to shut down connections on soft-stop. I can send 1 and 2 whenever you want. I would rather not write 3 before we agree on its shape. Thanks again for the review. ygkat
