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.
This commit is contained in:
Frdric Lcaille 2020-11-10 16:18:03 +01:00 committed by Willy Tarreau
parent 7f8f6cb926
commit d865935f32

View File

@ -42,6 +42,7 @@
#include <haproxy/thread.h> #include <haproxy/thread.h>
#include <haproxy/time.h> #include <haproxy/time.h>
#include <haproxy/tools.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); struct dcache_tx_entry *i);
static inline void flush_dcache(struct peer *peer); 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) static const char *statuscode_str(int statuscode)
{ {
switch (statuscode) { switch (statuscode) {
@ -1352,6 +1416,7 @@ static int peer_treat_updatemsg(struct appctx *appctx, struct peer *p, int updt,
unsigned int data_type; unsigned int data_type;
void *data_ptr; void *data_ptr;
TRACE_ENTER(PEERS_EV_UPDTMSG, NULL, p);
/* Here we have data message */ /* Here we have data message */
if (!st) if (!st)
goto ignore_msg; 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); expire = MS_TO_TICKS(st->table->expire);
if (updt) { if (updt) {
if (msg_len < sizeof(update)) if (msg_len < sizeof(update)) {
TRACE_PROTO("malformed message", PEERS_EV_UPDTMSG, NULL, p);
goto malformed_exit; goto malformed_exit;
}
memcpy(&update, *msg_cur, sizeof(update)); memcpy(&update, *msg_cur, sizeof(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) { if (exp) {
size_t expire_sz = sizeof expire; 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; goto malformed_exit;
}
memcpy(&expire, *msg_cur, expire_sz); memcpy(&expire, *msg_cur, expire_sz);
*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; unsigned int to_read, to_store;
to_read = intdecode(msg_cur, msg_end); 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; goto malformed_free_newts;
}
to_store = MIN(to_read, st->table->key_size - 1); 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; goto malformed_free_newts;
}
memcpy(newts->key.key, *msg_cur, to_store); memcpy(newts->key.key, *msg_cur, to_store);
newts->key.key[to_store] = 0; 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) { else if (st->table->type == SMP_T_SINT) {
unsigned int netinteger; 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; goto malformed_free_newts;
}
memcpy(&netinteger, *msg_cur, sizeof(netinteger)); memcpy(&netinteger, *msg_cur, sizeof(netinteger));
netinteger = ntohl(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); *msg_cur += sizeof(netinteger);
} }
else { 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; goto malformed_free_newts;
}
memcpy(newts->key.key, *msg_cur, st->table->key_size); memcpy(newts->key.key, *msg_cur, st->table->key_size);
*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; continue;
decoded_int = intdecode(msg_cur, msg_end); 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; goto malformed_unlock;
}
switch (stktable_data_types[data_type].std_type) { switch (stktable_data_types[data_type].std_type) {
case STD_T_SINT: 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_tick = tick_add(now_ms, -decoded_int) & ~0x1;
data.curr_ctr = intdecode(msg_cur, msg_end); 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; goto malformed_unlock;
}
data.prev_ctr = intdecode(msg_cur, msg_end); 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; goto malformed_unlock;
}
data_ptr = stktable_data_ptr(st->table, ts, data_type); data_ptr = stktable_data_ptr(st->table, ts, data_type);
if (data_ptr) if (data_ptr)
@ -1492,16 +1587,24 @@ static int peer_treat_updatemsg(struct appctx *appctx, struct peer *p, int updt,
break; break;
} }
data_len = decoded_int; 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; goto malformed_unlock;
}
/* Compute the end of the current data, <msg_end> being at the end of /* Compute the end of the current data, <msg_end> being at the end of
* the entire message. * the entire message.
*/ */
end = *msg_cur + data_len; end = *msg_cur + data_len;
id = intdecode(msg_cur, end); 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; goto malformed_unlock;
}
dc = p->dcache; dc = p->dcache;
if (*msg_cur == end) { 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(); chunk = get_trash_chunk();
value_len = intdecode(msg_cur, end); value_len = intdecode(msg_cur, end);
if (!*msg_cur || *msg_cur + value_len > 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; goto malformed_unlock;
}
chunk_memcpy(chunk, *msg_cur, value_len); chunk_memcpy(chunk, *msg_cur, value_len);
chunk->area[chunk->data] = '\0'; 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); HA_RWLOCK_WRUNLOCK(STK_SESS_LOCK, &ts->lock);
stktable_touch_remote(st->table, ts, 1); stktable_touch_remote(st->table, ts, 1);
TRACE_LEAVE(PEERS_EV_UPDTMSG, NULL, p);
return 1; return 1;
ignore_msg: ignore_msg:
/* skip consumed message */ /* skip consumed message */
co_skip(si_oc(si), totl); co_skip(si_oc(si), totl);
TRACE_DEVEL("leaving in error", PEERS_EV_UPDTMSG);
return 0; return 0;
malformed_unlock: 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); HA_RWLOCK_WRUNLOCK(STK_SESS_LOCK, &ts->lock);
stktable_touch_remote(st->table, ts, 1); stktable_touch_remote(st->table, ts, 1);
appctx->st0 = PEER_SESS_ST_ERRPROTO; appctx->st0 = PEER_SESS_ST_ERRPROTO;
TRACE_DEVEL("leaving in error", PEERS_EV_UPDTMSG);
return 0; return 0;
malformed_free_newts: 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); stksess_free(st->table, newts);
malformed_exit: malformed_exit:
appctx->st0 = PEER_SESS_ST_ERRPROTO; appctx->st0 = PEER_SESS_ST_ERRPROTO;
TRACE_DEVEL("leaving in error", PEERS_EV_UPDTMSG);
return 0; return 0;
} }