db: Instrument the DB interactions to trace their execution

db/utils.c

@@ -1,5 +1,6 @@
 #include "config.h"
 #include <ccan/tal/str/str.h>
+#include <common/trace.h>
 #include <common/utils.h>
 #include <db/common.h>
 #include <db/utils.h>
@@ -140,9 +141,12 @@ bool db_query_prepared_canfail(struct db_stmt *stmt)
 	 * read-only path. */
 	bool ret;
 	assert(stmt->query->readonly);
+	trace_span_start("db_query_prepared", stmt);
+	trace_span_tag(&ret, "query", stmt->query->query);
 	ret = stmt->db->config->query_fn(stmt);
 	stmt->executed = true;
 	list_del_from(&stmt->db->pending_statements, &stmt->list);
+	trace_span_end(stmt);
 	return ret;
 }
 
@@ -171,7 +175,10 @@ bool db_step(struct db_stmt *stmt)
 
 void db_exec_prepared_v2(struct db_stmt *stmt TAKES)
 {
+	trace_span_start("db_query_prepared", stmt);
+	trace_span_tag(stmt, "query", stmt->query->query);
 	bool ret = stmt->db->config->exec_fn(stmt);
+	trace_span_end(stmt);
 
 	if (stmt->db->readonly)
 		assert(stmt->query->readonly);
@@ -357,10 +364,12 @@ struct db *db_open_(const tal_t *ctx, const char *filename,
 	/* This must be outside a transaction, so catch it */
 	assert(!db->in_transaction);
 
+	trace_span_start("db_setup", db);
 	db_prepare_for_changes(db);
 	if (db->config->setup_fn && !db->config->setup_fn(db))
 		db_fatal(db, "Error calling DB setup: %s", db->error);
 	db_report_changes(db, NULL, 0);
+	trace_span_end(db);
 
 	return db;
 }

plugins/bkpr/test/Makefile

@@ -18,6 +18,7 @@ BOOKKEEPER_TEST_COMMON_OBJS :=			\
 	common/memleak.o			\
 	common/node_id.o			\
 	common/setup.o				\
+	common/trace.o				\
 	common/timeout.o			\
 	common/utils.o				\
 	common/version.o			\

plugins/bkpr/test/run-bkpr_db.c

@@ -253,21 +253,6 @@ 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,21 +259,6 @@ 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)

wallet/test/Makefile

@@ -25,6 +25,7 @@ WALLET_TEST_COMMON_OBJS :=			\
 	common/pseudorand.o			\
 	common/setup.o				\
 	common/timeout.o			\
+	common/trace.o				\
 	common/utils.o				\
 	common/utxo.o				\
 	common/wireaddr.o			\

wallet/test/run-db.c

@@ -325,12 +325,6 @@ u8 *towire_hsmd_get_output_scriptpubkey(const tal_t *ctx UNNEEDED, u64 channel_i
 /* Generated stub for towire_temporary_node_failure */
 u8 *towire_temporary_node_failure(const tal_t *ctx UNNEEDED)
 { fprintf(stderr, "towire_temporary_node_failure 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 txfilter_add_scriptpubkey */
 void txfilter_add_scriptpubkey(struct txfilter *filter UNNEEDED, const u8 *script TAKES UNNEEDED)
 { fprintf(stderr, "txfilter_add_scriptpubkey called!\n"); abort(); }

wallet/test/run-wallet.c

@@ -1155,12 +1155,6 @@ u8 *towire_warningfmt(const tal_t *ctx UNNEEDED,
 		      const struct channel_id *channel UNNEEDED,
 		      const char *fmt UNNEEDED, ...)
 { fprintf(stderr, "towire_warningfmt 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 try_reconnect */
 void try_reconnect(const tal_t *ctx UNNEEDED,
 		   struct peer *peer UNNEEDED,