Skip to content
rachel/workerd
File

Blob: src/workerd/io/trace-test.c++

29.2 KB
1// Copyright (c) 2017-2022 Cloudflare, Inc.
2// Licensed under the Apache 2.0 license found in the LICENSE file or at:
3//     https://opensource.org/licenses/Apache-2.0
4 
5#include <workerd/io/trace.h>
6#include <workerd/util/thread-scopes.h>
7 
8#include <capnp/message.h>
9#include <kj/compat/http.h>
10#include <kj/test.h>
11 
12namespace workerd::tracing {
13namespace {
14 
15class FakeEntropySource final: public kj::EntropySource {
16 public:
17  void generate(kj::ArrayPtr<byte> buffer) override {
18    // Write the uint64_t value to the buffer
19    buffer[0] = counter & 0xff;
20    buffer[1] = (counter >> 8) & 0xff;
21    buffer[2] = (counter >> 16) & 0xff;
22    buffer[3] = (counter >> 24) & 0xff;
23    buffer[4] = (counter >> 32) & 0xff;
24    buffer[5] = (counter >> 40) & 0xff;
25    buffer[6] = (counter >> 48) & 0xff;
26    buffer[7] = (counter >> 56) & 0xff;
27    counter++;
28  }
29 
30 private:
31  uint64_t counter = 0;
32};
33 
34KJ_TEST("can read trace ID string format") {
35  KJ_EXPECT(TraceId::fromGoString("z"_kj) == kj::none);
36 
37  KJ_EXPECT(TraceId::fromGoString("fedcba9876543210z"_kj) == kj::none);
38 
39  // Go parser supports non-(64 or 128) bit lengths -- unclear if anything cares.
40  KJ_EXPECT(TraceId(0, 0) == KJ_ASSERT_NONNULL(TraceId::fromGoString(""_kj)));
41  KJ_EXPECT(TraceId(0x1, 0) == KJ_ASSERT_NONNULL(TraceId::fromGoString("1"_kj)));
42 
43  KJ_EXPECT(TraceId(0xfedcba9876543210, 0) ==
44      KJ_ASSERT_NONNULL(TraceId::fromGoString("fedcba9876543210"_kj)));
45  KJ_EXPECT(TraceId(0xfedcba9876543210, 0) ==
46      KJ_ASSERT_NONNULL(TraceId::fromGoString("FEDCBA9876543210"_kj)));
47 
48  KJ_EXPECT(TraceId(0xfedcba9876543210, 0x1) ==
49      KJ_ASSERT_NONNULL(TraceId::fromGoString("01fedcba9876543210"_kj)));
50 
51  KJ_EXPECT(TraceId(0xfedcba9876543211, 0xfedcba9876543212) ==
52      KJ_ASSERT_NONNULL(TraceId::fromGoString("fedcba9876543212fedcba9876543211"_kj)));
53 
54  KJ_EXPECT(TraceId::fromGoString("01fedcba9876543212fedcba9876543211"_kj) == kj::none);
55}
56 
57KJ_TEST("can write trace ID string format") {
58  KJ_EXPECT(TraceId(0x1, 0).toGoString() == "0000000000000001"_kj);
59  KJ_EXPECT(TraceId(0xfedcba9876543210, 0).toGoString() == "fedcba9876543210"_kj);
60  KJ_EXPECT(TraceId(0xfedcba9876543210, 0x1).toGoString() == "0000000000000001fedcba9876543210"_kj);
61 
62  KJ_EXPECT(TraceId(0xfedcba9876543211, 0xfedcba9876543212).toGoString() ==
63      "fedcba9876543212fedcba9876543211"_kj);
64}
65 
66KJ_TEST("can read trace ID protobuf format") {
67  KJ_EXPECT(TraceId::fromProtobuf(""_kjb) == kj::none);
68  KJ_EXPECT(TraceId::fromProtobuf("z"_kjb) == kj::none);
69  KJ_EXPECT(TraceId::fromProtobuf("\xfe\xdc\xba\x98\x76\x54\x32\x12\xfe"_kjb) == kj::none);
70  KJ_EXPECT(
71      TraceId::fromProtobuf(
72          "\xfe\xdc\xba\x98\x76\x54\x32\x12\xfe\xdc\xba\x98\x76\x54\x32\x11\x01"_kjb) == kj::none);
73 
74  KJ_EXPECT(KJ_ASSERT_NONNULL(TraceId::fromProtobuf(
75                "\xfe\xdc\xba\x98\x76\x54\x32\x12\xfe\xdc\xba\x98\x76\x54\x32\x11"_kjb)) ==
76      TraceId(0xfedcba9876543211, 0xfedcba9876543212));
77}
78 
79KJ_TEST("can write trace ID protobuf format") {
80  KJ_EXPECT(TraceId(0, 0).toProtobuf() ==
81      "\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00"_kjb);
82 
83  KJ_EXPECT(TraceId(0xfedcba9876543211, 0xfedcba9876543212).toProtobuf() ==
84      "\xfe\xdc\xba\x98\x76\x54\x32\x12\xfe\xdc\xba\x98\x76\x54\x32\x11"_kjb);
85}
86 
87KJ_TEST("InvocationSpanContext") {
88  setPredictableModeForTest();
89  FakeEntropySource fakeEntropySource;
90  auto sc = InvocationSpanContext::newForInvocation(kj::none, fakeEntropySource);
91 
92  // In predictable mode, TraceId::fromEntropy returns deterministic but
93  // call-distinct values (process-wide counter), so the traceId and invocationId
94  // of independent invocations differ from each other and across tests. Capture
95  // the IDs and assert the propagation chain rather than specific constants.
96  auto initialTraceId = sc.getTraceId();
97  auto initialInvocationId = sc.getInvocationId();
98  KJ_EXPECT(sc.getSpanId() == SpanId(1));
99 
100  // And serialize that to a capnp struct...
101  capnp::MallocMessageBuilder builder;
102  auto root = builder.initRoot<rpc::InvocationSpanContext>();
103  sc.toCapnp(root);
104 
105  // Then back again...
106  auto sc2 = KJ_ASSERT_NONNULL(InvocationSpanContext::fromCapnp(root.asReader()));
107  KJ_EXPECT(sc2.getTraceId() == initialTraceId);
108  KJ_EXPECT(sc2.getInvocationId() == initialInvocationId);
109  KJ_EXPECT(sc2.getSpanId() == SpanId(1));
110  KJ_EXPECT(sc2.isTrigger());
111 
112  // The one that has been deserialized from capnp cannot create children...
113  try {
114    sc2.newChild();
115    KJ_FAIL_ASSERT("should not be able to create child span with SpanContext from capnp");
116  } catch (kj::Exception& ex) {
117    KJ_EXPECT(ex.getDescription() ==
118        "expected !isTrigger(); unable to create child spans on this context"_kj);
119  }
120 
121  // Children inherit both the traceId and invocationId of their parent.
122  auto sc3 = sc.newChild();
123  KJ_EXPECT(sc3.getTraceId() == initialTraceId);
124  KJ_EXPECT(sc3.getInvocationId() == initialInvocationId);
125  KJ_EXPECT(sc3.getSpanId() == SpanId(2));
126 
127  // Trigger-context propagation: traceId is inherited from sc2, but the
128  // invocationId is freshly generated for the new invocation.
129  auto sc4 = InvocationSpanContext::newForInvocation(sc2, fakeEntropySource);
130  KJ_EXPECT(sc4.getTraceId() == initialTraceId);
131  KJ_EXPECT(sc4.getInvocationId() != initialInvocationId);
132  KJ_EXPECT(sc4.getSpanId() == SpanId(3));
133 
134  auto& sc5 = KJ_ASSERT_NONNULL(sc4.getParent());
135  KJ_EXPECT(sc5.getTraceId() == initialTraceId);
136  KJ_EXPECT(sc5.getInvocationId() == initialInvocationId);
137  KJ_EXPECT(sc5.getSpanId() == SpanId(1));
138  KJ_EXPECT(sc5.isTrigger());
139}
140 
141KJ_TEST("InvocationSpanContext propagates traceFlags from trigger") {
142  setPredictableModeForTest();
143  FakeEntropySource fakeEntropySource;
144 
145  // Trigger with traceFlags set — propagates to new invocation
146  auto trigger = InvocationSpanContext(TraceId(1, 2), TraceId(3, 4), SpanId(5), TraceFlags(0x01));
147  KJ_EXPECT(KJ_ASSERT_NONNULL(trigger.getTraceFlags()) == TraceFlags(0x01));
148 
149  auto sc = InvocationSpanContext::newForInvocation(trigger, fakeEntropySource);
150  KJ_EXPECT(KJ_ASSERT_NONNULL(sc.getTraceFlags()) == TraceFlags(0x01));
151 
152  // No trigger — traceFlags is absent
153  auto sc2 = InvocationSpanContext::newForInvocation(kj::none, fakeEntropySource);
154  KJ_EXPECT(sc2.getTraceFlags() == kj::none);
155 
156  // newChild() propagates traceFlags
157  auto child = sc.newChild();
158  KJ_EXPECT(KJ_ASSERT_NONNULL(child.getTraceFlags()) == TraceFlags(0x01));
159 
160  auto child2 = sc2.newChild();
161  KJ_EXPECT(child2.getTraceFlags() == kj::none);
162}
163 
164KJ_TEST("InvocationSpanContext traceFlags capnp round-trip and newChild propagation") {
165  setPredictableModeForTest();
166  FakeEntropySource fakeEntropySource;
167 
168  // traceFlags=0x01 (sampled) survives round-trip and propagates through newChild
169  auto sampled = InvocationSpanContext(TraceId(1, 2), TraceId(3, 4), SpanId(5), TraceFlags(0x01));
170  capnp::MallocMessageBuilder b1;
171  sampled.toCapnp(b1.initRoot<rpc::InvocationSpanContext>());
172  auto rt1 =
173      KJ_ASSERT_NONNULL(InvocationSpanContext::fromCapnp(b1.getRoot<rpc::InvocationSpanContext>()));
174  KJ_EXPECT(KJ_ASSERT_NONNULL(rt1.getTraceFlags()) == TraceFlags(0x01));
175  auto child1 = InvocationSpanContext::newForInvocation(rt1, fakeEntropySource);
176  KJ_EXPECT(KJ_ASSERT_NONNULL(child1.newChild().getTraceFlags()) == TraceFlags(0x01));
177 
178  // traceFlags=0x00 (unsampled) is distinct from absent
179  auto unsampled = InvocationSpanContext(TraceId(1, 2), TraceId(3, 4), SpanId(5), TraceFlags(0x00));
180  capnp::MallocMessageBuilder b2;
181  unsampled.toCapnp(b2.initRoot<rpc::InvocationSpanContext>());
182  auto rt2 =
183      KJ_ASSERT_NONNULL(InvocationSpanContext::fromCapnp(b2.getRoot<rpc::InvocationSpanContext>()));
184  KJ_EXPECT(KJ_ASSERT_NONNULL(rt2.getTraceFlags()) == TraceFlags(0x00));
185  auto child2 = InvocationSpanContext::newForInvocation(rt2, fakeEntropySource);
186  KJ_EXPECT(KJ_ASSERT_NONNULL(child2.newChild().getTraceFlags()) == TraceFlags(0x00));
187 
188  // traceFlags absent stays absent
189  auto absent = InvocationSpanContext(TraceId(1, 2), TraceId(3, 4), SpanId(5), kj::none);
190  capnp::MallocMessageBuilder b3;
191  absent.toCapnp(b3.initRoot<rpc::InvocationSpanContext>());
192  auto rt3 =
193      KJ_ASSERT_NONNULL(InvocationSpanContext::fromCapnp(b3.getRoot<rpc::InvocationSpanContext>()));
194  KJ_EXPECT(rt3.getTraceFlags() == kj::none);
195  auto child3 = InvocationSpanContext::newForInvocation(rt3, fakeEntropySource);
196  KJ_EXPECT(child3.newChild().getTraceFlags() == kj::none);
197}
198 
199KJ_TEST("SpanContext") {
200  setPredictableModeForTest();
201  FakeEntropySource fakeEntropySource;
202  auto sc =
203      SpanContext(TraceId::fromEntropy(fakeEntropySource), SpanId::fromEntropy(fakeEntropySource));
204 
205  // In predictable mode, TraceId::fromEntropy returns deterministic but
206  // call-distinct values; capture the IDs and verify capnp round-trip.
207  auto initialTraceId = sc.getTraceId();
208  KJ_EXPECT(sc.getSpanId() == SpanId(1));
209  KJ_EXPECT(sc.getTraceFlags() == kj::none);
210 
211  capnp::MallocMessageBuilder builder;
212  auto root = builder.initRoot<rpc::SpanContext>();
213  sc.toCapnp(root);
214 
215  auto sc2 = SpanContext::fromCapnp(root.asReader());
216  KJ_EXPECT(sc2.getTraceId() == initialTraceId);
217  KJ_EXPECT(sc2.getSpanId() == SpanId(1));
218  KJ_EXPECT(sc2.getTraceFlags() == kj::none);
219}
220 
221KJ_TEST("SpanContext traceFlags preserved through capnp when set, absent when unset") {
222  auto sc = SpanContext(TraceId(1, 2), SpanId(3), TraceFlags(0x01));
223  KJ_EXPECT(KJ_ASSERT_NONNULL(sc.getTraceFlags()) == TraceFlags(0x01));
224 
225  capnp::MallocMessageBuilder builder;
226  auto root = builder.initRoot<rpc::SpanContext>();
227  sc.toCapnp(root);
228 
229  auto sc2 = SpanContext::fromCapnp(root.asReader());
230  KJ_EXPECT(sc2.getTraceId() == TraceId(1, 2));
231  KJ_EXPECT(KJ_ASSERT_NONNULL(sc2.getSpanId()) == SpanId(3));
232  KJ_EXPECT(KJ_ASSERT_NONNULL(sc2.getTraceFlags()) == TraceFlags(0x01));
233 
234  auto sc3 = SpanContext(TraceId(4, 5), SpanId(6));
235  capnp::MallocMessageBuilder builder2;
236  auto root2 = builder2.initRoot<rpc::SpanContext>();
237  sc3.toCapnp(root2);
238 
239  auto sc4 = SpanContext::fromCapnp(root2.asReader());
240  KJ_EXPECT(sc4.getTraceFlags() == kj::none);
241}
242 
243KJ_TEST("Read/Write FetchEventInfo works") {
244  capnp::MallocMessageBuilder builder;
245  auto fetchInfoBuilder = builder.initRoot<rpc::Trace::FetchEventInfo>();
246 
247  kj::Vector<FetchEventInfo::Header> headers;
248  headers.add(FetchEventInfo::Header(kj::str("foo"), kj::str("bar")));
249 
250  FetchEventInfo info(
251      kj::HttpMethod::GET, kj::str("https://example.com"), kj::str("{}"), headers.releaseAsArray());
252 
253  info.copyTo(fetchInfoBuilder);
254 
255  auto reader = fetchInfoBuilder.asReader();
256 
257  FetchEventInfo info2(reader);
258  KJ_ASSERT(info2.method == kj::HttpMethod::GET);
259  KJ_ASSERT(info2.url == "https://example.com"_kj);
260  KJ_ASSERT(info2.cfJson == "{}"_kj);
261  KJ_ASSERT(info2.headers.size() == 1);
262  KJ_ASSERT(info2.headers[0].name == "foo"_kj);
263  KJ_ASSERT(info2.headers[0].value == "bar"_kj);
264 
265  FetchEventInfo info3 = info.clone();
266  KJ_ASSERT(info3.method == kj::HttpMethod::GET);
267  KJ_ASSERT(info3.url == "https://example.com"_kj);
268  KJ_ASSERT(info3.cfJson == "{}"_kj);
269  KJ_ASSERT(info3.headers.size() == 1);
270  KJ_ASSERT(info3.headers[0].name == "foo"_kj);
271  KJ_ASSERT(info3.headers[0].value == "bar"_kj);
272}
273 
274KJ_TEST("Read/Write JsRpcEventInfo works") {
275  capnp::MallocMessageBuilder builder;
276  auto jsRpcInfoBuilder = builder.initRoot<rpc::Trace::JsRpcEventInfo>();
277 
278  JsRpcEventInfo info(kj::str("foo"));
279 
280  info.copyTo(jsRpcInfoBuilder);
281 
282  auto reader = jsRpcInfoBuilder.asReader();
283 
284  JsRpcEventInfo info2(reader);
285  KJ_ASSERT(info2.methodName == "foo"_kj);
286 
287  JsRpcEventInfo info3 = info.clone();
288  KJ_ASSERT(info3.methodName == "foo"_kj);
289}
290 
291KJ_TEST("Read/Write ScheduledEventInfo workers") {
292  capnp::MallocMessageBuilder builder;
293  auto infoBuilder = builder.initRoot<rpc::Trace::ScheduledEventInfo>();
294 
295  ScheduledEventInfo info(1.2, kj::str("foo"));
296 
297  info.copyTo(infoBuilder);
298 
299  auto reader = infoBuilder.asReader();
300 
301  ScheduledEventInfo info2(reader);
302  KJ_ASSERT(info2.scheduledTime == 1.2);
303  KJ_ASSERT(info2.cron == "foo"_kj);
304 
305  ScheduledEventInfo info3 = info.clone();
306  KJ_ASSERT(info3.scheduledTime == 1.2);
307  KJ_ASSERT(info3.cron == "foo"_kj);
308}
309 
310KJ_TEST("Read/Write AlarmEventInfo works") {
311  capnp::MallocMessageBuilder builder;
312  auto infoBuilder = builder.initRoot<rpc::Trace::AlarmEventInfo>();
313 
314  AlarmEventInfo info(kj::UNIX_EPOCH);
315 
316  info.copyTo(infoBuilder);
317 
318  auto reader = infoBuilder.asReader();
319 
320  AlarmEventInfo info2(reader);
321  KJ_ASSERT(info.scheduledTime == info2.scheduledTime);
322 
323  AlarmEventInfo info3 = info.clone();
324  KJ_ASSERT(info.scheduledTime == info3.scheduledTime);
325}
326 
327KJ_TEST("Read/Write QueueEventInfo works") {
328  capnp::MallocMessageBuilder builder;
329  auto infoBuilder = builder.initRoot<rpc::Trace::QueueEventInfo>();
330 
331  QueueEventInfo info(kj::str("foo"), 1);
332 
333  info.copyTo(infoBuilder);
334 
335  auto reader = infoBuilder.asReader();
336 
337  QueueEventInfo info2(reader);
338  KJ_ASSERT(info2.queueName == "foo"_kj);
339  KJ_ASSERT(info2.batchSize == 1);
340 
341  QueueEventInfo info3 = info.clone();
342  KJ_ASSERT(info2.queueName == "foo"_kj);
343  KJ_ASSERT(info2.batchSize == 1);
344}
345 
346KJ_TEST("Read/Write EmailEventInfo works") {
347  capnp::MallocMessageBuilder builder;
348  auto infoBuilder = builder.initRoot<rpc::Trace::EmailEventInfo>();
349 
350  EmailEventInfo info(kj::str("foo"), kj::str("bar"), 1);
351  info.copyTo(infoBuilder);
352 
353  auto reader = infoBuilder.asReader();
354 
355  EmailEventInfo info2(reader);
356  KJ_ASSERT(info2.mailFrom == "foo"_kj);
357  KJ_ASSERT(info2.rcptTo == "bar"_kj);
358  KJ_ASSERT(info2.rawSize == 1);
359 
360  EmailEventInfo info3 = info.clone();
361  KJ_ASSERT(info3.mailFrom == "foo"_kj);
362  KJ_ASSERT(info3.rcptTo == "bar"_kj);
363  KJ_ASSERT(info3.rawSize == 1);
364}
365 
366KJ_TEST("Read/Write TraceEventInfo works") {
367  capnp::MallocMessageBuilder builder;
368  auto infoBuilder = builder.initRoot<rpc::Trace::TraceEventInfo>();
369 
370  kj::Vector<kj::Own<Trace>> items(1);
371  items.add(kj::heap<Trace>(kj::none, kj::str("foo"), kj::none, kj::none, kj::none,
372      kj::Array<kj::String>(), kj::none, ExecutionModel::STATELESS));
373 
374  TraceEventInfo info(items.asPtr());
375  info.copyTo(infoBuilder);
376 
377  auto reader = infoBuilder.asReader();
378 
379  TraceEventInfo info2(reader);
380  KJ_ASSERT(info2.traces.size() == 1);
381  KJ_ASSERT(KJ_ASSERT_NONNULL(info2.traces[0].scriptName) == "foo"_kj);
382 
383  TraceEventInfo info3 = info.clone();
384  KJ_ASSERT(info2.traces.size() == 1);
385  KJ_ASSERT(KJ_ASSERT_NONNULL(info2.traces[0].scriptName) == "foo"_kj);
386}
387 
388KJ_TEST("Read/Write HibernatableWebSocketEventInfo works") {
389  capnp::MallocMessageBuilder builder;
390  auto infoBuilder = builder.initRoot<rpc::Trace::HibernatableWebSocketEventInfo>();
391 
392  HibernatableWebSocketEventInfo info(HibernatableWebSocketEventInfo::Message{});
393  info.copyTo(infoBuilder);
394 
395  auto reader = infoBuilder.asReader();
396 
397  HibernatableWebSocketEventInfo info2(reader);
398  KJ_ASSERT(info2.type.is<HibernatableWebSocketEventInfo::Message>());
399 
400  HibernatableWebSocketEventInfo info3 = info.clone();
401  KJ_ASSERT(info3.type.is<HibernatableWebSocketEventInfo::Message>());
402}
403 
404KJ_TEST("Read/Write FetchResponseInfo works") {
405  capnp::MallocMessageBuilder builder;
406  auto infoBuilder = builder.initRoot<rpc::Trace::FetchResponseInfo>();
407 
408  FetchResponseInfo info(123);
409  info.copyTo(infoBuilder);
410 
411  auto reader = infoBuilder.asReader();
412  FetchResponseInfo info2(reader);
413  KJ_ASSERT(info2.statusCode == 123);
414 
415  FetchResponseInfo info3 = info.clone();
416  KJ_ASSERT(info3.statusCode == 123);
417}
418 
419KJ_TEST("Read/Write DiagnosticChannelEvent works") {
420  capnp::MallocMessageBuilder builder;
421  auto infoBuilder = builder.initRoot<rpc::Trace::DiagnosticChannelEvent>();
422 
423  DiagnosticChannelEvent info(kj::UNIX_EPOCH, kj::str("foo"), kj::Array<kj::byte>());
424  info.copyTo(infoBuilder);
425 
426  auto reader = infoBuilder.asReader();
427 
428  DiagnosticChannelEvent info2(reader);
429  KJ_ASSERT(info2.timestamp == info.timestamp);
430  KJ_ASSERT(info2.channel == "foo"_kj);
431  KJ_ASSERT(info2.message.size() == 0);
432 
433  DiagnosticChannelEvent info3 = info.clone();
434  KJ_ASSERT(info3.timestamp == info.timestamp);
435  KJ_ASSERT(info3.channel == "foo"_kj);
436  KJ_ASSERT(info3.message.size() == 0);
437}
438 
439KJ_TEST("Read/Write Log works") {
440  capnp::MallocMessageBuilder builder;
441  auto infoBuilder = builder.initRoot<rpc::Trace::Log>();
442 
443  Log info(kj::UNIX_EPOCH, LogLevel::INFO, kj::str("foo"));
444  info.copyTo(infoBuilder);
445 
446  auto reader = infoBuilder.asReader();
447  Log info2(reader);
448  KJ_ASSERT(info.timestamp == info2.timestamp);
449  KJ_ASSERT(info2.logLevel == LogLevel::INFO);
450  KJ_ASSERT(info2.message == "foo"_kj);
451 
452  Log info3 = info.clone();
453  KJ_ASSERT(info.timestamp == info3.timestamp);
454  KJ_ASSERT(info3.logLevel == LogLevel::INFO);
455  KJ_ASSERT(info3.message == "foo"_kj);
456}
457 
458KJ_TEST("Read/Write Exception works") {
459  capnp::MallocMessageBuilder builder;
460  auto infoBuilder = builder.initRoot<rpc::Trace::Exception>();
461 
462  Exception info(kj::UNIX_EPOCH, kj::str("foo"), kj::str("bar"), kj::none);
463  info.copyTo(infoBuilder);
464 
465  auto reader = infoBuilder.asReader();
466  Exception info2(reader);
467  KJ_ASSERT(info.timestamp == info2.timestamp);
468  KJ_ASSERT(info2.name == "foo"_kj);
469  KJ_ASSERT(info2.message == "bar"_kj);
470  KJ_ASSERT(info2.stack == kj::none);
471 
472  Exception info3 = info.clone();
473  KJ_ASSERT(info.timestamp == info3.timestamp);
474  KJ_ASSERT(info3.name == "foo"_kj);
475  KJ_ASSERT(info3.message == "bar"_kj);
476  KJ_ASSERT(info3.stack == kj::none);
477}
478 
479KJ_TEST("Read/Write StreamDiagnosticsEvent works") {
480  capnp::MallocMessageBuilder builder;
481  auto infoBuilder = builder.initRoot<rpc::Trace::StreamDiagnosticsEvent>();
482 
483  StreamDiagnosticsEvent info(42);
484  info.copyTo(infoBuilder);
485 
486  auto reader = infoBuilder.asReader();
487  StreamDiagnosticsEvent info2(reader);
488  KJ_ASSERT(info2.droppedEventsCount == 42);
489 
490  StreamDiagnosticsEvent info3 = info.clone();
491  KJ_ASSERT(info3.droppedEventsCount == 42);
492}
493 
494KJ_TEST("Read/Write Attribute works") {
495  capnp::MallocMessageBuilder builder;
496  auto infoBuilder = builder.initRoot<rpc::Trace::Attribute>();
497 
498  Attribute attr("foo"_kjc, {123.0, 321.2});
499  attr.copyTo(infoBuilder);
500 
501  auto reader = infoBuilder.asReader();
502  Attribute info2(reader);
503  KJ_ASSERT(info2.name == "foo"_kj);
504  KJ_ASSERT(KJ_ASSERT_NONNULL(info2.value[0].tryGet<double>()) == 123.0);
505  KJ_ASSERT(KJ_ASSERT_NONNULL(info2.value[1].tryGet<double>()) == 321.2);
506}
507 
508KJ_TEST("Read/Write Return works") {
509  capnp::MallocMessageBuilder builder;
510  auto infoBuilder = builder.initRoot<rpc::Trace::Return>();
511 
512  FetchResponseInfo fetchInfo(123);
513  Return info(kj::mv(fetchInfo));
514  info.copyTo(infoBuilder);
515 
516  auto reader = infoBuilder.asReader();
517  Return info2(reader);
518  auto& fetchInfo2 = KJ_ASSERT_NONNULL(info2.info);
519  KJ_ASSERT(fetchInfo2.statusCode == 123);
520 
521  Return info3 = info.clone();
522  auto& fetchInfo3 = KJ_ASSERT_NONNULL(info3.info);
523  KJ_ASSERT(fetchInfo3.statusCode == 123);
524}
525 
526KJ_TEST("Read/Write SpanOpen works") {
527  capnp::MallocMessageBuilder builder;
528  auto infoBuilder = builder.initRoot<rpc::Trace::SpanOpen>();
529 
530  SpanOpen info(0x2a2a2a2a2a2a2a2a, "foo"_kjc, kj::none);
531  info.copyTo(infoBuilder);
532 
533  auto reader = infoBuilder.asReader();
534  SpanOpen info2(reader);
535  KJ_ASSERT(info2.operationName == "foo"_kj);
536  KJ_ASSERT(info2.info == kj::none);
537 
538  SpanOpen info3 = info.clone();
539  KJ_ASSERT(info3.operationName == "foo"_kj);
540  KJ_ASSERT(info3.info == kj::none);
541}
542 
543KJ_TEST("Read/Write SpanClose works") {
544  capnp::MallocMessageBuilder builder;
545  auto infoBuilder = builder.initRoot<rpc::Trace::SpanClose>();
546 
547  SpanClose info(EventOutcome::EXCEPTION);
548  info.copyTo(infoBuilder);
549 
550  auto reader = infoBuilder.asReader();
551 
552  SpanClose info2(reader);
553  KJ_ASSERT(info2.outcome == EventOutcome::EXCEPTION);
554 
555  SpanClose info3 = info.clone();
556  KJ_ASSERT(info3.outcome == EventOutcome::EXCEPTION);
557}
558 
559KJ_TEST("Read/Write Onset works") {
560  capnp::MallocMessageBuilder builder;
561  auto infoBuilder = builder.initRoot<rpc::Trace::Onset>();
562 
563  FetchEventInfo fetchInfo(
564      kj::HttpMethod::GET, kj::str("https://example.com"), kj::str("{}"), nullptr);
565 
566  Onset info(staticSpanId, Onset::Info(kj::mv(fetchInfo)),
567      {
568        .scriptName = kj::str("foo"),
569        .preview = TracePreview(kj::str("63bafce9179948688866bb22268eb1c6"),
570            kj::str("feature-my-branch"), kj::str("feature/my-branch")),
571      },
572      nullptr);
573  info.copyTo(infoBuilder);
574 
575  auto reader = infoBuilder.asReader();
576  Onset info2(reader);
577  FetchEventInfo& fetchInfo2 = KJ_ASSERT_NONNULL(info2.info.tryGet<FetchEventInfo>());
578  KJ_ASSERT(fetchInfo2.method == kj::HttpMethod::GET);
579  KJ_ASSERT(fetchInfo2.url == "https://example.com"_kj);
580  KJ_ASSERT(info2.workerInfo.executionModel == ExecutionModel::STATELESS);
581  auto& preview2 = KJ_ASSERT_NONNULL(info2.workerInfo.preview);
582  KJ_ASSERT(preview2.id == "63bafce9179948688866bb22268eb1c6"_kj);
583  KJ_ASSERT(preview2.slug == "feature-my-branch"_kj);
584  KJ_ASSERT(preview2.name == "feature/my-branch"_kj);
585 
586  Onset info3 = info.clone();
587  FetchEventInfo& fetchInfo3 = KJ_ASSERT_NONNULL(info3.info.tryGet<FetchEventInfo>());
588  KJ_ASSERT(fetchInfo3.method == kj::HttpMethod::GET);
589  KJ_ASSERT(fetchInfo3.url == "https://example.com"_kj);
590  KJ_ASSERT(info3.workerInfo.executionModel == ExecutionModel::STATELESS);
591  auto& preview3 = KJ_ASSERT_NONNULL(info3.workerInfo.preview);
592  KJ_ASSERT(preview3.id == "63bafce9179948688866bb22268eb1c6"_kj);
593  KJ_ASSERT(preview3.slug == "feature-my-branch"_kj);
594  KJ_ASSERT(preview3.name == "feature/my-branch"_kj);
595}
596 
597KJ_TEST("Read/Write Outcome works") {
598  capnp::MallocMessageBuilder builder;
599  auto infoBuilder = builder.initRoot<rpc::Trace::Outcome>();
600 
601  Outcome info(EventOutcome::EXCEPTION, 1 * kj::MILLISECONDS, 2 * kj::MILLISECONDS);
602  info.copyTo(infoBuilder);
603 
604  auto reader = infoBuilder.asReader();
605  Outcome info2(reader);
606  KJ_ASSERT(info2.outcome == EventOutcome::EXCEPTION);
607  KJ_ASSERT(info2.wallTime == 2 * kj::MILLISECONDS);
608  KJ_ASSERT(info2.cpuTime == 1 * kj::MILLISECONDS);
609 
610  Outcome info3 = info.clone();
611  KJ_ASSERT(info3.outcome == EventOutcome::EXCEPTION);
612  KJ_ASSERT(info3.wallTime == 2 * kj::MILLISECONDS);
613  KJ_ASSERT(info3.cpuTime == 1 * kj::MILLISECONDS);
614}
615 
616KJ_TEST("Read/Write TailEvent works") {
617  capnp::MallocMessageBuilder builder;
618  auto infoBuilder = builder.initRoot<rpc::Trace::TailEvent>();
619 
620  auto context = SpanContext(TraceId(0, 0), {staticSpanId});
621  Log log(kj::UNIX_EPOCH, LogLevel::INFO, kj::str("foo"));
622  auto invocationId = TraceId(0, 0);
623  TailEvent info(
624      context.getTraceId(), invocationId, context.getSpanId(), kj::UNIX_EPOCH, 0, kj::mv(log));
625  info.copyTo(infoBuilder);
626 
627  auto reader = infoBuilder.asReader();
628 
629  TailEvent info2(reader);
630  KJ_ASSERT(info2.timestamp == kj::UNIX_EPOCH);
631  KJ_ASSERT(info2.sequence == 0);
632  KJ_ASSERT(info2.invocationId == invocationId);
633  KJ_ASSERT(info2.spanContext == context);
634 
635  auto& log2 = KJ_ASSERT_NONNULL(info2.event.tryGet<Log>());
636  KJ_ASSERT(log2.timestamp == kj::UNIX_EPOCH);
637  KJ_ASSERT(log2.logLevel == LogLevel::INFO);
638  KJ_ASSERT(log2.message == "foo"_kj);
639 
640  TailEvent info3 = info.clone();
641  KJ_ASSERT(info3.timestamp == kj::UNIX_EPOCH);
642  KJ_ASSERT(info3.sequence == 0);
643  KJ_ASSERT(info3.invocationId == invocationId);
644  KJ_ASSERT(info3.spanContext == context);
645 
646  auto& log3 = KJ_ASSERT_NONNULL(info3.event.tryGet<Log>());
647  KJ_ASSERT(log3.timestamp == kj::UNIX_EPOCH);
648  KJ_ASSERT(log3.logLevel == LogLevel::INFO);
649  KJ_ASSERT(log3.message == "foo"_kj);
650}
651 
652KJ_TEST("Read/Write TailEvent with Multiple Attributes") {
653  capnp::MallocMessageBuilder builder;
654  auto infoBuilder = builder.initRoot<rpc::Trace::TailEvent>();
655 
656  TraceId traceId(0, 0);
657  auto context = SpanContext(traceId, {staticSpanId});
658 
659  // An attribute event can have one or more Attributes specified.
660  kj::Vector<Attribute> attrs(2);
661  attrs.add(Attribute("foo"_kjc, true));
662  attrs.add(Attribute("bar"_kjc, static_cast<int64_t>(123)));
663 
664  TailEvent info(kj::mv(context), traceId, kj::UNIX_EPOCH, 0, attrs.releaseAsArray());
665  info.copyTo(infoBuilder);
666 
667  TailEvent info2(infoBuilder.asReader());
668  auto& attrs2 = KJ_ASSERT_NONNULL(info2.event.tryGet<kj::Array<Attribute>>());
669  KJ_ASSERT(attrs2.size() == 2);
670 
671  KJ_ASSERT(attrs2[0].name == "foo"_kj);
672  KJ_ASSERT(attrs2[1].name == "bar"_kj);
673}
674 
675KJ_TEST("Trace with Preview") {
676  auto trace = kj::refcounted<Trace>(kj::str("test-stable-id"), kj::str("test-script"),
677      kj::none,  // scriptVersion
678      kj::str("test-namespace"), kj::str("test-script-id"),
679      kj::Array<kj::String>(),  // scriptTags
680      kj::str("test-entrypoint"), ExecutionModel::STATELESS,
681      kj::none,  // durableObjectId
682      TracePreview(kj::str("63bafce9179948688866bb22268eb1c6"), kj::str("feature-my-branch"),
683          kj::str("feature/my-branch")));
684 
685  capnp::MallocMessageBuilder builder;
686  auto traceBuilder = builder.initRoot<rpc::Trace>();
687  trace->copyTo(traceBuilder);
688 
689  auto trace2 = kj::refcounted<Trace>(traceBuilder.asReader());
690  auto& preview = KJ_ASSERT_NONNULL(trace2->preview);
691  KJ_ASSERT(preview.id == "63bafce9179948688866bb22268eb1c6"_kj);
692  KJ_ASSERT(preview.slug == "feature-my-branch"_kj);
693  KJ_ASSERT(preview.name == "feature/my-branch"_kj);
694}
695 
696KJ_TEST("Trace with Durable Object ID") {
697  auto trace = kj::refcounted<Trace>(kj::str("test-stable-id"), kj::str("test-script"),
698      kj::none,  // scriptVersion
699      kj::str("test-namespace"), kj::str("test-script-id"),
700      kj::Array<kj::String>(),  // scriptTags
701      kj::str("test-entrypoint"), ExecutionModel::DURABLE_OBJECT,
702      kj::str("abc123def456")  // durableObjectId
703  );
704 
705  capnp::MallocMessageBuilder builder;
706  auto traceBuilder = builder.initRoot<rpc::Trace>();
707  trace->copyTo(traceBuilder);
708 
709  auto trace2 = kj::refcounted<Trace>(traceBuilder.asReader());
710  KJ_ASSERT(KJ_REQUIRE_NONNULL(trace2->durableObjectId) == "abc123def456"_kj);
711}
712KJ_TEST("SpanContext::tryFromTraceparent valid") {
713  auto result = KJ_ASSERT_NONNULL(SpanContext::tryFromTraceparent(
714      "00-11223344556677889900aabbccddeeff-a1b2c3d4e5f60718-01"_kj));
715  KJ_EXPECT(result.getTraceId() == TraceId(0x9900aabbccddeeff, 0x1122334455667788));
716  KJ_EXPECT(KJ_ASSERT_NONNULL(result.getSpanId()) == SpanId(0xa1b2c3d4e5f60718));
717  KJ_EXPECT(KJ_ASSERT_NONNULL(result.getTraceFlags()) == 0x01);
718}
719 
720KJ_TEST("SpanContext::tryFromTraceparent sampled with extra flags") {
721  auto result = KJ_ASSERT_NONNULL(SpanContext::tryFromTraceparent(
722      "00-11223344556677889900aabbccddeeff-a1b2c3d4e5f60718-03"_kj));
723  KJ_EXPECT(result.getTraceId() == TraceId(0x9900aabbccddeeff, 0x1122334455667788));
724  KJ_EXPECT(KJ_ASSERT_NONNULL(result.getSpanId()) == SpanId(0xa1b2c3d4e5f60718));
725  KJ_EXPECT(KJ_ASSERT_NONNULL(result.getTraceFlags()) == 0x03);
726}
727 
728KJ_TEST("SpanContext::tryFromTraceparent rejects invalid inputs") {
729  // Empty
730  KJ_EXPECT(SpanContext::tryFromTraceparent(""_kj) == kj::none);
731  // Degenerate
732  KJ_EXPECT(SpanContext::tryFromTraceparent("---"_kj) == kj::none);
733  KJ_EXPECT(SpanContext::tryFromTraceparent("00-1-1-00"_kj) == kj::none);
734 
735  // Wrong total length (too short, too long)
736  KJ_EXPECT(SpanContext::tryFromTraceparent(
737                "00-11223344556677889900aabbccddeeff-a1b2c3d4e5f60718-0"_kj) == kj::none);
738  KJ_EXPECT(SpanContext::tryFromTraceparent(
739                "00-11223344556677889900aabbccddeeff-a1b2c3d4e5f60718-012"_kj) == kj::none);
740 
741  // Wrong field sizes: version too short
742  KJ_EXPECT(SpanContext::tryFromTraceparent(
743                "0-11223344556677889900aabbccddeeff0-a1b2c3d4e5f60718-01"_kj) == kj::none);
744  // Wrong field sizes: trace-id too long
745  KJ_EXPECT(SpanContext::tryFromTraceparent(
746                "00-11223344556677889900aabbccddeeff0-1b2c3d4e5f60718-01"_kj) == kj::none);
747  // Wrong field sizes: trace-id too short
748  KJ_EXPECT(SpanContext::tryFromTraceparent(
749                "00-11223344556677889900aabbccddee-a1b2c3d4e5f6071800-01"_kj) == kj::none);
750  // Wrong field sizes: parent-id too long
751  KJ_EXPECT(SpanContext::tryFromTraceparent(
752                "00-1223344556677889900aabbccddeeff-a1b2c3d4e5f607180-01"_kj) == kj::none);
753  // Wrong field sizes: parent-id too short
754  KJ_EXPECT(SpanContext::tryFromTraceparent(
755                "00-112233445566778899900aabbccddeeff-1b2c3d4e5f6071-01"_kj) == kj::none);
756  // Empty fields
757  KJ_EXPECT(SpanContext::tryFromTraceparent("00--a1b2c3d4e5f60718-01"_kj) == kj::none);
758  KJ_EXPECT(
759      SpanContext::tryFromTraceparent("00-11223344556677889900aabbccddeeff--01"_kj) == kj::none);
760 
761  // Bad hex
762  KJ_EXPECT(SpanContext::tryFromTraceparent(
763                "0g-11223344556677889900aabbccddeeff-a1b2c3d4e5f60718-01"_kj) == kj::none);
764  KJ_EXPECT(SpanContext::tryFromTraceparent(
765                "00-x1223344556677889900aabbccddeeff-a1b2c3d4e5f60718-01"_kj) == kj::none);
766  KJ_EXPECT(SpanContext::tryFromTraceparent(
767                "00-11223344556677889900aabbccddeeff-a1b2c3d4e5f6071x-01"_kj) == kj::none);
768 
769  // Unsupported version
770  KJ_EXPECT(SpanContext::tryFromTraceparent(
771                "01-11223344556677889900aabbccddeeff-a1b2c3d4e5f60718-01"_kj) == kj::none);
772  KJ_EXPECT(SpanContext::tryFromTraceparent(
773                "ff-11223344556677889900aabbccddeeff-a1b2c3d4e5f60718-01"_kj) == kj::none);
774 
775  // All-zero trace-id
776  KJ_EXPECT(SpanContext::tryFromTraceparent(
777                "00-00000000000000000000000000000000-a1b2c3d4e5f60718-01"_kj) == kj::none);
778 
779  // All-zero parent-id
780  KJ_EXPECT(SpanContext::tryFromTraceparent(
781                "00-11223344556677889900aabbccddeeff-0000000000000000-01"_kj) == kj::none);
782 
783  // Unsampled
784  auto unsampled = KJ_ASSERT_NONNULL(SpanContext::tryFromTraceparent(
785      "00-11223344556677889900aabbccddeeff-a1b2c3d4e5f60718-00"_kj));
786  KJ_EXPECT(unsampled.getTraceId() == TraceId(0x9900aabbccddeeff, 0x1122334455667788));
787  KJ_EXPECT(KJ_ASSERT_NONNULL(unsampled.getSpanId()) == SpanId(0xa1b2c3d4e5f60718));
788  KJ_EXPECT(KJ_ASSERT_NONNULL(unsampled.getTraceFlags()) == 0x00);
789}
790 
791}  // namespace
792}  // namespace workerd::tracing