Since 9561b9fb6 ("BUG/MINOR: sink: add tempo between 2 connection
attempts for sft servers"), process_sink_forward() only creates a new
session for an orphan sft once tick_is_expired() reports that
last_conn + 1s is in the past. But sft->last_conn is only refreshed
when a session is created, and ticks are compared using a signed
difference. So once a forwarder session has lasted 2^31 ms (~24.8
days) or more and then gets closed, last_conn + 1s appears to be in
the future: no session is created and the task expiry is armed up to
another ~24.8 days later. No reconnection is attempted during that
time and all messages sent to the ring server are lost.
This was observed in production on log backend servers after the
syslog receivers were restarted: all affected nodes had a worker
uptime between 2^31 and 2^32 ms, and none outside that window.
Compute the elapsed time as a wrap-safe signed difference instead.
Since last_conn may be set by another thread whose now_ms was slightly
more recent, a value a little in the future still honors the tempo,
but a last_conn more than 1s in the future can only result from a
wrap and is considered expired.
It must be backported everywhere 9561b9fb6 was backported (up to 2.6
it seems).
---
On affected nodes the servers stayed UP/L4OK, but "show sess all" had no
<SINKFWD> applet for them and the implicit ring's "dropped" counter grew
at the full incoming rate. It hit several hundred nodes at once after the
receivers were restarted.
Reproduced on 3.2.21 and 3.4.4 with gdb, by setting sft->last_conn to
now_ms - 0x90000000 on a running process and then restarting the
receiver: the server never reconnected. With the patch it reconnects
within 2s, and the 1s tempo between attempts while the receiver is
down is unchanged.
src/sink.c | 11 ++++++++++-
1 file changed, 10 insertions(+), 1 deletion(-)
diff --git a/src/sink.c b/src/sink.c
index d6b6c15f8..915cf334c 100644
--- a/src/sink.c
+++ b/src/sink.c
@@ -726,8 +726,17 @@ static struct task *process_sink_forward(struct task *
task, void *context, unsi
*/
if (!sft->appctx) {
int tempo = tick_add(sft->last_conn,
MS_TO_TICKS(1000));
+ int elapsed = (int)(now_ms - sft->last_conn);
- if (sft->last_conn == TICK_ETERNITY ||
tick_is_expired(tempo, now_ms))
+ /* <last_conn> is only refreshed when a session
is created, so
+ * after a session lasted 2^31 ms or more,
<tempo> looks like
+ * it's in the future and tick_is_expired()
would never trigger
+ * for another ~24.8 days. Use a wrap-safe
signed difference
+ * instead. <last_conn> may be slightly in the
future when set
+ * by another thread, but anything beyond 1s
can only be a wrap.
+ */
+ if (sft->last_conn == TICK_ETERNITY ||
+ elapsed >= MS_TO_TICKS(1000) || elapsed <
-MS_TO_TICKS(1000))
sft->appctx =
sink_forward_session_create(sink, sft);
else if (task->expire == TICK_ETERNITY)
task->expire = tempo;
--
2.52.0
