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 "trace.h"
6
 
7
#include <workerd/api/global-scope.h>
8
#include <workerd/api/http.h>
9
#include <workerd/api/util.h>
10
#include <workerd/io/io-context.h>
11
#include <workerd/io/tracer.h>
12
#include <workerd/jsg/ser.h>
13
#include <workerd/util/own-util.h>
14
#include <workerd/util/thread-scopes.h>
15
#include <workerd/util/uncaught-exception-source.h>
16
#include <workerd/util/uuid.h>
17
 
18
#include <capnp/schema.h>
19
#include <kj/encoding.h>
20
 
21
namespace workerd::api {
22
 
23
TailEvent::TailEvent(
24
    jsg::Lock& js, kj::LiteralStringConst type, kj::ArrayPtr<kj::Own<Trace>> events)
25
    : ExtendableEvent(type),
26
      events(KJ_MAP(e, events) -> jsg::Ref<TraceItem> { return js.alloc<TraceItem>(js, *e); }) {}
27
 
28
kj::Array<jsg::Ref<TraceItem>> TailEvent::getEvents() {
29
  return KJ_MAP(e, events) -> jsg::Ref<TraceItem> { return e.addRef(); };
30
}
31
 
32
namespace {
33
kj::Maybe<double> getTraceTimestamp(const Trace& trace) {
34
  if (trace.eventTimestamp == kj::UNIX_EPOCH) {
35
    return kj::none;
36
  }
37
  if (isPredictableModeForTest()) {
38
    return 0.0;
39
  }
40
  return (trace.eventTimestamp - kj::UNIX_EPOCH) / kj::MILLISECONDS;
41
}
42
 
43
double getTraceLogTimestamp(const tracing::Log& log) {
44
  if (isPredictableModeForTest()) {
45
    return 0;
46
  } else {
47
    return (log.timestamp - kj::UNIX_EPOCH) / kj::MILLISECONDS;
48
  }
49
}
50
 
51
double getTraceDiagnosticChannelEventTimestamp(const tracing::DiagnosticChannelEvent& event) {
52
  if (isPredictableModeForTest()) {
53
    return 0;
54
  } else {
55
    return (event.timestamp - kj::UNIX_EPOCH) / kj::MILLISECONDS;
56
  }
57
}
58
 
59
kj::LiteralStringConst getTraceLogLevel(const tracing::Log& log) {
60
  switch (log.logLevel) {
61
    case LogLevel::DEBUG_:
62
      return "debug"_kjc;
63
    case LogLevel::INFO:
64
      return "info"_kjc;
65
    case LogLevel::LOG:
66
      return "log"_kjc;
67
    case LogLevel::WARN:
68
      return "warn"_kjc;
69
    case LogLevel::ERROR:
70
      return "error"_kjc;
71
  }
72
  KJ_UNREACHABLE;
73
}
74
 
75
jsg::V8Ref<v8::Object> getTraceLogMessage(jsg::Lock& js, const tracing::Log& log) {
76
  return js.parseJson(log.message).cast<v8::Object>(js);
77
}
78
 
79
kj::Array<jsg::Ref<TraceLog>> getTraceLogs(jsg::Lock& js, const Trace& trace) {
80
  return KJ_MAP(x, trace.logs) -> jsg::Ref<TraceLog> { return js.alloc<TraceLog>(js, trace, x); };
81
}
82
 
83
kj::Array<jsg::Ref<TraceDiagnosticChannelEvent>> getTraceDiagnosticChannelEvents(
84
    jsg::Lock& js, const Trace& trace) {
85
  return KJ_MAP(x, trace.diagnosticChannelEvents) -> jsg::Ref<TraceDiagnosticChannelEvent> {
86
    return js.alloc<TraceDiagnosticChannelEvent>(trace, x);
87
  };
88
}
89
 
90
kj::Maybe<ScriptVersion> getTraceScriptVersion(const Trace& trace) {
91
  return trace.scriptVersion.map([](const auto& version) { return ScriptVersion(*version); });
92
}
93
 
94
double getTraceExceptionTimestamp(const tracing::Exception& ex) {
95
  if (isPredictableModeForTest()) {
96
    return 0;
97
  } else {
98
    return (ex.timestamp - kj::UNIX_EPOCH) / kj::MILLISECONDS;
99
  }
100
}
101
 
102
kj::Array<jsg::Ref<TraceException>> getTraceExceptions(jsg::Lock& js, const Trace& trace) {
103
  return KJ_MAP(x, trace.exceptions) -> jsg::Ref<TraceException> { return js.alloc<TraceException>(trace, x); };
104
}
105
 
106
jsg::Optional<kj::Array<kj::String>> getTraceScriptTags(const Trace& trace) {
107
  if (trace.scriptTags.size() > 0) {
108
    return KJ_MAP(t, trace.scriptTags) -> kj::String { return kj::str(t); };
109
  } else {
110
    return kj::none;
111
  }
112
}
113
 
114
TraceItem::TailAttributeValue getTraceTailAttributeValue(const tracing::Attribute& tag) {
115
  KJ_REQUIRE(tag.value.size() == 1, "tail attributes must contain exactly one value");
116
 
117
  KJ_SWITCH_ONEOF(tag.value[0]) {
118
    KJ_CASE_ONEOF(boolean, bool) {
119
      return TraceItem::TailAttributeValue(boolean);
120
    }
121
    KJ_CASE_ONEOF(number, double) {
122
      return TraceItem::TailAttributeValue(number);
123
    }
124
    KJ_CASE_ONEOF(integer, int64_t) {
125
      return TraceItem::TailAttributeValue(static_cast<double>(integer));
126
    }
127
    KJ_CASE_ONEOF(string, kj::ConstString) {
128
      return TraceItem::TailAttributeValue(kj::str(string));
129
    }
130
  }
131
  KJ_UNREACHABLE;
132
}
133
 
134
kj::Own<TraceItem::FetchEventInfo::Request::Detail> getFetchRequestDetail(
135
    jsg::Lock& js, const Trace& trace, const tracing::FetchEventInfo& eventInfo) {
136
  const auto getCf = [&]() -> jsg::Optional<jsg::V8Ref<v8::Object>> {
137
    const auto& cfJson = eventInfo.cfJson;
138
    if (cfJson.size() > 0) {
139
      return js.parseJson(cfJson).cast<v8::Object>(js);
140
    }
141
    return kj::none;
142
  };
143
 
144
  const auto getHeaders = [&]() -> kj::Array<tracing::FetchEventInfo::Header> {
145
    return KJ_MAP(header, eventInfo.headers) {
146
      return tracing::FetchEventInfo::Header(kj::str(header.name), kj::str(header.value));
147
    };
148
  };
149
 
150
  return kj::refcounted<TraceItem::FetchEventInfo::Request::Detail>(
151
      getCf(), getHeaders(), kj::str(eventInfo.method), kj::str(eventInfo.url));
152
}
153
 
154
kj::Maybe<TraceItem::EventInfo> getTraceEvent(jsg::Lock& js, const Trace& trace) {
155
  KJ_IF_SOME(e, trace.eventInfo) {
156
    KJ_SWITCH_ONEOF(e) {
157
      KJ_CASE_ONEOF(fetch, tracing::FetchEventInfo) {
158
        return kj::Maybe(
159
            js.alloc<TraceItem::FetchEventInfo>(js, trace, fetch, trace.fetchResponseInfo));
160
      }
161
      KJ_CASE_ONEOF(jsRpc, tracing::JsRpcEventInfo) {
162
        return kj::Maybe(js.alloc<TraceItem::JsRpcEventInfo>(trace, jsRpc));
163
      }
164
      KJ_CASE_ONEOF(scheduled, tracing::ScheduledEventInfo) {
165
        return kj::Maybe(js.alloc<TraceItem::ScheduledEventInfo>(trace, scheduled));
166
      }
167
      KJ_CASE_ONEOF(connect, tracing::ConnectEventInfo) {
168
        return kj::Maybe(jsg::alloc<TraceItem::ConnectEventInfo>(js, trace, connect));
169
      }
170
      KJ_CASE_ONEOF(alarm, tracing::AlarmEventInfo) {
171
        return kj::Maybe(js.alloc<TraceItem::AlarmEventInfo>(trace, alarm));
172
      }
173
      KJ_CASE_ONEOF(queue, tracing::QueueEventInfo) {
174
        return kj::Maybe(js.alloc<TraceItem::QueueEventInfo>(trace, queue));
175
      }
176
      KJ_CASE_ONEOF(email, tracing::EmailEventInfo) {
177
        return kj::Maybe(js.alloc<TraceItem::EmailEventInfo>(trace, email));
178
      }
179
      KJ_CASE_ONEOF(tracedTrace, tracing::TraceEventInfo) {
180
        return kj::Maybe(js.alloc<TraceItem::TailEventInfo>(js, trace, tracedTrace));
181
      }
182
      KJ_CASE_ONEOF(hibWs, tracing::HibernatableWebSocketEventInfo) {
183
        KJ_SWITCH_ONEOF(hibWs.type) {
184
          KJ_CASE_ONEOF(message, tracing::HibernatableWebSocketEventInfo::Message) {
185
            return kj::Maybe(
186
                js.alloc<TraceItem::HibernatableWebSocketEventInfo>(js, trace, message));
187
          }
188
          KJ_CASE_ONEOF(close, tracing::HibernatableWebSocketEventInfo::Close) {
189
            return kj::Maybe(js.alloc<TraceItem::HibernatableWebSocketEventInfo>(js, trace, close));
190
          }
191
          KJ_CASE_ONEOF(error, tracing::HibernatableWebSocketEventInfo::Error) {
192
            return kj::Maybe(js.alloc<TraceItem::HibernatableWebSocketEventInfo>(js, trace, error));
193
          }
194
        }
195
        KJ_UNREACHABLE;
196
      }
197
      KJ_CASE_ONEOF(custom, tracing::CustomEventInfo) {
198
        return kj::Maybe(js.alloc<TraceItem::CustomEventInfo>(trace, custom));
199
      }
200
    }
201
  }
202
  return kj::none;
203
}
204
}  // namespace
205
 
206
TraceItem::TraceItem(jsg::Lock& js, const Trace& trace)
207
    : eventInfo(getTraceEvent(js, trace)),
208
      eventTimestamp(getTraceTimestamp(trace)),
209
      logs(getTraceLogs(js, trace)),
210
      exceptions(getTraceExceptions(js, trace)),
211
      diagnosticChannelEvents(getTraceDiagnosticChannelEvents(js, trace)),
212
      scriptName(mapCopyString(trace.scriptName)),
213
      entrypoint(mapCopyString(trace.entrypoint)),
214
      scriptVersion(getTraceScriptVersion(trace)),
215
      dispatchNamespace(mapCopyString(trace.dispatchNamespace)),
216
      scriptTags(getTraceScriptTags(trace)),
217
      tailAttributes(trace.tailAttributes.map(
218
          [](auto& tags) { return KJ_MAP(tag, tags) { return tag.clone(); }; })),
219
      preview(trace.preview.map([](auto& p) { return TracePreviewInfo(p); })),
220
      durableObjectId(mapCopyString(trace.durableObjectId)),
221
      executionModel(kj::str(trace.executionModel)),
222
      outcome(kj::str(trace.outcome)),
223
      cpuTime(trace.cpuTime / kj::MILLISECONDS),
224
      wallTime(trace.wallTime / kj::MILLISECONDS),
225
      truncated(trace.truncated) {}
226
 
227
kj::Maybe<TraceItem::EventInfo> TraceItem::getEvent(jsg::Lock& js) {
228
  return eventInfo.map([](auto& info) -> TraceItem::EventInfo {
229
    KJ_SWITCH_ONEOF(info) {
230
      KJ_CASE_ONEOF(info, jsg::Ref<FetchEventInfo>) {
231
        return info.addRef();
232
      }
233
      KJ_CASE_ONEOF(info, jsg::Ref<JsRpcEventInfo>) {
234
        return info.addRef();
235
      }
236
      KJ_CASE_ONEOF(info, jsg::Ref<ScheduledEventInfo>) {
237
        return info.addRef();
238
      }
239
      KJ_CASE_ONEOF(info, jsg::Ref<AlarmEventInfo>) {
240
        return info.addRef();
241
      }
242
      KJ_CASE_ONEOF(info, jsg::Ref<QueueEventInfo>) {
243
        return info.addRef();
244
      }
245
      KJ_CASE_ONEOF(info, jsg::Ref<EmailEventInfo>) {
246
        return info.addRef();
247
      }
248
      KJ_CASE_ONEOF(info, jsg::Ref<TailEventInfo>) {
249
        return info.addRef();
250
      }
251
      KJ_CASE_ONEOF(info, jsg::Ref<HibernatableWebSocketEventInfo>) {
252
        return info.addRef();
253
      }
254
      KJ_CASE_ONEOF(info, jsg::Ref<CustomEventInfo>) {
255
        return info.addRef();
256
      }
257
      KJ_CASE_ONEOF(info, jsg::Ref<ConnectEventInfo>) {
258
        return info.addRef();
259
      }
260
    }
261
    KJ_UNREACHABLE;
262
  });
263
}
264
 
265
kj::Maybe<double> TraceItem::getEventTimestamp() {
266
  return eventTimestamp;
267
}
268
 
269
kj::ArrayPtr<jsg::Ref<TraceLog>> TraceItem::getLogs() {
270
  return logs;
271
}
272
 
273
kj::ArrayPtr<jsg::Ref<TraceException>> TraceItem::getExceptions() {
274
  return exceptions;
275
}
276
 
277
kj::ArrayPtr<jsg::Ref<TraceDiagnosticChannelEvent>> TraceItem::getDiagnosticChannelEvents() {
278
  return diagnosticChannelEvents;
279
}
280
 
281
kj::Maybe<kj::StringPtr> TraceItem::getScriptName() {
282
  return scriptName.map([](auto& name) -> kj::StringPtr { return name; });
283
}
284
 
285
jsg::Optional<kj::StringPtr> TraceItem::getEntrypoint() {
286
  return entrypoint;
287
}
288
 
289
jsg::Optional<ScriptVersion> TraceItem::getScriptVersion() {
290
  return scriptVersion;
291
}
292
 
293
jsg::Optional<kj::StringPtr> TraceItem::getDispatchNamespace() {
294
  return dispatchNamespace.map([](auto& ns) -> kj::StringPtr { return ns; });
295
}
296
 
297
jsg::Optional<kj::Array<kj::StringPtr>> TraceItem::getScriptTags() {
298
  return scriptTags.map(
299
      [](kj::Array<kj::String>& tags) { return KJ_MAP(t, tags) -> kj::StringPtr { return t; }; });
300
}
301
 
302
jsg::Optional<jsg::Dict<TraceItem::TailAttributeValue>> TraceItem::getTailAttributes() {
303
  return tailAttributes.map([](kj::Array<tracing::Attribute>& tags) {
304
    return jsg::Dict<TraceItem::TailAttributeValue>{
305
      .fields =
306
          KJ_MAP(tag, tags) {
307
      return jsg::Dict<TraceItem::TailAttributeValue>::Field{
308
        .name = kj::str(tag.name),
309
        .value = getTraceTailAttributeValue(tag),
310
      };
311
    },
312
    };
313
  });
314
}
315
 
316
jsg::Optional<TracePreviewInfo> TraceItem::getPreview() {
317
  return preview;
318
}
319
 
320
jsg::Optional<kj::StringPtr> TraceItem::getDurableObjectId() {
321
  return durableObjectId.map([](auto& id) -> kj::StringPtr { return id; });
322
}
323
 
324
kj::StringPtr TraceItem::getExecutionModel() {
325
  return executionModel;
326
}
327
 
328
kj::StringPtr TraceItem::getOutcome() {
329
  return outcome;
330
}
331
 
332
bool TraceItem::getTruncated() {
333
  return truncated;
334
}
335
 
336
uint TraceItem::getCpuTime() {
337
  return cpuTime;
338
}
339
 
340
uint TraceItem::getWallTime() {
341
  return wallTime;
342
}
343
 
344
TraceItem::FetchEventInfo::FetchEventInfo(jsg::Lock& js,
345
    const Trace& trace,
346
    const tracing::FetchEventInfo& eventInfo,
347
    kj::Maybe<const tracing::FetchResponseInfo&> responseInfo)
348
    : request(js.alloc<Request>(js, trace, eventInfo)),
349
      response(responseInfo.map([&](auto& info) { return js.alloc<Response>(trace, info); })) {}
350
 
351
TraceItem::FetchEventInfo::Request::Detail::Detail(jsg::Optional<jsg::V8Ref<v8::Object>> cf,
352
    kj::Array<tracing::FetchEventInfo::Header> headers,
353
    kj::String method,
354
    kj::String url)
355
    : cf(kj::mv(cf)),
356
      headers(kj::mv(headers)),
357
      method(kj::mv(method)),
358
      url(kj::mv(url)) {}
359
 
360
jsg::Ref<TraceItem::FetchEventInfo::Request> TraceItem::FetchEventInfo::getRequest() {
361
  return request.addRef();
362
}
363
 
364
jsg::Optional<jsg::Ref<TraceItem::FetchEventInfo::Response>> TraceItem::FetchEventInfo::
365
    getResponse() {
366
  return response.map([](auto& ref) mutable -> jsg::Ref<TraceItem::FetchEventInfo::Response> {
367
    return ref.addRef();
368
  });
369
}
370
 
371
TraceItem::FetchEventInfo::Request::Request(
372
    jsg::Lock& js, const Trace& trace, const tracing::FetchEventInfo& eventInfo)
373
    : detail(getFetchRequestDetail(js, trace, eventInfo)) {}
374
 
375
TraceItem::FetchEventInfo::Request::Request(Detail& detail, bool redacted)
376
    : redacted(redacted),
377
      detail(kj::addRef(detail)) {}
378
 
379
jsg::Optional<jsg::V8Ref<v8::Object>> TraceItem::FetchEventInfo::Request::getCf(jsg::Lock& js) {
380
  return detail->cf.map([&](jsg::V8Ref<v8::Object>& obj) { return obj.addRef(js); });
381
}
382
 
383
jsg::Dict<kj::String, kj::String> TraceItem::FetchEventInfo::Request::getHeaders(jsg::Lock& js) {
384
  auto shouldRedact = [](kj::StringPtr name) {
385
    return (
386
        //(name == "authorization"_kj) || // covered below
387
        (name == "cookie"_kj) || (name == "set-cookie"_kj) || name.contains("auth"_kjc) ||
388
        name.contains("jwt"_kjc) || name.contains("key"_kjc) || name.contains("secret"_kjc) ||
389
        name.contains("token"_kjc));
390
  };
391
 
392
  using HeaderDict = jsg::Dict<kj::String, kj::String>;
393
  auto builder = kj::heapArrayBuilder<HeaderDict::Field>(detail->headers.size());
394
  for (const auto& header: detail->headers) {
395
    auto v = (redacted && shouldRedact(header.name)) ? "REDACTED"_kj : header.value;
396
    builder.add(HeaderDict::Field{kj::str(header.name), kj::str(v)});
397
  }
398
 
399
  // TODO(conform): Better to return a frozen JS Object?
400
  return HeaderDict{builder.finish()};
401
}
402
 
403
kj::StringPtr TraceItem::FetchEventInfo::Request::getMethod() {
404
  return detail->method;
405
}
406
 
407
kj::String TraceItem::FetchEventInfo::Request::getUrl() {
408
  return (redacted ? redactUrl(detail->url) : kj::str(detail->url));
409
}
410
 
411
jsg::Ref<TraceItem::FetchEventInfo::Request> TraceItem::FetchEventInfo::Request::getUnredacted(
412
    jsg::Lock& js) {
413
  return js.alloc<Request>(*detail, false /* details are not redacted */);
414
}
415
 
416
TraceItem::FetchEventInfo::Response::Response(
417
    const Trace& trace, const tracing::FetchResponseInfo& responseInfo)
418
    : status(responseInfo.statusCode) {}
419
 
420
uint16_t TraceItem::FetchEventInfo::Response::getStatus() {
421
  return status;
422
}
423
 
424
TraceItem::JsRpcEventInfo::JsRpcEventInfo(
425
    const Trace& trace, const tracing::JsRpcEventInfo& eventInfo)
426
    : rpcMethod(kj::str(eventInfo.methodName)) {}
427
 
428
kj::StringPtr TraceItem::JsRpcEventInfo::getRpcMethod() {
429
  return rpcMethod;
430
}
431
 
432
TraceItem::ScheduledEventInfo::ScheduledEventInfo(
433
    const Trace& trace, const tracing::ScheduledEventInfo& eventInfo)
434
    : scheduledTime(eventInfo.scheduledTime),
435
      cron(kj::str(eventInfo.cron)) {}
436
 
437
double TraceItem::ScheduledEventInfo::getScheduledTime() {
438
  return scheduledTime;
439
}
440
kj::StringPtr TraceItem::ScheduledEventInfo::getCron() {
441
  return cron;
442
}
443
 
444
TraceItem::AlarmEventInfo::AlarmEventInfo(
445
    const Trace& trace, const tracing::AlarmEventInfo& eventInfo)
446
    : scheduledTime(eventInfo.scheduledTime) {}
447
 
448
kj::Date TraceItem::AlarmEventInfo::getScheduledTime() {
449
  return scheduledTime;
450
}
451
 
452
TraceItem::QueueEventInfo::QueueEventInfo(
453
    const Trace& trace, const tracing::QueueEventInfo& eventInfo)
454
    : queueName(kj::str(eventInfo.queueName)),
455
      batchSize(eventInfo.batchSize) {}
456
 
457
kj::StringPtr TraceItem::QueueEventInfo::getQueueName() {
458
  return queueName;
459
}
460
 
461
uint32_t TraceItem::QueueEventInfo::getBatchSize() {
462
  return batchSize;
463
}
464
 
465
TraceItem::EmailEventInfo::EmailEventInfo(
466
    const Trace& trace, const tracing::EmailEventInfo& eventInfo)
467
    : mailFrom(kj::str(eventInfo.mailFrom)),
468
      rcptTo(kj::str(eventInfo.rcptTo)),
469
      rawSize(eventInfo.rawSize) {}
470
 
471
kj::StringPtr TraceItem::EmailEventInfo::getMailFrom() {
472
  return mailFrom;
473
}
474
 
475
kj::StringPtr TraceItem::EmailEventInfo::getRcptTo() {
476
  return rcptTo;
477
}
478
 
479
uint32_t TraceItem::EmailEventInfo::getRawSize() {
480
  return rawSize;
481
}
482
 
483
kj::Array<jsg::Ref<TraceItem::TailEventInfo::TailItem>> getConsumedEventsFromEventInfo(
484
    jsg::Lock& js, const tracing::TraceEventInfo& eventInfo) {
485
  return KJ_MAP(t, eventInfo.traces) -> jsg::Ref<TraceItem::TailEventInfo::TailItem> {
486
    return js.alloc<TraceItem::TailEventInfo::TailItem>(t);
487
  };
488
}
489
 
490
TraceItem::TailEventInfo::TailEventInfo(
491
    jsg::Lock& js, const Trace& trace, const tracing::TraceEventInfo& eventInfo)
492
    : consumedEvents(getConsumedEventsFromEventInfo(js, eventInfo)) {}
493
 
494
kj::Array<jsg::Ref<TraceItem::TailEventInfo::TailItem>> TraceItem::TailEventInfo::
495
    getConsumedEvents() {
496
  return KJ_MAP(consumedEvent, consumedEvents) -> jsg::Ref<TailEventInfo::TailItem> {
497
    return consumedEvent.addRef();
498
  };
499
}
500
 
501
TraceItem::TailEventInfo::TailItem::TailItem(const tracing::TraceEventInfo::TraceItem& traceItem)
502
    : scriptName(mapCopyString(traceItem.scriptName)) {}
503
 
504
kj::Maybe<kj::StringPtr> TraceItem::TailEventInfo::TailItem::getScriptName() {
505
  return scriptName;
506
}
507
 
508
TraceDiagnosticChannelEvent::TraceDiagnosticChannelEvent(
509
    const Trace& trace, const tracing::DiagnosticChannelEvent& eventInfo)
510
    : timestamp(getTraceDiagnosticChannelEventTimestamp(eventInfo)),
511
      channel(kj::heapString(eventInfo.channel)),
512
      message(kj::heapArray<kj::byte>(eventInfo.message)) {}
513
 
514
kj::StringPtr TraceDiagnosticChannelEvent::getChannel() {
515
  return channel;
516
}
517
 
518
jsg::JsValue TraceDiagnosticChannelEvent::getMessage(jsg::Lock& js) {
519
  if (message.size() == 0) return js.undefined();
520
  jsg::Deserializer des(js, message.asPtr());
521
  return des.readValue(js);
522
}
523
 
524
double TraceDiagnosticChannelEvent::getTimestamp() {
525
  return timestamp;
526
}
527
 
528
ScriptVersion::ScriptVersion(workerd::ScriptVersion::Reader version)
529
    : id{[&]() -> kj::Maybe<kj::String> {
530
        return UUID::fromUpperLower(version.getId().getUpper(), version.getId().getLower())
531
            .map([](const auto& uuid) { return uuid.toString(); });
532
      }()},
533
      tag{[&]() -> kj::Maybe<kj::String> {
534
        if (version.hasTag()) {
535
          return kj::str(version.getTag());
536
        }
537
        return kj::none;
538
      }()},
539
      message{[&]() -> kj::Maybe<kj::String> {
540
        if (version.hasMessage()) {
541
          return kj::str(version.getMessage());
542
        }
543
        return kj::none;
544
      }()} {}
545
 
546
ScriptVersion::ScriptVersion(const ScriptVersion& other)
547
    : id{mapCopyString(other.id)},
548
      tag{mapCopyString(other.tag)},
549
      message{mapCopyString(other.message)} {}
550
 
551
TracePreviewInfo::TracePreviewInfo(const tracing::TracePreview& preview)
552
    : id(kj::str(preview.id)),
553
      slug(kj::str(preview.slug)),
554
      name(kj::str(preview.name)) {}
555
 
556
TracePreviewInfo::TracePreviewInfo(const TracePreviewInfo& other)
557
    : id(kj::str(other.id)),
558
      slug(kj::str(other.slug)),
559
      name(kj::str(other.name)) {}
560
 
561
TraceItem::CustomEventInfo::CustomEventInfo(
562
    const Trace& trace, const tracing::CustomEventInfo& eventInfo)
563
    : eventInfo(eventInfo) {}
564
 
565
TraceItem::HibernatableWebSocketEventInfo::HibernatableWebSocketEventInfo(jsg::Lock& js,
566
    const Trace& trace,
567
    const tracing::HibernatableWebSocketEventInfo::Message eventInfo)
568
    : eventType(js.alloc<TraceItem::HibernatableWebSocketEventInfo::Message>(trace, eventInfo)) {}
569
 
570
TraceItem::HibernatableWebSocketEventInfo::HibernatableWebSocketEventInfo(jsg::Lock& js,
571
    const Trace& trace,
572
    const tracing::HibernatableWebSocketEventInfo::Close eventInfo)
573
    : eventType(js.alloc<TraceItem::HibernatableWebSocketEventInfo::Close>(trace, eventInfo)) {}
574
 
575
TraceItem::HibernatableWebSocketEventInfo::HibernatableWebSocketEventInfo(jsg::Lock& js,
576
    const Trace& trace,
577
    const tracing::HibernatableWebSocketEventInfo::Error eventInfo)
578
    : eventType(js.alloc<TraceItem::HibernatableWebSocketEventInfo::Error>(trace, eventInfo)) {}
579
 
580
TraceItem::HibernatableWebSocketEventInfo::Type TraceItem::HibernatableWebSocketEventInfo::
581
    getEvent() {
582
  KJ_SWITCH_ONEOF(eventType) {
583
    KJ_CASE_ONEOF(m, jsg::Ref<TraceItem::HibernatableWebSocketEventInfo::Message>) {
584
      return m.addRef();
585
    }
586
    KJ_CASE_ONEOF(c, jsg::Ref<TraceItem::HibernatableWebSocketEventInfo::Close>) {
587
      return c.addRef();
588
    }
589
    KJ_CASE_ONEOF(e, jsg::Ref<TraceItem::HibernatableWebSocketEventInfo::Error>) {
590
      return e.addRef();
591
    }
592
  }
593
  KJ_UNREACHABLE;
594
}
595
 
596
uint16_t TraceItem::HibernatableWebSocketEventInfo::Close::getCode() {
597
  return eventInfo.code;
598
}
599
 
600
bool TraceItem::HibernatableWebSocketEventInfo::Close::getWasClean() {
601
  return eventInfo.wasClean;
602
}
603
 
604
TraceLog::TraceLog(jsg::Lock& js, const Trace& trace, const tracing::Log& log)
605
    : timestamp(getTraceLogTimestamp(log)),
606
      level(getTraceLogLevel(log)),
607
      message(getTraceLogMessage(js, log)) {}
608
 
609
double TraceLog::getTimestamp() {
610
  return timestamp;
611
}
612
 
613
kj::StringPtr TraceLog::getLevel() {
614
  return level;
615
}
616
 
617
jsg::V8Ref<v8::Object> TraceLog::getMessage(jsg::Lock& js) {
618
  return message.addRef(js);
619
}
620
 
621
TraceException::TraceException(const Trace& trace, const tracing::Exception& exception)
622
    : timestamp(getTraceExceptionTimestamp(exception)),
623
      name(kj::str(exception.name)),
624
      message(kj::str(exception.message)),
625
      stack(mapCopyString(exception.stack)) {}
626
 
627
double TraceException::getTimestamp() {
628
  return timestamp;
629
}
630
 
631
kj::StringPtr TraceException::getMessage() {
632
  return message;
633
}
634
 
635
kj::StringPtr TraceException::getName() {
636
  return name;
637
}
638
 
639
jsg::Optional<kj::StringPtr> TraceException::getStack(jsg::Lock& js) {
640
  return stack;
641
}
642
 
643
TraceMetrics::TraceMetrics(uint cpuTime, uint wallTime): cpuTime(cpuTime), wallTime(wallTime) {}
644
 
645
jsg::Ref<TraceMetrics> UnsafeTraceMetrics::fromTrace(jsg::Lock& js, jsg::Ref<TraceItem> item) {
646
  return js.alloc<TraceMetrics>(item->getCpuTime(), item->getWallTime());
647
}
648
 
649
namespace {
650
kj::Promise<void> sendTracesToExportedHandler(kj::Own<IoContext::IncomingRequest> incomingRequest,
651
    kj::Maybe<kj::StringPtr> entrypointNamePtr,
652
    kj::Maybe<Worker::VersionInfo> versionInfo,
653
    Frankenvalue props,
654
    kj::ArrayPtr<kj::Own<Trace>> traces,
655
    bool isDynamicDispatch) {
656
  // Mark the request as delivered because we're about to run some JS.
657
  incomingRequest->delivered();
658
 
659
  auto& context = incomingRequest->getContext();
660
  auto& metrics = incomingRequest->getMetrics();
661
 
662
  auto nonEmptyTraces = kj::Vector<kj::Own<Trace>>(kj::size(traces));
663
  for (auto& trace: traces) {
664
    if (trace->eventInfo != kj::none) {
665
      nonEmptyTraces.add(kj::addRef(*trace));
666
    }
667
  }
668
 
669
  // Add the actual JS as a wait until because the handler may be an event listener which can't
670
  // wait around for async resolution. We're relying on `drain()` below to persist `incomingRequest`
671
  // and its members until this task completes.
672
  auto entrypointName = mapCopyString(entrypointNamePtr);
673
  try {
674
    co_await context.run(
675
        [&context, nonEmptyTraces = nonEmptyTraces.asPtr(), entrypointName = kj::mv(entrypointName),
676
            versionInfo = kj::mv(versionInfo), props = kj::mv(props),
677
            isDynamicDispatch](Worker::Lock& lock) mutable {
678
      jsg::AsyncContextFrame::StorageScope traceScope = context.makeAsyncTraceScope(lock);
679
      jsg::AsyncContextFrame::StorageScope userTraceScope = context.makeUserAsyncTraceScope(lock);
680
 
681
      auto handler = lock.getExportedHandler(entrypointName, kj::mv(versionInfo), kj::mv(props),
682
          context.getActor(), isDynamicDispatch);
683
      return lock.getGlobalScope().sendTraces(nonEmptyTraces, lock, handler);
684
    });
685
  } catch (kj::Exception& e) {
686
    // TODO(someday): We only report sendTraces() as failed for metrics/logging if the initial
687
    //   event handler throws an exception; we do not consider waitUntil(). But all async work done
688
    //   in a trace handler has to be done using waitUntil(). So, this seems wrong. Should we
689
    //   change it so any waitUntil() failure counts as an error? For that matter, arguably *all*
690
    //   event types should report failure if a waitUntil() throws?
691
    metrics.reportFailure(e);
692
 
693
    // Log JS exceptions (from the initial sendTraces() call) to the JS console, if inspector is
694
    // attached. This also has the effect of logging internal errors to syslog. (Note that
695
    // exceptions that occur asynchronously while waiting for the context to drain will be
696
    // logged elsewhere.)
697
    context.logUncaughtExceptionAsync(UncaughtExceptionSource::TRACE_HANDLER, kj::mv(e));
698
  };
699
 
700
  co_await incomingRequest->drain();
701
}
702
}  // namespace
703
 
704
tracing::EventInfo TraceCustomEvent::getEventInfo() const {
705
  return tracing::TraceEventInfo(traces);
706
}
707
 
708
auto TraceCustomEvent::run(kj::Own<IoContext::IncomingRequest> incomingRequest,
709
    kj::Maybe<kj::StringPtr> entrypointNamePtr,
710
    kj::Maybe<Worker::VersionInfo> versionInfo,
711
    Frankenvalue props,
712
    kj::TaskSet& waitUntilTasks,
713
    bool isDynamicDispatch) -> kj::Promise<Result> {
714
  // Don't bother to wait around for the handler to run, just hand it off to the waitUntil tasks.
715
  waitUntilTasks.add(sendTracesToExportedHandler(kj::mv(incomingRequest), entrypointNamePtr,
716
      kj::mv(versionInfo), kj::mv(props), traces, isDynamicDispatch));
717
 
718
  // Reporting a proper outcome and return event here would be nice, but for that we'd need to await
719
  // running the tail handler...
720
  return Result{
721
    .outcome = EventOutcome::OK,
722
  };
723
}
724
 
725
auto TraceCustomEvent::sendRpc(capnp::HttpOverCapnpFactory& httpOverCapnpFactory,
726
    capnp::ByteStreamFactory& byteStreamFactory,
727
    workerd::rpc::EventDispatcher::Client dispatcher) -> kj::Promise<Result> {
728
  auto req = dispatcher.sendTracesRequest();
729
  auto out = req.initTraces(traces.size());
730
  for (auto i: kj::indices(traces)) {
731
    traces[i]->copyTo(out[i]);
732
  }
733
 
734
  auto resp = co_await req.send();
735
  auto respResult = resp.getResult();
736
  co_return WorkerInterface::CustomEvent::Result{
737
    .outcome = respResult.getOutcome(),
738
  };
739
}
740
 
741
void TailEvent::visitForMemoryInfo(jsg::MemoryTracker& tracker) const {
742
  for (const auto& event: events) {
743
    tracker.trackField(nullptr, event);
744
  }
745
}
746
 
747
void TraceItem::visitForMemoryInfo(jsg::MemoryTracker& tracker) const {
748
  KJ_IF_SOME(event, eventInfo) {
749
    KJ_SWITCH_ONEOF(event) {
750
      KJ_CASE_ONEOF(info, jsg::Ref<FetchEventInfo>) {
751
        tracker.trackField("eventInfo", info);
752
      }
753
      KJ_CASE_ONEOF(info, jsg::Ref<JsRpcEventInfo>) {
754
        tracker.trackField("eventInfo", info);
755
      }
756
      KJ_CASE_ONEOF(info, jsg::Ref<ScheduledEventInfo>) {
757
        tracker.trackField("eventInfo", info);
758
      }
759
      KJ_CASE_ONEOF(info, jsg::Ref<AlarmEventInfo>) {
760
        tracker.trackField("eventInfo", info);
761
      }
762
      KJ_CASE_ONEOF(info, jsg::Ref<QueueEventInfo>) {
763
        tracker.trackField("eventInfo", info);
764
      }
765
      KJ_CASE_ONEOF(info, jsg::Ref<EmailEventInfo>) {
766
        tracker.trackField("eventInfo", info);
767
      }
768
      KJ_CASE_ONEOF(info, jsg::Ref<TailEventInfo>) {
769
        tracker.trackField("eventInfo", info);
770
      }
771
      KJ_CASE_ONEOF(info, jsg::Ref<CustomEventInfo>) {
772
        tracker.trackField("eventInfo", info);
773
      }
774
      KJ_CASE_ONEOF(info, jsg::Ref<HibernatableWebSocketEventInfo>) {
775
        tracker.trackField("eventInfo", info);
776
      }
777
      KJ_CASE_ONEOF(info, jsg::Ref<ConnectEventInfo>) {
778
        tracker.trackField("eventInfo", info);
779
      }
780
    }
781
  }
782
  for (const auto& log: logs) {
783
    tracker.trackField("log", log);
784
  }
785
  for (const auto& exception: exceptions) {
786
    tracker.trackField("exception", exception);
787
  }
788
  for (const auto& event: diagnosticChannelEvents) {
789
    tracker.trackField("diagnosticChannelEvent", event);
790
  }
791
  tracker.trackField("scriptName", scriptName);
792
  tracker.trackField("scriptVersion", scriptVersion);
793
  tracker.trackField("dispatchNamespace", dispatchNamespace);
794
  KJ_IF_SOME(tags, scriptTags) {
795
    for (const auto& tag: tags) {
796
      tracker.trackField("scriptTag", tag);
797
    }
798
  }
799
  KJ_IF_SOME(tags, tailAttributes) {
800
    for (const auto& tag: tags) {
801
      tracker.trackFieldWithSize("tailAttributeName", tag.name.size());
802
      for (const auto& value: tag.value) {
803
        KJ_IF_SOME(string, value.tryGet<kj::ConstString>()) {
804
          tracker.trackFieldWithSize("tailAttributeValue", string.size());
805
        }
806
      }
807
    }
808
  }
809
  tracker.trackField("preview", preview);
810
  tracker.trackField("outcome", outcome);
811
}
812
 
813
void TraceItem::FetchEventInfo::visitForMemoryInfo(jsg::MemoryTracker& tracker) const {
814
  tracker.trackField("request", request);
815
  tracker.trackField("response", response);
816
}
817
 
818
void TraceItem::TailEventInfo::visitForMemoryInfo(jsg::MemoryTracker& tracker) const {
819
  for (const auto& event: consumedEvents) {
820
    tracker.trackField(nullptr, event);
821
  }
822
}
823
 
824
void TraceItem::HibernatableWebSocketEventInfo::visitForMemoryInfo(
825
    jsg::MemoryTracker& tracker) const {
826
  KJ_SWITCH_ONEOF(eventType) {
827
    KJ_CASE_ONEOF(message, jsg::Ref<Message>) {
828
      tracker.trackField("message", message);
829
    }
830
    KJ_CASE_ONEOF(close, jsg::Ref<Close>) {
831
      tracker.trackField("close", close);
832
    }
833
    KJ_CASE_ONEOF(error, jsg::Ref<Error>) {
834
      tracker.trackField("error", error);
835
    }
836
  }
837
}
838
 
839
TraceItem::ConnectEventInfo::ConnectEventInfo(
840
    jsg::Lock& js, const Trace& trace, const tracing::ConnectEventInfo& eventInfo) {}
841
 
842
}  // namespace workerd::api