1
Fork 0

log: support dynamic log levels for registered log topics

Handle log level patterns in libpipewire instead of the SPA logger.

This allows dynamically changing the log levels also for log topics,
which we do when log.level metadata changes.

The syntax for PIPEWIRE_DEBUG and log.level in config files and metadata
is now the same.
This commit is contained in:
Pauli Virtanen 2023-12-23 21:09:45 +02:00 committed by Wim Taymans
parent 1197b581d9
commit 3cff30c651
6 changed files with 304 additions and 127 deletions

View File

@ -264,11 +264,7 @@ struct pw_context *pw_context_new(struct pw_loop *main_loop,
if (getenv("PIPEWIRE_DEBUG") == NULL &&
(str = pw_properties_get(properties, "log.level")) != NULL) {
enum spa_log_level lev;
if (pw_parse_log_level(str, &lev))
pw_log_set_level(lev);
else
if (pw_log_set_level_string(str) < 0)
pw_log_warn("%p: invalid log.level in context properties", this);
}

View File

@ -12,9 +12,11 @@
#include <spa/debug/format.h>
#include <spa/pod/iter.h>
#include <spa/utils/list.h>
#include <spa/utils/string.h>
#include <pipewire/log.h>
#include <pipewire/private.h>
#include <pipewire/cleanup.h>
SPA_LOG_IMPL(default_log);
@ -26,6 +28,21 @@ static struct spa_log *global_log = &default_log.log;
SPA_EXPORT
struct spa_log_topic *PW_LOG_TOPIC_DEFAULT;
struct topic {
struct spa_list link;
struct spa_log_topic *t;
unsigned int refcnt;
};
struct pattern {
struct spa_list link;
enum spa_log_level level;
char pattern[];
};
static struct spa_list topics = SPA_LIST_INIT(&topics);
static struct spa_list patterns = SPA_LIST_INIT(&patterns);
PW_LOG_TOPIC_STATIC(log_topic, "pw.log"); /* log topic for this file here */
PW_LOG_TOPIC(log_buffers, "pw.buffers");
PW_LOG_TOPIC(log_client, "pw.client");
@ -55,6 +72,112 @@ PW_LOG_TOPIC(log_work_queue, "pw.work-queue");
PW_LOG_TOPIC(PW_LOG_TOPIC_DEFAULT, "default");
static struct topic *find_topic(struct spa_log_topic *t)
{
struct topic *topic;
spa_list_for_each(topic, &topics, link)
if (topic->t == t)
return topic;
return NULL;
}
static struct topic *add_topic(struct spa_log_topic *t)
{
struct topic *topic;
topic = calloc(1, sizeof(struct topic));
if (!topic)
return NULL;
topic->t = t;
spa_list_append(&topics, &topic->link);
return topic;
}
static void update_topic_level(struct spa_log_topic *t)
{
enum spa_log_level level = pw_log_level;
bool has_custom_level = false;
const char *topic = t->topic;
struct pattern *pattern;
spa_list_for_each(pattern, &patterns, link) {
if (fnmatch(pattern->pattern, topic, 0) != 0)
continue;
level = pattern->level;
has_custom_level = true;
break;
}
t->level = level;
t->has_custom_level = has_custom_level;
}
static void update_all_topic_levels(void)
{
struct topic *topic;
spa_list_for_each(topic, &topics, link)
update_topic_level(topic->t);
}
SPA_EXPORT
void pw_log_topic_register(struct spa_log_topic *t)
{
struct topic *topic;
topic = find_topic(t);
if (!topic) {
update_topic_level(t);
topic = add_topic(t);
if (!topic)
return;
}
++topic->refcnt;
}
SPA_EXPORT
void pw_log_topic_unregister(struct spa_log_topic *t)
{
struct topic *topic;
topic = find_topic(t);
if (!topic)
return;
if (topic->refcnt-- <= 1) {
spa_list_remove(&topic->link);
free(topic);
}
}
void pw_log_topic_register_enum(const struct spa_log_topic_enum *e)
{
struct spa_log_topic * const *t;
if (!e)
return;
for (t = e->topics; t < e->topics_end; ++t)
pw_log_topic_register(*t);
}
void pw_log_topic_unregister_enum(const struct spa_log_topic_enum *e)
{
struct spa_log_topic * const *t;
if (!e)
return;
for (t = e->topics; t < e->topics_end; ++t)
pw_log_topic_unregister(*t);
}
/** Set the global log interface
* \param log the global log to set
*/
@ -89,6 +212,118 @@ void pw_log_set_level(enum spa_log_level level)
global_log->level = level;
}
static int add_pattern(struct spa_list *list, const char *str, enum spa_log_level level)
{
struct pattern *pattern;
size_t len = strlen(str);
pattern = calloc(1, sizeof(struct pattern) + len + 1);
if (!pattern)
return -errno;
pattern->level = level;
memcpy(pattern->pattern, str, len);
spa_list_append(list, &pattern->link);
return 0;
}
static bool
parse_log_level(const char *str, enum spa_log_level *l)
{
uint32_t lvl;
if (!str)
return false;
if (strlen(str) == 1) {
/* SPA levels, plus a few duplicate codes that
* WirePlumber supports for some GLib levels. */
switch (str[0]) {
case 'X': lvl = SPA_LOG_LEVEL_NONE; break;
case 'F': lvl = SPA_LOG_LEVEL_NONE; break; /* fatal */
case 'E': lvl = SPA_LOG_LEVEL_ERROR; break;
case 'W': lvl = SPA_LOG_LEVEL_WARN; break;
case 'N': lvl = SPA_LOG_LEVEL_WARN; break; /* notice */
case 'I': lvl = SPA_LOG_LEVEL_INFO; break;
case 'D': lvl = SPA_LOG_LEVEL_DEBUG; break;
case 'T': lvl = SPA_LOG_LEVEL_TRACE; break;
default:
goto check_int;
}
} else {
check_int:
if (!spa_atou32(str, &lvl, 0))
return false;
if (lvl > SPA_LOG_LEVEL_TRACE)
return false;
}
*l = lvl;
return true;
}
static int
parse_log_string(const char *str, struct spa_list *list, enum spa_log_level *level)
{
struct spa_list new_patterns = SPA_LIST_INIT(&new_patterns);
int n_tokens;
*level = DEFAULT_LOG_LEVEL;
if (!str || !*str)
return 0;
spa_auto(pw_strv) tokens = pw_split_strv(str, ",", INT_MAX, &n_tokens);
if (n_tokens > 0) {
int i;
for (i = 0; i < n_tokens; i++) {
int n_tok;
char *tok[2];
enum spa_log_level lvl;
n_tok = pw_split_ip(tokens[i], ":", SPA_N_ELEMENTS(tok), tok);
if (n_tok == 2 && parse_log_level(tok[1], &lvl)) {
add_pattern(&new_patterns, tok[0], lvl);
} else if (n_tok == 1 && parse_log_level(tok[0], &lvl)) {
*level = lvl;
} else {
pw_log_warn("Ignoring invalid format in log level: '%s'",
tokens[i]);
}
}
}
/* Connection namespace disabled by default */
add_pattern(&new_patterns, "conn.*", SPA_LOG_LEVEL_NONE);
spa_list_insert_list(list, &new_patterns);
return 0;
}
int pw_log_set_level_string(const char *str)
{
struct spa_list new_patterns = SPA_LIST_INIT(&new_patterns);
struct pattern *pattern;
enum spa_log_level level;
int res;
if ((res = parse_log_string(str, &new_patterns, &level)) < 0)
return res;
pw_log_level = level;
global_log->level = level;
spa_list_consume(pattern, &patterns, link) {
spa_list_remove(&pattern->link);
free(pattern);
}
spa_list_insert_list(&patterns, &new_patterns);
update_all_topic_levels();
return 0;
}
/** Log a message for the given topic
* \param level the log level
* \param topic the topic
@ -234,31 +469,46 @@ void pw_log_log_object(enum spa_log_level level,
void
pw_log_init(void)
{
PW_LOG_TOPIC_INIT(PW_LOG_TOPIC_DEFAULT);
PW_LOG_TOPIC_INIT(log_buffers);
PW_LOG_TOPIC_INIT(log_client);
PW_LOG_TOPIC_INIT(log_conf);
PW_LOG_TOPIC_INIT(log_context);
PW_LOG_TOPIC_INIT(log_core);
PW_LOG_TOPIC_INIT(log_data_loop);
PW_LOG_TOPIC_INIT(log_device);
PW_LOG_TOPIC_INIT(log_factory);
PW_LOG_TOPIC_INIT(log_filter);
PW_LOG_TOPIC_INIT(log_global);
PW_LOG_TOPIC_INIT(log_link);
PW_LOG_TOPIC_INIT(log_loop);
PW_LOG_TOPIC_INIT(log_main_loop);
PW_LOG_TOPIC_INIT(log_mem);
PW_LOG_TOPIC_INIT(log_metadata);
PW_LOG_TOPIC_INIT(log_module);
PW_LOG_TOPIC_INIT(log_node);
PW_LOG_TOPIC_INIT(log_port);
PW_LOG_TOPIC_INIT(log_properties);
PW_LOG_TOPIC_INIT(log_protocol);
PW_LOG_TOPIC_INIT(log_proxy);
PW_LOG_TOPIC_INIT(log_resource);
PW_LOG_TOPIC_INIT(log_stream);
PW_LOG_TOPIC_INIT(log_thread_loop);
PW_LOG_TOPIC_INIT(log_topic);
PW_LOG_TOPIC_INIT(log_work_queue);
pw_log_topic_register(PW_LOG_TOPIC_DEFAULT);
pw_log_topic_register(log_buffers);
pw_log_topic_register(log_client);
pw_log_topic_register(log_conf);
pw_log_topic_register(log_context);
pw_log_topic_register(log_core);
pw_log_topic_register(log_data_loop);
pw_log_topic_register(log_device);
pw_log_topic_register(log_factory);
pw_log_topic_register(log_filter);
pw_log_topic_register(log_global);
pw_log_topic_register(log_link);
pw_log_topic_register(log_loop);
pw_log_topic_register(log_main_loop);
pw_log_topic_register(log_mem);
pw_log_topic_register(log_metadata);
pw_log_topic_register(log_module);
pw_log_topic_register(log_node);
pw_log_topic_register(log_port);
pw_log_topic_register(log_properties);
pw_log_topic_register(log_protocol);
pw_log_topic_register(log_proxy);
pw_log_topic_register(log_resource);
pw_log_topic_register(log_stream);
pw_log_topic_register(log_thread_loop);
pw_log_topic_register(log_topic);
pw_log_topic_register(log_work_queue);
}
void
pw_log_deinit(void)
{
struct pattern *pattern;
spa_list_consume(pattern, &patterns, link) {
spa_list_remove(&pattern->link);
free(pattern);
}
/* don't free log topics, since they usually won't get re-registered */
pw_log_set(NULL);
}

