BUG/MEDIUM: sink: reconnect attempt not working after session lasted more than ~25...

As described in GH #3508, if a sink session lasted for more that 24.85
days and suddenly stops, the automatic sink session restart mechanism
won't try to reconnect to the server as it would normally. This regression
was introduced by commit 9561b9f ("BUG/MINOR: sink: add tempo between 2
connection attempts for sft servers"). The underlying cause is that we
rely on a 32 timer which is updated at the time of the last connection
attempt, which will eventually wrap when no connection attempt is
performed for more than 24.85 days (this is the case when the session
uptime reaches that time). In that case the timer ends up being in the
future and will not be considered as expired anymore when compared with
now_ms.

To fix the issue, we now look at the applet release/closing date instead
of its creation, this way we ensure that sft->last_close should not wrap
because the time between the applet release and a new attempt is relatively
short, since any new message queued in the forwarding queue will cause the
applet to perform a new attempt. Thus it is not expected that the timer
holds value greater than a few seconds, minutes or worst case hours.

However we need to mention a special case: if the syslog server becomes
unavailable for more that ~25 days, in that case stf->last_close could
wrap, causing the applet to stop trying to connect to the server, but
this is acceptable because a server that is not available for that long
can be considered as dead.

Thanks to GH user @ygkat for reporting the issue and providing very precise
analysis of the bug with a patch proposal, although the final patch followed
Willy's suggestion.

It should be backported to all stable versions (anywhere 9561b9f was
backported).

diff --git a/include/haproxy/sink-t.h b/include/haproxy/sink-t.h
index a9db336f1aa93d47b20f800cfdff39596ccf01df..e865efdddb48c7b370587f1e4e9890b8135fd7e6 100644 (file)
--- a/include/haproxy/sink-t.h
+++ b/include/haproxy/sink-t.h
@@ -40,7 +40,7 @@ enum sink_type {
 struct sink_forward_target {
        struct server *srv;    // used server
        struct appctx *appctx; // appctx of current session
-       uint last_conn;        // copy of now_ms for last session establishment attempt
+       uint last_close;       // copy of now_ms for last session destroy/close
        size_t ofs;            // ring buffer reader offset
        size_t e_processed;    // processed events
        struct sink *sink;     // the associated sink

diff --git a/src/sink.c b/src/sink.c
index d6b6c15f8d6485f5b061289814b24a990a7b1e6a..e3a69703b12d561ead331bcfeeff774d63377c7b 100644 (file)
--- a/src/sink.c
+++ b/src/sink.c
@@ -621,6 +621,7 @@ static void sink_forward_session_release(struct appctx *appctx)
        HA_SPIN_LOCK(SFT_LOCK, &sft->lock);
        BUG_ON(sft->appctx != appctx);
        __sink_forward_session_deinit(sft);
+       sft->last_close = now_ms;
        HA_SPIN_UNLOCK(SFT_LOCK, &sft->lock);
 }
 
@@ -695,7 +696,6 @@ static struct appctx *sink_forward_session_create(struct sink *sink, struct sink
                goto out_close;
        appctx->svcctx = (void *)sft;
        appctx_wakeup(appctx);
-       sft->last_conn = now_ms;
        return appctx;
 
        /* Error unrolling */
@@ -723,11 +723,19 @@ static struct task *process_sink_forward(struct task * task, void *context, unsi
                         *
                         * We enforce a tempo to ensure we don't perform more than 1 session
                         * establishment attempt per second.
+                        *
+                        * Note: last_close will wrap after 24.85 days, which may happen if
+                        * the server remains unavailable for that long, in that case it will
+                        * cause the tick_is_expired() test to always fail since tempo will be
+                        * in the future. This means the applet will stop trying to reconnect
+                        * to the server. We accept this pitfall because a server that was
+                        * unavailable for that long can be considered as definitely dead, but
+                        * this is something to keep in mind.
                         */
                        if (!sft->appctx) {
-                               int tempo = tick_add(sft->last_conn, MS_TO_TICKS(1000));
+                               int tempo = tick_add(sft->last_close, MS_TO_TICKS(1000));
 
-                               if (sft->last_conn == TICK_ETERNITY || tick_is_expired(tempo, now_ms))
+                               if (sft->last_close == TICK_ETERNITY || tick_is_expired(tempo, now_ms))
                                        sft->appctx = sink_forward_session_create(sink, sft);
                                else if (task->expire == TICK_ETERNITY)
                                        task->expire = tempo;