Rebase of PR #7556

bitcoin/test/run-psbt-from-tx.c

@@ -65,12 +65,12 @@ u8 *scriptpubkey_p2wsh(const tal_t *ctx UNNEEDED, const u8 *witnessscript UNNEED
 /* Generated stub for sha256_double */
 void sha256_double(struct sha256_double *shadouble UNNEEDED, const void *p UNNEEDED, size_t len UNNEEDED)
 { fprintf(stderr, "sha256_double called!\n"); abort(); }
+/* Generated stub for signature_from_der */
+bool signature_from_der(const u8 *der UNNEEDED, size_t len UNNEEDED, struct bitcoin_signature *sig UNNEEDED)
+{ fprintf(stderr, "signature_from_der called!\n"); abort(); }
 /* Generated stub for signature_to_der */
 size_t signature_to_der(u8 der[73] UNNEEDED, const struct bitcoin_signature *sig UNNEEDED)
 { fprintf(stderr, "signature_to_der called!\n"); abort(); }
-/* Generated stub for signature_to_der */
-bool signature_from_der(const u8 *der UNNEEDED, size_t len UNNEEDED, struct bitcoin_signature *sig UNNEEDED)
-{ fprintf(stderr, "signature_from_der called!\n"); abort(); }
 /* Generated stub for towire_sha256_double */
 void towire_sha256_double(u8 **pptr UNNEEDED, const struct sha256_double *sha256d UNNEEDED)
 { fprintf(stderr, "towire_sha256_double called!\n"); abort(); }

common/test/run-splice_script.c

@@ -35,6 +35,7 @@ void command_log(struct command *cmd UNNEEDED, enum log_level level UNNEEDED,
 		 const char *fmt UNNEEDED, ...)
 
 { fprintf(stderr, "command_log called!\n"); abort(); }
+/* Generated stub for mvt_tag_str */
 const char *mvt_tag_str(enum mvt_tag tag UNNEEDED)
 { fprintf(stderr, "mvt_tag_str called!\n"); abort(); }
 /* AUTOGENERATED MOCKS END */

common/trace.c

@@ -269,6 +269,12 @@ void trace_span_tag(const void *key, const char *name, const char *value)
 	size_t s = tal_count(span->tags);
 	tal_resize(&span->tags, s + 1);
 	span->tags[s].name = tal_strdup(span->tags, name);
+	if (strstarts(value, "\"")
+		&& strlen(value) > 1
+		&& strends(value, "\"")) {
+		value = tal_strndup(tmpctx, value + 1,
+			strlen(value) - 2);
+	}
 	span->tags[s].value = tal_strdup(span->tags, value);
 }
 

plugins/Makefile

@@ -23,8 +23,8 @@ PLUGIN_COMMANDO_OBJS := $(PLUGIN_COMMANDO_SRC:.c=.o)
 PLUGIN_KEYSEND_SRC := plugins/keysend.c
 PLUGIN_KEYSEND_OBJS := $(PLUGIN_KEYSEND_SRC:.c=.o)
 
-PLUGIN_LIB_SRC := plugins/libplugin.c
-PLUGIN_LIB_HEADER := plugins/libplugin.h
+PLUGIN_LIB_SRC := plugins/libplugin.c common/trace.c
+PLUGIN_LIB_HEADER := plugins/libplugin.h common/trace.h
 PLUGIN_LIB_OBJS := $(PLUGIN_LIB_SRC:.c=.o)
 
 PLUGIN_PAY_LIB_SRC := \

plugins/bkpr/test/run-bkpr_db.c

