askrene: add child_log function so child can do logging.

We just shim rq_log for now, but we'll be weaning the child process off
that soon.

Signed-off-by: Rusty Russell <rusty@rustcorp.com.au>

plugins/askrene/Makefile

@@ -10,7 +10,8 @@ PLUGIN_ASKRENE_SRC := \
 	plugins/askrene/explain_failure.c \
 	plugins/askrene/graph.c \
 	plugins/askrene/priorityqueue.c \
-	plugins/askrene/algorithm.c
+	plugins/askrene/algorithm.c \
+	plugins/askrene/child/child_log.c \
 
 PLUGIN_ASKRENE_HEADER := \
 	plugins/askrene/askrene.h \
@@ -24,7 +25,8 @@ PLUGIN_ASKRENE_HEADER := \
 	plugins/askrene/explain_failure.h \
 	plugins/askrene/graph.h \
 	plugins/askrene/priorityqueue.h \
-	plugins/askrene/algorithm.h
+	plugins/askrene/algorithm.h \
+	plugins/askrene/child/child_log.h \
 
 PLUGIN_ASKRENE_OBJS := $(PLUGIN_ASKRENE_SRC:.c=.o)
 

plugins/askrene/askrene.c

@@ -20,16 +20,22 @@
 #include <common/json_param.h>
 #include <common/json_stream.h>
 #include <common/route.h>
+#include <common/status_wiregen.h>
 #include <errno.h>
 #include <inttypes.h>
 #include <math.h>
 #include <plugins/askrene/askrene.h>
+#include <plugins/askrene/child/child_log.h>
 #include <plugins/askrene/flow.h>
 #include <plugins/askrene/layer.h>
 #include <plugins/askrene/mcf.h>
 #include <plugins/askrene/reserve.h>
 #include <sys/wait.h>
 #include <unistd.h>
+#include <wire/wire_sync.h>
+
+/* Temporary hack */
+static bool am_child = false;
 
 /* "spendable" for a channel assumes a single HTLC: for additional HTLCs,
  * the need to pay for fees (if we're the owner) reduces it */
