MINOR: peers: Add traces to peer_treat_updatemsg().

Add minimalistic traces for peers with only one event to diagnose potential
issues when decode peer update messages.

diff --git a/src/peers.c b/src/peers.c
index aac015a23cbce363b02576e3164e4f4a3a5cba6f..276e5cece59c92a2e0538c9b91c1e58cd5e22617 100644 (file)
--- a/src/peers.c
+++ b/src/peers.c
@@ -42,6 +42,7 @@
 #include <haproxy/thread.h>
 #include <haproxy/time.h>
 #include <haproxy/tools.h>
+#include <haproxy/trace.h>
 
 
 /*******************************/
@@ -288,6 +289,69 @@ static struct ebpt_node *dcache_tx_insert(struct dcache *dc,
                                           struct dcache_tx_entry *i);
 static inline void flush_dcache(struct peer *peer);
 
+/* trace source and events */
+static void peers_trace(enum trace_level level, uint64_t mask,
+                        const struct trace_source *src,
+                        const struct ist where, const struct ist func,
+                        const void *a1, const void *a2, const void *a3, const void *a4);
+
+static const struct trace_event peers_trace_events[] = {
+#define PEERS_EV_UPDTMSG         (1 << 0)
+       { .mask = PEERS_EV_UPDTMSG,    .name = "updtmsg",      .desc = "update message received" },
+};
+
+static const struct name_desc peers_trace_lockon_args[4] = {
+       /* arg1 */ { /* already used by the connection */ },
+       /* arg2 */ { .name="peers", .desc="Peers protocol" },
+       /* arg3 */ { },
+       /* arg4 */ { }
+};
+
+static const struct name_desc peers_trace_decoding[] = {
+#define PEERS_VERB_CLEAN    1
+       { .name="clean",    .desc="only user-friendly stuff, generally suitable for level \"user\"" },
+       { /* end */ }
+};
+
+
+struct trace_source trace_peers = {
+       .name = IST("peers"),
+       .desc = "Peers protocol",
+       .arg_def = TRC_ARG1_CONN,  /* TRACE()'s first argument is always a connection */
+       .default_cb = peers_trace,
+       .known_events = peers_trace_events,
+       .lockon_args = peers_trace_lockon_args,
+       .decoding = peers_trace_decoding,
+       .report_events = ~0,  /* report everything by default */
+};
+
+#define TRACE_SOURCE    &trace_peers
+INITCALL1(STG_REGISTER, trace_register_source, TRACE_SOURCE);
+
+static void peers_trace(enum trace_level level, uint64_t mask,
+                        const struct trace_source *src,
+                        const struct ist where, const struct ist func,
+                        const void *a1, const void *a2, const void *a3, const void *a4)
+{
+       if (mask & PEERS_EV_UPDTMSG) {
+               if (a2) {
+                       const struct peer *peer = a2;
+
+                       chunk_appendf(&trace_buf, " peer=%s", peer->id);
+               }
+               if (a3) {
+                       const char *p = a3;
+
+                       chunk_appendf(&trace_buf, " @%p", p);
+               }
+               if (a4) {
+                       const size_t *val = a4;
+
+                       chunk_appendf(&trace_buf, " %llu", (unsigned long long)*val);
+               }
+       }
+}
+
 static const char *statuscode_str(int statuscode)
 {
        switch (statuscode) {
@@ -1352,6 +1416,7 @@ static int peer_treat_updatemsg(struct appctx *appctx, struct peer *p, int updt,
        unsigned int data_type;
        void *data_ptr;
 
+       TRACE_ENTER(PEERS_EV_UPDTMSG, NULL, p);
        /* Here we have data message */
        if (!st)
                goto ignore_msg;
@@ -1359,8 +1424,10 @@ static int peer_treat_updatemsg(struct appctx *appctx, struct peer *p, int updt,
        expire = MS_TO_TICKS(st->table->expire);
 
        if (updt) {
-               if (msg_len < sizeof(update))
+               if (msg_len < sizeof(update)) {
+                       TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG, NULL, p);
                        goto malformed_exit;
+               }
 
                memcpy(&update, *msg_cur, sizeof(update));
                *msg_cur += sizeof(update);
@@ -1373,8 +1440,13 @@ static int peer_treat_updatemsg(struct appctx *appctx, struct peer *p, int updt,
        if (exp) {
                size_t expire_sz = sizeof expire;
 
-               if (*msg_cur + expire_sz > msg_end)
+               if (*msg_cur + expire_sz > msg_end) {
+                       TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG,
+                                   NULL, p, *msg_cur);
+                       TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG,
+                                   NULL, p, msg_end, &expire_sz);
                        goto malformed_exit;
+               }
 
                memcpy(&expire, *msg_cur, expire_sz);
                *msg_cur += expire_sz;
@@ -1389,12 +1461,19 @@ static int peer_treat_updatemsg(struct appctx *appctx, struct peer *p, int updt,
                unsigned int to_read, to_store;
 
                to_read = intdecode(msg_cur, msg_end);
-               if (!*msg_cur)
+               if (!*msg_cur) {
+                       TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG, NULL, p);
                        goto malformed_free_newts;
+               }
 
                to_store = MIN(to_read, st->table->key_size - 1);
-               if (*msg_cur + to_store > msg_end)
+               if (*msg_cur + to_store > msg_end) {
+                       TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG,
+                                   NULL, p, *msg_cur);
+                       TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG,
+                                   NULL, p, msg_end, &to_store);
                        goto malformed_free_newts;
+               }
 
                memcpy(newts->key.key, *msg_cur, to_store);
                newts->key.key[to_store] = 0;
@@ -1403,8 +1482,13 @@ static int peer_treat_updatemsg(struct appctx *appctx, struct peer *p, int updt,
        else if (st->table->type == SMP_T_SINT) {
                unsigned int netinteger;
 
-               if (*msg_cur + sizeof(netinteger) > msg_end)
+               if (*msg_cur + sizeof(netinteger) > msg_end) {
+                       TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG,
+                                   NULL, p, *msg_cur);
+                       TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG,
+                                   NULL, p, msg_end);
                        goto malformed_free_newts;
+               }
 
                memcpy(&netinteger, *msg_cur, sizeof(netinteger));
                netinteger = ntohl(netinteger);
@@ -1412,8 +1496,13 @@ static int peer_treat_updatemsg(struct appctx *appctx, struct peer *p, int updt,
                *msg_cur += sizeof(netinteger);
        }
        else {
-               if (*msg_cur + st->table->key_size > msg_end)
+               if (*msg_cur + st->table->key_size > msg_end) {
+                       TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG,
+                                   NULL, p, *msg_cur);
+                       TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG,
+                                   NULL, p, msg_end, &st->table->key_size);
                        goto malformed_free_newts;
+               }
 
                memcpy(newts->key.key, *msg_cur, st->table->key_size);
                *msg_cur += st->table->key_size;
@@ -1435,8 +1524,10 @@ static int peer_treat_updatemsg(struct appctx *appctx, struct peer *p, int updt,
                        continue;
 
                decoded_int = intdecode(msg_cur, msg_end);
-               if (!*msg_cur)
+               if (!*msg_cur) {
+                       TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG, NULL, p);
                        goto malformed_unlock;
+               }
 
                switch (stktable_data_types[data_type].std_type) {
                case STD_T_SINT:
@@ -1467,12 +1558,16 @@ static int peer_treat_updatemsg(struct appctx *appctx, struct peer *p, int updt,
 
                        data.curr_tick = tick_add(now_ms, -decoded_int) & ~0x1;
                        data.curr_ctr = intdecode(msg_cur, msg_end);
-                       if (!*msg_cur)
+                       if (!*msg_cur) {
+                               TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG, NULL, p);
                                goto malformed_unlock;
+                       }
 
                        data.prev_ctr = intdecode(msg_cur, msg_end);
-                       if (!*msg_cur)
+                       if (!*msg_cur) {
+                               TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG, NULL, p);
                                goto malformed_unlock;
+                       }
 
                        data_ptr = stktable_data_ptr(st->table, ts, data_type);
                        if (data_ptr)
@@ -1492,16 +1587,24 @@ static int peer_treat_updatemsg(struct appctx *appctx, struct peer *p, int updt,
                                break;
                        }
                        data_len = decoded_int;
-                       if (*msg_cur + data_len > msg_end)
+                       if (*msg_cur + data_len > msg_end) {
+                               TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG,
+                                           NULL, p, *msg_cur);
+                               TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG,
+                                           NULL, p, msg_end, &data_len);
                                goto malformed_unlock;
