diff --git a/src/traces/traces.c b/src/traces/traces.c index f10eae249..0919d3b77 100644 --- a/src/traces/traces.c +++ b/src/traces/traces.c @@ -6,6 +6,8 @@ #include "foundation/constants.h" enum { TRACE_PATH_SLASHES = 3, TRACE_NOT_FOUND = -1 }; +#include +#include #include #include #include @@ -63,6 +65,38 @@ const char *cbm_extract_path_from_url(const char *url, char *buf, size_t buf_sz) /* ── parseDuration ───────────────────────────────────────────────── */ +/* Read one nanosecond timestamp. Answers false for text that does not read + * cleanly from its first character to its last, the way src/main.c:1104 does + * it: an end pointer says where the read stopped, errno catches a number too + * large, and *end == '\0' catches anything left over. A leading blank is + * refused too, because strtoll would otherwise step over it. */ +static bool trace_read_nano(const char *text, int64_t *out) { + if (!text || !text[0] || isspace((unsigned char)text[0])) { + return false; + } + char *end = NULL; + errno = 0; + long long value = strtoll(text, &end, CBM_DECIMAL_BASE); + if (errno != 0 || !end || end == text || *end != '\0') { + return false; + } + *out = (int64_t)value; + return true; +} + +int64_t cbm_parse_duration_checked(const char *start_nano, const char *end_nano, bool *ok) { + int64_t start = 0; + int64_t end = 0; + bool read_both = trace_read_nano(start_nano, &start) && trace_read_nano(end_nano, &end); + if (ok) { + *ok = read_both; + } + if (!read_both) { + return 0; + } + return (end > start) ? (end - start) : 0; +} + int64_t cbm_parse_duration(const char *start_nano, const char *end_nano) { if (!start_nano || !end_nano) { return 0; @@ -115,7 +149,14 @@ bool cbm_extract_http_info(const cbm_trace_span_t *span, const char *service_nam return false; } - out->duration_ns = cbm_parse_duration(span->start_time, span->end_time); + /* A timestamp nobody can read is not a measurement. It used to read as 0, + * so an unreadable START time reported the whole end time as the duration + * -- a made-up number that looks like a real one. The HTTP method and path + * on this span are still good, so the span is still returned and only the + * duration says it is missing. */ + bool timed = false; + int64_t duration = cbm_parse_duration_checked(span->start_time, span->end_time, &timed); + out->duration_ns = timed ? duration : CBM_DURATION_UNKNOWN; return true; } diff --git a/src/traces/traces.h b/src/traces/traces.h index ff628e44d..3f18e37ea 100644 --- a/src/traces/traces.h +++ b/src/traces/traces.h @@ -43,6 +43,8 @@ typedef struct { const char *path; const char *status_code; int span_kind; + /* Nanoseconds, or CBM_DURATION_UNKNOWN when the span's timestamps could + * not be read. A duration of 0 means the span really took no time. */ int64_t duration_ns; } cbm_http_span_info_t; @@ -62,9 +64,20 @@ bool cbm_extract_http_info(const cbm_trace_span_t *span, const char *service_nam * Writes to buf (up to buf_sz). Returns buf, or "" if not a valid URL. */ const char *cbm_extract_path_from_url(const char *url, char *buf, size_t buf_sz); -/* Parse nanosecond timestamp strings and return duration. */ +/* A duration nobody could measure. Kept apart from 0, which is a real span + * that took no time. */ +#define CBM_DURATION_UNKNOWN (-1) + +/* Parse nanosecond timestamp strings and return duration. Text that cannot be + * read counts as 0, so an unreadable timestamp and a span that took no time + * give the same answer. Use cbm_parse_duration_checked when that matters. */ int64_t cbm_parse_duration(const char *start_nano, const char *end_nano); +/* Same, and also says whether both timestamps could be read. *ok is false for + * a NULL argument and for any text that does not read cleanly end to end, so + * a caller can tell "took no time" from "nobody could measure this". */ +int64_t cbm_parse_duration_checked(const char *start_nano, const char *end_nano, bool *ok); + /* Calculate P99 from an array of int64_t values. * Sorts values in-place. Returns 0 for empty array. */ int64_t cbm_calculate_p99(int64_t *values, int count); diff --git a/tests/test_traces.c b/tests/test_traces.c index 18d02a90d..efae8918f 100644 --- a/tests/test_traces.c +++ b/tests/test_traces.c @@ -265,6 +265,82 @@ TEST(traces_parse_duration_large_values) { PASS(); } +/* A timestamp the code cannot read is not a measurement of no time. + * + * strtoll answers 0 for text it cannot read, and the subtraction guard turns + * that into a duration of 0 ns. A span that genuinely took no time and a span + * whose timestamps were garbage then look the same, and no later query can + * tell them apart. cbm_parse_duration_checked reports which one it read. */ +TEST(traces_parse_duration_checked_reports_unreadable_timestamps) { + bool ok = false; + + /* Positive control: a good pair still reads, and still answers the same + * number cbm_parse_duration answers. */ + int64_t d = cbm_parse_duration_checked("1000000000", "1050000000", &ok); + ASSERT(ok); + ASSERT_EQ(d, 50000000); + + /* A real measurement of no time reads fine. Zero is an answer here. */ + ok = false; + d = cbm_parse_duration_checked("5000000000", "5000000000", &ok); + ASSERT(ok); + ASSERT_EQ(d, 0); + + /* End before start reads fine too. The clamp to 0 is the caller's rule, + * not a reading failure. */ + ok = false; + d = cbm_parse_duration_checked("1000", "500", &ok); + ASSERT(ok); + ASSERT_EQ(d, 0); + + /* The claim: text that does not read is reported, not folded into 0. */ + const char *unreadable[] = {"abc", "", " 100", "100ns", "1e9"}; + for (size_t i = 0; i < sizeof(unreadable) / sizeof(unreadable[0]); i++) { + ok = true; + (void)cbm_parse_duration_checked(unreadable[i], "1050000000", &ok); + ASSERT(!ok); + ok = true; + (void)cbm_parse_duration_checked("1000000000", unreadable[i], &ok); + ASSERT(!ok); + } + + /* A NULL argument was never a measurement either. */ + ok = true; + (void)cbm_parse_duration_checked(NULL, "1000", &ok); + ASSERT(!ok); + ok = true; + (void)cbm_parse_duration_checked("1000", NULL, &ok); + ASSERT(!ok); + PASS(); +} + +/* A span whose timestamps cannot be read keeps its method and path, and says + * the duration was not recorded rather than claiming it was zero. */ +TEST(traces_extract_http_info_marks_unreadable_duration) { + cbm_trace_attr_t attrs[] = { + {.key = "http.method", .string_value = "GET"}, + {.key = "http.route", .string_value = "/api/orders"}, + {.key = "http.status_code", .string_value = "200"}, + }; + cbm_trace_span_t span = { + .kind = 2, + .attributes = attrs, + .attr_count = 3, + .start_time = "not-a-timestamp", + .end_time = "1050000000", + }; + + cbm_http_span_info_t info; + bool ok = cbm_extract_http_info(&span, "svc", &info); + /* The HTTP part of the span is still good data, so it is still returned. */ + ASSERT(ok); + ASSERT_STR_EQ(info.method, "GET"); + ASSERT_STR_EQ(info.path, "/api/orders"); + /* The claim: not recorded, rather than a duration of zero. */ + ASSERT_EQ(info.duration_ns, CBM_DURATION_UNKNOWN); + PASS(); +} + /* ── TestCalculateP99 — edge cases ────────────────────────────────── */ TEST(traces_calculate_p99_100_values) { @@ -341,4 +417,6 @@ SUITE(traces) { RUN_TEST(traces_parse_duration_both_null); RUN_TEST(traces_parse_duration_equal); RUN_TEST(traces_parse_duration_large_values); + RUN_TEST(traces_parse_duration_checked_reports_unreadable_timestamps); + RUN_TEST(traces_extract_http_info_marks_unreadable_duration); }