From d465610ec3ea46ceb40309e83e72e20997759b50 Mon Sep 17 00:00:00 2001 From: Willy Tarreau Date: Tue, 6 Aug 2024 16:44:33 +0200 Subject: [PATCH] MEDIUM: trace: implement a "follow" mechanism With "follow" from one source to another, it becomes possible for a source to automatically follow another source's tracked pointer. The best example is the session: - the "session" source is enabled and has a "lockon session" -> its lockon_ptr is equal to the session when valid - other sources (h1,h2,h3 etc) are configured for "follow session" and will then automatically check if session's lockon_ptr matches its own session, in which case tracing will be enabled for that trace (no state change). It's not necessary to start/pause/stop traces when using this, only "follow" followed by a source with lockon enabled is needed. Some combinations might work better than others. At the moment the session is almost never known from the backend, but this may improve. The meta-source "all" is supported for the follower so that all sources will follow the tracked one. --- doc/management.txt | 21 +++++++++++ include/haproxy/trace-t.h | 1 + include/haproxy/trace.h | 4 +- src/trace.c | 79 ++++++++++++++++++++++++++++++++++++++- 4 files changed, 101 insertions(+), 4 deletions(-) diff --git a/doc/management.txt b/doc/management.txt index 6187297248..a0daa262b1 100644 --- a/doc/management.txt +++ b/doc/management.txt @@ -3936,6 +3936,27 @@ trace event [ [+|-|!] ] One way to completely disable a trace source is to pass "event none", and this source will instantly be totally ignored. +trace follow + This permits the source to also emit traces when the other source + is locked on a criteria and the same criteria matches for the + current source as well. For example, if a source is locked on a session, + following that source from another one will make that other one emit traces + for all events related to this session. This may be used to some extents to + track backend requests along with the associated frontend connections. The + "session" source makes this easier by providing a "new" and an "end" events + that are usable for lock-on processing. Note that the source does + not need to have its traces enabled in this case, and its tracing state will + not be affected either. It is, however, possible that some events may be + missing if they do not contain information that allow to correlate them with + the tracked element. The meta-source "all" may also be used with this + command: in this case, all sources will follow . + + Example: + trace session lock session + trace session start sess_new + trace session pause sess_end + trace h1 follow session + trace level [] Without argument, this will list all trace levels for this source, and the current one will be indicated by a star ('*') prepended in front of it. With diff --git a/include/haproxy/trace-t.h b/include/haproxy/trace-t.h index 322fccdcec..8cd912ef26 100644 --- a/include/haproxy/trace-t.h +++ b/include/haproxy/trace-t.h @@ -167,6 +167,7 @@ struct trace_source { /* trace state part below */ enum trace_state state; const void *lockon_ptr; // what to lockon when lockon is set + const struct trace_source *follow; // other trace source's tracker to follow }; #endif /* _HAPROXY_TRACE_T_H */ diff --git a/include/haproxy/trace.h b/include/haproxy/trace.h index 703ac8dbde..f6749160ce 100644 --- a/include/haproxy/trace.h +++ b/include/haproxy/trace.h @@ -45,7 +45,7 @@ * preparation processing. */ #define _trace_enabled(level, mask, src, args...) \ - (unlikely((src)->state != TRACE_STATE_STOPPED && \ + (unlikely(((src)->state != TRACE_STATE_STOPPED || (src)->follow) && \ __trace_enabled(level, mask, src, ##args, NULL) > 0)) /* sends a trace for the given source. Arguments are passed in the exact same @@ -54,7 +54,7 @@ */ #define _trace(level, mask, src, args...) \ do { \ - if (unlikely((src)->state != TRACE_STATE_STOPPED)) \ + if (unlikely((src)->state != TRACE_STATE_STOPPED || (src)->follow)) \ __trace(level, mask, src, ##args); \ } while (0) diff --git a/src/trace.c b/src/trace.c index 5a8891b53a..e328e5fe64 100644 --- a/src/trace.c +++ b/src/trace.c @@ -101,8 +101,12 @@ int __trace_enabled(enum trace_level level, uint64_t mask, struct trace_source * const struct quic_conn *qc = NULL; const struct appctx *appctx = NULL; const void *lockon_ptr = NULL; + const struct trace_source *origin = NULL; - if (likely(src->state == TRACE_STATE_STOPPED)) + /* in case we also follow another one (e.g. session) */ + origin = HA_ATOMIC_LOAD(&src->follow); + + if (likely(src->state == TRACE_STATE_STOPPED) && !origin) return 0; /* check that at least one action is interested by this event */ @@ -209,6 +213,34 @@ int __trace_enabled(enum trace_level level, uint64_t mask, struct trace_source * *plockptr = lockon_ptr; } + /* or we may also follow another source's locked pointer */ + if (origin) { + if (!origin->lockon_ptr) + return 0; + + switch (origin->lockon) { + case TRACE_LOCKON_BACKEND: lockon_ptr = be; break; + case TRACE_LOCKON_CONNECTION: lockon_ptr = conn; break; + case TRACE_LOCKON_FRONTEND: lockon_ptr = fe; break; + case TRACE_LOCKON_LISTENER: lockon_ptr = li; break; + case TRACE_LOCKON_SERVER: lockon_ptr = srv; break; + case TRACE_LOCKON_SESSION: lockon_ptr = sess; break; + case TRACE_LOCKON_STREAM: lockon_ptr = strm; break; + case TRACE_LOCKON_CHECK: lockon_ptr = check; break; + case TRACE_LOCKON_THREAD: lockon_ptr = ti; break; + case TRACE_LOCKON_QCON: lockon_ptr = qc; break; + case TRACE_LOCKON_APPCTX: lockon_ptr = appctx; break; + case TRACE_LOCKON_ARG1: lockon_ptr = a1; break; + case TRACE_LOCKON_ARG2: lockon_ptr = a2; break; + case TRACE_LOCKON_ARG3: lockon_ptr = a3; break; + case TRACE_LOCKON_ARG4: lockon_ptr = a4; break; + default: break; // silence stupid gcc -Wswitch + } + + if (origin->lockon_ptr != lockon_ptr) + return 0; + } + /* here the trace is running and is tracking a desired item */ if ((src->report_events & mask) == 0 || level > src->level) { /* tracking did match, and might have to be disabled */ @@ -434,7 +466,7 @@ static int trace_parse_statement(char **args, char **msg) chunk_printf(&trash, "Supported trace sources and states (.=stopped, w=waiting, R=running) :\n" " [.] 0 : not a source, will immediately stop all traces\n" - " [.] all : all sources below, only for 'sink' and 'level'\n" + " [.] all : all sources below, only for 'sink', 'level' and 'follow'\n" ); list_for_each_entry(src, &trace_sources, source_link) @@ -455,6 +487,7 @@ static int trace_parse_statement(char **args, char **msg) if (strcmp(args[1], "all") == 0) { if (*args[2] && + strcmp(args[2], "follow") != 0 && strcmp(args[2], "sink") != 0 && strcmp(args[2], "level") != 0) { memprintf(msg, "'%s' not applicable to meta-source 'all'", args[2]); @@ -476,6 +509,7 @@ static int trace_parse_statement(char **args, char **msg) //" filter : list/enable/disable generic filters\n" " level : list/set trace reporting level\n" " lock : automatic lock on thread/connection/stream/...\n" + " follow : passively follow another source's locked pointer (e.g. session)\n" " pause : pause and automatically restart after a specific event\n" " sink : list/set event sinks\n" " start : start immediately or after a specific event\n" @@ -484,6 +518,47 @@ static int trace_parse_statement(char **args, char **msg) *msg = strdup(*msg); return LOG_WARNING; } + else if (strcmp(args[2], "follow") == 0) { + const struct trace_source *origin = src ? HA_ATOMIC_LOAD(&src->follow) : NULL; + + if (!*args[3]) { + /* no arg => report the list of supported sources as a warning */ + if (origin) + chunk_printf(&trash, "Currently following source '%s'.\n", origin->name.ptr); + else if (src) + chunk_printf(&trash, "Not currently following any other source.\n"); + else + chunk_reset(&trash); + + chunk_appendf(&trash, + "Please specify another source to follow, among the following ones:\n" + " [.] none : follow no other source\n" + ); + + list_for_each_entry(origin, &trace_sources, source_link) + chunk_appendf(&trash, " [%c] %-10s : %s\n", trace_state_char(origin->state), origin->name.ptr, origin->desc); + + trash.area[trash.data] = 0; + *msg = strdup(trash.area); + return LOG_WARNING; + } + + origin = NULL; + if (strcmp(args[3], "none") != 0) { + origin = trace_find_source(args[3]); + if (!origin) { + memprintf(msg, "No such trace source '%s'", args[3]); + return LOG_ERR; + } + } + + if (src) + HA_ATOMIC_STORE(&src->follow, origin); + else + list_for_each_entry(src, &trace_sources, source_link) + if (src != origin) + HA_ATOMIC_STORE(&src->follow, origin); + } else if ((strcmp(args[2], "event") == 0 && (ev_ptr = &src->report_events)) || (strcmp(args[2], "pause") == 0 && (ev_ptr = &src->pause_events)) || (strcmp(args[2], "start") == 0 && (ev_ptr = &src->start_events)) ||