udebug: add support for logging via udebug

Signed-off-by: John Crispin <john@phrozen.org>
Signed-off-by: Felix Fietkau <nbd@nbd.name>

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)

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
 

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);
 }

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 @@ static void handle_firmware(struct blob_attr *msg, struct blob_attr *data)
 		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);
 }
 

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

procd.h

@@ -18,6 +18,7 @@
 #include <libubox/uloop.h>
 #include <libubox/utils.h>
 #include <libubus.h>
+#include <udebug.h>
 
 #include <stdio.h>
 #include <syslog.h>
@@ -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

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;
 		}
 	}

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;

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);
 	}
 

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);