@@ -317,6 +323,12 @@ const char *rq_log(const tal_t *ctx,
 	msg = tal_vfmt(ctx, fmt, args);
 	va_end(args);
 
+	/* FIXME: This is a hack! */
+	if (am_child) {
+		child_log(tmpctx, level, "%s", msg);
+		return msg;
+	}
+
 	plugin_notify_message(rq->cmd, level, "%s", msg);
 
 	/* Notifications already get logged at debug. Otherwise reduce
@@ -630,9 +642,10 @@ static int fork_router_child(struct route_query *rq,
 			     bool include_fees,
 			     const char *cmd_id,
 			     struct json_filter *cmd_filter,
+			     int *log_fd,
 			     int *child_pid)
 {
-	int replyfds[2];
+	int replyfds[2], logfds[2];
 	double probability;
 	struct flow **flows;
 	struct route **routes;
@@ -642,19 +655,31 @@ static int fork_router_child(struct route_query *rq,
 
 	if (pipe(replyfds) != 0)
 		return -1;
-	*child_pid = fork();
-	if (*child_pid < 0) {
+	if (pipe(logfds) != 0) {
 		close_noerr(replyfds[0]);
 		close_noerr(replyfds[1]);
 		return -1;
 	}
+	*child_pid = fork();
+	if (*child_pid < 0) {
+		close_noerr(replyfds[0]);
+		close_noerr(replyfds[1]);
+		close_noerr(logfds[0]);
+		close_noerr(logfds[1]);
+		return -1;
+	}
 	if (*child_pid != 0) {
+		close(logfds[1]);
 		close(replyfds[1]);
+		*log_fd = logfds[0];
 		return replyfds[0];
 	}
 
 	/* We are the child.  Run the algo */
+	close(logfds[0]);
 	close(replyfds[0]);
+	set_child_log_fd(logfds[1]);
+	am_child = true;
 	if (algo == ALGO_SINGLE_PATH) {
 		err = single_path_routes(rq, rq, deadline, srcnode, dstnode,
 					 amount, maxfee, finalcltv,
@@ -710,6 +735,18 @@ static int fork_router_child(struct route_query *rq,
 	exit(0);
 }
 
+static void process_child_logs(struct route_query *rq, int log_fd)
+{
+	u8 *msg;
+	while ((msg = wire_sync_read(tmpctx, log_fd)) != NULL) {
+		enum log_level level;
+		char *entry;
+		struct node_id *peer;
+		if (fromwire_status_log(tmpctx, msg, &level, &peer, &entry))
+			rq_log(tmpctx, rq, level, "%s", entry);
+	}
+}
+
 static struct command_result *do_getroutes(struct command *cmd,
 					   struct gossmap_localmods *localmods,
 					   struct getroutes_info *info)
@@ -720,7 +757,7 @@ static struct command_result *do_getroutes(struct command *cmd,
 	bool include_fees;
 	const char *err, *json;
 	struct timemono time_start, deadline;
-	int child_fd, child_pid, child_status;
+	int child_fd, log_fd, child_pid, child_status;
 
 	/* update the gossmap */
 	if (gossmap_refresh(askrene->gossmap)) {
@@ -836,13 +873,15 @@ static struct command_result *do_getroutes(struct command *cmd,
 				     deadline, srcnode, dstnode, info->amount,
 				     info->maxfee, info->finalcltv, info->maxdelay,
 				     include_fees,
-				     cmd->id, cmd->filter, &child_pid);
+				     cmd->id, cmd->filter, &log_fd, &child_pid);
 	if (child_fd == -1) {
 		err = tal_fmt(tmpctx, "failed to fork: %s", strerror(errno));
 		goto fail_broken;
 	}
 
 	/* FIXME: Go async! */
+	process_child_logs(rq, log_fd);
+	close(log_fd);
 	json = grab_fd_str(cmd, child_fd);
 	close(child_fd);
 	waitpid(child_pid, &child_status, 0);

plugins/askrene/child/child_log.c

@@ -0,0 +1,57 @@
+#include "config.h"
+#include <assert.h>
+#include <ccan/read_write_all/read_write_all.h>
+#include <ccan/tal/str/str.h>
+#include <common/status_wiregen.h>
+#include <common/utils.h>
+#include <plugins/askrene/child/child_log.h>
+#include <wire/wire_sync.h>
+
+static int log_fd = -1;
+
+static const char *child_logv(const tal_t *ctx,
+			      enum log_level level,
+			      const char *fmt,
+			      va_list ap)
+{
+	const char *str = tal_vfmt(ctx, fmt, ap);
+	u8 *msg;
+
+	/* We reuse status_wire here */
+	msg = towire_status_log(NULL, level, NULL, str);
+	if (!wire_sync_write(log_fd, take(msg)))
+		abort();
+	return str;
+}
+
+const char *child_log(const tal_t *ctx,
+		      enum log_level level,
+		      const char *fmt,
+		      ...)
+{
+	va_list args;
+	const char *str;
+
+	va_start(args, fmt);
+	str = child_logv(ctx, level, fmt, args);
+	va_end(args);
+	return str;
+}
+
+void child_err(const char *fmt, ...)
+{
+	va_list args;
+
+	va_start(args, fmt);
+	child_logv(tmpctx, LOG_BROKEN, fmt, args);
+	va_end(args);
+
+	abort();
+}
+
+void set_child_log_fd(int fd)
+{
+	assert(log_fd == -1);
+	assert(fd != -1);
+	log_fd = fd;
+}

plugins/askrene/child/child_log.h

@@ -0,0 +1,20 @@
+#ifndef LIGHTNING_PLUGINS_ASKRENE_CHILD_CHILD_LOG_H
+#define LIGHTNING_PLUGINS_ASKRENE_CHILD_CHILD_LOG_H
+#include "config.h"
+#include <ccan/tal/tal.h>
+#include <common/status_levels.h>
+
+/* Logs this, and also returns the string allocated off ctx */
+const char *child_log(const tal_t *ctx,
+		      enum log_level level,
+		      const char *fmt,
+		      ...)
+	PRINTF_FMT(3,4);
+
+/* BROKEN variant. */
+void child_err(const char *fmt, ...)
+	PRINTF_FMT(1, 2) NORETURN;
+
+/* At initialization, we set this to the fd for child_log() to write to */
+void set_child_log_fd(int fd);
+#endif /* LIGHTNING_PLUGINS_ASKRENE_CHILD_CHILD_LOG_H */