@@ -253,6 +253,21 @@ void towire_u8_array(u8 **pptr UNNEEDED, const u8 *arr UNNEEDED, size_t num UNNE
 /* Generated stub for towire_wirestring */
 void towire_wirestring(u8 **pptr UNNEEDED, const char *str UNNEEDED)
 { fprintf(stderr, "towire_wirestring called!\n"); abort(); }
+/* Generated stub for trace_span_end */
+void trace_span_end(const void *key UNNEEDED)
+{ fprintf(stderr, "trace_span_end called!\n"); abort(); }
+/* Generated stub for trace_span_resume */
+void trace_span_resume(const void *key UNNEEDED)
+{ fprintf(stderr, "trace_span_resume called!\n"); abort(); }
+/* Generated stub for trace_span_start */
+void trace_span_start(const char *name UNNEEDED, const void *key UNNEEDED)
+{ fprintf(stderr, "trace_span_start called!\n"); abort(); }
+/* Generated stub for trace_span_suspend */
+void trace_span_suspend(const void *key UNNEEDED)
+{ fprintf(stderr, "trace_span_suspend called!\n"); abort(); }
+/* Generated stub for trace_span_tag */
+void trace_span_tag(const void *key UNNEEDED, const char *name UNNEEDED, const char *value UNNEEDED)
+{ fprintf(stderr, "trace_span_tag called!\n"); abort(); }
 /* AUTOGENERATED MOCKS END */
 
 static char *tmp_dsn(const tal_t *ctx)

plugins/bkpr/test/run-recorder.c

@@ -259,6 +259,21 @@ void towire_u8_array(u8 **pptr UNNEEDED, const u8 *arr UNNEEDED, size_t num UNNE
 /* Generated stub for towire_wirestring */
 void towire_wirestring(u8 **pptr UNNEEDED, const char *str UNNEEDED)
 { fprintf(stderr, "towire_wirestring called!\n"); abort(); }
+/* Generated stub for trace_span_end */
+void trace_span_end(const void *key UNNEEDED)
+{ fprintf(stderr, "trace_span_end called!\n"); abort(); }
+/* Generated stub for trace_span_resume */
+void trace_span_resume(const void *key UNNEEDED)
+{ fprintf(stderr, "trace_span_resume called!\n"); abort(); }
+/* Generated stub for trace_span_start */
+void trace_span_start(const char *name UNNEEDED, const void *key UNNEEDED)
+{ fprintf(stderr, "trace_span_start called!\n"); abort(); }
+/* Generated stub for trace_span_suspend */
+void trace_span_suspend(const void *key UNNEEDED)
+{ fprintf(stderr, "trace_span_suspend called!\n"); abort(); }
+/* Generated stub for trace_span_tag */
+void trace_span_tag(const void *key UNNEEDED, const char *name UNNEEDED, const char *value UNNEEDED)
+{ fprintf(stderr, "trace_span_tag called!\n"); abort(); }
 /* AUTOGENERATED MOCKS END */
 
 static char *tmp_dsn(const tal_t *ctx)

plugins/libplugin-pay.c

@@ -11,9 +11,11 @@
 #include <common/memleak.h>
 #include <common/pseudorand.h>
 #include <common/random_select.h>
+#include <common/trace.h>
 #include <errno.h>
 #include <math.h>
 #include <plugins/libplugin-pay.h>
+#include <stdio.h>
 #include <sys/types.h>
 #include <wire/peer_wire.h>
 
@@ -2250,6 +2252,18 @@ static struct command_result *payment_finished(struct payment *p)
 	return command_finished(cmd, ret);
 }
 
+const char * const payment_step_str[] =
+{
+    [PAYMENT_STEP_INITIALIZED] = "PAYMENT_STEP_INITIALIZED",
+    [PAYMENT_STEP_GOT_ROUTE] = "PAYMENT_STEP_GOT_ROUTE",
+    [PAYMENT_STEP_RETRY_GETROUTE]  = "PAYMENT_STEP_RETRY_GETROUTE",
+    [PAYMENT_STEP_ONION_PAYLOAD]  = "PAYMENT_STEP_ONION_PAYLOAD",
+    [PAYMENT_STEP_SPLIT] = "PAYMENT_STEP_SPLIT",
+    [PAYMENT_STEP_RETRY] = "PAYMENT_STEP_RETRY",
+    [PAYMENT_STEP_FAILED]  = "PAYMENT_STEP_FAILED",
+    [PAYMENT_STEP_SUCCESS]  = "PAYMENT_STEP_SUCCESS",
+};
+
 void payment_set_step(struct payment *p, enum payment_step newstep)
 {
 	p->current_modifier = -1;
@@ -2264,19 +2278,26 @@ struct command_result *payment_continue(struct payment *p)
 {
 	struct payment_modifier *mod;
 	void *moddata;
+
+	trace_span_start("payment_continue", p);
 	/* If we are in the middle of calling the modifiers, continue calling
 	 * them, otherwise we can continue with the payment state-machine. */
 	p->current_modifier++;
 	mod = p->modifiers[p->current_modifier];
 
 	if (mod != NULL) {
+		char *str = tal_fmt(tmpctx, "%d", p->current_modifier);
+		trace_span_tag(p, "modifier", str);
+		trace_span_end(p);
 		/* There is another modifier, so call it. */
 		moddata = p->modifier_data[p->current_modifier];
 		return mod->post_step_cb(moddata, p);
 	} else {
 		/* There are no more modifiers, so reset the call chain and
 		 * proceed to the next state. */
 		p->current_modifier = -1;
+		trace_span_tag(p, "step", payment_step_str[p->step]);
+		trace_span_end(p);
 		switch (p->step) {
 		case PAYMENT_STEP_INITIALIZED:
 		case PAYMENT_STEP_RETRY_GETROUTE:
@@ -2299,6 +2320,7 @@ struct command_result *payment_continue(struct payment *p)
 			return command_still_pending(payment_cmd(p));
 		}
 	}
+	trace_span_end(p);
 	/* We should never get here, it'd mean one of the state machine called
 	 * `payment_continue` after the final state. */
 	abort();

plugins/libplugin.c

@@ -15,6 +15,7 @@
 #include <common/memleak.h>
 #include <common/plugin.h>
 #include <common/route.h>
+#include <common/trace.h>
 #include <errno.h>
 #include <plugins/libplugin.h>
 #include <stdio.h>
@@ -1058,7 +1059,14 @@ static void handle_rpc_reply(struct plugin *plugin, const jsmntok_t *toks)
 	cmd_freed = false;
 	tal_add_destructor2(out->cmd, destroy_cmd_mark_freed, &cmd_freed);
 
+	trace_span_resume(out);
 	contenttok = json_get_member(buf, toks, "error");
+
+	/* Annotate the JSON-RPC span whether it succeeded or failed,
+	 * and then emit it. */
+	trace_span_tag(out, "error", contenttok ? "true" : "false");
+	trace_span_end(out);
+
 	if (contenttok) {
 		if (out->errcb)
 			res = out->errcb(out->cmd, out->method, buf, contenttok, out->arg);
@@ -1096,6 +1104,14 @@ send_outreq(const struct out_req *req)
 	json_object_end(req->js);
 	json_stream_close(req->js, req->cmd);
 
+	/* We are about to hand control over to the RPC, so suspend
+	 * the current span. It'll be resumed as soon as we have a
+	 * result to pass to either the error or the success
+	 * callback. */
+	trace_span_start("jsonrpc", req);
+	trace_span_tag(req, "id", req->id);
+	trace_span_suspend(req);
+
 	ld_rpc_send(req->cmd->plugin, req->js);
 	notleak_with_children(req->cmd);
 	return &pending;

plugins/test/run-route-calc.c

@@ -283,7 +283,7 @@ void memleak_scan_htable(struct htable *memtable UNNEEDED, const struct htable *
 void *notleak_(void *ptr UNNEEDED, bool plus_children UNNEEDED)
 { fprintf(stderr, "notleak_ called!\n"); abort(); }
 /* Generated stub for plugin_err */
-void  plugin_err(struct plugin *p UNNEEDED, const char *fmt UNNEEDED, ...)
+void   plugin_err(struct plugin *p UNNEEDED, const char *fmt UNNEEDED, ...)
 { fprintf(stderr, "plugin_err called!\n"); abort(); }
 /* Generated stub for plugin_log */
 void plugin_log(struct plugin *p UNNEEDED, enum log_level l UNNEEDED, const char *fmt UNNEEDED, ...)
@@ -314,6 +314,15 @@ void towire_bigsize(u8 **pptr UNNEEDED, const bigsize_t val UNNEEDED)
 /* Generated stub for towire_channel_id */
 void towire_channel_id(u8 **pptr UNNEEDED, const struct channel_id *channel_id UNNEEDED)
 { fprintf(stderr, "towire_channel_id called!\n"); abort(); }
+/* Generated stub for trace_span_end */
+void trace_span_end(const void *key UNNEEDED)
+{ fprintf(stderr, "trace_span_end called!\n"); abort(); }
+/* Generated stub for trace_span_start */
+void trace_span_start(const char *name UNNEEDED, const void *key UNNEEDED)
+{ fprintf(stderr, "trace_span_start called!\n"); abort(); }
+/* Generated stub for trace_span_tag */
+void trace_span_tag(const void *key UNNEEDED, const char *name UNNEEDED, const char *value UNNEEDED)
+{ fprintf(stderr, "trace_span_tag called!\n"); abort(); }
 /* AUTOGENERATED MOCKS END */
 
 #ifndef SUPERVERBOSE

plugins/test/run-route-overlong.c

@@ -280,7 +280,7 @@ void memleak_scan_htable(struct htable *memtable UNNEEDED, const struct htable *
 void *notleak_(void *ptr UNNEEDED, bool plus_children UNNEEDED)
 { fprintf(stderr, "notleak_ called!\n"); abort(); }
 /* Generated stub for plugin_err */
-void  plugin_err(struct plugin *p UNNEEDED, const char *fmt UNNEEDED, ...)
+void   plugin_err(struct plugin *p UNNEEDED, const char *fmt UNNEEDED, ...)
 { fprintf(stderr, "plugin_err called!\n"); abort(); }
 /* Generated stub for plugin_log */
 void plugin_log(struct plugin *p UNNEEDED, enum log_level l UNNEEDED, const char *fmt UNNEEDED, ...)
@@ -311,6 +311,15 @@ void towire_bigsize(u8 **pptr UNNEEDED, const bigsize_t val UNNEEDED)
 /* Generated stub for towire_channel_id */
 void towire_channel_id(u8 **pptr UNNEEDED, const struct channel_id *channel_id UNNEEDED)
 { fprintf(stderr, "towire_channel_id called!\n"); abort(); }
+/* Generated stub for trace_span_end */
+void trace_span_end(const void *key UNNEEDED)
+{ fprintf(stderr, "trace_span_end called!\n"); abort(); }
+/* Generated stub for trace_span_start */
+void trace_span_start(const char *name UNNEEDED, const void *key UNNEEDED)
+{ fprintf(stderr, "trace_span_start called!\n"); abort(); }
+/* Generated stub for trace_span_tag */
+void trace_span_tag(const void *key UNNEEDED, const char *name UNNEEDED, const char *value UNNEEDED)
+{ fprintf(stderr, "trace_span_tag called!\n"); abort(); }
 /* AUTOGENERATED MOCKS END */
 
 #ifndef SUPERVERBOSE