#include "config.h" #include #include #include #include #include #include #include #include #include #include #include #include #if HAVE_USDT #include #define MAX_ACTIVE_SPANS 128 #define SPAN_ID_LEN 33 const char *trace_service_name = "lightningd"; struct span_tag { char *name, *value; }; struct span { size_t key; u64 id; struct span *parent; u64 start_time; u64 end_time; struct span_tag *tags; char *name; }; /* All traces we emit are prefixed with this constant. */ static u64 trace_prefix = 0; static struct span *active_spans; static struct span *current; static size_t last_span_id; static void trace_span_id_serialize(struct span *s, char *dest) { hex_encode(&trace_prefix, 8, dest, 17); hex_encode(&s->id, 8, 16 + dest, 17); } static void trace_init(void) { randombytes_buf(&trace_prefix, sizeof(u64)); active_spans = malloc(sizeof(struct span) * MAX_ACTIVE_SPANS); last_span_id = 1; current = NULL; } /** * Convert the pointer to a context object to a numeric key. */ static size_t trace_key(const void *key) { return (size_t)key; } static struct span *trace_span_find(size_t key) { for (size_t i = 0; i < MAX_ACTIVE_SPANS; i++) if (active_spans[i].key == key) return &active_spans[i]; return NULL; } /** * Find an empty slot for a new span. */ static struct span *trace_span_slot(void) { struct span *s = trace_span_find(0); /* Might end up here if we have more than MAX_ACTIVE_SPANS * concurrent spans. */ assert(s); assert(s->parent == NULL); assert(s != current); return s; } static void trace_emit(struct span *s) { char id[SPAN_ID_LEN]; trace_span_id_serialize(s, id); char *res = tal_fmt( NULL, "[{\"id\": \"%s\", \"name\": \"%s\", " "\"timestamp\": %" PRIu64 ", \"duration\": %" PRIu64 ",", id + 16, s->name, s->start_time, s->end_time - s->start_time); tal_append_fmt(&res, "\"localEndpoint\": { \"serviceName\": \"%s\"}, ", trace_service_name); if (s->parent != NULL) { trace_span_id_serialize(s->parent, id); tal_append_fmt(&res, "\"parentId\": \"%s\",", id + 16); } tal_append_fmt(&res, "\"tags\": {"); for (size_t i = 0; i < tal_count(s->tags); i++) { tal_append_fmt(&res, "%s\"%s\": \"%s\"", i == 0 ? "" : ", ", s->tags[i].name, s->tags[i].value); } trace_span_id_serialize(s, id); tal_append_fmt(&res, "}, \"traceId\": \"%.*s\"}]", 16, id); DTRACE_PROBE2(lightningd, span_emit, id, res); tal_free(res); } /** * Release the span back into the pool of available spans. */ static void trace_span_clear(struct span *s) { s->key = 0; s->id = 0; s->parent = NULL; s->name = tal_free(s->name); s->tags = tal_free(s->tags); } void trace_span_start(const char *name, const void *key) { if (!trace_prefix) trace_init(); size_t numkey = trace_key(key); struct timeabs now = time_now(); assert(trace_span_find(numkey) == NULL); struct span *s = trace_span_slot(); assert(current == NULL || current->id != 0); // assert(current != s); s->key = numkey; s->id = last_span_id++; s->start_time = (now.ts.tv_sec * 1000000) + now.ts.tv_nsec / 1000; s->parent = current; s->tags = notleak(tal_arr(NULL, struct span_tag, 0)); s->name = notleak(tal_strdup(NULL, name)); current = s; DTRACE_PROBE1(lightningd, span_start, s->id); } void trace_span_end(const void *key) { size_t numkey = trace_key(key); struct span *s = trace_span_find(numkey); assert(s && "Span to end not found"); assert(s == current && "Ending a span that isn't the current one"); struct timeabs now = time_now(); s->end_time = (now.ts.tv_sec * 1000000) + now.ts.tv_nsec / 1000; DTRACE_PROBE1(lightningd, span_end, s->id); trace_emit(s); /* Reset the context span we are in. */ current = s->parent; /* Now reset the span */ trace_span_clear(s); } void trace_span_tag(const void *key, const char *name, const char *value) { size_t numkey = trace_key(key); struct span *span = trace_span_find(numkey); assert(span); size_t s = tal_count(span->tags); tal_resize(&span->tags, s + 1); span->tags[s].name = tal_strdup(span->tags, name); span->tags[s].value = tal_strdup(span->tags, value); } void trace_span_suspend(const void *key) { size_t numkey = trace_key(key); struct span *span = trace_span_find(numkey); current = NULL; DTRACE_PROBE1(lightningd, span_suspend, span->id); } void trace_span_resume(const void *key) { size_t numkey = trace_key(key); current = trace_span_find(numkey); DTRACE_PROBE1(lightningd, span_resume, current->id); } #else /* HAVE_USDT */ void trace_span_start(const char *name, const void *key) {} void trace_span_end(const void *key) {} void trace_span_suspend(const void *key) {} void trace_span_resume(const void *key) {} void trace_span_tag(const void *key, const char *name, const char *value) {} #endif /* HAVE_USDT */