MINOR: trace: Be able to chain commands for a source in one line

In the configuration file or on the CLI, configuring traces for a specific
source is a bit painful because this must be done in several lines. Thanks
to this patch, it is now possible to fully configure traces for a source in
one line. For instance, the following on the CLI:

  trace h1 sink stderr; trace h1 level developer; trace h1 verbosity complete; trace h1 start now

can now be replaced by:

  trace h1 sink stderr level developer verbosity complete start now

The same is true for the 'trace' directives in the configuration file.
This commit is contained in:
Christopher Faulet 2024-10-01 11:05:48 +02:00
parent 15a520d474
commit c39c351a73
3 changed files with 209 additions and 189 deletions

View File

@ -4350,11 +4350,9 @@ traces
used. All direcitives are evaluated in the declararion order, the last ones
overriding previous ones.
trace <args...>
trace <source> <args...>
Configures on "trace" subsystem. Each of them can be found in the management
manual, and follow the exact same syntax. Only one statement per line is
permitted (i.e. if some long trace configurations using semi-colons are to be
imported, they must be placed one per line). Any output that the "trace"
manual, and follow the exact same syntax. Any output that the "trace"
command would produce will be emitted during the parsing step of the
section. Most of the time these will be errors and warnings, but certain
incomplete commands might list permissible choices. This command is not meant
@ -4377,15 +4375,8 @@ trace <args...>
backing-file /tmp/h2.traces
traces
trace h1 sink buf1
trace h1 level developer
trace h1 verbosity complete
trace h1 start now
trace h2 sink buf1
trace h2 level developer
trace h2 verbosity complete
trace h2 start now
trace h1 sink buf1 level developer verbosity complete start now
trace h2 sink buf1 level developer verbosity complete start now
3.4. Userlists
--------------

View File

