Skip to content

Commit

Permalink
Add script version to worker trace events.
Browse files Browse the repository at this point in the history
  • Loading branch information
jp4a50 committed Nov 28, 2023
1 parent b230f0f commit 6c1162f
Show file tree
Hide file tree
Showing 5 changed files with 39 additions and 14 deletions.
5 changes: 5 additions & 0 deletions src/workerd/api/trace.c++
Original file line number Diff line number Diff line change
Expand Up @@ -175,6 +175,7 @@ TraceItem::TraceItem(jsg::Lock& js, const Trace& trace)
dispatchNamespace(trace.dispatchNamespace.map([](auto& ns) { return kj::str(ns); })),
scriptTags(getTraceScriptTags(trace)),
outcome(getTraceOutcome(trace)),
scriptVersion(trace.scriptVersion.map([](auto& version) { return kj::str(version); })),
cpuTime(trace.cpuTime / kj::MILLISECONDS),
wallTime(trace.wallTime / kj::MILLISECONDS) {}

Expand Down Expand Up @@ -225,6 +226,10 @@ jsg::Optional<kj::Array<kj::StringPtr>> TraceItem::getScriptTags() {

kj::StringPtr TraceItem::getOutcome() { return outcome; }

kj::Maybe<kj::StringPtr> TraceItem::getScriptVersion() {
return scriptVersion.map([](auto& scriptVersion) -> kj::StringPtr { return scriptVersion; });
}

uint TraceItem::getCpuTime() { return cpuTime; }

uint TraceItem::getWallTime() { return wallTime; }
Expand Down
3 changes: 3 additions & 0 deletions src/workerd/api/trace.h
Original file line number Diff line number Diff line change
Expand Up @@ -74,6 +74,7 @@ class TraceItem final: public jsg::Object {
jsg::Optional<kj::StringPtr> getDispatchNamespace();
jsg::Optional<kj::Array<kj::StringPtr>> getScriptTags();
kj::StringPtr getOutcome();
kj::Maybe<kj::StringPtr> getScriptVersion();

uint getCpuTime();
uint getWallTime();
Expand All @@ -88,6 +89,7 @@ class TraceItem final: public jsg::Object {
JSG_LAZY_READONLY_INSTANCE_PROPERTY(dispatchNamespace, getDispatchNamespace);
JSG_LAZY_READONLY_INSTANCE_PROPERTY(scriptTags, getScriptTags);
JSG_LAZY_READONLY_INSTANCE_PROPERTY(outcome, getOutcome);
JSG_LAZY_READONLY_INSTANCE_PROPERTY(scriptVersion, getScriptVersion);
}

private:
Expand All @@ -100,6 +102,7 @@ class TraceItem final: public jsg::Object {
kj::Maybe<kj::String> dispatchNamespace;
jsg::Optional<kj::Array<kj::String>> scriptTags;
kj::String outcome;
kj::Maybe<kj::String> scriptVersion;
uint cpuTime;
uint wallTime;
};
Expand Down
36 changes: 24 additions & 12 deletions src/workerd/io/trace.c++
Original file line number Diff line number Diff line change
Expand Up @@ -185,11 +185,13 @@ Trace::Exception::Exception(kj::Date timestamp, kj::String name, kj::String mess
: timestamp(timestamp), name(kj::mv(name)), message(kj::mv(message)) {}

Trace::Trace(kj::Maybe<kj::String> stableId, kj::Maybe<kj::String> scriptName,
kj::Maybe<kj::String> dispatchNamespace, kj::Array<kj::String> scriptTags)
kj::Maybe<kj::String> dispatchNamespace, kj::Array<kj::String> scriptTags,
kj::Maybe<kj::String> scriptVersion)
: stableId(kj::mv(stableId)),
scriptName(kj::mv(scriptName)),
dispatchNamespace(kj::mv(dispatchNamespace)),
scriptTags(kj::mv(scriptTags)) {}
scriptTags(kj::mv(scriptTags)),
scriptVersion(kj::mv(scriptVersion)) {}
Trace::Trace(rpc::Trace::Reader reader) {
mergeFrom(reader, PipelineLogLevel::FULL);
}
Expand All @@ -214,11 +216,14 @@ void Trace::copyTo(rpc::Trace::Builder builder) {
builder.setOutcome(outcome);
builder.setCpuTime(cpuTime / kj::MILLISECONDS);
builder.setWallTime(wallTime / kj::MILLISECONDS);
KJ_IF_SOME(s, scriptName) {
builder.setScriptName(s);
KJ_IF_SOME(name, scriptName) {
builder.setScriptName(name);
}
KJ_IF_SOME(version, scriptVersion) {
builder.setScriptVersion(version);
}
KJ_IF_SOME(s, dispatchNamespace) {
builder.setDispatchNamespace(s);
KJ_IF_SOME(ns, dispatchNamespace) {
builder.setDispatchNamespace(ns);
}

{
Expand Down Expand Up @@ -296,13 +301,18 @@ void Trace::mergeFrom(rpc::Trace::Reader reader, PipelineLogLevel pipelineLogLev
wallTime = reader.getWallTime() * kj::MILLISECONDS;

// mergeFrom() is called both when deserializing traces from a sandboxed
// worker and when deserializing traces sent to a sandboxed trace worker. In
// the former case, the trace's scriptName is already set and the deserialized
// value is missing, so we need to be careful not to overwrite the set value.
// worker and when deserializing traces sent to a sandboxed trace worker. In
// the former case, the trace's scriptName (and other fields like
// scriptVersion) are already set and the deserialized value is missing, so
// we need to be careful not to overwrite the set value.
if (reader.hasScriptName()) {
scriptName = kj::str(reader.getScriptName());
}

if (reader.hasScriptVersion()) {
scriptVersion = kj::str(reader.getScriptVersion());
}

if (reader.hasDispatchNamespace()) {
dispatchNamespace = kj::str(reader.getDispatchNamespace());
}
Expand Down Expand Up @@ -438,8 +448,10 @@ kj::Promise<kj::Array<kj::Own<Trace>>> PipelineTracer::onComplete() {

kj::Own<WorkerTracer> PipelineTracer::makeWorkerTracer(
PipelineLogLevel pipelineLogLevel, kj::Maybe<kj::String> stableId,
kj::Maybe<kj::String> scriptName, kj::Maybe<kj::String> dispatchNamespace, kj::Array<kj::String> scriptTags) {
auto trace = kj::refcounted<Trace>(kj::mv(stableId), kj::mv(scriptName), kj::mv(dispatchNamespace), kj::mv(scriptTags));
kj::Maybe<kj::String> scriptName, kj::Maybe<kj::String> dispatchNamespace,
kj::Array<kj::String> scriptTags, kj::Maybe<kj::String> scriptVersion) {
auto trace = kj::refcounted<Trace>(kj::mv(stableId), kj::mv(scriptName),
kj::mv(dispatchNamespace), kj::mv(scriptTags), kj::mv(scriptVersion));
traces.add(kj::addRef(*trace));
return kj::refcounted<WorkerTracer>(kj::addRef(*this), kj::mv(trace), pipelineLogLevel);
}
Expand All @@ -450,7 +462,7 @@ WorkerTracer::WorkerTracer(kj::Own<PipelineTracer> parentPipeline,
parentPipeline(kj::mv(parentPipeline)) {}
WorkerTracer::WorkerTracer(PipelineLogLevel pipelineLogLevel)
: pipelineLogLevel(pipelineLogLevel),
trace(kj::refcounted<Trace>(nullptr, nullptr, nullptr, nullptr)) {}
trace(kj::refcounted<Trace>(kj::none, kj::none, kj::none, nullptr, kj::none)) {}

void WorkerTracer::log(kj::Date timestamp, LogLevel logLevel, kj::String message) {
if (trace->exceededLogLimit) {
Expand Down
8 changes: 6 additions & 2 deletions src/workerd/io/trace.h
Original file line number Diff line number Diff line change
Expand Up @@ -49,7 +49,9 @@ enum class PipelineLogLevel {
// Collects trace information about the handling of a worker/pipeline fetch event.
class Trace final : public kj::Refcounted {
public:
explicit Trace(kj::Maybe<kj::String> stableId, kj::Maybe<kj::String> scriptName, kj::Maybe<kj::String> dispatchNamespace, kj::Array<kj::String> scriptTags);
explicit Trace(kj::Maybe<kj::String> stableId, kj::Maybe<kj::String> scriptName,
kj::Maybe<kj::String> dispatchNamespace, kj::Array<kj::String> scriptTags,
kj::Maybe<kj::String> scriptVersion);
Trace(rpc::Trace::Reader reader);
~Trace() noexcept(false);
KJ_DISALLOW_COPY_AND_MOVE(Trace);
Expand Down Expand Up @@ -233,6 +235,7 @@ class Trace final : public kj::Refcounted {
kj::Maybe<kj::String> scriptName;
kj::Maybe<kj::String> dispatchNamespace;
kj::Array<kj::String> scriptTags;
kj::Maybe<kj::String> scriptVersion;

kj::Vector<Log> logs;
// A request's trace can have multiple exceptions due to separate request/waitUntil tasks.
Expand Down Expand Up @@ -293,7 +296,8 @@ class PipelineTracer final : public kj::Refcounted {
kj::Maybe<kj::String> stableId,
kj::Maybe<kj::String> scriptName,
kj::Maybe<kj::String> dispatchNamespace,
kj::Array<kj::String> scriptTags);
kj::Array<kj::String> scriptTags,
kj::Maybe<kj::String> scriptVersion);
// Makes a tracer for a worker stage.

private:
Expand Down
1 change: 1 addition & 0 deletions src/workerd/io/worker-interface.capnp
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,7 @@ struct Trace @0x8e8d911203762d34 {

outcome @2 :EventOutcome;
scriptName @4 :Text;
scriptVersion @19 :Text;

eventTimestampNs @5 :Int64;

Expand Down

0 comments on commit 6c1162f

Please sign in to comment.