From 1d293cc9755159ca8eb4fea220c59d41399519bd Mon Sep 17 00:00:00 2001 From: James M Snell Date: Wed, 20 Nov 2024 09:56:54 -0800 Subject: [PATCH] Move tracing info types out of Trace class These will be reused by the streaming Trace implementation that does not use the Trace class. Separate them out. --- src/workerd/api/hibernatable-web-socket.c++ | 14 +- src/workerd/api/queue.c++ | 2 +- src/workerd/api/trace.c++ | 83 ++-- src/workerd/api/trace.h | 58 +-- src/workerd/api/worker-rpc.c++ | 2 +- src/workerd/io/trace.c++ | 161 ++++---- src/workerd/io/trace.h | 418 +++++++++++--------- src/workerd/io/worker-entrypoint.c++ | 8 +- src/workerd/server/server.c++ | 2 +- 9 files changed, 384 insertions(+), 364 deletions(-) diff --git a/src/workerd/api/hibernatable-web-socket.c++ b/src/workerd/api/hibernatable-web-socket.c++ index ecb83fe7fe5..2748c9c3ac9 100644 --- a/src/workerd/api/hibernatable-web-socket.c++ +++ b/src/workerd/api/hibernatable-web-socket.c++ @@ -75,27 +75,27 @@ kj::Promise HibernatableWebSocketCustomEve auto eventParameters = consumeParams(); KJ_IF_SOME(t, incomingRequest->getWorkerTracer()) { - Trace::HibernatableWebSocketEventInfo::Type type = - [&]() -> Trace::HibernatableWebSocketEventInfo::Type { + tracing::HibernatableWebSocketEventInfo::Type type = + [&]() -> tracing::HibernatableWebSocketEventInfo::Type { KJ_SWITCH_ONEOF(eventParameters.eventType) { KJ_CASE_ONEOF(_, HibernatableSocketParams::Text) { - return Trace::HibernatableWebSocketEventInfo::Message{}; + return tracing::HibernatableWebSocketEventInfo::Message{}; } KJ_CASE_ONEOF(data, HibernatableSocketParams::Data) { - return Trace::HibernatableWebSocketEventInfo::Message{}; + return tracing::HibernatableWebSocketEventInfo::Message{}; } KJ_CASE_ONEOF(close, HibernatableSocketParams::Close) { - return Trace::HibernatableWebSocketEventInfo::Close{ + return tracing::HibernatableWebSocketEventInfo::Close{ .code = close.code, .wasClean = close.wasClean}; } KJ_CASE_ONEOF(_, HibernatableSocketParams::Error) { - return Trace::HibernatableWebSocketEventInfo::Error{}; + return tracing::HibernatableWebSocketEventInfo::Error{}; } } KJ_UNREACHABLE; }(); - t.setEventInfo(context.now(), Trace::HibernatableWebSocketEventInfo(kj::mv(type))); + t.setEventInfo(context.now(), tracing::HibernatableWebSocketEventInfo(kj::mv(type))); } try { diff --git a/src/workerd/api/queue.c++ b/src/workerd/api/queue.c++ index c0cf06a3e43..8b7b95475a9 100644 --- a/src/workerd/api/queue.c++ +++ b/src/workerd/api/queue.c++ @@ -531,7 +531,7 @@ kj::Promise QueueCustomEventImpl::run( } KJ_IF_SOME(t, incomingRequest->getWorkerTracer()) { - t.setEventInfo(context.now(), Trace::QueueEventInfo(kj::mv(queueName), batchSize)); + t.setEventInfo(context.now(), tracing::QueueEventInfo(kj::mv(queueName), batchSize)); } // Create a custom refcounted type for holding the queueEvent so that we can pass it to the diff --git a/src/workerd/api/trace.c++ b/src/workerd/api/trace.c++ index c71cfe67864..b456f25676d 100644 --- a/src/workerd/api/trace.c++ +++ b/src/workerd/api/trace.c++ @@ -37,7 +37,7 @@ kj::Maybe getTraceTimestamp(const Trace& trace) { return (trace.eventTimestamp - kj::UNIX_EPOCH) / kj::MILLISECONDS; } -double getTraceLogTimestamp(const Trace::Log& log) { +double getTraceLogTimestamp(const tracing::Log& log) { if (isPredictableModeForTest()) { return 0; } else { @@ -45,7 +45,7 @@ double getTraceLogTimestamp(const Trace::Log& log) { } } -double getTraceDiagnosticChannelEventTimestamp(const Trace::DiagnosticChannelEvent& event) { +double getTraceDiagnosticChannelEventTimestamp(const tracing::DiagnosticChannelEvent& event) { if (isPredictableModeForTest()) { return 0; } else { @@ -53,7 +53,7 @@ double getTraceDiagnosticChannelEventTimestamp(const Trace::DiagnosticChannelEve } } -kj::String getTraceLogLevel(const Trace::Log& log) { +kj::String getTraceLogLevel(const tracing::Log& log) { switch (log.logLevel) { case LogLevel::DEBUG_: return kj::str("debug"); @@ -69,7 +69,7 @@ kj::String getTraceLogLevel(const Trace::Log& log) { KJ_UNREACHABLE; } -jsg::V8Ref getTraceLogMessage(jsg::Lock& js, const Trace::Log& log) { +jsg::V8Ref getTraceLogMessage(jsg::Lock& js, const tracing::Log& log) { return js.parseJson(log.message).cast(js); } @@ -96,7 +96,7 @@ kj::Maybe getTraceScriptVersion(const Trace& trace) { return trace.scriptVersion.map([](const auto& version) { return ScriptVersion(*version); }); } -double getTraceExceptionTimestamp(const Trace::Exception& ex) { +double getTraceExceptionTimestamp(const tracing::Exception& ex) { if (isPredictableModeForTest()) { return 0; } else { @@ -126,7 +126,7 @@ kj::String enumToStr(const Enum& var) { } kj::Own getFetchRequestDetail( - jsg::Lock& js, const Trace& trace, const Trace::FetchEventInfo& eventInfo) { + jsg::Lock& js, const Trace& trace, const tracing::FetchEventInfo& eventInfo) { const auto getCf = [&]() -> jsg::Optional> { const auto& cfJson = eventInfo.cfJson; if (cfJson.size() > 0) { @@ -135,9 +135,9 @@ kj::Own getFetchRequestDetail( return kj::none; }; - const auto getHeaders = [&]() -> kj::Array { + const auto getHeaders = [&]() -> kj::Array { return KJ_MAP(header, eventInfo.headers) { - return Trace::FetchEventInfo::Header(kj::str(header.name), kj::str(header.value)); + return tracing::FetchEventInfo::Header(kj::str(header.name), kj::str(header.value)); }; }; @@ -148,43 +148,43 @@ kj::Own getFetchRequestDetail( kj::Maybe getTraceEvent(jsg::Lock& js, const Trace& trace) { KJ_IF_SOME(e, trace.eventInfo) { KJ_SWITCH_ONEOF(e) { - KJ_CASE_ONEOF(fetch, Trace::FetchEventInfo) { + KJ_CASE_ONEOF(fetch, tracing::FetchEventInfo) { return kj::Maybe( jsg::alloc(js, trace, fetch, trace.fetchResponseInfo)); } - KJ_CASE_ONEOF(jsRpc, Trace::JsRpcEventInfo) { + KJ_CASE_ONEOF(jsRpc, tracing::JsRpcEventInfo) { return kj::Maybe(jsg::alloc(trace, jsRpc)); } - KJ_CASE_ONEOF(scheduled, Trace::ScheduledEventInfo) { + KJ_CASE_ONEOF(scheduled, tracing::ScheduledEventInfo) { return kj::Maybe(jsg::alloc(trace, scheduled)); } - KJ_CASE_ONEOF(alarm, Trace::AlarmEventInfo) { + KJ_CASE_ONEOF(alarm, tracing::AlarmEventInfo) { return kj::Maybe(jsg::alloc(trace, alarm)); } - KJ_CASE_ONEOF(queue, Trace::QueueEventInfo) { + KJ_CASE_ONEOF(queue, tracing::QueueEventInfo) { return kj::Maybe(jsg::alloc(trace, queue)); } - KJ_CASE_ONEOF(email, Trace::EmailEventInfo) { + KJ_CASE_ONEOF(email, tracing::EmailEventInfo) { return kj::Maybe(jsg::alloc(trace, email)); } - KJ_CASE_ONEOF(tracedTrace, Trace::TraceEventInfo) { + KJ_CASE_ONEOF(tracedTrace, tracing::TraceEventInfo) { return kj::Maybe(jsg::alloc(trace, tracedTrace)); } - KJ_CASE_ONEOF(hibWs, Trace::HibernatableWebSocketEventInfo) { + KJ_CASE_ONEOF(hibWs, tracing::HibernatableWebSocketEventInfo) { KJ_SWITCH_ONEOF(hibWs.type) { - KJ_CASE_ONEOF(message, Trace::HibernatableWebSocketEventInfo::Message) { + KJ_CASE_ONEOF(message, tracing::HibernatableWebSocketEventInfo::Message) { return kj::Maybe(jsg::alloc(trace, message)); } - KJ_CASE_ONEOF(close, Trace::HibernatableWebSocketEventInfo::Close) { + KJ_CASE_ONEOF(close, tracing::HibernatableWebSocketEventInfo::Close) { return kj::Maybe(jsg::alloc(trace, close)); } - KJ_CASE_ONEOF(error, Trace::HibernatableWebSocketEventInfo::Error) { + KJ_CASE_ONEOF(error, tracing::HibernatableWebSocketEventInfo::Error) { return kj::Maybe(jsg::alloc(trace, error)); } } KJ_UNREACHABLE; } - KJ_CASE_ONEOF(custom, Trace::CustomEventInfo) { + KJ_CASE_ONEOF(custom, tracing::CustomEventInfo) { return kj::Maybe(jsg::alloc(trace, custom)); } } @@ -304,13 +304,13 @@ uint TraceItem::getWallTime() { TraceItem::FetchEventInfo::FetchEventInfo(jsg::Lock& js, const Trace& trace, - const Trace::FetchEventInfo& eventInfo, - kj::Maybe responseInfo) + const tracing::FetchEventInfo& eventInfo, + kj::Maybe responseInfo) : request(jsg::alloc(js, trace, eventInfo)), response(responseInfo.map([&](auto& info) { return jsg::alloc(trace, info); })) {} TraceItem::FetchEventInfo::Request::Detail::Detail(jsg::Optional> cf, - kj::Array headers, + kj::Array headers, kj::String method, kj::String url) : cf(kj::mv(cf)), @@ -330,7 +330,7 @@ jsg::Optional> TraceItem::FetchEve } TraceItem::FetchEventInfo::Request::Request( - jsg::Lock& js, const Trace& trace, const Trace::FetchEventInfo& eventInfo) + jsg::Lock& js, const Trace& trace, const tracing::FetchEventInfo& eventInfo) : detail(getFetchRequestDetail(js, trace, eventInfo)) {} TraceItem::FetchEventInfo::Request::Request(Detail& detail, bool redacted) @@ -375,7 +375,7 @@ jsg::Ref TraceItem::FetchEventInfo::Request: } TraceItem::FetchEventInfo::Response::Response( - const Trace& trace, const Trace::FetchResponseInfo& responseInfo) + const Trace& trace, const tracing::FetchResponseInfo& responseInfo) : status(responseInfo.statusCode) {} uint16_t TraceItem::FetchEventInfo::Response::getStatus() { @@ -383,7 +383,7 @@ uint16_t TraceItem::FetchEventInfo::Response::getStatus() { } TraceItem::JsRpcEventInfo::JsRpcEventInfo( - const Trace& trace, const Trace::JsRpcEventInfo& eventInfo) + const Trace& trace, const tracing::JsRpcEventInfo& eventInfo) : rpcMethod(kj::str(eventInfo.methodName)) {} kj::StringPtr TraceItem::JsRpcEventInfo::getRpcMethod() { @@ -391,7 +391,7 @@ kj::StringPtr TraceItem::JsRpcEventInfo::getRpcMethod() { } TraceItem::ScheduledEventInfo::ScheduledEventInfo( - const Trace& trace, const Trace::ScheduledEventInfo& eventInfo) + const Trace& trace, const tracing::ScheduledEventInfo& eventInfo) : scheduledTime(eventInfo.scheduledTime), cron(kj::str(eventInfo.cron)) {} @@ -403,7 +403,7 @@ kj::StringPtr TraceItem::ScheduledEventInfo::getCron() { } TraceItem::AlarmEventInfo::AlarmEventInfo( - const Trace& trace, const Trace::AlarmEventInfo& eventInfo) + const Trace& trace, const tracing::AlarmEventInfo& eventInfo) : scheduledTime(eventInfo.scheduledTime) {} kj::Date TraceItem::AlarmEventInfo::getScheduledTime() { @@ -411,7 +411,7 @@ kj::Date TraceItem::AlarmEventInfo::getScheduledTime() { } TraceItem::QueueEventInfo::QueueEventInfo( - const Trace& trace, const Trace::QueueEventInfo& eventInfo) + const Trace& trace, const tracing::QueueEventInfo& eventInfo) : queueName(kj::str(eventInfo.queueName)), batchSize(eventInfo.batchSize) {} @@ -424,7 +424,7 @@ uint32_t TraceItem::QueueEventInfo::getBatchSize() { } TraceItem::EmailEventInfo::EmailEventInfo( - const Trace& trace, const Trace::EmailEventInfo& eventInfo) + const Trace& trace, const tracing::EmailEventInfo& eventInfo) : mailFrom(kj::str(eventInfo.mailFrom)), rcptTo(kj::str(eventInfo.rcptTo)), rawSize(eventInfo.rawSize) {} @@ -442,13 +442,14 @@ uint32_t TraceItem::EmailEventInfo::getRawSize() { } kj::Array> getConsumedEventsFromEventInfo( - const Trace::TraceEventInfo& eventInfo) { + const tracing::TraceEventInfo& eventInfo) { return KJ_MAP(t, eventInfo.traces) -> jsg::Ref { return jsg::alloc(t); }; } -TraceItem::TailEventInfo::TailEventInfo(const Trace& trace, const Trace::TraceEventInfo& eventInfo) +TraceItem::TailEventInfo::TailEventInfo( + const Trace& trace, const tracing::TraceEventInfo& eventInfo) : consumedEvents(getConsumedEventsFromEventInfo(eventInfo)) {} kj::Array> TraceItem::TailEventInfo:: @@ -458,7 +459,7 @@ kj::Array> TraceItem::TailEventInfo }; } -TraceItem::TailEventInfo::TailItem::TailItem(const Trace::TraceEventInfo::TraceItem& traceItem) +TraceItem::TailEventInfo::TailItem::TailItem(const tracing::TraceEventInfo::TraceItem& traceItem) : scriptName(traceItem.scriptName.map([](auto& s) { return kj::str(s); })) {} kj::Maybe TraceItem::TailEventInfo::TailItem::getScriptName() { @@ -466,7 +467,7 @@ kj::Maybe TraceItem::TailEventInfo::TailItem::getScriptName() { } TraceDiagnosticChannelEvent::TraceDiagnosticChannelEvent( - const Trace& trace, const Trace::DiagnosticChannelEvent& eventInfo) + const Trace& trace, const tracing::DiagnosticChannelEvent& eventInfo) : timestamp(getTraceDiagnosticChannelEventTimestamp(eventInfo)), channel(kj::heapString(eventInfo.channel)), message(kj::heapArray(eventInfo.message)) {} @@ -509,19 +510,19 @@ ScriptVersion::ScriptVersion(const ScriptVersion& other) message{other.message.map([](const auto& message) { return kj::str(message); })} {} TraceItem::CustomEventInfo::CustomEventInfo( - const Trace& trace, const Trace::CustomEventInfo& eventInfo) + const Trace& trace, const tracing::CustomEventInfo& eventInfo) : eventInfo(eventInfo) {} TraceItem::HibernatableWebSocketEventInfo::HibernatableWebSocketEventInfo( - const Trace& trace, const Trace::HibernatableWebSocketEventInfo::Message& eventInfo) + const Trace& trace, const tracing::HibernatableWebSocketEventInfo::Message& eventInfo) : eventType(jsg::alloc(trace, eventInfo)) {} TraceItem::HibernatableWebSocketEventInfo::HibernatableWebSocketEventInfo( - const Trace& trace, const Trace::HibernatableWebSocketEventInfo::Close& eventInfo) + const Trace& trace, const tracing::HibernatableWebSocketEventInfo::Close& eventInfo) : eventType(jsg::alloc(trace, eventInfo)) {} TraceItem::HibernatableWebSocketEventInfo::HibernatableWebSocketEventInfo( - const Trace& trace, const Trace::HibernatableWebSocketEventInfo::Error& eventInfo) + const Trace& trace, const tracing::HibernatableWebSocketEventInfo::Error& eventInfo) : eventType(jsg::alloc(trace, eventInfo)) {} TraceItem::HibernatableWebSocketEventInfo::Type TraceItem::HibernatableWebSocketEventInfo:: @@ -548,7 +549,7 @@ bool TraceItem::HibernatableWebSocketEventInfo::Close::getWasClean() { return eventInfo.wasClean; } -TraceLog::TraceLog(jsg::Lock& js, const Trace& trace, const Trace::Log& log) +TraceLog::TraceLog(jsg::Lock& js, const Trace& trace, const tracing::Log& log) : timestamp(getTraceLogTimestamp(log)), level(getTraceLogLevel(log)), message(getTraceLogMessage(js, log)) {} @@ -565,7 +566,7 @@ jsg::V8Ref TraceLog::getMessage(jsg::Lock& js) { return message.addRef(js); } -TraceException::TraceException(const Trace& trace, const Trace::Exception& exception) +TraceException::TraceException(const Trace& trace, const tracing::Exception& exception) : timestamp(getTraceExceptionTimestamp(exception)), name(kj::str(exception.name)), message(kj::str(exception.message)), @@ -604,7 +605,7 @@ kj::Promise sendTracesToExportedHandler(kj::OwngetMetrics(); KJ_IF_SOME(t, incomingRequest->getWorkerTracer()) { - t.setEventInfo(context.now(), Trace::TraceEventInfo(traces)); + t.setEventInfo(context.now(), tracing::TraceEventInfo(traces)); } auto nonEmptyTraces = kj::Vector>(kj::size(traces)); diff --git a/src/workerd/api/trace.h b/src/workerd/api/trace.h index 97fa550d9c8..b6a3e628be8 100644 --- a/src/workerd/api/trace.h +++ b/src/workerd/api/trace.h @@ -145,7 +145,7 @@ class TraceItem final: public jsg::Object { }; // When adding a new TraceItem eventInfo type, it is important not to -// try keeping a reference to the Trace and Trace::*EventInfo inputs. +// try keeping a reference to the Trace and tracing::*EventInfo inputs. // They are kj heap objects that have a lifespan that is managed independently // of the TraceItem object. Each of the implementations here extract the // necessary detail on creation and use LAZY instance properties to minimize @@ -168,8 +168,8 @@ class TraceItem::FetchEventInfo final: public jsg::Object { explicit FetchEventInfo(jsg::Lock& js, const Trace& trace, - const Trace::FetchEventInfo& eventInfo, - kj::Maybe responseInfo); + const tracing::FetchEventInfo& eventInfo, + kj::Maybe responseInfo); jsg::Ref getRequest(); jsg::Optional> getResponse(); @@ -191,12 +191,12 @@ class TraceItem::FetchEventInfo::Request final: public jsg::Object { public: struct Detail: public kj::Refcounted { jsg::Optional> cf; - kj::Array headers; + kj::Array headers; kj::String method; kj::String url; Detail(jsg::Optional> cf, - kj::Array headers, + kj::Array headers, kj::String method, kj::String url); @@ -210,7 +210,7 @@ class TraceItem::FetchEventInfo::Request final: public jsg::Object { } }; - explicit Request(jsg::Lock& js, const Trace& trace, const Trace::FetchEventInfo& eventInfo); + explicit Request(jsg::Lock& js, const Trace& trace, const tracing::FetchEventInfo& eventInfo); // Creates a possibly unredacted instance that shared a ref of the Detail explicit Request(Detail& detail, bool redacted = true); @@ -242,7 +242,7 @@ class TraceItem::FetchEventInfo::Request final: public jsg::Object { class TraceItem::FetchEventInfo::Response final: public jsg::Object { public: - explicit Response(const Trace& trace, const Trace::FetchResponseInfo& responseInfo); + explicit Response(const Trace& trace, const tracing::FetchResponseInfo& responseInfo); uint16_t getStatus(); @@ -256,7 +256,7 @@ class TraceItem::FetchEventInfo::Response final: public jsg::Object { class TraceItem::JsRpcEventInfo final: public jsg::Object { public: - explicit JsRpcEventInfo(const Trace& trace, const Trace::JsRpcEventInfo& eventInfo); + explicit JsRpcEventInfo(const Trace& trace, const tracing::JsRpcEventInfo& eventInfo); // We call this `rpcMethod` to make clear this is an RPC event, since some tail workers rely // on duck-typing EventInfo based on the properties present. (`methodName` might be ambiguous @@ -279,7 +279,7 @@ class TraceItem::JsRpcEventInfo final: public jsg::Object { class TraceItem::ScheduledEventInfo final: public jsg::Object { public: - explicit ScheduledEventInfo(const Trace& trace, const Trace::ScheduledEventInfo& eventInfo); + explicit ScheduledEventInfo(const Trace& trace, const tracing::ScheduledEventInfo& eventInfo); double getScheduledTime(); kj::StringPtr getCron(); @@ -300,7 +300,7 @@ class TraceItem::ScheduledEventInfo final: public jsg::Object { class TraceItem::AlarmEventInfo final: public jsg::Object { public: - explicit AlarmEventInfo(const Trace& trace, const Trace::AlarmEventInfo& eventInfo); + explicit AlarmEventInfo(const Trace& trace, const tracing::AlarmEventInfo& eventInfo); kj::Date getScheduledTime(); @@ -314,7 +314,7 @@ class TraceItem::AlarmEventInfo final: public jsg::Object { class TraceItem::QueueEventInfo final: public jsg::Object { public: - explicit QueueEventInfo(const Trace& trace, const Trace::QueueEventInfo& eventInfo); + explicit QueueEventInfo(const Trace& trace, const tracing::QueueEventInfo& eventInfo); kj::StringPtr getQueueName(); uint32_t getBatchSize(); @@ -336,7 +336,7 @@ class TraceItem::QueueEventInfo final: public jsg::Object { class TraceItem::EmailEventInfo final: public jsg::Object { public: - explicit EmailEventInfo(const Trace& trace, const Trace::EmailEventInfo& eventInfo); + explicit EmailEventInfo(const Trace& trace, const tracing::EmailEventInfo& eventInfo); kj::StringPtr getMailFrom(); kj::StringPtr getRcptTo(); @@ -363,7 +363,7 @@ class TraceItem::TailEventInfo final: public jsg::Object { public: class TailItem; - explicit TailEventInfo(const Trace& trace, const Trace::TraceEventInfo& eventInfo); + explicit TailEventInfo(const Trace& trace, const tracing::TraceEventInfo& eventInfo); kj::Array> getConsumedEvents(); @@ -379,7 +379,7 @@ class TraceItem::TailEventInfo final: public jsg::Object { class TraceItem::TailEventInfo::TailItem final: public jsg::Object { public: - explicit TailItem(const Trace::TraceEventInfo::TraceItem& traceItem); + explicit TailItem(const tracing::TraceEventInfo::TraceItem& traceItem); kj::Maybe getScriptName(); @@ -402,11 +402,11 @@ class TraceItem::HibernatableWebSocketEventInfo final: public jsg::Object { class Error; explicit HibernatableWebSocketEventInfo( - const Trace& trace, const Trace::HibernatableWebSocketEventInfo::Message& eventInfo); + const Trace& trace, const tracing::HibernatableWebSocketEventInfo::Message& eventInfo); explicit HibernatableWebSocketEventInfo( - const Trace& trace, const Trace::HibernatableWebSocketEventInfo::Close& eventInfo); + const Trace& trace, const tracing::HibernatableWebSocketEventInfo::Close& eventInfo); explicit HibernatableWebSocketEventInfo( - const Trace& trace, const Trace::HibernatableWebSocketEventInfo::Error& eventInfo); + const Trace& trace, const tracing::HibernatableWebSocketEventInfo::Error& eventInfo); using Type = kj::OneOf, jsg::Ref, jsg::Ref>; @@ -425,7 +425,7 @@ class TraceItem::HibernatableWebSocketEventInfo final: public jsg::Object { class TraceItem::HibernatableWebSocketEventInfo::Message final: public jsg::Object { public: explicit Message( - const Trace& trace, const Trace::HibernatableWebSocketEventInfo::Message& eventInfo) + const Trace& trace, const tracing::HibernatableWebSocketEventInfo::Message& eventInfo) : eventInfo(eventInfo) {} static constexpr kj::StringPtr webSocketEventType = "message"_kj; @@ -438,12 +438,13 @@ class TraceItem::HibernatableWebSocketEventInfo::Message final: public jsg::Obje } private: - const Trace::HibernatableWebSocketEventInfo::Message& eventInfo; + const tracing::HibernatableWebSocketEventInfo::Message& eventInfo; }; class TraceItem::HibernatableWebSocketEventInfo::Close final: public jsg::Object { public: - explicit Close(const Trace& trace, const Trace::HibernatableWebSocketEventInfo::Close& eventInfo) + explicit Close( + const Trace& trace, const tracing::HibernatableWebSocketEventInfo::Close& eventInfo) : eventInfo(eventInfo) {} static constexpr kj::StringPtr webSocketEventType = "close"_kj; @@ -461,12 +462,13 @@ class TraceItem::HibernatableWebSocketEventInfo::Close final: public jsg::Object } private: - const Trace::HibernatableWebSocketEventInfo::Close& eventInfo; + const tracing::HibernatableWebSocketEventInfo::Close& eventInfo; }; class TraceItem::HibernatableWebSocketEventInfo::Error final: public jsg::Object { public: - explicit Error(const Trace& trace, const Trace::HibernatableWebSocketEventInfo::Error& eventInfo) + explicit Error( + const Trace& trace, const tracing::HibernatableWebSocketEventInfo::Error& eventInfo) : eventInfo(eventInfo) {} static constexpr kj::StringPtr webSocketEventType = "error"_kj; @@ -479,23 +481,23 @@ class TraceItem::HibernatableWebSocketEventInfo::Error final: public jsg::Object } private: - const Trace::HibernatableWebSocketEventInfo::Error& eventInfo; + const tracing::HibernatableWebSocketEventInfo::Error& eventInfo; }; class TraceItem::CustomEventInfo final: public jsg::Object { public: - explicit CustomEventInfo(const Trace& trace, const Trace::CustomEventInfo& eventInfo); + explicit CustomEventInfo(const Trace& trace, const tracing::CustomEventInfo& eventInfo); JSG_RESOURCE_TYPE(CustomEventInfo) {} private: - const Trace::CustomEventInfo& eventInfo; + const tracing::CustomEventInfo& eventInfo; }; class TraceDiagnosticChannelEvent final: public jsg::Object { public: explicit TraceDiagnosticChannelEvent( - const Trace& trace, const Trace::DiagnosticChannelEvent& eventInfo); + const Trace& trace, const tracing::DiagnosticChannelEvent& eventInfo); double getTimestamp(); kj::StringPtr getChannel(); @@ -520,7 +522,7 @@ class TraceDiagnosticChannelEvent final: public jsg::Object { class TraceLog final: public jsg::Object { public: - TraceLog(jsg::Lock& js, const Trace& trace, const Trace::Log& log); + TraceLog(jsg::Lock& js, const Trace& trace, const tracing::Log& log); double getTimestamp(); kj::StringPtr getLevel(); @@ -545,7 +547,7 @@ class TraceLog final: public jsg::Object { class TraceException final: public jsg::Object { public: - TraceException(const Trace& trace, const Trace::Exception& exception); + TraceException(const Trace& trace, const tracing::Exception& exception); double getTimestamp(); kj::StringPtr getName(); diff --git a/src/workerd/api/worker-rpc.c++ b/src/workerd/api/worker-rpc.c++ index 8fe4612100a..d82068e5df8 100644 --- a/src/workerd/api/worker-rpc.c++ +++ b/src/workerd/api/worker-rpc.c++ @@ -1673,7 +1673,7 @@ class EntrypointJsRpcTarget final: public JsRpcTargetBase { void addTrace(jsg::Lock& js, IoContext& ioctx, kj::StringPtr methodName) override { KJ_IF_SOME(t, tracer) { - t->setEventInfo(ioctx.now(), Trace::JsRpcEventInfo(kj::str(methodName))); + t->setEventInfo(ioctx.now(), tracing::JsRpcEventInfo(kj::str(methodName))); } } }; diff --git a/src/workerd/io/trace.c++ b/src/workerd/io/trace.c++ index 731c1522090..e4153f06f80 100644 --- a/src/workerd/io/trace.c++ +++ b/src/workerd/io/trace.c++ @@ -242,14 +242,14 @@ static kj::HttpMethod validateMethod(capnp::HttpMethod method) { } // namespace -Trace::FetchEventInfo::FetchEventInfo( +tracing::FetchEventInfo::FetchEventInfo( kj::HttpMethod method, kj::String url, kj::String cfJson, kj::Array
headers) : method(method), url(kj::mv(url)), cfJson(kj::mv(cfJson)), headers(kj::mv(headers)) {} -Trace::FetchEventInfo::FetchEventInfo(rpc::Trace::FetchEventInfo::Reader reader) +tracing::FetchEventInfo::FetchEventInfo(rpc::Trace::FetchEventInfo::Reader reader) : method(validateMethod(reader.getMethod())), url(kj::str(reader.getUrl())), cfJson(kj::str(reader.getCfJson())) { @@ -258,7 +258,7 @@ Trace::FetchEventInfo::FetchEventInfo(rpc::Trace::FetchEventInfo::Reader reader) headers = v.releaseAsArray(); } -void Trace::FetchEventInfo::copyTo(rpc::Trace::FetchEventInfo::Builder builder) { +void tracing::FetchEventInfo::copyTo(rpc::Trace::FetchEventInfo::Builder builder) { builder.setMethod(static_cast(method)); builder.setUrl(url); builder.setCfJson(cfJson); @@ -269,145 +269,145 @@ void Trace::FetchEventInfo::copyTo(rpc::Trace::FetchEventInfo::Builder builder) } } -Trace::FetchEventInfo::Header::Header(kj::String name, kj::String value) +tracing::FetchEventInfo::Header::Header(kj::String name, kj::String value) : name(kj::mv(name)), value(kj::mv(value)) {} -Trace::FetchEventInfo::Header::Header(rpc::Trace::FetchEventInfo::Header::Reader reader) +tracing::FetchEventInfo::Header::Header(rpc::Trace::FetchEventInfo::Header::Reader reader) : name(kj::str(reader.getName())), value(kj::str(reader.getValue())) {} -void Trace::FetchEventInfo::Header::copyTo(rpc::Trace::FetchEventInfo::Header::Builder builder) { +void tracing::FetchEventInfo::Header::copyTo(rpc::Trace::FetchEventInfo::Header::Builder builder) { builder.setName(name); builder.setValue(value); } -Trace::JsRpcEventInfo::JsRpcEventInfo(kj::String methodName): methodName(kj::mv(methodName)) {} +tracing::JsRpcEventInfo::JsRpcEventInfo(kj::String methodName): methodName(kj::mv(methodName)) {} -Trace::JsRpcEventInfo::JsRpcEventInfo(rpc::Trace::JsRpcEventInfo::Reader reader) +tracing::JsRpcEventInfo::JsRpcEventInfo(rpc::Trace::JsRpcEventInfo::Reader reader) : methodName(kj::str(reader.getMethodName())) {} -void Trace::JsRpcEventInfo::copyTo(rpc::Trace::JsRpcEventInfo::Builder builder) { +void tracing::JsRpcEventInfo::copyTo(rpc::Trace::JsRpcEventInfo::Builder builder) { builder.setMethodName(methodName); } -Trace::ScheduledEventInfo::ScheduledEventInfo(double scheduledTime, kj::String cron) +tracing::ScheduledEventInfo::ScheduledEventInfo(double scheduledTime, kj::String cron) : scheduledTime(scheduledTime), cron(kj::mv(cron)) {} -Trace::ScheduledEventInfo::ScheduledEventInfo(rpc::Trace::ScheduledEventInfo::Reader reader) +tracing::ScheduledEventInfo::ScheduledEventInfo(rpc::Trace::ScheduledEventInfo::Reader reader) : scheduledTime(reader.getScheduledTime()), cron(kj::str(reader.getCron())) {} -void Trace::ScheduledEventInfo::copyTo(rpc::Trace::ScheduledEventInfo::Builder builder) { +void tracing::ScheduledEventInfo::copyTo(rpc::Trace::ScheduledEventInfo::Builder builder) { builder.setScheduledTime(scheduledTime); builder.setCron(cron); } -Trace::AlarmEventInfo::AlarmEventInfo(kj::Date scheduledTime): scheduledTime(scheduledTime) {} +tracing::AlarmEventInfo::AlarmEventInfo(kj::Date scheduledTime): scheduledTime(scheduledTime) {} -Trace::AlarmEventInfo::AlarmEventInfo(rpc::Trace::AlarmEventInfo::Reader reader) +tracing::AlarmEventInfo::AlarmEventInfo(rpc::Trace::AlarmEventInfo::Reader reader) : scheduledTime(reader.getScheduledTimeMs() * kj::MILLISECONDS + kj::UNIX_EPOCH) {} -void Trace::AlarmEventInfo::copyTo(rpc::Trace::AlarmEventInfo::Builder builder) { +void tracing::AlarmEventInfo::copyTo(rpc::Trace::AlarmEventInfo::Builder builder) { builder.setScheduledTimeMs((scheduledTime - kj::UNIX_EPOCH) / kj::MILLISECONDS); } -Trace::QueueEventInfo::QueueEventInfo(kj::String queueName, uint32_t batchSize) +tracing::QueueEventInfo::QueueEventInfo(kj::String queueName, uint32_t batchSize) : queueName(kj::mv(queueName)), batchSize(batchSize) {} -Trace::QueueEventInfo::QueueEventInfo(rpc::Trace::QueueEventInfo::Reader reader) +tracing::QueueEventInfo::QueueEventInfo(rpc::Trace::QueueEventInfo::Reader reader) : queueName(kj::heapString(reader.getQueueName())), batchSize(reader.getBatchSize()) {} -void Trace::QueueEventInfo::copyTo(rpc::Trace::QueueEventInfo::Builder builder) { +void tracing::QueueEventInfo::copyTo(rpc::Trace::QueueEventInfo::Builder builder) { builder.setQueueName(queueName); builder.setBatchSize(batchSize); } -Trace::EmailEventInfo::EmailEventInfo(kj::String mailFrom, kj::String rcptTo, uint32_t rawSize) +tracing::EmailEventInfo::EmailEventInfo(kj::String mailFrom, kj::String rcptTo, uint32_t rawSize) : mailFrom(kj::mv(mailFrom)), rcptTo(kj::mv(rcptTo)), rawSize(rawSize) {} -Trace::EmailEventInfo::EmailEventInfo(rpc::Trace::EmailEventInfo::Reader reader) +tracing::EmailEventInfo::EmailEventInfo(rpc::Trace::EmailEventInfo::Reader reader) : mailFrom(kj::heapString(reader.getMailFrom())), rcptTo(kj::heapString(reader.getRcptTo())), rawSize(reader.getRawSize()) {} -void Trace::EmailEventInfo::copyTo(rpc::Trace::EmailEventInfo::Builder builder) { +void tracing::EmailEventInfo::copyTo(rpc::Trace::EmailEventInfo::Builder builder) { builder.setMailFrom(mailFrom); builder.setRcptTo(rcptTo); builder.setRawSize(rawSize); } -kj::Vector getTraceItemsFromTraces( +kj::Vector getTraceItemsFromTraces( kj::ArrayPtr> traces) { - return KJ_MAP(t, traces) -> Trace::TraceEventInfo::TraceItem { - return Trace::TraceEventInfo::TraceItem( + return KJ_MAP(t, traces) -> tracing::TraceEventInfo::TraceItem { + return tracing::TraceEventInfo::TraceItem( t->scriptName.map([](auto& scriptName) { return kj::str(scriptName); })); }; } -Trace::TraceEventInfo::TraceEventInfo(kj::ArrayPtr> traces) +tracing::TraceEventInfo::TraceEventInfo(kj::ArrayPtr> traces) : traces(getTraceItemsFromTraces(traces)) {} -kj::Vector getTraceItemsFromReader( +kj::Vector getTraceItemsFromReader( rpc::Trace::TraceEventInfo::Reader reader) { - return KJ_MAP(r, reader.getTraces()) -> Trace::TraceEventInfo::TraceItem { - return Trace::TraceEventInfo::TraceItem(r); + return KJ_MAP(r, reader.getTraces()) -> tracing::TraceEventInfo::TraceItem { + return tracing::TraceEventInfo::TraceItem(r); }; } -Trace::TraceEventInfo::TraceEventInfo(rpc::Trace::TraceEventInfo::Reader reader) +tracing::TraceEventInfo::TraceEventInfo(rpc::Trace::TraceEventInfo::Reader reader) : traces(getTraceItemsFromReader(reader)) {} -void Trace::TraceEventInfo::copyTo(rpc::Trace::TraceEventInfo::Builder builder) { +void tracing::TraceEventInfo::copyTo(rpc::Trace::TraceEventInfo::Builder builder) { auto list = builder.initTraces(traces.size()); for (auto i: kj::indices(traces)) { traces[i].copyTo(list[i]); } } -Trace::TraceEventInfo::TraceItem::TraceItem(kj::Maybe scriptName) +tracing::TraceEventInfo::TraceItem::TraceItem(kj::Maybe scriptName) : scriptName(kj::mv(scriptName)) {} -Trace::TraceEventInfo::TraceItem::TraceItem(rpc::Trace::TraceEventInfo::TraceItem::Reader reader) +tracing::TraceEventInfo::TraceItem::TraceItem(rpc::Trace::TraceEventInfo::TraceItem::Reader reader) : scriptName(kj::str(reader.getScriptName())) {} -void Trace::TraceEventInfo::TraceItem::copyTo( +void tracing::TraceEventInfo::TraceItem::copyTo( rpc::Trace::TraceEventInfo::TraceItem::Builder builder) { KJ_IF_SOME(name, scriptName) { builder.setScriptName(name); } } -Trace::DiagnosticChannelEvent::DiagnosticChannelEvent( +tracing::DiagnosticChannelEvent::DiagnosticChannelEvent( kj::Date timestamp, kj::String channel, kj::Array message) : timestamp(timestamp), channel(kj::mv(channel)), message(kj::mv(message)) {} -Trace::DiagnosticChannelEvent::DiagnosticChannelEvent( +tracing::DiagnosticChannelEvent::DiagnosticChannelEvent( rpc::Trace::DiagnosticChannelEvent::Reader reader) : timestamp(kj::UNIX_EPOCH + reader.getTimestampNs() * kj::NANOSECONDS), channel(kj::heapString(reader.getChannel())), message(kj::heapArray(reader.getMessage())) {} -void Trace::DiagnosticChannelEvent::copyTo(rpc::Trace::DiagnosticChannelEvent::Builder builder) { +void tracing::DiagnosticChannelEvent::copyTo(rpc::Trace::DiagnosticChannelEvent::Builder builder) { builder.setTimestampNs((timestamp - kj::UNIX_EPOCH) / kj::NANOSECONDS); builder.setChannel(channel); builder.setMessage(message); } -Trace::HibernatableWebSocketEventInfo::HibernatableWebSocketEventInfo(Type type): type(type) {} +tracing::HibernatableWebSocketEventInfo::HibernatableWebSocketEventInfo(Type type): type(type) {} -Trace::HibernatableWebSocketEventInfo::HibernatableWebSocketEventInfo( +tracing::HibernatableWebSocketEventInfo::HibernatableWebSocketEventInfo( rpc::Trace::HibernatableWebSocketEventInfo::Reader reader) : type(readFrom(reader)) {} -void Trace::HibernatableWebSocketEventInfo::copyTo( +void tracing::HibernatableWebSocketEventInfo::copyTo( rpc::Trace::HibernatableWebSocketEventInfo::Builder builder) { auto typeBuilder = builder.initType(); KJ_SWITCH_ONEOF(type) { @@ -425,7 +425,7 @@ void Trace::HibernatableWebSocketEventInfo::copyTo( } } -Trace::HibernatableWebSocketEventInfo::Type Trace::HibernatableWebSocketEventInfo::readFrom( +tracing::HibernatableWebSocketEventInfo::Type tracing::HibernatableWebSocketEventInfo::readFrom( rpc::Trace::HibernatableWebSocketEventInfo::Reader reader) { auto type = reader.getType(); switch (type.which()) { @@ -445,21 +445,21 @@ Trace::HibernatableWebSocketEventInfo::Type Trace::HibernatableWebSocketEventInf } } -Trace::FetchResponseInfo::FetchResponseInfo(uint16_t statusCode): statusCode(statusCode) {} +tracing::FetchResponseInfo::FetchResponseInfo(uint16_t statusCode): statusCode(statusCode) {} -Trace::FetchResponseInfo::FetchResponseInfo(rpc::Trace::FetchResponseInfo::Reader reader) +tracing::FetchResponseInfo::FetchResponseInfo(rpc::Trace::FetchResponseInfo::Reader reader) : statusCode(reader.getStatusCode()) {} -void Trace::FetchResponseInfo::copyTo(rpc::Trace::FetchResponseInfo::Builder builder) { +void tracing::FetchResponseInfo::copyTo(rpc::Trace::FetchResponseInfo::Builder builder) { builder.setStatusCode(statusCode); } -Trace::Log::Log(kj::Date timestamp, LogLevel logLevel, kj::String message) +tracing::Log::Log(kj::Date timestamp, LogLevel logLevel, kj::String message) : timestamp(timestamp), logLevel(logLevel), message(kj::mv(message)) {} -Trace::Exception::Exception( +tracing::Exception::Exception( kj::Date timestamp, kj::String name, kj::String message, kj::Maybe stack) : timestamp(timestamp), name(kj::mv(name)), @@ -541,39 +541,39 @@ void Trace::copyTo(rpc::Trace::Builder builder) { auto eventInfoBuilder = builder.initEventInfo(); KJ_IF_SOME(e, eventInfo) { KJ_SWITCH_ONEOF(e) { - KJ_CASE_ONEOF(fetch, FetchEventInfo) { + KJ_CASE_ONEOF(fetch, tracing::FetchEventInfo) { auto fetchBuilder = eventInfoBuilder.initFetch(); fetch.copyTo(fetchBuilder); } - KJ_CASE_ONEOF(jsRpc, JsRpcEventInfo) { + KJ_CASE_ONEOF(jsRpc, tracing::JsRpcEventInfo) { auto jsRpcBuilder = eventInfoBuilder.initJsRpc(); jsRpc.copyTo(jsRpcBuilder); } - KJ_CASE_ONEOF(scheduled, ScheduledEventInfo) { + KJ_CASE_ONEOF(scheduled, tracing::ScheduledEventInfo) { auto scheduledBuilder = eventInfoBuilder.initScheduled(); scheduled.copyTo(scheduledBuilder); } - KJ_CASE_ONEOF(alarm, AlarmEventInfo) { + KJ_CASE_ONEOF(alarm, tracing::AlarmEventInfo) { auto alarmBuilder = eventInfoBuilder.initAlarm(); alarm.copyTo(alarmBuilder); } - KJ_CASE_ONEOF(queue, QueueEventInfo) { + KJ_CASE_ONEOF(queue, tracing::QueueEventInfo) { auto queueBuilder = eventInfoBuilder.initQueue(); queue.copyTo(queueBuilder); } - KJ_CASE_ONEOF(email, EmailEventInfo) { + KJ_CASE_ONEOF(email, tracing::EmailEventInfo) { auto emailBuilder = eventInfoBuilder.initEmail(); email.copyTo(emailBuilder); } - KJ_CASE_ONEOF(trace, TraceEventInfo) { + KJ_CASE_ONEOF(trace, tracing::TraceEventInfo) { auto traceBuilder = eventInfoBuilder.initTrace(); trace.copyTo(traceBuilder); } - KJ_CASE_ONEOF(hibWs, HibernatableWebSocketEventInfo) { + KJ_CASE_ONEOF(hibWs, tracing::HibernatableWebSocketEventInfo) { auto hibWsBuilder = eventInfoBuilder.initHibernatableWebSocket(); hibWs.copyTo(hibWsBuilder); } - KJ_CASE_ONEOF(custom, CustomEventInfo) { + KJ_CASE_ONEOF(custom, tracing::CustomEventInfo) { eventInfoBuilder.initCustom(); } } @@ -594,13 +594,13 @@ void Trace::copyTo(rpc::Trace::Builder builder) { } } -void Trace::Log::copyTo(rpc::Trace::Log::Builder builder) { +void tracing::Log::copyTo(rpc::Trace::Log::Builder builder) { builder.setTimestampNs((timestamp - kj::UNIX_EPOCH) / kj::NANOSECONDS); builder.setLogLevel(logLevel); builder.setMessage(message); } -void Trace::Exception::copyTo(rpc::Trace::Exception::Builder builder) { +void tracing::Exception::copyTo(rpc::Trace::Exception::Builder builder) { builder.setTimestampNs((timestamp - kj::UNIX_EPOCH) / kj::NANOSECONDS); builder.setName(name); builder.setMessage(message); @@ -661,31 +661,31 @@ void Trace::mergeFrom(rpc::Trace::Reader reader, PipelineLogLevel pipelineLogLev auto e = reader.getEventInfo(); switch (e.which()) { case rpc::Trace::EventInfo::Which::FETCH: - eventInfo = FetchEventInfo(e.getFetch()); + eventInfo = tracing::FetchEventInfo(e.getFetch()); break; case rpc::Trace::EventInfo::Which::JS_RPC: - eventInfo = JsRpcEventInfo(e.getJsRpc()); + eventInfo = tracing::JsRpcEventInfo(e.getJsRpc()); break; case rpc::Trace::EventInfo::Which::SCHEDULED: - eventInfo = ScheduledEventInfo(e.getScheduled()); + eventInfo = tracing::ScheduledEventInfo(e.getScheduled()); break; case rpc::Trace::EventInfo::Which::ALARM: - eventInfo = AlarmEventInfo(e.getAlarm()); + eventInfo = tracing::AlarmEventInfo(e.getAlarm()); break; case rpc::Trace::EventInfo::Which::QUEUE: - eventInfo = QueueEventInfo(e.getQueue()); + eventInfo = tracing::QueueEventInfo(e.getQueue()); break; case rpc::Trace::EventInfo::Which::EMAIL: - eventInfo = EmailEventInfo(e.getEmail()); + eventInfo = tracing::EmailEventInfo(e.getEmail()); break; case rpc::Trace::EventInfo::Which::TRACE: - eventInfo = TraceEventInfo(e.getTrace()); + eventInfo = tracing::TraceEventInfo(e.getTrace()); break; case rpc::Trace::EventInfo::Which::HIBERNATABLE_WEB_SOCKET: - eventInfo = HibernatableWebSocketEventInfo(e.getHibernatableWebSocket()); + eventInfo = tracing::HibernatableWebSocketEventInfo(e.getHibernatableWebSocket()); break; case rpc::Trace::EventInfo::Which::CUSTOM: - eventInfo = CustomEventInfo(e.getCustom()); + eventInfo = tracing::CustomEventInfo(e.getCustom()); break; case rpc::Trace::EventInfo::Which::NONE: eventInfo = kj::none; @@ -694,15 +694,15 @@ void Trace::mergeFrom(rpc::Trace::Reader reader, PipelineLogLevel pipelineLogLev } if (reader.hasResponse()) { - fetchResponseInfo = FetchResponseInfo(reader.getResponse()); + fetchResponseInfo = tracing::FetchResponseInfo(reader.getResponse()); } } -Trace::Log::Log(rpc::Trace::Log::Reader reader) +tracing::Log::Log(rpc::Trace::Log::Reader reader) : timestamp(kj::UNIX_EPOCH + reader.getTimestampNs() * kj::NANOSECONDS), logLevel(reader.getLogLevel()), message(kj::str(reader.getMessage())) {} -Trace::Exception::Exception(rpc::Trace::Exception::Reader reader) +tracing::Exception::Exception(rpc::Trace::Exception::Reader reader) : timestamp(kj::UNIX_EPOCH + reader.getTimestampNs() * kj::NANOSECONDS), name(kj::str(reader.getName())), message(kj::str(reader.getMessage())) { @@ -827,7 +827,7 @@ void WorkerTracer::log(kj::Date timestamp, LogLevel logLevel, kj::String message if (pipelineLogLevel == PipelineLogLevel::NONE) { return; } - size_t newSize = trace->bytesUsed + sizeof(Trace::Log) + message.size(); + size_t newSize = trace->bytesUsed + sizeof(tracing::Log) + message.size(); if (newSize > MAX_TRACE_BYTES) { trace->exceededLogLimit = true; trace->truncated = true; @@ -900,7 +900,7 @@ void WorkerTracer::addException( if (pipelineLogLevel == PipelineLogLevel::NONE) { return; } - size_t newSize = trace->bytesUsed + sizeof(Trace::Exception) + name.size() + message.size(); + size_t newSize = trace->bytesUsed + sizeof(tracing::Exception) + name.size() + message.size(); KJ_IF_SOME(s, stack) { newSize += s.size(); } @@ -924,7 +924,7 @@ void WorkerTracer::addDiagnosticChannelEvent( return; } size_t newSize = - trace->bytesUsed + sizeof(Trace::DiagnosticChannelEvent) + channel.size() + message.size(); + trace->bytesUsed + sizeof(tracing::DiagnosticChannelEvent) + channel.size() + message.size(); if (newSize > MAX_TRACE_BYTES) { trace->exceededDiagnosticChannelEventLimit = true; trace->truncated = true; @@ -936,7 +936,7 @@ void WorkerTracer::addDiagnosticChannelEvent( trace->diagnosticChannelEvents.add(timestamp, kj::mv(channel), kj::mv(message)); } -void WorkerTracer::setEventInfo(kj::Date timestamp, Trace::EventInfo&& info) { +void WorkerTracer::setEventInfo(kj::Date timestamp, tracing::EventInfo&& info) { KJ_ASSERT(trace->eventInfo == kj::none, "tracer can only be used for a single event"); // TODO(someday): For now, we're using logLevel == none as a hint to avoid doing anything @@ -952,7 +952,7 @@ void WorkerTracer::setEventInfo(kj::Date timestamp, Trace::EventInfo&& info) { size_t newSize = trace->bytesUsed; KJ_SWITCH_ONEOF(info) { - KJ_CASE_ONEOF(fetch, Trace::FetchEventInfo) { + KJ_CASE_ONEOF(fetch, tracing::FetchEventInfo) { newSize += fetch.url.size(); for (const auto& header: fetch.headers) { newSize += header.name.size() + header.value.size(); @@ -962,18 +962,11 @@ void WorkerTracer::setEventInfo(kj::Date timestamp, Trace::EventInfo&& info) { trace->truncated = true; trace->logs.add(timestamp, LogLevel::WARN, kj::str("[\"Trace resource limit exceeded; could not capture event info.\"]")); - trace->eventInfo = Trace::FetchEventInfo(fetch.method, {}, {}, {}); + trace->eventInfo = tracing::FetchEventInfo(fetch.method, {}, {}, {}); return; } } - KJ_CASE_ONEOF(_, Trace::JsRpcEventInfo) {} - KJ_CASE_ONEOF(_, Trace::ScheduledEventInfo) {} - KJ_CASE_ONEOF(_, Trace::AlarmEventInfo) {} - KJ_CASE_ONEOF(_, Trace::QueueEventInfo) {} - KJ_CASE_ONEOF(_, Trace::EmailEventInfo) {} - KJ_CASE_ONEOF(_, Trace::TraceEventInfo) {} - KJ_CASE_ONEOF(_, Trace::HibernatableWebSocketEventInfo) {} - KJ_CASE_ONEOF(_, Trace::CustomEventInfo) {} + KJ_CASE_ONEOF_DEFAULT {} } trace->bytesUsed = newSize; trace->eventInfo = kj::mv(info); @@ -991,7 +984,7 @@ void WorkerTracer::setWallTime(kj::Duration wallTime) { trace->wallTime = wallTime; } -void WorkerTracer::setFetchResponseInfo(Trace::FetchResponseInfo&& info) { +void WorkerTracer::setFetchResponseInfo(tracing::FetchResponseInfo&& info) { // Match the behavior of setEventInfo(). Any resolution of the TODO comments // in setEventInfo() that are related to this check while probably also affect // this function. @@ -999,7 +992,7 @@ void WorkerTracer::setFetchResponseInfo(Trace::FetchResponseInfo&& info) { return; } - KJ_REQUIRE(KJ_REQUIRE_NONNULL(trace->eventInfo).is()); + KJ_REQUIRE(KJ_REQUIRE_NONNULL(trace->eventInfo).is()); KJ_ASSERT(trace->fetchResponseInfo == kj::none, "setFetchResponseInfo can only be called once"); trace->fetchResponseInfo = kj::mv(info); } diff --git a/src/workerd/io/trace.h b/src/workerd/io/trace.h index 3912915867c..880e9851dbc 100644 --- a/src/workerd/io/trace.h +++ b/src/workerd/io/trace.h @@ -31,6 +31,8 @@ using kj::uint; typedef rpc::Trace::Log::Level LogLevel; typedef rpc::Trace::ExecutionModel ExecutionModel; +class Trace; + namespace tracing { // A 128-bit globally unique trace identifier. This will be used for both // external and internal tracing. Specifically, for internal tracing, this @@ -219,242 +221,274 @@ class InvocationSpanContext final: public kj::Refcounted, kj::String KJ_STRINGIFY(const TraceId& id); kj::String KJ_STRINGIFY(const kj::Rc& context); -} // namespace tracing -enum class PipelineLogLevel { - // WARNING: This must be kept in sync with PipelineDef::LogLevel (which is not in the OSS - // release). - NONE, - FULL -}; +class FetchEventInfo final { + public: + class Header; -struct Span; + explicit FetchEventInfo( + kj::HttpMethod method, kj::String url, kj::String cfJson, kj::Array
headers); + FetchEventInfo(rpc::Trace::FetchEventInfo::Reader reader); -// TODO(someday): See if we can merge similar code concepts... Trace fills a role similar to -// MetricsCollector::Reporter::StageEvent, and Tracer fills a role similar to -// MetricsCollector::Request. Currently, the major differences are: -// -// - MetricsCollector::Request uses its destructor to measure a IoContext's wall time, so -// it needs to live exactly as long as its IoContext. Tracer currently needs to live as -// long as both the IoContext and those of any subrequests. -// - Due to the difference in lifetimes, results of each become available in a different order, -// and intermediate values can be freed at different times. -// - Request builds a vector of results, while Tracer builds a tree. + class Header final { + public: + explicit Header(kj::String name, kj::String value); + Header(rpc::Trace::FetchEventInfo::Header::Reader reader); -// TODO(cleanup) - worth separating into immutable Trace vs. mutable TraceBuilder? + kj::String name; + kj::String value; -// Collects trace information about the handling of a worker/pipeline fetch event. -class Trace final: public kj::Refcounted { - public: - explicit Trace(kj::Maybe stableId, - kj::Maybe scriptName, - kj::Maybe> scriptVersion, - kj::Maybe dispatchNamespace, - kj::Maybe scriptId, - kj::Array scriptTags, - kj::Maybe entrypoint, - ExecutionModel executionModel); - Trace(rpc::Trace::Reader reader); - ~Trace() noexcept(false); - KJ_DISALLOW_COPY_AND_MOVE(Trace); + void copyTo(rpc::Trace::FetchEventInfo::Header::Builder builder); - class FetchEventInfo { - public: - class Header; + JSG_MEMORY_INFO(Header) { + tracker.trackField("name", name); + tracker.trackField("value", value); + } + }; - explicit FetchEventInfo( - kj::HttpMethod method, kj::String url, kj::String cfJson, kj::Array
headers); - FetchEventInfo(rpc::Trace::FetchEventInfo::Reader reader); + kj::HttpMethod method; + kj::String url; + // TODO(perf): It might be more efficient to store some sort of parsed JSON result instead? + kj::String cfJson; + kj::Array
headers; - class Header { - public: - explicit Header(kj::String name, kj::String value); - Header(rpc::Trace::FetchEventInfo::Header::Reader reader); + void copyTo(rpc::Trace::FetchEventInfo::Builder builder); +}; - kj::String name; - kj::String value; +class JsRpcEventInfo final { + public: + explicit JsRpcEventInfo(kj::String methodName); + JsRpcEventInfo(rpc::Trace::JsRpcEventInfo::Reader reader); - void copyTo(rpc::Trace::FetchEventInfo::Header::Builder builder); + kj::String methodName; - JSG_MEMORY_INFO(Header) { - tracker.trackField("name", name); - tracker.trackField("value", value); - } - }; + void copyTo(rpc::Trace::JsRpcEventInfo::Builder builder); +}; - kj::HttpMethod method; - kj::String url; - // TODO(perf): It might be more efficient to store some sort of parsed JSON result instead? - kj::String cfJson; - kj::Array
headers; +class ScheduledEventInfo final { + public: + explicit ScheduledEventInfo(double scheduledTime, kj::String cron); + ScheduledEventInfo(rpc::Trace::ScheduledEventInfo::Reader reader); - void copyTo(rpc::Trace::FetchEventInfo::Builder builder); - }; + double scheduledTime; + kj::String cron; - class JsRpcEventInfo { - public: - explicit JsRpcEventInfo(kj::String methodName); - JsRpcEventInfo(rpc::Trace::JsRpcEventInfo::Reader reader); + void copyTo(rpc::Trace::ScheduledEventInfo::Builder builder); +}; - kj::String methodName; +class AlarmEventInfo final { + public: + explicit AlarmEventInfo(kj::Date scheduledTime); + AlarmEventInfo(rpc::Trace::AlarmEventInfo::Reader reader); - void copyTo(rpc::Trace::JsRpcEventInfo::Builder builder); - }; + kj::Date scheduledTime; - class ScheduledEventInfo { - public: - explicit ScheduledEventInfo(double scheduledTime, kj::String cron); - ScheduledEventInfo(rpc::Trace::ScheduledEventInfo::Reader reader); + void copyTo(rpc::Trace::AlarmEventInfo::Builder builder); +}; - double scheduledTime; - kj::String cron; +class QueueEventInfo final { + public: + explicit QueueEventInfo(kj::String queueName, uint32_t batchSize); + QueueEventInfo(rpc::Trace::QueueEventInfo::Reader reader); - void copyTo(rpc::Trace::ScheduledEventInfo::Builder builder); - }; + kj::String queueName; + uint32_t batchSize; - class AlarmEventInfo { - public: - explicit AlarmEventInfo(kj::Date scheduledTime); - AlarmEventInfo(rpc::Trace::AlarmEventInfo::Reader reader); + void copyTo(rpc::Trace::QueueEventInfo::Builder builder); +}; + +class EmailEventInfo final { + public: + explicit EmailEventInfo(kj::String mailFrom, kj::String rcptTo, uint32_t rawSize); + EmailEventInfo(rpc::Trace::EmailEventInfo::Reader reader); - kj::Date scheduledTime; + kj::String mailFrom; + kj::String rcptTo; + uint32_t rawSize; - void copyTo(rpc::Trace::AlarmEventInfo::Builder builder); - }; + void copyTo(rpc::Trace::EmailEventInfo::Builder builder); +}; + +class TraceEventInfo final { + public: + class TraceItem; + + explicit TraceEventInfo(kj::ArrayPtr> traces); + TraceEventInfo(rpc::Trace::TraceEventInfo::Reader reader); - class QueueEventInfo { + class TraceItem final { public: - explicit QueueEventInfo(kj::String queueName, uint32_t batchSize); - QueueEventInfo(rpc::Trace::QueueEventInfo::Reader reader); + explicit TraceItem(kj::Maybe scriptName); + TraceItem(rpc::Trace::TraceEventInfo::TraceItem::Reader reader); - kj::String queueName; - uint32_t batchSize; + kj::Maybe scriptName; - void copyTo(rpc::Trace::QueueEventInfo::Builder builder); + void copyTo(rpc::Trace::TraceEventInfo::TraceItem::Builder builder); }; - class EmailEventInfo { - public: - explicit EmailEventInfo(kj::String mailFrom, kj::String rcptTo, uint32_t rawSize); - EmailEventInfo(rpc::Trace::EmailEventInfo::Reader reader); + kj::Vector traces; - kj::String mailFrom; - kj::String rcptTo; - uint32_t rawSize; + void copyTo(rpc::Trace::TraceEventInfo::Builder builder); +}; - void copyTo(rpc::Trace::EmailEventInfo::Builder builder); +class HibernatableWebSocketEventInfo final { + public: + struct Message {}; + struct Close { + uint16_t code; + bool wasClean; }; + struct Error {}; - class TraceEventInfo { - public: - class TraceItem; + using Type = kj::OneOf; - explicit TraceEventInfo(kj::ArrayPtr> traces); - TraceEventInfo(rpc::Trace::TraceEventInfo::Reader reader); + explicit HibernatableWebSocketEventInfo(Type type); + HibernatableWebSocketEventInfo(rpc::Trace::HibernatableWebSocketEventInfo::Reader reader); - class TraceItem { - public: - explicit TraceItem(kj::Maybe scriptName); - TraceItem(rpc::Trace::TraceEventInfo::TraceItem::Reader reader); + Type type; - kj::Maybe scriptName; + void copyTo(rpc::Trace::HibernatableWebSocketEventInfo::Builder builder); + static Type readFrom(rpc::Trace::HibernatableWebSocketEventInfo::Reader reader); +}; - void copyTo(rpc::Trace::TraceEventInfo::TraceItem::Builder builder); - }; +class CustomEventInfo final { + public: + explicit CustomEventInfo() {}; + CustomEventInfo(rpc::Trace::CustomEventInfo::Reader reader) {}; +}; - kj::Vector traces; +class FetchResponseInfo final { + public: + explicit FetchResponseInfo(uint16_t statusCode); + FetchResponseInfo(rpc::Trace::FetchResponseInfo::Reader reader); - void copyTo(rpc::Trace::TraceEventInfo::Builder builder); - }; + uint16_t statusCode; - class HibernatableWebSocketEventInfo { - public: - struct Message {}; - struct Close { - uint16_t code; - bool wasClean; - }; - struct Error {}; + void copyTo(rpc::Trace::FetchResponseInfo::Builder builder); +}; - using Type = kj::OneOf; +class DiagnosticChannelEvent final { + public: + explicit DiagnosticChannelEvent( + kj::Date timestamp, kj::String channel, kj::Array message); + DiagnosticChannelEvent(rpc::Trace::DiagnosticChannelEvent::Reader reader); + DiagnosticChannelEvent(DiagnosticChannelEvent&&) = default; + KJ_DISALLOW_COPY(DiagnosticChannelEvent); - explicit HibernatableWebSocketEventInfo(Type type); - HibernatableWebSocketEventInfo(rpc::Trace::HibernatableWebSocketEventInfo::Reader reader); + kj::Date timestamp; + kj::String channel; + kj::Array message; - Type type; + void copyTo(rpc::Trace::DiagnosticChannelEvent::Builder builder); +}; - void copyTo(rpc::Trace::HibernatableWebSocketEventInfo::Builder builder); - static Type readFrom(rpc::Trace::HibernatableWebSocketEventInfo::Reader reader); - }; +class Log final { + public: + explicit Log(kj::Date timestamp, LogLevel logLevel, kj::String message); + Log(rpc::Trace::Log::Reader reader); + Log(Log&&) = default; + KJ_DISALLOW_COPY(Log); + ~Log() noexcept(false) = default; - class CustomEventInfo { - public: - explicit CustomEventInfo() {}; - CustomEventInfo(rpc::Trace::CustomEventInfo::Reader reader) {}; - }; + // Only as accurate as Worker's Date.now(), for Spectre mitigation. + kj::Date timestamp; - class FetchResponseInfo { - public: - explicit FetchResponseInfo(uint16_t statusCode); - FetchResponseInfo(rpc::Trace::FetchResponseInfo::Reader reader); + LogLevel logLevel; + // TODO(soon): Just string for now. Eventually, capture serialized JS objects. + kj::String message; - uint16_t statusCode; + void copyTo(rpc::Trace::Log::Builder builder); +}; - void copyTo(rpc::Trace::FetchResponseInfo::Builder builder); - }; +class Exception final { + public: + explicit Exception( + kj::Date timestamp, kj::String name, kj::String message, kj::Maybe stack); + Exception(rpc::Trace::Exception::Reader reader); + Exception(Exception&&) = default; + KJ_DISALLOW_COPY(Exception); + ~Exception() noexcept(false) = default; - class DiagnosticChannelEvent { - public: - explicit DiagnosticChannelEvent( - kj::Date timestamp, kj::String channel, kj::Array message); - DiagnosticChannelEvent(rpc::Trace::DiagnosticChannelEvent::Reader reader); - DiagnosticChannelEvent(DiagnosticChannelEvent&&) = default; - KJ_DISALLOW_COPY(DiagnosticChannelEvent); + // Only as accurate as Worker's Date.now(), for Spectre mitigation. + kj::Date timestamp; - kj::Date timestamp; - kj::String channel; - kj::Array message; + kj::String name; + kj::String message; - void copyTo(rpc::Trace::DiagnosticChannelEvent::Builder builder); - }; + kj::Maybe stack; - class Log { - public: - explicit Log(kj::Date timestamp, LogLevel logLevel, kj::String message); - Log(rpc::Trace::Log::Reader reader); - Log(Log&&) = default; - KJ_DISALLOW_COPY(Log); - ~Log() noexcept(false) = default; + void copyTo(rpc::Trace::Exception::Builder builder); +}; - // Only as accurate as Worker's Date.now(), for Spectre mitigation. - kj::Date timestamp; +// EventInfo types are used to describe the onset of an invocation. The FetchEventInfo +// can also be used to describe the start of a fetch subrequest. +using EventInfo = kj::OneOf; +} // namespace tracing - LogLevel logLevel; - // TODO(soon): Just string for now. Eventually, capture serialized JS objects. - kj::String message; +enum class PipelineLogLevel { + // WARNING: This must be kept in sync with PipelineDef::LogLevel (which is not in the OSS + // release). + NONE, + FULL +}; - void copyTo(rpc::Trace::Log::Builder builder); - }; +struct Span; - class Exception { - public: - explicit Exception( - kj::Date timestamp, kj::String name, kj::String message, kj::Maybe stack); - Exception(rpc::Trace::Exception::Reader reader); - Exception(Exception&&) = default; - KJ_DISALLOW_COPY(Exception); - ~Exception() noexcept(false) = default; - - // Only as accurate as Worker's Date.now(), for Spectre mitigation. - kj::Date timestamp; +// TODO(someday): See if we can merge similar code concepts... Trace fills a role similar to +// MetricsCollector::Reporter::StageEvent, and Tracer fills a role similar to +// MetricsCollector::Request. Currently, the major differences are: +// +// - MetricsCollector::Request uses its destructor to measure a IoContext's wall time, so +// it needs to live exactly as long as its IoContext. Tracer currently needs to live as +// long as both the IoContext and those of any subrequests. +// - Due to the difference in lifetimes, results of each become available in a different order, +// and intermediate values can be freed at different times. +// - Request builds a vector of results, while Tracer builds a tree. - kj::String name; - kj::String message; +// TODO(cleanup) - worth separating into immutable Trace vs. mutable TraceBuilder? - kj::Maybe stack; +// Collects trace information about the handling of a worker/pipeline fetch event. +class Trace final: public kj::Refcounted { + public: + explicit Trace(kj::Maybe stableId, + kj::Maybe scriptName, + kj::Maybe> scriptVersion, + kj::Maybe dispatchNamespace, + kj::Maybe scriptId, + kj::Array scriptTags, + kj::Maybe entrypoint, + ExecutionModel executionModel); + Trace(rpc::Trace::Reader reader); + ~Trace() noexcept(false); + KJ_DISALLOW_COPY_AND_MOVE(Trace); - void copyTo(rpc::Trace::Exception::Builder builder); - }; +#define DEPRECATED_ALIAS(Name) \ + using Name [[deprecated("Use tracing::" #Name " directly")]] = tracing::Name + + DEPRECATED_ALIAS(FetchEventInfo); + DEPRECATED_ALIAS(FetchResponseInfo); + DEPRECATED_ALIAS(JsRpcEventInfo); + DEPRECATED_ALIAS(ScheduledEventInfo); + DEPRECATED_ALIAS(AlarmEventInfo); + DEPRECATED_ALIAS(QueueEventInfo); + DEPRECATED_ALIAS(EmailEventInfo); + DEPRECATED_ALIAS(TraceEventInfo); + DEPRECATED_ALIAS(HibernatableWebSocketEventInfo); + DEPRECATED_ALIAS(CustomEventInfo); + DEPRECATED_ALIAS(DiagnosticChannelEvent); + DEPRECATED_ALIAS(Log); + DEPRECATED_ALIAS(Exception); + DEPRECATED_ALIAS(EventInfo); + +#undef DEPRECATED_ALIAS // Empty for toplevel worker. kj::Maybe stableId; @@ -462,18 +496,8 @@ class Trace final: public kj::Refcounted { // We treat the origin value as "unset". kj::Date eventTimestamp = kj::UNIX_EPOCH; - typedef kj::OneOf - EventInfo; - kj::Maybe eventInfo; - // TODO(someday): Support more event types. + kj::Maybe eventInfo; + // TODO(someday): Work out what sort of information we may want to convey about the parent // trace, if any. @@ -484,18 +508,18 @@ class Trace final: public kj::Refcounted { kj::Array scriptTags; kj::Maybe entrypoint; - kj::Vector logs; + kj::Vector logs; // TODO(o11y): Convert this to actually store spans. - kj::Vector spans; + kj::Vector spans; // A request's trace can have multiple exceptions due to separate request/waitUntil tasks. - kj::Vector exceptions; + kj::Vector exceptions; - kj::Vector diagnosticChannelEvents; + kj::Vector diagnosticChannelEvents; ExecutionModel executionModel; EventOutcome outcome = EventOutcome::UNKNOWN; - kj::Maybe fetchResponseInfo; + kj::Maybe fetchResponseInfo; kj::Duration cpuTime; kj::Duration wallTime; @@ -594,11 +618,11 @@ class WorkerTracer final: public kj::Refcounted { kj::Date timestamp, kj::String channel, kj::Array message); // Adds info about the event that triggered the trace. Must not be called more than once. - void setEventInfo(kj::Date timestamp, Trace::EventInfo&&); + void setEventInfo(kj::Date timestamp, tracing::EventInfo&&); // Adds info about the response. Must not be called more than once, and only // after passing a FetchEventInfo to setEventInfo(). - void setFetchResponseInfo(Trace::FetchResponseInfo&&); + void setFetchResponseInfo(tracing::FetchResponseInfo&&); void setOutcome(EventOutcome outcome); diff --git a/src/workerd/io/worker-entrypoint.c++ b/src/workerd/io/worker-entrypoint.c++ index 9bcb04e4060..53373716319 100644 --- a/src/workerd/io/worker-entrypoint.c++ +++ b/src/workerd/io/worker-entrypoint.c++ @@ -254,11 +254,11 @@ kj::Promise WorkerEntrypoint::request(kj::HttpMethod method, slot.add(value); }); auto traceHeadersArray = KJ_MAP(entry, traceHeaders) { - return Trace::FetchEventInfo::Header(kj::mv(entry.key), kj::strArray(entry.value, ", ")); + return tracing::FetchEventInfo::Header(kj::mv(entry.key), kj::strArray(entry.value, ", ")); }; t.setEventInfo(timestamp, - Trace::FetchEventInfo(method, kj::str(url), kj::mv(cfJson), kj::mv(traceHeadersArray))); + tracing::FetchEventInfo(method, kj::str(url), kj::mv(cfJson), kj::mv(traceHeadersArray))); } auto metricsForCatch = kj::addRef(incomingRequest->getMetrics()); @@ -478,7 +478,7 @@ kj::Promise WorkerEntrypoint::runScheduled( KJ_IF_SOME(t, context.getWorkerTracer()) { double eventTime = (scheduledTime - kj::UNIX_EPOCH) / kj::MILLISECONDS; - t.setEventInfo(context.now(), Trace::ScheduledEventInfo(eventTime, kj::str(cron))); + t.setEventInfo(context.now(), tracing::ScheduledEventInfo(eventTime, kj::str(cron))); } // Scheduled handlers run entirely in waitUntil() tasks. @@ -536,7 +536,7 @@ kj::Promise WorkerEntrypoint::runAlarmImpl( incomingRequest->delivered(); KJ_IF_SOME(t, incomingRequest->getWorkerTracer()) { - t.setEventInfo(context.now(), Trace::AlarmEventInfo(scheduledTime)); + t.setEventInfo(context.now(), tracing::AlarmEventInfo(scheduledTime)); } auto scheduleAlarmResult = co_await actor.scheduleAlarm(scheduledTime); diff --git a/src/workerd/server/server.c++ b/src/workerd/server/server.c++ index 89d556df8c6..a2a0be03093 100644 --- a/src/workerd/server/server.c++ +++ b/src/workerd/server/server.c++ @@ -1453,7 +1453,7 @@ class RequestObserverWithTracer final: public RequestObserver, public WorkerInte ~RequestObserverWithTracer() noexcept(false) { KJ_IF_SOME(t, tracer) { if (fetchStatus != 0) { - t->setFetchResponseInfo(Trace::FetchResponseInfo(fetchStatus)); + t->setFetchResponseInfo(tracing::FetchResponseInfo(fetchStatus)); } t->setCPUTime(0 * kj::MILLISECONDS); t->setWallTime(0 * kj::MILLISECONDS);