View File

@ -106,6 +106,22 @@ pw_log_logv(enum spa_log_level level,
#define PW_LOG_TOPIC_INIT(var) \
spa_log_topic_init(pw_log_get(), var);
/**
* Register log topic with the logger, to enable dynamic log levels.
* Topic must be unregistered before freeing it or plugin unload.
* May be used instead of \ref PW_LOG_TOPIC_INIT
*
* \since 1.1.0
*/
void pw_log_topic_register(struct spa_log_topic *t);
/**
* Unregister log topic
*
* \since 1.1.0
*/
void pw_log_topic_unregister(struct spa_log_topic *t);
/** Check if a loglevel is enabled */
#define pw_log_level_enabled(lev) (pw_log_level >= (lev))
#define pw_log_topic_enabled(lev,t) ((t) && (t)->has_custom_level ? (t)->level >= (lev) : pw_log_level_enabled((lev)))

View File

@ -469,87 +469,6 @@ static struct spa_log *load_journal_logger(struct support *support,
}
#endif
bool
pw_parse_log_level(const char *str, enum spa_log_level *l)
{
uint32_t lvl;
if (!str)
return false;
if (strlen(str) == 1) {
/* SPA levels, plus a few duplicate codes that
* WirePlumber supports for some GLib levels. */
switch (str[0]) {
case 'X': lvl = SPA_LOG_LEVEL_NONE; break;
case 'F': lvl = SPA_LOG_LEVEL_NONE; break; /* fatal */
case 'E': lvl = SPA_LOG_LEVEL_ERROR; break;
case 'W': lvl = SPA_LOG_LEVEL_WARN; break;
case 'N': lvl = SPA_LOG_LEVEL_WARN; break; /* notice */
case 'I': lvl = SPA_LOG_LEVEL_INFO; break;
case 'D': lvl = SPA_LOG_LEVEL_DEBUG; break;
case 'T': lvl = SPA_LOG_LEVEL_TRACE; break;
default:
goto check_int;
}
} else {
check_int:
if (!spa_atou32(str, &lvl, 0))
return false;
if (lvl > SPA_LOG_LEVEL_TRACE)
return false;
}
*l = lvl;
return true;
}
static char *
parse_pw_debug_env(void)
{
const char *str;
int n_tokens;
char json[1024] = {0};
char *pos = json;
char *end = pos + sizeof(json) - 1;
enum spa_log_level lvl;
str = getenv("PIPEWIRE_DEBUG");
if (!str || !*str)
return NULL;
/* String format is PIPEWIRE_DEBUG=[<glob>:]<level>,...,
* converted into [{ conn.* = 0}, {glob = level}, {glob = level}, ....] ,
* with the connection namespace disabled by default.
*/
pos += spa_scnprintf(pos, end - pos, "[ { conn.* = %d },", SPA_LOG_LEVEL_NONE);
spa_auto(pw_strv) tokens = pw_split_strv(str, ",", INT_MAX, &n_tokens);
if (n_tokens > 0) {
int i;
for (i = 0; i < n_tokens; i++) {
int n_tok;
char *tok[2];
n_tok = pw_split_ip(tokens[i], ":", SPA_N_ELEMENTS(tok), tok);
if (n_tok == 2 && pw_parse_log_level(tok[1], &lvl)) {
char *pattern = tok[0];
pos += spa_scnprintf(pos, end - pos, "{ %s = %d },",
pattern, lvl);
} else if (n_tok == 1 && pw_parse_log_level(tok[0], &lvl)) {
pw_log_set_level(lvl);
} else {
pw_log_warn("Ignoring invalid format in PIPEWIRE_DEBUG: '%s'",
tokens[i]);
}
}
}
pos += spa_scnprintf(pos, end - pos, "]");
return strdup(json);
}
/** Initialize PipeWire
*
* \param argc pointer to argc
@ -604,8 +523,6 @@ void pw_init(int *argc, char **argv[])
spa_list_init(&support->registry.handles);
if (pw_log_is_default()) {
char *patterns = NULL;
n_items = 0;
if (!support->no_color) {
if ((str = getenv("PIPEWIRE_LOG_COLOR")) == NULL)
@ -619,8 +536,6 @@ void pw_init(int *argc, char **argv[])
items[n_items++] = SPA_DICT_ITEM_INIT(SPA_KEY_LOG_LEVEL, level);
if ((str = getenv("PIPEWIRE_LOG")) != NULL)
items[n_items++] = SPA_DICT_ITEM_INIT(SPA_KEY_LOG_FILE, str);
if ((patterns = parse_pw_debug_env()) != NULL)
items[n_items++] = SPA_DICT_ITEM_INIT(SPA_KEY_LOG_PATTERNS, patterns);
info = SPA_DICT_INIT(items, n_items);
log = add_interface(support, SPA_NAME_SUPPORT_LOG, SPA_TYPE_INTERFACE_Log, &info);
@ -634,7 +549,10 @@ void pw_init(int *argc, char **argv[])
pw_log_set(log);
}
#endif
free(patterns);
str = getenv("PIPEWIRE_DEBUG");
if (str && *str)
pw_log_set_level_string(str);
} else {
support->support[support->n_support++] =
SPA_SUPPORT_INIT(SPA_TYPE_INTERFACE_Log, pw_log_get());
@ -687,7 +605,7 @@ void pw_deinit(void)
goto done;
pthread_mutex_lock(&support_lock);
pw_log_set(NULL);
pw_log_deinit();
spa_list_consume(h, &registry->handles, link)
unref_handle(h);

View File

@ -1295,7 +1295,10 @@ void pw_settings_clean(struct pw_context *context);
bool pw_should_dlclose(void);
bool pw_parse_log_level(const char *str, enum spa_log_level *l);
int pw_log_set_level_string(const char *str);
void pw_log_topic_register_enum(const struct spa_log_topic_enum *e);
void pw_log_topic_unregister_enum(const struct spa_log_topic_enum *e);
/** \endcond */

View File

@ -142,13 +142,7 @@ static int metadata_property(void *data, uint32_t subject, const char *key,
return 0;
if (spa_streq(key, "log.level")) {
enum spa_log_level lev;
if (!value)
pw_log_set_level(DEFAULT_LOG_LEVEL);
else if (pw_parse_log_level(value, &lev))
pw_log_set_level(lev);
else
if (pw_log_set_level_string(value) < 0)
pw_log_warn("Ignoring unknown settings metadata log.level '%s'", value);
} else if (spa_streq(key, "clock.rate")) {
v = value ? atoi(value) : 0;