trace: use a static buffer instead of tal_fmt().

There's an EBPF limit anyway, so stick with a 512-byte buffer.

This brings us back to 621ns per trace:

Before:
	real	0m13.441000-14.592000(14.2686+/-0.43)s
	user	0m11.265000-12.289000(11.9626+/-0.37)s
	sys	0m2.175000-2.381000(2.3048+/-0.072)s

After:
	real	0m5.819000-6.472000(6.2064+/-0.26)s
	user	0m3.779000-4.101000(3.956+/-0.12)s
	sys	0m2.040000-2.431000(2.2496+/-0.15)s

Signed-off-by: Rusty Russell <[email protected]>

Author: rustyrussell

common/trace.c

@@ -2,7 +2,6 @@
 #include <assert.h>
 #include <ccan/htable/htable.h>
 #include <ccan/str/hex/hex.h>
-#include <ccan/tal/str/str.h>
 #include <ccan/tal/tal.h>
 #include <ccan/time/time.h>
 #include <common/json_stream.h>
@@ -214,11 +213,15 @@ static struct span *trace_span_slot(void)
 	return s;
 }
 
+#define MAX_BUF_SIZE 512
+
 static void trace_emit(struct span *s)
 {
 	char span_id[HEX_SPAN_ID_SIZE];
 	char trace_id[HEX_TRACE_ID_SIZE];
 	char parent_span_id[HEX_SPAN_ID_SIZE];
+	char buffer[MAX_BUF_SIZE + 1];
+	size_t len;
 
 	/* If this is a remote span it's not up to us to emit it. Make
 	 * this a no-op. `trace_span_end` will take care of cleaning
@@ -232,32 +235,41 @@ static void trace_emit(struct span *s)
 	if (s->parent)
 		hex_encode(s->parent_id, SPAN_ID_SIZE, parent_span_id, HEX_SPAN_ID_SIZE);
 
-	char *res = tal_fmt(
-	    NULL,
-	    "[{\"id\": \"%s\", \"name\": \"%s\", "
-	    "\"timestamp\": %" PRIu64 ", \"duration\": %" PRIu64 ",",
-	    span_id, s->name, s->start_time, s->end_time - s->start_time);
-
-	tal_append_fmt(&res, "\"localEndpoint\": { \"serviceName\": \"%s\"}, ",
-		       trace_service_name);
+	len = snprintf(buffer, MAX_BUF_SIZE,
+		       "[{\"id\": \"%s\", \"name\": \"%s\", "
+		       "\"timestamp\": %" PRIu64 ", \"duration\": %" PRIu64 ","
+		       "\"localEndpoint\": { \"serviceName\": \"%s\"}, ",
+		       span_id, s->name, s->start_time, s->end_time - s->start_time, trace_service_name);
 
 	if (s->parent != NULL) {
-		tal_append_fmt(&res, "\"parentId\": \"%s\",", parent_span_id);
+		len += snprintf(buffer + len, MAX_BUF_SIZE - len,
+				"\"parentId\": \"%s\",",
+				parent_span_id);
+		if (len > MAX_BUF_SIZE)
+			len = MAX_BUF_SIZE;
 	}
 
-	tal_append_fmt(&res, "\"tags\": {");
+	len += snprintf(buffer + len, MAX_BUF_SIZE - len,
+			"\"tags\": {");
+	if (len > MAX_BUF_SIZE)
+		len = MAX_BUF_SIZE;
 	for (size_t i = 0; i < SPAN_MAX_TAGS; i++) {
 		if (!s->tags[i].name)
 			continue;
-		tal_append_fmt(&res, "%s\"%s\": \"%.*s\"", i == 0 ? "" : ", ",
-			       s->tags[i].name,
-			       s->tags[i].valuelen,
-			       s->tags[i].valuestr);
+		len += snprintf(buffer + len, MAX_BUF_SIZE - len,
+				"%s\"%s\": \"%.*s\"", i == 0 ? "" : ", ",
+				s->tags[i].name,
+				s->tags[i].valuelen,
+				s->tags[i].valuestr);
+		if (len > MAX_BUF_SIZE)
+			len = MAX_BUF_SIZE;
 	}
-
-	tal_append_fmt(&res, "}, \"traceId\": \"%s\"}]", trace_id);
-	DTRACE_PROBE2(lightningd, span_emit, span_id, res);
-	tal_free(res);
+	len += snprintf(buffer + len, MAX_BUF_SIZE - len,
+			"}, \"traceId\": \"%s\"}]", trace_id);
+	if (len > MAX_BUF_SIZE)
+		len = MAX_BUF_SIZE;
+	buffer[len] = '\0';
+	DTRACE_PROBE2(lightningd, span_emit, span_id, buffer);
 }
 
 /**