blob: 27b4afc4ddc9dd990d0f41202d3fc1fd5fd77f4f [file] [log] [blame]
Willy Tarreau4151c752019-08-08 18:21:26 +02001/*
2 * Runtime tracing API
3 *
4 * Copyright (C) 2000-2019 Willy Tarreau - w@1wt.eu
5 *
6 * This library is free software; you can redistribute it and/or
7 * modify it under the terms of the GNU Lesser General Public
8 * License as published by the Free Software Foundation, version 2.1
9 * exclusively.
10 *
11 * This library is distributed in the hope that it will be useful,
12 * but WITHOUT ANY WARRANTY; without even the implied warranty of
13 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU
14 * Lesser General Public License for more details.
15 *
16 * You should have received a copy of the GNU Lesser General Public
17 * License along with this library; if not, write to the Free Software
18 * Foundation, Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA
19 */
20
Willy Tarreaueb6f7012020-05-27 16:21:26 +020021#include <import/ist.h>
Willy Tarreau2741c8c2020-06-02 11:28:02 +020022#include <haproxy/api.h>
23#include <haproxy/buf.h>
Willy Tarreau9fd05422022-11-16 17:29:12 +010024#include <haproxy/cfgparse.h>
Willy Tarreau83487a82020-06-04 20:19:54 +020025#include <haproxy/cli.h>
Willy Tarreau36979d92020-06-05 17:27:29 +020026#include <haproxy/errors.h>
Willy Tarreau2741c8c2020-06-02 11:28:02 +020027#include <haproxy/istbuf.h>
Willy Tarreau853b2972020-05-27 18:01:47 +020028#include <haproxy/list.h>
Willy Tarreauaeed4a82020-06-04 22:01:04 +020029#include <haproxy/log.h>
Willy Tarreauba2f73d2020-06-03 20:02:28 +020030#include <haproxy/sink.h>
Willy Tarreauc6d61d72020-06-04 19:02:42 +020031#include <haproxy/trace.h>
Willy Tarreau4151c752019-08-08 18:21:26 +020032
33struct list trace_sources = LIST_HEAD_INIT(trace_sources);
Willy Tarreau88ebd402019-08-19 15:55:34 +020034THREAD_LOCAL struct buffer trace_buf = { };
35
36/* allocates the trace buffers. Returns 0 in case of failure. It is safe to
37 * call to call this function multiple times if the size changes.
38 */
39static int alloc_trace_buffers_per_thread()
40{
41 chunk_init(&trace_buf, my_realloc2(trace_buf.area, global.tune.bufsize), global.tune.bufsize);
Willy Tarreau2e7fdfc2019-11-25 19:43:31 +010042 return !!trace_buf.area;
Willy Tarreau88ebd402019-08-19 15:55:34 +020043}
44
45static void free_trace_buffers_per_thread()
46{
47 chunk_destroy(&trace_buf);
48}
Willy Tarreau4151c752019-08-08 18:21:26 +020049
Willy Tarreau88ebd402019-08-19 15:55:34 +020050REGISTER_PER_THREAD_ALLOC(alloc_trace_buffers_per_thread);
51REGISTER_PER_THREAD_FREE(free_trace_buffers_per_thread);
Willy Tarreau864e8802019-08-08 18:48:12 +020052
Willy Tarreaud8b99ed2019-08-21 17:05:46 +020053/* pick the lowest non-null argument with a non-null arg_def mask */
54static inline const void *trace_pick_arg(uint32_t arg_def, const void *a1, const void *a2, const void *a3, const void *a4)
55{
56 if (arg_def & 0x0000FFFF) {
57 if ((arg_def & 0x000000FF) && a1)
58 return a1;
59 if ((arg_def & 0x0000FF00) && a2)
60 return a2;
61 }
62
63 if (arg_def & 0xFFFF0000) {
64 if ((arg_def & 0x00FF0000) && a3)
65 return a3;
66 if ((arg_def & 0xFF000000) && a4)
67 return a4;
68 }
69
70 return NULL;
71}
72
Willy Tarreau8f9a9702023-01-24 17:48:53 +010073/* Reports whether the trace is enabled for the specified arguments, needs to enable
74 * or disable tracking. It gets the same API as __trace() except for <cb> and <msg>
75 * which are not used and were dropped, and plockptr which is an optional pointer to
76 * the lockptr to be updated (or NULL) for tracking. The function returns:
77 * 0 if the trace is not enabled for the module or these values
78 * <0 if the trace matches some locking criteria but don't have the proper level.
79 * In this case the interested caller might have to consider disabling tracking.
80 * >0 if the trace is enabled for the given criteria.
81 * In all cases, <plockptr> will only be set if non-null and if a locking criterion
82 * matched. It will be up to the caller to enable tracking if desired. A casual
83 * tester not interested in adjusting tracking (i.e. calling the function before
84 * deciding so prepare a buffer to be dumped) will only need to pass 0 for plockptr
85 * and check if the result is >0.
86 */
87int __trace_enabled(enum trace_level level, uint64_t mask, struct trace_source *src,
88 const struct ist where, const char *func,
89 const void *a1, const void *a2, const void *a3, const void *a4,
90 const void **plockptr)
Willy Tarreau4c2ae482019-08-12 15:51:58 +020091{
Willy Tarreaud8b99ed2019-08-21 17:05:46 +020092 const struct listener *li = NULL;
93 const struct proxy *fe = NULL;
94 const struct proxy *be = NULL;
95 const struct server *srv = NULL;
96 const struct session *sess = NULL;
97 const struct stream *strm = NULL;
98 const struct connection *conn = NULL;
Christopher Faulet6d80b632021-04-12 11:53:16 +020099 const struct check *check = NULL;
Amaury Denoyellebaea9642021-12-21 11:26:02 +0100100 const struct quic_conn *qc = NULL;
Christopher Faulet26e09352023-03-29 17:42:28 +0200101 const struct appctx *appctx = NULL;
Willy Tarreaud8b99ed2019-08-21 17:05:46 +0200102 const void *lockon_ptr = NULL;
Willy Tarreau419bd492019-08-12 17:27:09 +0200103
Willy Tarreau4c2ae482019-08-12 15:51:58 +0200104 if (likely(src->state == TRACE_STATE_STOPPED))
Willy Tarreau8f9a9702023-01-24 17:48:53 +0100105 return 0;
Willy Tarreau4c2ae482019-08-12 15:51:58 +0200106
107 /* check that at least one action is interested by this event */
108 if (((src->report_events | src->start_events | src->pause_events | src->stop_events) & mask) == 0)
Willy Tarreau8f9a9702023-01-24 17:48:53 +0100109 return 0;
Willy Tarreau4c2ae482019-08-12 15:51:58 +0200110
Willy Tarreaud8b99ed2019-08-21 17:05:46 +0200111 /* retrieve available information from the caller's arguments */
112 if (src->arg_def & TRC_ARGS_CONN)
113 conn = trace_pick_arg(src->arg_def & TRC_ARGS_CONN, a1, a2, a3, a4);
114
115 if (src->arg_def & TRC_ARGS_SESS)
116 sess = trace_pick_arg(src->arg_def & TRC_ARGS_SESS, a1, a2, a3, a4);
117
118 if (src->arg_def & TRC_ARGS_STRM)
119 strm = trace_pick_arg(src->arg_def & TRC_ARGS_STRM, a1, a2, a3, a4);
120
Christopher Faulet6d80b632021-04-12 11:53:16 +0200121 if (src->arg_def & TRC_ARGS_CHK)
122 check = trace_pick_arg(src->arg_def & TRC_ARGS_CHK, a1, a2, a3, a4);
123
Amaury Denoyellebaea9642021-12-21 11:26:02 +0100124 if (src->arg_def & TRC_ARGS_QCON)
125 qc = trace_pick_arg(src->arg_def & TRC_ARGS_QCON, a1, a2, a3, a4);
Amaury Denoyellebaea9642021-12-21 11:26:02 +0100126
Christopher Faulet26e09352023-03-29 17:42:28 +0200127 if (src->arg_def & TRC_ARGS_APPCTX)
128 appctx = trace_pick_arg(src->arg_def & TRC_ARGS_APPCTX, a1, a2, a3, a4);
129
Willy Tarreaud8b99ed2019-08-21 17:05:46 +0200130 if (!sess && strm)
131 sess = strm->sess;
Willy Tarreau6e805da2022-03-18 17:37:20 +0100132 else if (!sess && conn && LIST_INLIST(&conn->session_list))
Willy Tarreaud8b99ed2019-08-21 17:05:46 +0200133 sess = conn->owner;
Christopher Faulet6d80b632021-04-12 11:53:16 +0200134 else if (!sess && check)
135 sess = check->sess;
Christopher Faulet26e09352023-03-29 17:42:28 +0200136 else if (!sess && appctx)
137 sess = appctx->sess;
Willy Tarreaud8b99ed2019-08-21 17:05:46 +0200138
139 if (sess) {
140 fe = sess->fe;
141 li = sess->listener;
142 }
143
144 if (!li && conn)
145 li = objt_listener(conn->target);
146
147 if (li && !fe)
148 fe = li->bind_conf->frontend;
149
150 if (strm) {
151 be = strm->be;
152 srv = strm->srv_conn;
153 }
Christopher Faulet6d80b632021-04-12 11:53:16 +0200154 if (check) {
155 srv = check->server;
Christopher Faulete3b25742022-06-08 09:06:15 +0200156 be = (srv ? srv->proxy : NULL);
Christopher Faulet6d80b632021-04-12 11:53:16 +0200157 }
Willy Tarreaud8b99ed2019-08-21 17:05:46 +0200158
159 if (!srv && conn)
160 srv = objt_server(conn->target);
161
162 if (srv && !be)
163 be = srv->proxy;
164
165 if (!be && conn)
166 be = objt_proxy(conn->target);
167
Willy Tarreau4c2ae482019-08-12 15:51:58 +0200168 /* TODO: add handling of filters here, return if no match (not even update states) */
169
170 /* check if we need to start the trace now */
171 if (src->state == TRACE_STATE_WAITING) {
172 if ((src->start_events & mask) == 0)
Willy Tarreau8f9a9702023-01-24 17:48:53 +0100173 return 0;
Willy Tarreau4c2ae482019-08-12 15:51:58 +0200174
175 /* TODO: add update of lockon+lockon_ptr here */
176 HA_ATOMIC_STORE(&src->state, TRACE_STATE_RUNNING);
177 }
178
Willy Tarreaud8b99ed2019-08-21 17:05:46 +0200179 /* we may want to lock on a particular object */
180 if (src->lockon != TRACE_LOCKON_NOTHING) {
181 switch (src->lockon) {
Christopher Faulet26e09352023-03-29 17:42:28 +0200182 case TRACE_LOCKON_BACKEND: lockon_ptr = be; break;
183 case TRACE_LOCKON_CONNECTION: lockon_ptr = conn; break;
184 case TRACE_LOCKON_FRONTEND: lockon_ptr = fe; break;
185 case TRACE_LOCKON_LISTENER: lockon_ptr = li; break;
186 case TRACE_LOCKON_SERVER: lockon_ptr = srv; break;
187 case TRACE_LOCKON_SESSION: lockon_ptr = sess; break;
188 case TRACE_LOCKON_STREAM: lockon_ptr = strm; break;
189 case TRACE_LOCKON_CHECK: lockon_ptr = check; break;
190 case TRACE_LOCKON_THREAD: lockon_ptr = ti; break;
191 case TRACE_LOCKON_QCON: lockon_ptr = qc; break;
192 case TRACE_LOCKON_APPCTX: lockon_ptr = appctx; break;
193 case TRACE_LOCKON_ARG1: lockon_ptr = a1; break;
194 case TRACE_LOCKON_ARG2: lockon_ptr = a2; break;
195 case TRACE_LOCKON_ARG3: lockon_ptr = a3; break;
196 case TRACE_LOCKON_ARG4: lockon_ptr = a4; break;
Willy Tarreaud8b99ed2019-08-21 17:05:46 +0200197 default: break; // silence stupid gcc -Wswitch
198 }
199
200 if (src->lockon_ptr && src->lockon_ptr != lockon_ptr)
Willy Tarreau8f9a9702023-01-24 17:48:53 +0100201 return 0;
Willy Tarreaud8b99ed2019-08-21 17:05:46 +0200202
Willy Tarreau8f9a9702023-01-24 17:48:53 +0100203 if (*plockptr && !src->lockon_ptr && lockon_ptr && src->state == TRACE_STATE_RUNNING)
204 *plockptr = lockon_ptr;
Willy Tarreaud8b99ed2019-08-21 17:05:46 +0200205 }
206
Willy Tarreau4c2ae482019-08-12 15:51:58 +0200207 /* here the trace is running and is tracking a desired item */
Willy Tarreau8f9a9702023-01-24 17:48:53 +0100208 if ((src->report_events & mask) == 0 || level > src->level) {
209 /* tracking did match, and might have to be disabled */
210 return -1;
211 }
Willy Tarreau4c2ae482019-08-12 15:51:58 +0200212
Willy Tarreau8f9a9702023-01-24 17:48:53 +0100213 /* OK trace still enabled */
214 return 1;
215}
216
217/* write a message for the given trace source */
218void __trace(enum trace_level level, uint64_t mask, struct trace_source *src,
219 const struct ist where, const char *func,
220 const void *a1, const void *a2, const void *a3, const void *a4,
221 void (*cb)(enum trace_level level, uint64_t mask, const struct trace_source *src,
222 const struct ist where, const struct ist func,
223 const void *a1, const void *a2, const void *a3, const void *a4),
224 const struct ist msg)
225{
226 const void *lockon_ptr;
227 struct ist ist_func = ist(func);
228 char tnum[4];
229 struct ist line[12];
230 int words = 0;
231 int ret;
232
233 lockon_ptr = NULL;
234 ret = __trace_enabled(level, mask, src, where, func, a1, a2, a3, a4, &lockon_ptr);
235 if (lockon_ptr)
236 HA_ATOMIC_STORE(&src->lockon_ptr, lockon_ptr);
237
238 if (ret <= 0) {
239 if (ret < 0) // may have to disable tracking
240 goto end;
241 return;
242 }
Willy Tarreau4c2ae482019-08-12 15:51:58 +0200243
Willy Tarreau419bd492019-08-12 17:27:09 +0200244 /* log the logging location truncated to 10 chars from the right so that
245 * the line number and the end of the file name are there.
246 */
Willy Tarreau09fb0df2019-08-29 08:40:59 +0200247 line[words++] = ist("[");
Willy Tarreaua9f5b962019-08-28 10:08:58 +0200248 tnum[0] = '0' + tid / 10;
249 tnum[1] = '0' + tid % 10;
250 tnum[2] = '|';
251 tnum[3] = 0;
Willy Tarreau09fb0df2019-08-29 08:40:59 +0200252 line[words++] = ist(tnum);
253 line[words++] = src->name;
254 line[words++] = ist("|");
Frédéric Lécaillefd183142020-12-02 16:51:00 +0100255 line[words++] = ist2("012345" + level, 1); // "0" to "5"
Willy Tarreau052ad362019-08-29 09:08:36 +0200256 line[words++] = ist("|");
Willy Tarreau09fb0df2019-08-29 08:40:59 +0200257 line[words] = where;
258 if (line[words].len > 13) {
259 line[words].ptr += (line[words].len - 13);
260 line[words].len = 13;
Willy Tarreau419bd492019-08-12 17:27:09 +0200261 }
Willy Tarreau09fb0df2019-08-29 08:40:59 +0200262 words++;
263 line[words++] = ist("] ");
264
Tim Duesterhus7b5777d2021-03-02 18:57:28 +0100265 if (isttest(ist_func)) {
Willy Tarreau09fb0df2019-08-29 08:40:59 +0200266 line[words++] = ist_func;
267 line[words++] = ist("(): ");
268 }
Willy Tarreaubfd14fc2019-08-19 16:28:07 +0200269
Willy Tarreau3da00262019-08-28 07:03:58 +0200270 if (!cb)
271 cb = src->default_cb;
272
Willy Tarreau370a6942019-08-29 08:24:16 +0200273 if (cb && src->verbosity) {
Willy Tarreaubfd14fc2019-08-19 16:28:07 +0200274 /* decode function passed, we want to pre-fill the
275 * buffer with the message and let the decode function
276 * do its job, possibly even overwriting it.
277 */
278 b_reset(&trace_buf);
279 b_istput(&trace_buf, msg);
Willy Tarreau09fb0df2019-08-29 08:40:59 +0200280 cb(level, mask, src, where, ist_func, a1, a2, a3, a4);
Tim Duesterhus92c696e2021-02-28 16:11:36 +0100281 line[words] = ist2(trace_buf.area, trace_buf.data);
Willy Tarreau09fb0df2019-08-29 08:40:59 +0200282 words++;
Willy Tarreaubfd14fc2019-08-19 16:28:07 +0200283 }
Willy Tarreau370a6942019-08-29 08:24:16 +0200284 else {
285 /* Note that here we could decide to print some args whose type
286 * is known, when verbosity is above the quiet level, and even
287 * to print the name and values of those which are declared for
288 * lock-on.
289 */
Willy Tarreau09fb0df2019-08-29 08:40:59 +0200290 line[words++] = msg;
Willy Tarreau370a6942019-08-29 08:24:16 +0200291 }
Willy Tarreau419bd492019-08-12 17:27:09 +0200292
Willy Tarreau4c2ae482019-08-12 15:51:58 +0200293 if (src->sink)
Emeric Brun54648852020-07-06 15:54:06 +0200294 sink_write(src->sink, line, words, 0, 0, NULL);
Willy Tarreau4c2ae482019-08-12 15:51:58 +0200295
296 end:
297 /* check if we need to stop the trace now */
298 if ((src->stop_events & mask) != 0) {
Willy Tarreaubeadb5c2019-08-20 18:57:48 +0200299 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
Willy Tarreau4c2ae482019-08-12 15:51:58 +0200300 HA_ATOMIC_STORE(&src->state, TRACE_STATE_STOPPED);
301 }
302 else if ((src->pause_events & mask) != 0) {
Willy Tarreaubeadb5c2019-08-20 18:57:48 +0200303 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
Willy Tarreau4c2ae482019-08-12 15:51:58 +0200304 HA_ATOMIC_STORE(&src->state, TRACE_STATE_WAITING);
305 }
306}
307
Willy Tarreau4b36d5e2023-01-24 18:03:07 +0100308/* this callback may be used when no output modification is desired */
309void trace_no_cb(enum trace_level level, uint64_t mask, const struct trace_source *src,
310 const struct ist where, const struct ist func,
311 const void *a1, const void *a2, const void *a3, const void *a4)
312{
313 /* do nothing */
314}
315
Willy Tarreau4de2cda2022-03-02 14:53:00 +0100316/* registers trace source <source>. Modifies the list element!
317 * The {start,pause,stop,report} events are not changed so the source may
318 * preset them.
319 */
320void trace_register_source(struct trace_source *source)
321{
322 source->lockon = TRACE_LOCKON_NOTHING;
323 source->level = TRACE_LEVEL_USER;
324 source->verbosity = 1;
325 source->sink = NULL;
326 source->state = TRACE_STATE_STOPPED;
327 source->lockon_ptr = NULL;
328 LIST_APPEND(&trace_sources, &source->source_link);
329}
330
Willy Tarreau864e8802019-08-08 18:48:12 +0200331struct trace_source *trace_find_source(const char *name)
332{
333 struct trace_source *src;
334 const struct ist iname = ist(name);
335
336 list_for_each_entry(src, &trace_sources, source_link)
337 if (isteq(src->name, iname))
338 return src;
339 return NULL;
340}
341
342const struct trace_event *trace_find_event(const struct trace_event *ev, const char *name)
343{
344 for (; ev && ev->mask; ev++)
345 if (strcmp(ev->name, name) == 0)
346 return ev;
347 return NULL;
348}
349
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100350/* Parse a "trace" statement. Returns a severity as a LOG_* level and a status
351 * message that may be delivered to the user, in <msg>. The message will be
352 * nulled first and msg must be a valid pointer. A null status message output
353 * indicates no error. Be careful not to use the return value as a boolean, as
354 * LOG_* values are not ordered as one could imagine (LOG_EMERG is zero). The
355 * function may/will use the trash buffer as the storage for the response
356 * message so that the caller never needs to release anything.
357 */
358static int trace_parse_statement(char **args, const char **msg)
Willy Tarreau864e8802019-08-08 18:48:12 +0200359{
360 struct trace_source *src;
361 uint64_t *ev_ptr = NULL;
362
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100363 /* no error by default */
364 *msg = NULL;
Willy Tarreau864e8802019-08-08 18:48:12 +0200365
366 if (!*args[1]) {
367 /* no arg => report the list of supported sources as a warning */
368 chunk_printf(&trash,
369 "Supported trace sources and states (.=stopped, w=waiting, R=running) :\n"
370 " [.] 0 : not a source, will immediately stop all traces\n"
371 );
372
373 list_for_each_entry(src, &trace_sources, source_link)
374 chunk_appendf(&trash, " [%c] %-10s : %s\n", trace_state_char(src->state), src->name.ptr, src->desc);
375
376 trash.area[trash.data] = 0;
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100377 *msg = trash.area;
378 return LOG_WARNING;
Willy Tarreau864e8802019-08-08 18:48:12 +0200379 }
380
381 if (strcmp(args[1], "0") == 0) {
382 /* emergency stop of all traces */
383 list_for_each_entry(src, &trace_sources, source_link)
384 HA_ATOMIC_STORE(&src->state, TRACE_STATE_STOPPED);
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100385 *msg = "All traces now stopped";
386 return LOG_NOTICE;
Willy Tarreau864e8802019-08-08 18:48:12 +0200387 }
388
389 src = trace_find_source(args[1]);
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100390 if (!src) {
391 *msg = "No such trace source";
392 return LOG_ERR;
393 }
Willy Tarreau864e8802019-08-08 18:48:12 +0200394
395 if (!*args[2]) {
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100396 *msg = "Supported commands:\n"
397 " event : list/enable/disable source-specific event reporting\n"
398 //" filter : list/enable/disable generic filters\n"
399 " level : list/set trace reporting level\n"
400 " lock : automatic lock on thread/connection/stream/...\n"
401 " pause : pause and automatically restart after a specific event\n"
402 " sink : list/set event sinks\n"
403 " start : start immediately or after a specific event\n"
404 " stop : stop immediately or after a specific event\n"
405 " verbosity : list/set trace output verbosity\n";
406 return LOG_WARNING;
Willy Tarreau864e8802019-08-08 18:48:12 +0200407 }
408 else if ((strcmp(args[2], "event") == 0 && (ev_ptr = &src->report_events)) ||
409 (strcmp(args[2], "pause") == 0 && (ev_ptr = &src->pause_events)) ||
410 (strcmp(args[2], "start") == 0 && (ev_ptr = &src->start_events)) ||
411 (strcmp(args[2], "stop") == 0 && (ev_ptr = &src->stop_events))) {
412 const struct trace_event *ev;
413 const char *name = args[3];
414 int neg = 0;
415 int i;
416
417 /* skip prefix '!', '-', '+' and remind negation */
418 while (*name) {
419 if (*name == '!' || *name == '-')
420 neg = 1;
421 else if (*name == '+')
422 neg = 0;
423 else
424 break;
425 name++;
426 }
427
428 if (!*name) {
429 chunk_printf(&trash, "Supported events for source %s (+=enabled, -=disabled):\n", src->name.ptr);
430 if (ev_ptr != &src->report_events)
Willy Tarreau99282dd2019-08-30 07:37:32 +0200431 chunk_appendf(&trash, " - now : don't wait for events, immediately change the state\n");
432 chunk_appendf(&trash, " - none : disable all event types\n");
433 chunk_appendf(&trash, " - any : enable all event types\n");
Willy Tarreau864e8802019-08-08 18:48:12 +0200434 for (i = 0; src->known_events && src->known_events[i].mask; i++) {
Willy Tarreau99282dd2019-08-30 07:37:32 +0200435 chunk_appendf(&trash, " %c %-12s : %s\n",
Willy Tarreau864e8802019-08-08 18:48:12 +0200436 trace_event_char(*ev_ptr, src->known_events[i].mask),
437 src->known_events[i].name, src->known_events[i].desc);
438 }
439 trash.area[trash.data] = 0;
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100440 *msg = trash.area;
441 return LOG_WARNING;
Willy Tarreau864e8802019-08-08 18:48:12 +0200442 }
443
444 if (strcmp(name, "now") == 0 && ev_ptr != &src->report_events) {
445 HA_ATOMIC_STORE(ev_ptr, 0);
Willy Tarreaubeadb5c2019-08-20 18:57:48 +0200446 if (ev_ptr == &src->pause_events) {
447 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
Willy Tarreau864e8802019-08-08 18:48:12 +0200448 HA_ATOMIC_STORE(&src->state, TRACE_STATE_WAITING);
Willy Tarreaubeadb5c2019-08-20 18:57:48 +0200449 }
450 else if (ev_ptr == &src->start_events) {
Willy Tarreau864e8802019-08-08 18:48:12 +0200451 HA_ATOMIC_STORE(&src->state, TRACE_STATE_RUNNING);
Willy Tarreaubeadb5c2019-08-20 18:57:48 +0200452 }
453 else if (ev_ptr == &src->stop_events) {
454 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
Willy Tarreau864e8802019-08-08 18:48:12 +0200455 HA_ATOMIC_STORE(&src->state, TRACE_STATE_STOPPED);
Willy Tarreaubeadb5c2019-08-20 18:57:48 +0200456 }
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100457 *msg = NULL;
Willy Tarreau864e8802019-08-08 18:48:12 +0200458 return 0;
459 }
460
461 if (strcmp(name, "none") == 0)
462 HA_ATOMIC_STORE(ev_ptr, 0);
463 else if (strcmp(name, "any") == 0)
464 HA_ATOMIC_STORE(ev_ptr, ~0);
465 else {
466 ev = trace_find_event(src->known_events, name);
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100467 if (!ev) {
468 *msg = "No such trace event";
469 return LOG_ERR;
470 }
Willy Tarreau864e8802019-08-08 18:48:12 +0200471
472 if (!neg)
473 HA_ATOMIC_OR(ev_ptr, ev->mask);
474 else
475 HA_ATOMIC_AND(ev_ptr, ~ev->mask);
476 }
477 }
478 else if (strcmp(args[2], "sink") == 0) {
479 const char *name = args[3];
480 struct sink *sink;
481
482 if (!*name) {
483 chunk_printf(&trash, "Supported sinks for source %s (*=current):\n", src->name.ptr);
484 chunk_appendf(&trash, " %c none : no sink\n", src->sink ? ' ' : '*');
485 list_for_each_entry(sink, &sink_list, sink_list) {
486 chunk_appendf(&trash, " %c %-10s : %s\n",
487 src->sink == sink ? '*' : ' ',
488 sink->name, sink->desc);
489 }
490 trash.area[trash.data] = 0;
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100491 *msg = trash.area;
492 return LOG_WARNING;
Willy Tarreau864e8802019-08-08 18:48:12 +0200493 }
494
495 if (strcmp(name, "none") == 0)
496 sink = NULL;
497 else {
498 sink = sink_find(name);
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100499 if (!sink) {
500 *msg = "No such sink";
501 return LOG_ERR;
502 }
Willy Tarreau864e8802019-08-08 18:48:12 +0200503 }
504
505 HA_ATOMIC_STORE(&src->sink, sink);
506 }
Willy Tarreauaaaf4112019-08-12 17:57:57 +0200507 else if (strcmp(args[2], "level") == 0) {
508 const char *name = args[3];
509
510 if (!*name) {
Willy Tarreau2ea549b2019-08-29 08:01:48 +0200511 chunk_printf(&trash, "Supported trace levels for source %s:\n", src->name.ptr);
Willy Tarreaua1f12742020-12-01 09:46:46 +0100512 chunk_appendf(&trash, " %c error : report errors\n",
513 src->level == TRACE_LEVEL_ERROR ? '*' : ' ');
514 chunk_appendf(&trash, " %c user : also information useful to the end user\n",
Willy Tarreauaaaf4112019-08-12 17:57:57 +0200515 src->level == TRACE_LEVEL_USER ? '*' : ' ');
Willy Tarreau2ea549b2019-08-29 08:01:48 +0200516 chunk_appendf(&trash, " %c proto : also protocol-level updates\n",
Willy Tarreauaaaf4112019-08-12 17:57:57 +0200517 src->level == TRACE_LEVEL_PROTO ? '*' : ' ');
Willy Tarreau2ea549b2019-08-29 08:01:48 +0200518 chunk_appendf(&trash, " %c state : also report internal state changes\n",
Willy Tarreauaaaf4112019-08-12 17:57:57 +0200519 src->level == TRACE_LEVEL_STATE ? '*' : ' ');
Willy Tarreau2ea549b2019-08-29 08:01:48 +0200520 chunk_appendf(&trash, " %c data : also report data transfers\n",
521 src->level == TRACE_LEVEL_DATA ? '*' : ' ');
522 chunk_appendf(&trash, " %c developer : also report information useful only to the developer\n",
Willy Tarreauaaaf4112019-08-12 17:57:57 +0200523 src->level == TRACE_LEVEL_DEVELOPER ? '*' : ' ');
524 trash.area[trash.data] = 0;
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100525 *msg = trash.area;
526 return LOG_WARNING;
Willy Tarreauaaaf4112019-08-12 17:57:57 +0200527 }
528
Willy Tarreaua1f12742020-12-01 09:46:46 +0100529 if (strcmp(name, "error") == 0)
530 HA_ATOMIC_STORE(&src->level, TRACE_LEVEL_ERROR);
531 else if (strcmp(name, "user") == 0)
Willy Tarreauaaaf4112019-08-12 17:57:57 +0200532 HA_ATOMIC_STORE(&src->level, TRACE_LEVEL_USER);
Willy Tarreauaaaf4112019-08-12 17:57:57 +0200533 else if (strcmp(name, "proto") == 0)
534 HA_ATOMIC_STORE(&src->level, TRACE_LEVEL_PROTO);
535 else if (strcmp(name, "state") == 0)
536 HA_ATOMIC_STORE(&src->level, TRACE_LEVEL_STATE);
Willy Tarreau2ea549b2019-08-29 08:01:48 +0200537 else if (strcmp(name, "data") == 0)
538 HA_ATOMIC_STORE(&src->level, TRACE_LEVEL_DATA);
Willy Tarreauaaaf4112019-08-12 17:57:57 +0200539 else if (strcmp(name, "developer") == 0)
540 HA_ATOMIC_STORE(&src->level, TRACE_LEVEL_DEVELOPER);
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100541 else {
542 *msg = "No such trace level";
543 return LOG_ERR;
544 }
Willy Tarreauaaaf4112019-08-12 17:57:57 +0200545 }
Willy Tarreau60e4c9f2019-08-20 19:24:10 +0200546 else if (strcmp(args[2], "lock") == 0) {
547 const char *name = args[3];
548
549 if (!*name) {
550 chunk_printf(&trash, "Supported lock-on criteria for source %s:\n", src->name.ptr);
551 if (src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_STRM))
552 chunk_appendf(&trash, " %c backend : lock on the backend that started the trace\n",
553 src->lockon == TRACE_LOCKON_BACKEND ? '*' : ' ');
554
Christopher Faulet6d80b632021-04-12 11:53:16 +0200555 if (src->arg_def & TRC_ARGS_CHK)
556 chunk_appendf(&trash, " %c check : lock on the check that started the trace\n",
557 src->lockon == TRACE_LOCKON_CHECK ? '*' : ' ');
558
Willy Tarreau60e4c9f2019-08-20 19:24:10 +0200559 if (src->arg_def & TRC_ARGS_CONN)
560 chunk_appendf(&trash, " %c connection : lock on the connection that started the trace\n",
561 src->lockon == TRACE_LOCKON_CONNECTION ? '*' : ' ');
562
563 if (src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_SESS|TRC_ARGS_STRM))
564 chunk_appendf(&trash, " %c frontend : lock on the frontend that started the trace\n",
565 src->lockon == TRACE_LOCKON_FRONTEND ? '*' : ' ');
566
567 if (src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_SESS|TRC_ARGS_STRM))
568 chunk_appendf(&trash, " %c listener : lock on the listener that started the trace\n",
569 src->lockon == TRACE_LOCKON_LISTENER ? '*' : ' ');
570
571 chunk_appendf(&trash, " %c nothing : do not lock on anything\n",
572 src->lockon == TRACE_LOCKON_NOTHING ? '*' : ' ');
573
574 if (src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_STRM))
575 chunk_appendf(&trash, " %c server : lock on the server that started the trace\n",
576 src->lockon == TRACE_LOCKON_SERVER ? '*' : ' ');
577
578 if (src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_SESS|TRC_ARGS_STRM))
579 chunk_appendf(&trash, " %c session : lock on the session that started the trace\n",
580 src->lockon == TRACE_LOCKON_SESSION ? '*' : ' ');
581
582 if (src->arg_def & TRC_ARGS_STRM)
583 chunk_appendf(&trash, " %c stream : lock on the stream that started the trace\n",
584 src->lockon == TRACE_LOCKON_STREAM ? '*' : ' ');
585
Christopher Faulet26e09352023-03-29 17:42:28 +0200586 if (src->arg_def & TRC_ARGS_APPCTX)
587 chunk_appendf(&trash, " %c applet : lock on the applet that started the trace\n",
588 src->lockon == TRACE_LOCKON_APPCTX ? '*' : ' ');
589
Willy Tarreau60e4c9f2019-08-20 19:24:10 +0200590 chunk_appendf(&trash, " %c thread : lock on the thread that started the trace\n",
591 src->lockon == TRACE_LOCKON_THREAD ? '*' : ' ');
592
593 if (src->lockon_args && src->lockon_args[0].name)
594 chunk_appendf(&trash, " %c %-10s : %s\n",
595 src->lockon == TRACE_LOCKON_ARG1 ? '*' : ' ',
596 src->lockon_args[0].name, src->lockon_args[0].desc);
597
598 if (src->lockon_args && src->lockon_args[1].name)
599 chunk_appendf(&trash, " %c %-10s : %s\n",
600 src->lockon == TRACE_LOCKON_ARG2 ? '*' : ' ',
601 src->lockon_args[1].name, src->lockon_args[1].desc);
602
603 if (src->lockon_args && src->lockon_args[2].name)
604 chunk_appendf(&trash, " %c %-10s : %s\n",
605 src->lockon == TRACE_LOCKON_ARG3 ? '*' : ' ',
606 src->lockon_args[2].name, src->lockon_args[2].desc);
607
608 if (src->lockon_args && src->lockon_args[3].name)
609 chunk_appendf(&trash, " %c %-10s : %s\n",
610 src->lockon == TRACE_LOCKON_ARG4 ? '*' : ' ',
611 src->lockon_args[3].name, src->lockon_args[3].desc);
612
613 trash.area[trash.data] = 0;
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100614 *msg = trash.area;
615 return LOG_WARNING;
Willy Tarreau60e4c9f2019-08-20 19:24:10 +0200616 }
617 else if ((src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_STRM)) && strcmp(name, "backend") == 0) {
618 HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_BACKEND);
619 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
620 }
Christopher Faulet6d80b632021-04-12 11:53:16 +0200621 else if ((src->arg_def & TRC_ARGS_CHK) && strcmp(name, "check") == 0) {
622 HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_CHECK);
623 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
624 }
Willy Tarreau60e4c9f2019-08-20 19:24:10 +0200625 else if ((src->arg_def & TRC_ARGS_CONN) && strcmp(name, "connection") == 0) {
626 HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_CONNECTION);
627 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
628 }
629 else if ((src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_SESS|TRC_ARGS_STRM)) && strcmp(name, "frontend") == 0) {
630 HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_FRONTEND);
631 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
632 }
633 else if ((src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_SESS|TRC_ARGS_STRM)) && strcmp(name, "listener") == 0) {
634 HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_LISTENER);
635 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
636 }
637 else if (strcmp(name, "nothing") == 0) {
638 HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_NOTHING);
639 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
640 }
641 else if ((src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_STRM)) && strcmp(name, "server") == 0) {
642 HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_SERVER);
643 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
644 }
645 else if ((src->arg_def & (TRC_ARGS_CONN|TRC_ARGS_SESS|TRC_ARGS_STRM)) && strcmp(name, "session") == 0) {
646 HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_SESSION);
647 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
648 }
649 else if ((src->arg_def & TRC_ARGS_STRM) && strcmp(name, "stream") == 0) {
650 HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_STREAM);
651 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
652 }
Christopher Faulet26e09352023-03-29 17:42:28 +0200653 else if ((src->arg_def & TRC_ARGS_APPCTX) && strcmp(name, "appctx") == 0) {
654 HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_APPCTX);
655 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
656 }
Willy Tarreau60e4c9f2019-08-20 19:24:10 +0200657 else if (strcmp(name, "thread") == 0) {
658 HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_THREAD);
659 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
660 }
661 else if (src->lockon_args && src->lockon_args[0].name && strcmp(name, src->lockon_args[0].name) == 0) {
662 HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_ARG1);
663 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
664 }
665 else if (src->lockon_args && src->lockon_args[1].name && strcmp(name, src->lockon_args[1].name) == 0) {
666 HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_ARG2);
667 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
668 }
669 else if (src->lockon_args && src->lockon_args[2].name && strcmp(name, src->lockon_args[2].name) == 0) {
670 HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_ARG3);
671 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
672 }
673 else if (src->lockon_args && src->lockon_args[3].name && strcmp(name, src->lockon_args[3].name) == 0) {
674 HA_ATOMIC_STORE(&src->lockon, TRACE_LOCKON_ARG4);
675 HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
676 }
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100677 else {
678 *msg = "Unsupported lock-on criterion";
679 return LOG_ERR;
680 }
Willy Tarreau60e4c9f2019-08-20 19:24:10 +0200681 }
Willy Tarreau370a6942019-08-29 08:24:16 +0200682 else if (strcmp(args[2], "verbosity") == 0) {
683 const char *name = args[3];
684 const struct name_desc *nd;
685
686 if (!*name) {
687 chunk_printf(&trash, "Supported trace verbosities for source %s:\n", src->name.ptr);
688 chunk_appendf(&trash, " %c quiet : only report basic information with no decoding\n",
689 src->verbosity == 0 ? '*' : ' ');
690 if (!src->decoding || !src->decoding[0].name) {
691 chunk_appendf(&trash, " %c default : report extra information when available\n",
692 src->verbosity > 0 ? '*' : ' ');
693 } else {
694 for (nd = src->decoding; nd->name && nd->desc; nd++)
695 chunk_appendf(&trash, " %c %-10s : %s\n",
696 nd == (src->decoding + src->verbosity - 1) ? '*' : ' ',
697 nd->name, nd->desc);
698 }
699 trash.area[trash.data] = 0;
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100700 *msg = trash.area;
701 return LOG_WARNING;
Willy Tarreau370a6942019-08-29 08:24:16 +0200702 }
703
704 if (strcmp(name, "quiet") == 0)
705 HA_ATOMIC_STORE(&src->verbosity, 0);
706 else if (!src->decoding || !src->decoding[0].name) {
707 if (strcmp(name, "default") == 0)
708 HA_ATOMIC_STORE(&src->verbosity, 1);
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100709 else {
710 *msg = "No such verbosity level";
711 return LOG_ERR;
712 }
Willy Tarreau370a6942019-08-29 08:24:16 +0200713 } else {
714 for (nd = src->decoding; nd->name && nd->desc; nd++)
715 if (strcmp(name, nd->name) == 0)
716 break;
717
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100718 if (!nd->name || !nd->desc) {
719 *msg = "No such verbosiry level";
720 return LOG_ERR;
721 }
Willy Tarreau370a6942019-08-29 08:24:16 +0200722
723 HA_ATOMIC_STORE(&src->verbosity, (nd - src->decoding) + 1);
724 }
725 }
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100726 else {
727 *msg = "Unknown trace keyword";
728 return LOG_ERR;
729 }
730 return 0;
731
732}
733
Willy Tarreau9fd05422022-11-16 17:29:12 +0100734/* parse a "trace" statement in the "global" section, returns 1 if a message is returned, otherwise zero */
735static int cfg_parse_trace(char **args, int section_type, struct proxy *curpx,
736 const struct proxy *defpx, const char *file, int line,
737 char **err)
738{
739 const char *msg;
740 int severity;
741
742 severity = trace_parse_statement(args, &msg);
743 if (msg) {
744 if (severity >= LOG_NOTICE)
745 ha_notice("parsing [%s:%d] : '%s': %s\n", file, line, args[0], msg);
746 else if (severity >= LOG_WARNING)
747 ha_warning("parsing [%s:%d] : '%s': %s\n", file, line, args[0], msg);
748 else {
749 ha_alert("parsing [%s:%d] : '%s': %s\n", file, line, args[0], msg);
750 return -1;
751 }
752 }
753 return 0;
754}
755
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100756/* parse the command, returns 1 if a message is returned, otherwise zero */
757static int cli_parse_trace(char **args, char *payload, struct appctx *appctx, void *private)
758{
759 const char *msg;
760 int severity;
761
762 if (!cli_has_level(appctx, ACCESS_LVL_OPER))
763 return 1;
764
765 severity = trace_parse_statement(args, &msg);
766 if (msg)
767 return cli_msg(appctx, severity, msg);
Willy Tarreau864e8802019-08-08 18:48:12 +0200768
Willy Tarreauc11f1cd2022-11-16 17:18:04 +0100769 /* total success */
Willy Tarreau864e8802019-08-08 18:48:12 +0200770 return 0;
771}
772
Willy Tarreau85b15752019-08-12 16:44:33 +0200773/* parse the command, returns 1 if a message is returned, otherwise zero */
774static int cli_parse_show_trace(char **args, char *payload, struct appctx *appctx, void *private)
775{
776 struct trace_source *src;
777 const struct sink *sink;
778 int i;
779
780 args++; // make args[1] the 1st arg
781
782 if (!*args[1]) {
783 /* no arg => report the list of supported sources */
784 chunk_printf(&trash,
785 "Supported trace sources and states (.=stopped, w=waiting, R=running) :\n"
786 );
787
788 list_for_each_entry(src, &trace_sources, source_link) {
789 sink = src->sink;
790 chunk_appendf(&trash, " [%c] %-10s -> %s [drp %u] [%s]\n",
791 trace_state_char(src->state), src->name.ptr,
792 sink ? sink->name : "none",
793 sink ? sink->ctx.dropped : 0,
794 src->desc);
795 }
796
797 trash.area[trash.data] = 0;
798 return cli_msg(appctx, LOG_INFO, trash.area);
799 }
800
801 if (!cli_has_level(appctx, ACCESS_LVL_OPER))
802 return 1;
803
804 src = trace_find_source(args[1]);
805 if (!src)
806 return cli_err(appctx, "No such trace source");
807
808 sink = src->sink;
809 chunk_printf(&trash, "Trace status for %s:\n", src->name.ptr);
810 chunk_appendf(&trash, " - sink: %s [%u dropped]\n",
811 sink ? sink->name : "none", sink ? sink->ctx.dropped : 0);
812
Willy Tarreau99282dd2019-08-30 07:37:32 +0200813 chunk_appendf(&trash, " - event name : report start stop pause\n");
Willy Tarreau85b15752019-08-12 16:44:33 +0200814 for (i = 0; src->known_events && src->known_events[i].mask; i++) {
Willy Tarreau99282dd2019-08-30 07:37:32 +0200815 chunk_appendf(&trash, " %-12s : %c %c %c %c\n",
Willy Tarreau85b15752019-08-12 16:44:33 +0200816 src->known_events[i].name,
817 trace_event_char(src->report_events, src->known_events[i].mask),
818 trace_event_char(src->start_events, src->known_events[i].mask),
819 trace_event_char(src->stop_events, src->known_events[i].mask),
820 trace_event_char(src->pause_events, src->known_events[i].mask));
821 }
822
823 trash.area[trash.data] = 0;
824 return cli_msg(appctx, LOG_WARNING, trash.area);
825}
826
Willy Tarreau864e8802019-08-08 18:48:12 +0200827static struct cli_kw_list cli_kws = {{ },{
Willy Tarreaub205bfd2021-05-07 11:38:37 +0200828 { { "trace", NULL }, "trace [<module>|0] [cmd [args...]] : manage live tracing (empty to list, 0 to stop all)", cli_parse_trace, NULL, NULL },
829 { { "show", "trace", NULL }, "show trace [<module>] : show live tracing state", cli_parse_show_trace, NULL, NULL },
Willy Tarreau864e8802019-08-08 18:48:12 +0200830 {{},}
831}};
832
833INITCALL1(STG_REGISTER, cli_register_kw, &cli_kws);
834
Willy Tarreau9fd05422022-11-16 17:29:12 +0100835static struct cfg_kw_list cfg_kws = {ILH, {
836 { CFG_GLOBAL, "trace", cfg_parse_trace, KWF_EXPERIMENTAL },
837 { /* END */ },
838}};
839
840INITCALL1(STG_REGISTER, cfg_register_keywords, &cfg_kws);
841
Willy Tarreau4151c752019-08-08 18:21:26 +0200842/*
843 * Local variables:
844 * c-indent-level: 8
845 * c-basic-offset: 8
846 * End:
847 */