@ -3931,16 +3931,21 @@ trace 0
to terminate a debugging session or as an emergency action to be used in case
complex traces were enabled on multiple sources and impact the service.
trace <source> event [ [+|-|!]<name> ]
trace <source> [<args...>]
Configure traces for the source <source>. Without argument, this will list all
supported sub-commands to the given source. Multiple sub-commands can be
chained. Following sub-commands are supported:
event [ [+|-|!]<name> ]
Without argument, this will list all the events supported by the designated
source. They are prefixed with a "-" if they are not enabled, or a "+" if
they are enabled. It is important to note that a single trace may be labelled
with multiple events, and as long as any of the enabled events matches one of
the events labelled on the trace, the event will be passed to the trace
subsystem. For example, receiving an HTTP/2 frame of type HEADERS may trigger
a frame event and a stream event since the frame creates a new stream. If
either the frame event or the stream event are enabled for this source, the
frame will be passed to the trace framework.
they are enabled. It is important to note that a single trace may be
labelled with multiple events, and as long as any of the enabled events
matches one of the events labelled on the trace, the event will be passed to
the trace subsystem. For example, receiving an HTTP/2 frame of type HEADERS
may trigger a frame event and a stream event since the frame creates a new
stream. If either the frame event or the stream event are enabled for this
source, the frame will be passed to the trace framework.
With an argument, it is possible to toggle the state of each event and
individually enable or disable them. Two special keywords are supported,
@ -3954,7 +3959,7 @@ trace <source> event [ [+|-|!]<name> ]
One way to completely disable a trace source is to pass "event none", and
this source will instantly be totally ignored.
trace <source> follow <other_source>
follow <other_source>
This permits the source <source> to also emit traces when the other source
<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,
@ -3970,12 +3975,9 @@ trace <source> follow <other_source>
command: in this case, all sources will follow <other_source>.
Example:
trace session lock session
trace session start sess_new
trace session pause sess_end
trace h1 follow session
trace h1 lock session start sess_new pause sess_end follow session
trace <source> level [<level>]
level [<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
an argument, this will change the trace level to the specified level. Detail
@ -4018,14 +4020,14 @@ trace <source> level [<level>]
"all" may also be used with this command: in this case, the level will be
applied to all existing sources at once.
trace <source> lock [criterion]
lock [criterion]
Without argument, this will list all the criteria supported by this source
for lock-on processing, and display the current choice by a star ('*') in
front of it. Lock-on means that the source will focus on the first matching
event and only stick to the criterion which triggered this event, and ignore
all other ones until the trace stops. This allows for example to take a trace
on a single connection or on a single stream. The following criteria are
supported by some traces, though not necessarily all, since some of them
all other ones until the trace stops. This allows for example to take a
trace on a single connection or on a single stream. The following criteria
are supported by some traces, though not necessarily all, since some of them
might not be available to the source :
backend lock on the backend that started the trace
@ -4042,11 +4044,11 @@ trace <source> lock [criterion]
to lock on the H2 stream and ignore other streams once a strace starts.
When a criterion is passed in argument, this one is used instead of the
other ones and any existing tracking is immediately terminated so that it can
restart with the new criterion. The special keyword "nothing" is supported by
all sources to permanently disable tracking.
other ones and any existing tracking is immediately terminated so that it
can restart with the new criterion. The special keyword "nothing" is
supported by all sources to permanently disable tracking.
trace <source> { pause | start | stop } [ [+|-|!]event]
{ pause | start | stop } [ [+|-|!]event]
Without argument, this will list the events enabled to automatically pause,
start, or stop a trace for this source. These events are specific to each
trace source. With an argument, this will either enable the event for the
@ -4056,55 +4058,56 @@ trace <source> { pause | start | stop } [ [+|-|!]event]
supported just like in "trace event".
The 3 supported actions are respectively "pause", "start" and "stop". The
"pause" action enumerates events which will cause a running trace to stop and
wait for a new start event to restart it. The "start" action enumerates the
events which switch the trace into the waiting mode until one of the start
events appears. And the "stop" action enumerates the events which definitely
stop the trace until it is manually enabled again. In practice it makes sense
to manually start a trace using "start now" without caring about events, and
to stop it using "stop now". In order to capture more subtle event sequences,
setting "start" to a normal event (like receiving an HTTP request) and "stop"
to a very rare event like emitting a certain error, will ensure that the last
captured events will match the desired criteria. And the pause event is
useful to detect the end of a sequence, disable the lock-on and wait for
another opportunity to take a capture. In this case it can make sense to
enable lock-on to spot only one specific criterion (e.g. a stream), and have
"start" set to anything that starts this criterion (e.g. all events which
create a stream), "stop" set to the expected anomaly, and "pause" to anything
that ends that criterion (e.g. any end of stream event). In this case the
trace log will contain complete sequences of perfectly clean series affecting
a single object, until the last sequence containing everything from the
beginning to the anomaly.
"pause" action enumerates events which will cause a running trace to stop
and wait for a new start event to restart it. The "start" action enumerates
the events which switch the trace into the waiting mode until one of the
start events appears. And the "stop" action enumerates the events which
definitely stop the trace until it is manually enabled again. In practice it
makes sense to manually start a trace using "start now" without caring about
events, and to stop it using "stop now". In order to capture more subtle
event sequences, setting "start" to a normal event (like receiving an HTTP
request) and "stop" to a very rare event like emitting a certain error, will
ensure that the last captured events will match the desired criteria. And
the pause event is useful to detect the end of a sequence, disable the
lock-on and wait for another opportunity to take a capture. In this case it
can make sense to enable lock-on to spot only one specific criterion (e.g. a
stream), and have "start" set to anything that starts this criterion
(e.g. all events which create a stream), "stop" set to the expected anomaly,
and "pause" to anything that ends that criterion (e.g. any end of stream
event). In this case the trace log will contain complete sequences of
perfectly clean series affecting a single object, until the last sequence
containing everything from the beginning to the anomaly.
trace <source> sink [<sink>]
sink [<sink>]
Without argument, this will list all event sinks available for this source,
and the currently configured one will have a star ('*') prepended in front
of it. Sink "none" is always available and means that all events are simply
dropped, though their processing is not ignored (e.g. lock-on does occur).
Other sinks are available depending on configuration and build options, but
typically "stdout" and "stderr" will be usable in debug mode, and in-memory
ring buffers should be available as well. When a name is specified, the sink
instantly changes for the specified source. Events are not changed during a
sink change. In the worst case some may be lost if an invalid sink is used
(or "none"), but operations do continue to a different destination. The
meta-source "all" may also be used with this command: in this case, the
sink will be applied to all existing sources at once.
ring buffers should be available as well. When a name is specified, the
sink instantly changes for the specified source. Events are not changed
during a sink change. In the worst case some may be lost if an invalid sink
is used (or "none"), but operations do continue to a different
destination. The meta-source "all" may also be used with this command: in
this case, the sink will be applied to all existing sources at once.
trace <source> verbosity [<level>]
Without argument, this will list all verbosity levels for this source, and the
current one will be indicated by a star ('*') prepended in front of it. With
an argument, this will change the verbosity level to the specified one.
verbosity [<level>]
Without argument, this will list all verbosity levels for this source, and
the current one will be indicated by a star ('*') prepended in front of
it. With an argument, this will change the verbosity level to the specified
one.
Verbosity levels indicate how far the trace decoder should go to provide
detailed information. It depends on the trace source, since some sources will
not even provide a specific decoder. Level "quiet" is always available and
disables any decoding. It can be useful when trying to figure what's
detailed information. It depends on the trace source, since some sources
will not even provide a specific decoder. Level "quiet" is always available
and disables any decoding. It can be useful when trying to figure what's
happening before trying to understand the details, since it will have a very
low impact on performance and trace size. When no verbosity levels are
declared by a source, level "default" is available and will cause a decoder
to be called when specified in the traces. It is an opportunistic decoding.
When the source declares some verbosity levels, these ones are listed with
a description of what they correspond to. In this case the trace decoder
When the source declares some verbosity levels, these ones are listed with a
description of what they correspond to. In this case the trace decoder
provided by the source will be as accurate as possible based on the
information available at the trace point. The first level above "quiet" is
set by default.

View File

@ -449,8 +449,9 @@ static int trace_source_parse_verbosity(struct trace_source *src,
*/
static int trace_parse_statement(char **args, char **msg)
{
struct trace_source *src;
struct trace_source *orig_src, *src;
uint64_t *ev_ptr = NULL;
int cur_arg;
/* no error by default */
*msg = NULL;
@ -480,24 +481,18 @@ 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]);
return LOG_ERR;
}
src = NULL;
orig_src = NULL;
}
else {
src = trace_find_source(args[1]);
if (!src) {
orig_src = trace_find_source(args[1]);
if (!orig_src) {
memprintf(msg, "No such trace source '%s'", args[1]);
return LOG_ERR;
}
}
if (!*args[2]) {
cur_arg = 2;
if (!*args[cur_arg]) {
*msg = "Supported commands:\n"
" event : list/enable/disable source-specific event reporting\n"
//" filter : list/enable/disable generic filters\n"
@ -512,10 +507,24 @@ static int trace_parse_statement(char **args, char **msg)
*msg = strdup(*msg);
return LOG_WARNING;
}
else if (strcmp(args[2], "follow") == 0) {
next_stmt:
if (!*args[cur_arg])
goto out;
src = orig_src;
if (src == NULL &&
strcmp(args[cur_arg], "follow") != 0 &&
strcmp(args[cur_arg], "sink") != 0 &&
strcmp(args[cur_arg], "level") != 0) {
memprintf(msg, "'%s' not applicable to meta-source 'all'", args[cur_arg]);
return LOG_ERR;
}
if (strcmp(args[cur_arg], "follow") == 0) {
const struct trace_source *origin = src ? HA_ATOMIC_LOAD(&src->follow) : NULL;
if (!*args[3]) {
if (!*args[cur_arg+1]) {
/* no arg => report the list of supported sources as a warning */
if (origin)
chunk_printf(&trash, "Currently following source '%s'.\n", origin->name.ptr);
@ -538,10 +547,10 @@ static int trace_parse_statement(char **args, char **msg)
}
origin = NULL;
if (strcmp(args[3], "none") != 0) {
origin = trace_find_source(args[3]);
if (strcmp(args[cur_arg+1], "none") != 0) {
origin = trace_find_source(args[cur_arg+1]);
if (!origin) {
memprintf(msg, "No such trace source '%s'", args[3]);
memprintf(msg, "No such trace source '%s'", args[cur_arg+1]);
return LOG_ERR;
}
}
@ -552,13 +561,15 @@ static int trace_parse_statement(char **args, char **msg)
list_for_each_entry(src, &trace_sources, source_link)
if (src != origin)
HA_ATOMIC_STORE(&src->follow, origin);
cur_arg += 2;
goto next_stmt;
}
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)) ||
(strcmp(args[2], "stop") == 0 && (ev_ptr = &src->stop_events))) {
else if ((strcmp(args[cur_arg], "event") == 0 && (ev_ptr = &src->report_events)) ||
(strcmp(args[cur_arg], "pause") == 0 && (ev_ptr = &src->pause_events)) ||
(strcmp(args[cur_arg], "start") == 0 && (ev_ptr = &src->start_events)) ||
(strcmp(args[cur_arg], "stop") == 0 && (ev_ptr = &src->stop_events))) {
const struct trace_event *ev;
const char *name = args[3];
const char *name = args[cur_arg+1];
int neg = 0;
int i;
@ -609,10 +620,8 @@ static int trace_parse_statement(char **args, char **msg)
HA_ATOMIC_STORE(&src->lockon_ptr, NULL);
HA_ATOMIC_STORE(&src->state, TRACE_STATE_STOPPED);
}
return 0;
}
if (strcmp(name, "none") == 0)
else if (strcmp(name, "none") == 0)
HA_ATOMIC_STORE(ev_ptr, 0);
else if (strcmp(name, "any") == 0) {
enum trace_state old = TRACE_STATE_STOPPED;
@ -638,9 +647,12 @@ static int trace_parse_statement(char **args, char **msg)
if (ev_ptr == &src->start_events && HA_ATOMIC_LOAD(ev_ptr) != 0)
HA_ATOMIC_CAS(&src->state, &old, TRACE_STATE_WAITING);
}
cur_arg += 2;
goto next_stmt;
}
else if (strcmp(args[2], "sink") == 0) {
const char *name = args[3];
else if (strcmp(args[cur_arg], "sink") == 0) {
const char *name = args[cur_arg+1];
struct sink *sink;
if (!*name) {
@ -671,9 +683,12 @@ static int trace_parse_statement(char **args, char **msg)
else
list_for_each_entry(src, &trace_sources, source_link)
HA_ATOMIC_STORE(&src->sink, sink);
cur_arg += 2;
goto next_stmt;
}
else if (strcmp(args[2], "level") == 0) {
const char *name = args[3];
else if (strcmp(args[cur_arg], "level") == 0) {
const char *name = args[cur_arg+1];
int level = -1;
if (*name)
@ -706,9 +721,12 @@ static int trace_parse_statement(char **args, char **msg)
else
list_for_each_entry(src, &trace_sources, source_link)
HA_ATOMIC_STORE(&src->level, level);
cur_arg += 2;
goto next_stmt;
}
else if (strcmp(args[2], "lock") == 0) {
const char *name = args[3];
else if (strcmp(args[cur_arg], "lock") == 0) {
const char *name = args[cur_arg+1];
if (!*name) {
chunk_printf(&trash, "Supported lock-on criteria for source %s:\n", src->name.ptr);
@ -850,9 +868,12 @@ static int trace_parse_statement(char **args, char **msg)
memprintf(msg, "Unsupported lock-on criterion '%s'", name);
return LOG_ERR;
}
cur_arg += 2;
goto next_stmt;
}
else if (strcmp(args[2], "verbosity") == 0) {
const char *name = args[3];
else if (strcmp(args[cur_arg], "verbosity") == 0) {
const char *name = args[cur_arg+1];
const struct name_desc *nd;
int verbosity = -1;
@ -881,11 +902,16 @@ static int trace_parse_statement(char **args, char **msg)
}
HA_ATOMIC_STORE(&src->verbosity, verbosity);
cur_arg += 2;
goto next_stmt;
}
else {
memprintf(msg, "Unknown trace keyword '%s'", args[2]);
memprintf(msg, "Unknown trace keyword '%s'", args[cur_arg]);
return LOG_ERR;
}
out:
return 0;
}