From 7e6c6efd6fbcc7955801c5e2ac915a90697e1fd9 Mon Sep 17 00:00:00 2001 From: John Crispin Date: Tue, 28 Nov 2023 08:48:33 +0100 Subject: [PATCH] udebug: add support for logging via udebug Signed-off-by: John Crispin Signed-off-by: Felix Fietkau --- CMakeLists.txt | 7 +++++-- log.h | 7 +++++++ plug/coldplug.c | 6 +++--- plug/hotplug.c | 22 ++++++++++---------- procd.c | 50 ++++++++++++++++++++++++++++++++++++++++++++++ procd.h | 4 ++++ service/instance.c | 24 +++++++++++----------- service/service.c | 10 +++++----- service/watch.c | 6 +++--- ubus.c | 8 ++++++++ 10 files changed, 108 insertions(+), 36 deletions(-) diff --git a/CMakeLists.txt b/CMakeLists.txt index 488c555..e734bf7 100644 --- a/CMakeLists.txt +++ b/CMakeLists.txt @@ -31,8 +31,9 @@ FIND_LIBRARY(uci NAMES uci) FIND_LIBRARY(blobmsg_json NAMES blobmsg_json) FIND_LIBRARY(json_script NAMES json_script) FIND_LIBRARY(json NAMES json-c json) +FIND_LIBRARY(udebug NAMES udebug) -SET(LIBS ${ubox} ${ubus} ${json} ${blobmsg_json} ${json_script}) +SET(LIBS ${ubox} ${ubus} ${json} ${blobmsg_json} ${json_script} ${udebug}) IF(DEBUG) ADD_DEFINITIONS(-DUDEV_DEBUG -g3) @@ -52,12 +53,14 @@ add_subdirectory(upgraded) ADD_EXECUTABLE(procd ${SOURCES}) TARGET_LINK_LIBRARIES(procd ${LIBS}) +SET_TARGET_PROPERTIES(procd PROPERTIES COMPILE_DEFINITIONS "HAS_UDEBUG") INSTALL(TARGETS procd RUNTIME DESTINATION ${CMAKE_INSTALL_SBINDIR} ) FIND_PATH(ubox_include_dir libubox/uloop.h) -INCLUDE_DIRECTORIES(${ubox_include_dir}) +FIND_PATH(udebug_include_dir NAMES udebug.h) +INCLUDE_DIRECTORIES(${ubox_include_dir} ${udebug_include_dir}) IF(DISABLE_INIT) ADD_DEFINITIONS(-DDISABLE_INIT) diff --git a/log.h b/log.h index f0c4268..77bb34b 100644 --- a/log.h +++ b/log.h @@ -22,6 +22,13 @@ ulog(LOG_NOTICE, fmt, ## __VA_ARGS__); \ } } while (0) +#define P_DEBUG(level, fmt, ...) do { \ + if (debug >= level) { \ + ulog(LOG_NOTICE, fmt, ## __VA_ARGS__); \ + } else { \ + procd_udebug_printf(fmt, ## __VA_ARGS__); \ + } } while (0) + #define LOG ULOG_INFO #define ERROR ULOG_ERR diff --git a/plug/coldplug.c b/plug/coldplug.c index 308b79d..f84acef 100644 --- a/plug/coldplug.c +++ b/plug/coldplug.c @@ -29,14 +29,14 @@ static struct uloop_process udevtrigger; static void coldplug_complete(struct uloop_timeout *t) { - DEBUG(4, "Coldplug complete\n"); + P_DEBUG(4, "Coldplug complete\n"); hotplug_last_event(NULL); procd_state_next(); } static void udevtrigger_complete(struct uloop_process *proc, int ret) { - DEBUG(4, "Finished udevtrigger\n"); + P_DEBUG(4, "Finished udevtrigger\n"); hotplug_last_event(coldplug_complete); } @@ -70,5 +70,5 @@ void procd_coldplug(void) uloop_process_add(&udevtrigger); - DEBUG(4, "Launched coldplug instance, pid=%d\n", (int) udevtrigger.pid); + P_DEBUG(4, "Launched coldplug instance, pid=%d\n", (int) udevtrigger.pid); } diff --git a/plug/hotplug.c b/plug/hotplug.c index beff38a..53f3383 100644 --- a/plug/hotplug.c +++ b/plug/hotplug.c @@ -231,7 +231,7 @@ static void handle_firmware(struct blob_attr *msg, struct blob_attr *data) int fw, src, load, len; static char buf[4096]; - DEBUG(2, "Firmware request for %s/%s\n", dir, file); + P_DEBUG(2, "Firmware request for %s/%s\n", dir, file); if (!file || !dir || !dev) { ERROR("Request for unknown firmware %s/%s\n", dir, file); @@ -296,7 +296,7 @@ send_to_kernel: ERROR("failed to write to %s: %m\n", loadpath); close(load); - DEBUG(2, "Done loading %s\n", path); + P_DEBUG(2, "Done loading %s\n", path); exit(EXIT_FAILURE); } @@ -305,12 +305,12 @@ static void handle_start_console(struct blob_attr *msg, struct blob_attr *data) { char *dev = blobmsg_get_string(blobmsg_data(data)); - DEBUG(2, "Start console request for %s\n", dev); + P_DEBUG(2, "Start console request for %s\n", dev); procd_inittab_run("respawn"); procd_inittab_run("askfirst"); - DEBUG(2, "Done starting console for %s\n", dev); + P_DEBUG(2, "Done starting console for %s\n", dev); exit(EXIT_FAILURE); } @@ -390,12 +390,12 @@ static void queue_next(void) uloop_process_add(&queue_proc); - DEBUG(4, "Launched hotplug exec instance, pid=%d\n", (int) queue_proc.pid); + P_DEBUG(4, "Launched hotplug exec instance, pid=%d\n", (int) queue_proc.pid); } static void queue_proc_cb(struct uloop_process *c, int ret) { - DEBUG(4, "Finished hotplug exec instance, pid=%d\n", (int) c->pid); + P_DEBUG(4, "Finished hotplug exec instance, pid=%d\n", (int) c->pid); if (current) { current->complete(current->msg, current->data, ret); @@ -513,13 +513,13 @@ static void rule_handle_command(struct json_script_ctx *ctx, const char *name, int rem, i; if (debug > 3) { - DEBUG(4, "Command: %s\n", name); + P_DEBUG(4, "Command: %s\n", name); blobmsg_for_each_attr(cur, data, rem) - DEBUG(4, " %s\n", (char *) blobmsg_data(cur)); + P_DEBUG(4, " %s\n", (char *) blobmsg_data(cur)); - DEBUG(4, "Message:\n"); + P_DEBUG(4, "Message:\n"); blobmsg_for_each_attr(cur, vars, rem) - DEBUG(4, " %s=%s\n", blobmsg_name(cur), (char *) blobmsg_data(cur)); + P_DEBUG(4, " %s=%s\n", blobmsg_name(cur), (char *) blobmsg_data(cur)); } for (i = 0; i < ARRAY_SIZE(handlers); i++) @@ -560,7 +560,7 @@ static void hotplug_handler_debug(struct blob_attr *data) return; str = blobmsg_format_json(data, true); - DEBUG(3, "%s\n", str); + P_DEBUG(3, "%s\n", str); free(str); } diff --git a/procd.c b/procd.c index 3de6208..1223283 100644 --- a/procd.c +++ b/procd.c @@ -27,6 +27,55 @@ unsigned int debug; +static struct udebug ud; +static struct udebug_buf udb; +static bool udebug_enabled; + +static void procd_udebug_vprintf(const char *format, va_list ap) +{ + if (!udebug_enabled) + return; + + udebug_entry_init(&udb); + udebug_entry_vprintf(&udb, format, ap); + udebug_entry_add(&udb); +} + +void procd_udebug_printf(const char *format, ...) +{ + va_list ap; + + va_start(ap, format); + procd_udebug_vprintf(format, ap); + va_end(ap); +} + +void procd_udebug_set_enabled(bool val) +{ + static const struct udebug_buf_meta meta = { + .name = "procd_log", + .format = UDEBUG_FORMAT_STRING, + }; + + if (udebug_enabled == val) + return; + + udebug_enabled = val; + if (!val) { + ulog_udebug(NULL); + udebug_buf_free(&udb); + udebug_free(&ud); + return; + } + + udebug_init(&ud); + udebug_auto_connect(&ud, NULL); + udebug_buf_init(&udb, 1024, 64 * 1024); + udebug_buf_add(&ud, &udb, &meta); + ulog_udebug(&udb); +} + + static int usage(const char *prog) { fprintf(stderr, "Usage: %s [options]\n" @@ -74,6 +123,7 @@ int main(int argc, char **argv) setsid(); uloop_init(); procd_signal(); + procd_udebug_set_enabled(true); if (getpid() != 1) procd_connect_ubus(); else diff --git a/procd.h b/procd.h index fd29a12..bca3c42 100644 --- a/procd.h +++ b/procd.h @@ -18,6 +18,7 @@ #include #include #include +#include #include #include @@ -55,4 +56,7 @@ void watch_add(const char *_name, void *id); void watch_del(void *id); void watch_ubus(struct ubus_context *ctx); +void procd_udebug_printf(const char *format, ...); +void procd_udebug_set_enabled(bool val); + #endif diff --git a/service/instance.c b/service/instance.c index bb4ded7..ed5d0a4 100644 --- a/service/instance.c +++ b/service/instance.c @@ -664,7 +664,7 @@ instance_start(struct service_instance *in) return; } - DEBUG(2, "Started instance %s::%s[%d]\n", in->srv->name, in->name, pid); + P_DEBUG(2, "Started instance %s::%s[%d]\n", in->srv->name, in->name, pid); in->proc.pid = pid; instance_writepid(in); clock_gettime(CLOCK_MONOTONIC, &in->start); @@ -684,7 +684,7 @@ instance_start(struct service_instance *in) if (in->watchdog.mode != INSTANCE_WATCHDOG_MODE_DISABLED) { uloop_timeout_set(&in->watchdog.timeout, in->watchdog.freq * 1000); - DEBUG(2, "Started instance %s::%s watchdog timer : timeout = %d\n", in->srv->name, in->name, in->watchdog.freq); + P_DEBUG(2, "Started instance %s::%s watchdog timer : timeout = %d\n", in->srv->name, in->name, in->watchdog.freq); } service_event("instance.start", in->srv->name, in->name); @@ -830,7 +830,7 @@ instance_exit(struct uloop_process *p, int ret) clock_gettime(CLOCK_MONOTONIC, &tp); runtime = tp.tv_sec - in->start.tv_sec; - DEBUG(2, "Instance %s::%s exit with error code %d after %ld seconds\n", in->srv->name, in->name, ret, runtime); + P_DEBUG(2, "Instance %s::%s exit with error code %d after %ld seconds\n", in->srv->name, in->name, ret, runtime); in->exit_code = instance_exit_code(ret); uloop_timeout_cancel(&in->timeout); @@ -901,7 +901,7 @@ instance_watchdog(struct uloop_timeout *t) { struct service_instance *in = container_of(t, struct service_instance, watchdog.timeout); - DEBUG(3, "instance %s::%s watchdog timer expired\n", in->srv->name, in->name); + P_DEBUG(3, "instance %s::%s watchdog timer expired\n", in->srv->name, in->name); if (in->respawn) instance_restart(in); @@ -1333,7 +1333,7 @@ instance_config_parse(struct service_instance *in) blobmsg_for_each_attr(cur2, tb[INSTANCE_ATTR_WATCH], rem) { if (blobmsg_type(cur2) != BLOBMSG_TYPE_STRING) continue; - DEBUG(3, "watch for %s\n", blobmsg_get_string(cur2)); + P_DEBUG(3, "watch for %s\n", blobmsg_get_string(cur2)); watch_add(blobmsg_get_string(cur2), in); } } @@ -1423,9 +1423,9 @@ instance_config_parse(struct service_instance *in) int facility = syslog_facility_str_to_int(blobmsg_get_string(tb[INSTANCE_ATTR_FACILITY])); if (facility != -1) { in->syslog_facility = facility; - DEBUG(3, "setting facility '%s'\n", blobmsg_get_string(tb[INSTANCE_ATTR_FACILITY])); + P_DEBUG(3, "setting facility '%s'\n", blobmsg_get_string(tb[INSTANCE_ATTR_FACILITY])); } else - DEBUG(3, "unknown syslog facility '%s' given, using default (LOG_DAEMON)\n", blobmsg_get_string(tb[INSTANCE_ATTR_FACILITY])); + P_DEBUG(3, "unknown syslog facility '%s' given, using default (LOG_DAEMON)\n", blobmsg_get_string(tb[INSTANCE_ATTR_FACILITY])); } if (tb[INSTANCE_ATTR_WATCHDOG]) { @@ -1442,18 +1442,18 @@ instance_config_parse(struct service_instance *in) if (vals[0] >= 0 && vals[0] < __INSTANCE_WATCHDOG_MODE_MAX) { in->watchdog.mode = vals[0]; - DEBUG(3, "setting watchdog mode (%d)\n", vals[0]); + P_DEBUG(3, "setting watchdog mode (%d)\n", vals[0]); } else { in->watchdog.mode = 0; - DEBUG(3, "unknown watchdog mode (%d) given, using default (0)\n", vals[0]); + P_DEBUG(3, "unknown watchdog mode (%d) given, using default (0)\n", vals[0]); } if (vals[1] > 0) { in->watchdog.freq = vals[1]; - DEBUG(3, "setting watchdog timeout (%d)\n", vals[0]); + P_DEBUG(3, "setting watchdog timeout (%d)\n", vals[0]); } else { in->watchdog.freq = 30; - DEBUG(3, "invalid watchdog timeout (%d) given, using default (30)\n", vals[1]); + P_DEBUG(3, "invalid watchdog timeout (%d) given, using default (30)\n", vals[1]); } } @@ -1468,7 +1468,7 @@ instance_config_parse(struct service_instance *in) in->srv->name, in->name, UJAIL_BIN_PATH, r); return false; } - DEBUG(2, "unable to find %s: %m (%d)\n", UJAIL_BIN_PATH, r); + P_DEBUG(2, "unable to find %s: %m (%d)\n", UJAIL_BIN_PATH, r); in->has_jail = false; } } diff --git a/service/service.c b/service/service.c index bb3e121..bd0e290 100644 --- a/service/service.c +++ b/service/service.c @@ -66,14 +66,14 @@ service_instance_update(struct vlist_tree *tree, struct vlist_node *node_new, in_n = container_of(node_new, struct service_instance, node); if (in_o && in_n) { - DEBUG(2, "Update instance %s::%s\n", in_o->srv->name, in_o->name); + P_DEBUG(2, "Update instance %s::%s\n", in_o->srv->name, in_o->name); instance_update(in_o, in_n); instance_free(in_n); } else if (in_o) { - DEBUG(2, "Stop instance %s::%s\n", in_o->srv->name, in_o->name); + P_DEBUG(2, "Stop instance %s::%s\n", in_o->srv->name, in_o->name); instance_stop(in_o, true); } else if (in_n && in_n->srv->autostart) { - DEBUG(2, "Start instance %s::%s\n", in_n->srv->name, in_n->name); + P_DEBUG(2, "Start instance %s::%s\n", in_n->srv->name, in_n->name); instance_start(in_n); } blob_buf_init(&b, 0); @@ -419,11 +419,11 @@ service_handle_set(struct ubus_context *ctx, struct ubus_object *obj, s = avl_find_element(&services, name, s, avl); if (s) { - DEBUG(2, "Update service %s\n", name); + P_DEBUG(2, "Update service %s\n", name); return service_update(s, tb, add); } - DEBUG(2, "Create service %s\n", name); + P_DEBUG(2, "Create service %s\n", name); s = service_alloc(name); if (!s) return UBUS_STATUS_UNKNOWN_ERROR; diff --git a/service/watch.c b/service/watch.c index 349b484..e6f8da0 100644 --- a/service/watch.c +++ b/service/watch.c @@ -40,7 +40,7 @@ static void watch_subscribe_cb(struct ubus_context *ctx, struct ubus_event_handl struct blob_attr *attr; const char *path; - DEBUG(3, "ubus event %s\n", type); + P_DEBUG(3, "ubus event %s\n", type); if (strcmp(type, "ubus.object.add") != 0) return; @@ -49,7 +49,7 @@ static void watch_subscribe_cb(struct ubus_context *ctx, struct ubus_event_handl return; path = blobmsg_data(attr); - DEBUG(3, "ubus path %s\n", path); + P_DEBUG(3, "ubus path %s\n", path); list_for_each_entry(o, &watch_objects, list) { unsigned int id; @@ -99,7 +99,7 @@ watch_notify_cb(struct ubus_context *ctx, struct ubus_object *obj, char *str; str = blobmsg_format_json(msg, true); - DEBUG(3, "Received ubus notify '%s': %s\n", method, str); + P_DEBUG(3, "Received ubus notify '%s': %s\n", method, str); free(str); } diff --git a/ubus.c b/ubus.c index a15be4c..b0b7c9a 100644 --- a/ubus.c +++ b/ubus.c @@ -23,6 +23,13 @@ char *ubus_socket = NULL; static struct ubus_context *ctx; static struct uloop_timeout ubus_timer; static int timeout; +static struct udebug_ubus udebug; + +static void +procd_udebug_cb(struct udebug_ubus *ctx, struct blob_attr *data, bool enabled) +{ + procd_udebug_set_enabled(enabled); +} static void reset_timeout(void) { @@ -67,6 +74,7 @@ ubus_connect_cb(struct uloop_timeout *timeout) return; } + udebug_ubus_init(&udebug, ctx, "procd", procd_udebug_cb); ctx->connection_lost = ubus_disconnect_cb; ubus_init_hotplug(ctx); ubus_init_service(ctx); -- 2.30.2