+                       }
 
                        /* Compute the end of the current data, <msg_end> being at the end of
                         * the entire message.
                         */
                        end = *msg_cur + data_len;
                        id = intdecode(msg_cur, end);
-                       if (!*msg_cur || !id)
+                       if (!*msg_cur || !id) {
+                               TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG,
+                                           NULL, p, *msg_cur, &id);
                                goto malformed_unlock;
+                       }
 
                        dc = p->dcache;
                        if (*msg_cur == end) {
@@ -1515,8 +1618,13 @@ static int peer_treat_updatemsg(struct appctx *appctx, struct peer *p, int updt,
                                chunk = get_trash_chunk();
                                value_len = intdecode(msg_cur, end);
                                if (!*msg_cur || *msg_cur + value_len > end ||
-                                       unlikely(value_len + 1 >= chunk->size))
+                                       unlikely(value_len + 1 >= chunk->size)) {
+                                       TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG,
+                                                   NULL, p, *msg_cur, &value_len);
+                                       TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG,
+                                                   NULL, p, end, &chunk->size);
                                        goto malformed_unlock;
+                               }
 
                                chunk_memcpy(chunk, *msg_cur, value_len);
                                chunk->area[chunk->data] = '\0';
@@ -1539,11 +1647,13 @@ static int peer_treat_updatemsg(struct appctx *appctx, struct peer *p, int updt,
 
        HA_RWLOCK_WRUNLOCK(STK_SESS_LOCK, &ts->lock);
        stktable_touch_remote(st->table, ts, 1);
+       TRACE_LEAVE(PEERS_EV_UPDTMSG, NULL, p);
        return 1;
 
  ignore_msg:
        /* skip consumed message */
        co_skip(si_oc(si), totl);
+       TRACE_DEVEL("leaving in error", PEERS_EV_UPDTMSG);
        return 0;
 
  malformed_unlock:
@@ -1551,6 +1661,7 @@ static int peer_treat_updatemsg(struct appctx *appctx, struct peer *p, int updt,
        HA_RWLOCK_WRUNLOCK(STK_SESS_LOCK, &ts->lock);
        stktable_touch_remote(st->table, ts, 1);
        appctx->st0 = PEER_SESS_ST_ERRPROTO;
+       TRACE_DEVEL("leaving in error", PEERS_EV_UPDTMSG);
        return 0;
 
  malformed_free_newts:
@@ -1558,6 +1669,7 @@ static int peer_treat_updatemsg(struct appctx *appctx, struct peer *p, int updt,
        stksess_free(st->table, newts);
  malformed_exit:
        appctx->st0 = PEER_SESS_ST_ERRPROTO;
+       TRACE_DEVEL("leaving in error", PEERS_EV_UPDTMSG);
        return 0;
 }