diff --git a/src/workerd/api/actor-state.c++ b/src/workerd/api/actor-state.c++ index 92da7f3de5f..91b5b51e014 100644 --- a/src/workerd/api/actor-state.c++ +++ b/src/workerd/api/actor-state.c++ @@ -478,7 +478,8 @@ jsg::Promise DurableObjectStorageOperations::setAlarm( "setAlarm() cannot be called with an alarm time <= 0"); auto& context = IoContext::current(); - auto traceContext = context.makeUserTraceSpan("durable_object_storage_setAlarm"_kjc); + auto traceContext = + context.makeUserTraceSpan("durable_object_storage_setAlarm"_kjc, SpanKind::PRODUCER); // This doesn't check if we have an alarm handler per say. It checks if we have an initialized // (post-ctor) JS durable object with an alarm handler. Notably, this means this won't throw if // `setAlarm` is invoked in the DO ctor even if the DO class does not have an alarm handler. This @@ -655,7 +656,8 @@ jsg::Promise> DurableObjectStorage::transaction(jsg::Lo callback, jsg::Optional options) { auto& context = IoContext::current(); - auto traceContext = context.makeUserTraceSpan("durable_object_storage_transaction"_kjc); + auto traceContext = + context.makeUserTraceSpan("durable_object_storage_transaction"_kjc, SpanKind::INTERNAL); struct TxnResult { jsg::JsRef value; @@ -755,7 +757,8 @@ jsg::JsRef DurableObjectStorage::transactionSync( jsg::Promise DurableObjectStorage::sync(jsg::Lock& js) { auto& context = IoContext::current(); - auto traceContext = context.makeUserTraceSpan("durable_object_storage_sync"_kjc); + auto traceContext = + context.makeUserTraceSpan("durable_object_storage_sync"_kjc, SpanKind::INTERNAL); KJ_IF_SOME(p, cache->onNoPendingFlush(traceContext.getInternalSpanParent())) { // Note that we're not actually flushing since that will happen anyway once we go async. We're // merely checking if we have any pending or in-flight operations, and providing a promise that @@ -852,7 +855,8 @@ jsg::Ref DurableObjectStorage::getKv(jsg::Lock& js) { kj::Promise DurableObjectStorage::getCurrentBookmark() { auto& context = IoContext::current(); - auto traceContext = context.makeUserTraceSpan("durable_object_storage_getCurrentBookmark"_kjc); + auto traceContext = context.makeUserTraceSpan( + "durable_object_storage_getCurrentBookmark"_kjc, SpanKind::INTERNAL); return cache->getCurrentBookmark(traceContext.getInternalSpanParent()) .attach(kj::mv(traceContext)); @@ -868,7 +872,8 @@ kj::Promise DurableObjectStorage::onNextSessionRestoreBookmark(kj::S kj::Promise DurableObjectStorage::waitForBookmark(kj::String bookmark) { auto& context = IoContext::current(); - auto traceContext = context.makeUserTraceSpan("durable_object_storage_waitForBookmark"_kjc); + auto traceContext = + context.makeUserTraceSpan("durable_object_storage_waitForBookmark"_kjc, SpanKind::INTERNAL); return cache->waitForBookmark(bookmark, traceContext.getInternalSpanParent()) .attach(kj::mv(traceContext)); diff --git a/src/workerd/api/queue.c++ b/src/workerd/api/queue.c++ index fd3d90b9eba..13a993589c1 100644 --- a/src/workerd/api/queue.c++ +++ b/src/workerd/api/queue.c++ @@ -216,7 +216,8 @@ kj::Promise WorkerQueue::send( // queue broker's domain, and the start of the URL path including the account ID and queue ID. All // we have to do is provide the end of the path (which is "/message") to send a single message. - auto client = context.getHttpClient(subrequestChannel, true, kj::none, "queue_send"_kjc); + auto traceContext = context.makeUserTraceSpan("queue_send"_kjc, SpanKind::PRODUCER); + auto client = context.getHttpClient(subrequestChannel, true, kj::none, traceContext); auto req = client->request( kj::HttpMethod::POST, "https://fake-host/message"_kjc, headers, serialized.data.size()); @@ -240,7 +241,7 @@ kj::Promise WorkerQueue::send( }; return handleSend(kj::mv(req), kj::mv(serialized), kj::mv(client), headerIds, exposeErrorCodes) - .attach(context.registerPendingEvent()); + .attach(kj::mv(traceContext), context.registerPendingEvent()); }; jsg::Promise WorkerQueue::sendWithResponse(jsg::Lock& js, @@ -277,7 +278,8 @@ jsg::Promise WorkerQueue::sendWithResponse(jsg::Lock& serialized = serializeV8(js, body); } - auto client = context.getHttpClient(subrequestChannel, true, kj::none, "queue_send"_kjc); + auto traceContext = context.makeUserTraceSpan("queue_send"_kjc, SpanKind::PRODUCER); + auto client = context.getHttpClient(subrequestChannel, true, kj::none, traceContext); auto req = client->request( kj::HttpMethod::POST, "https://fake-host/message"_kjc, headers, serialized.data.size()); @@ -301,7 +303,8 @@ jsg::Promise WorkerQueue::sendWithResponse(jsg::Lock& }; auto promise = - handleSend(kj::mv(req), kj::mv(serialized), kj::mv(client), headerIds, exposeErrorCodes); + handleSend(kj::mv(req), kj::mv(serialized), kj::mv(client), headerIds, exposeErrorCodes) + .attach(kj::mv(traceContext)); return context.awaitIo( js, kj::mv(promise), [&responseHandler](jsg::Lock& js, kj::String text) -> SendResponse { @@ -384,7 +387,8 @@ kj::Promise WorkerQueue::sendBatch(jsg::Lock& js, kj::String body(bodyBuilder.releaseAsArray()); KJ_DASSERT(jsg::JsValue::fromJson(js, body).isObject()); - auto client = context.getHttpClient(subrequestChannel, true, kj::none, "queue_send"_kjc); + auto traceContext = context.makeUserTraceSpan("queue_send"_kjc, SpanKind::PRODUCER); + auto client = context.getHttpClient(subrequestChannel, true, kj::none, traceContext); // We add info about the size of the batch to the headers so that the queue implementation can // decide whether it's too large. @@ -427,7 +431,7 @@ kj::Promise WorkerQueue::sendBatch(jsg::Lock& js, }; return handleWrite(kj::mv(req), kj::mv(body), kj::mv(client), headerIds, exposeErrorCodes) - .attach(context.registerPendingEvent()); + .attach(kj::mv(traceContext), context.registerPendingEvent()); }; jsg::Promise WorkerQueue::metrics( @@ -530,7 +534,8 @@ jsg::Promise WorkerQueue::sendBatchWithResponse( kj::String body(bodyBuilder.releaseAsArray()); KJ_DASSERT(jsg::JsValue::fromJson(js, body).isObject()); - auto client = context.getHttpClient(subrequestChannel, true, kj::none, "queue_send"_kjc); + auto traceContext = context.makeUserTraceSpan("queue_send"_kjc, SpanKind::PRODUCER); + auto client = context.getHttpClient(subrequestChannel, true, kj::none, traceContext); auto headers = kj::HttpHeaders(context.getHeaderTable()); headers.addPtr("CF-Queue-Batch-Count"_kj, kj::str(messageCount)); @@ -565,8 +570,8 @@ jsg::Promise WorkerQueue::sendBatchWithResponse( co_return kj::str(responseBody.asChars()); }; - auto promise = - handleWrite(kj::mv(req), kj::mv(body), kj::mv(client), headerIds, exposeErrorCodes); + auto promise = handleWrite(kj::mv(req), kj::mv(body), kj::mv(client), headerIds, exposeErrorCodes) + .attach(kj::mv(traceContext)); return context.awaitIo( js, kj::mv(promise), [&responseHandler](jsg::Lock& js, kj::String text) -> SendBatchResponse { diff --git a/src/workerd/api/sql.c++ b/src/workerd/api/sql.c++ index 37483eee64c..c3272f42ce7 100644 --- a/src/workerd/api/sql.c++ +++ b/src/workerd/api/sql.c++ @@ -129,7 +129,7 @@ jsg::Ref SqlStorage::prepare(jsg::Lock& js, jsg::JsString double SqlStorage::getDatabaseSize(jsg::Lock& js) { auto& context = IoContext::current(); TraceContext traceContext = - context.makeUserTraceSpan("durable_object_storage_getDatabaseSize"_kjc); + context.makeUserTraceSpan("durable_object_storage_getDatabaseSize"_kjc, SpanKind::INTERNAL); traceContext.setTag("db.operation.name"_kjc, "getDatabaseSize"_kjc); auto& db = getDb(js); int64_t pages = execMemoized(db, pragmaPageCount, diff --git a/src/workerd/api/tests/tail-worker-test.js b/src/workerd/api/tests/tail-worker-test.js index 434d8357db0..fbcf50d25c4 100644 --- a/src/workerd/api/tests/tail-worker-test.js +++ b/src/workerd/api/tests/tail-worker-test.js @@ -85,7 +85,7 @@ export const test = { let expected = [ // http-test.js: fetch and scheduled events get reported correctly. // First event is emitted by the test() event, which allows us to get some coverage for span tracing. - '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","scriptTags":[],"info":{"type":"custom"}}{"type":"spanOpen","name":"fetch","spanId":"0000000000000001"}{"type":"attributes","info":[{"name":"network.protocol.name","value":"http"},{"name":"network.protocol.version","value":"HTTP/1.1"},{"name":"http.request.method","value":"POST"},{"name":"url.full","value":"http://placeholder/body-length"},{"name":"http.request.body.size","value":"3"},{"name":"http.response.status_code","value":"200"},{"name":"http.response.body.size","value":"22"}]}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"fetch","spanId":"0000000000000002"}{"type":"attributes","info":[{"name":"network.protocol.name","value":"http"},{"name":"network.protocol.version","value":"HTTP/1.1"},{"name":"http.request.method","value":"POST"},{"name":"url.full","value":"http://placeholder/body-length"},{"name":"http.response.status_code","value":"200"},{"name":"http.response.body.size","value":"31"}]}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"fetch","spanId":"0000000000000003"}{"type":"attributes","info":[{"name":"network.protocol.name","value":"http"},{"name":"network.protocol.version","value":"HTTP/1.1"},{"name":"http.request.method","value":"GET"},{"name":"url.full","value":"http://placeholder/ray-id"},{"name":"http.response.status_code","value":"200"},{"name":"http.response.body.size","value":"0"},{"name":"cloudflare.ray_id","value":"test-ray-id-123"}]}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"scheduled","spanId":"0000000000000004"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"scheduled","spanId":"0000000000000005"}{"type":"spanClose","outcome":"ok"}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', + '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","scriptTags":[],"info":{"type":"custom"}}{"type":"spanOpen","name":"fetch","spanId":"0000000000000001","spanKind":"client"}{"type":"attributes","info":[{"name":"network.protocol.name","value":"http"},{"name":"network.protocol.version","value":"HTTP/1.1"},{"name":"http.request.method","value":"POST"},{"name":"url.full","value":"http://placeholder/body-length"},{"name":"http.request.body.size","value":"3"},{"name":"http.response.status_code","value":"200"},{"name":"http.response.body.size","value":"22"}]}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"fetch","spanId":"0000000000000002","spanKind":"client"}{"type":"attributes","info":[{"name":"network.protocol.name","value":"http"},{"name":"network.protocol.version","value":"HTTP/1.1"},{"name":"http.request.method","value":"POST"},{"name":"url.full","value":"http://placeholder/body-length"},{"name":"http.response.status_code","value":"200"},{"name":"http.response.body.size","value":"31"}]}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"fetch","spanId":"0000000000000003","spanKind":"client"}{"type":"attributes","info":[{"name":"network.protocol.name","value":"http"},{"name":"network.protocol.version","value":"HTTP/1.1"},{"name":"http.request.method","value":"GET"},{"name":"url.full","value":"http://placeholder/ray-id"},{"name":"http.response.status_code","value":"200"},{"name":"http.response.body.size","value":"0"},{"name":"cloudflare.ray_id","value":"test-ray-id-123"}]}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"scheduled","spanId":"0000000000000004","spanKind":"client"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"scheduled","spanId":"0000000000000005","spanKind":"client"}{"type":"spanClose","outcome":"ok"}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","scriptTags":[],"info":{"type":"fetch","method":"POST","url":"http://placeholder/body-length","headers":[]}}{"type":"return","info":{"type":"fetch","statusCode":200}}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","scriptTags":[],"info":{"type":"fetch","method":"POST","url":"http://placeholder/body-length","headers":[]}}{"type":"return","info":{"type":"fetch","statusCode":200}}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","scriptTags":[],"info":{"type":"fetch","method":"GET","url":"http://placeholder/ray-id","headers":[]}}{"type":"return","info":{"type":"fetch","statusCode":200}}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', @@ -99,7 +99,7 @@ export const test = { '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","scriptTags":[],"info":{"type":"fetch","method":"GET","url":"","headers":[]}}{"type":"return","info":{"type":"fetch","statusCode":404}}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', // queue-test.js: queue events - '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","scriptTags":[],"info":{"type":"custom"}}{"type":"spanOpen","name":"queue_send","spanId":"0000000000000001"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"queue_send","spanId":"0000000000000002"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"queue_send","spanId":"0000000000000003"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"queue_send","spanId":"0000000000000004"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"queue_send","spanId":"0000000000000005"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"queue","spanId":"0000000000000006"}{"type":"spanClose","outcome":"ok"}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', + '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","scriptTags":[],"info":{"type":"custom"}}{"type":"spanOpen","name":"queue_send","spanId":"0000000000000001","spanKind":"producer"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"queue_send","spanId":"0000000000000002","spanKind":"producer"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"queue_send","spanId":"0000000000000003","spanKind":"producer"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"queue_send","spanId":"0000000000000004","spanKind":"producer"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"queue_send","spanId":"0000000000000005","spanKind":"producer"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"queue","spanId":"0000000000000006","spanKind":"client"}{"type":"spanClose","outcome":"ok"}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","scriptTags":[],"info":{"type":"fetch","method":"POST","url":"https://fake-host/message","headers":[{"name":"content-type","value":"application/octet-stream"},{"name":"x-msg-delay-secs","value":"2"},{"name":"x-msg-fmt","value":"text"}]}}{"type":"return","info":{"type":"fetch","statusCode":200}}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","scriptTags":[],"info":{"type":"fetch","method":"POST","url":"https://fake-host/message","headers":[{"name":"content-type","value":"application/octet-stream"},{"name":"x-msg-fmt","value":"bytes"}]}}{"type":"return","info":{"type":"fetch","statusCode":200}}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","scriptTags":[],"info":{"type":"fetch","method":"POST","url":"https://fake-host/message","headers":[{"name":"content-type","value":"application/octet-stream"},{"name":"x-msg-fmt","value":"json"}]}}{"type":"return","info":{"type":"fetch","statusCode":200}}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', @@ -108,8 +108,8 @@ export const test = { '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","scriptTags":[],"info":{"type":"queue","queueName":"test-queue","batchSize":5}}{"type":"return"}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', // actor-alarms-test.js: alarm events - '{"type":"onset","executionModel":"durableObject","spanId":"0000000000000000","entrypoint":"DurableObjectExample","scriptTags":[],"info":{"type":"fetch","method":"GET","url":"http://foo/test","headers":[]}}{"type":"spanOpen","name":"durable_object_storage_setAlarm","spanId":"0000000000000001"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"durable_object_storage_getAlarm","spanId":"0000000000000002"}{"type":"spanClose","outcome":"ok"}{"type":"return","info":{"type":"fetch","statusCode":200}}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', - '{"type":"onset","executionModel":"durableObject","spanId":"0000000000000000","entrypoint":"DurableObjectExample","scriptTags":[],"info":{"type":"alarm","scheduledTime":"1970-01-01T00:00:00.000Z"}}{"type":"spanOpen","name":"durable_object_storage_getAlarm","spanId":"0000000000000001"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"durable_object_storage_getAlarm","spanId":"0000000000000002"}{"type":"spanClose","outcome":"ok"}{"type":"return"}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', + '{"type":"onset","executionModel":"durableObject","spanId":"0000000000000000","entrypoint":"DurableObjectExample","scriptTags":[],"info":{"type":"fetch","method":"GET","url":"http://foo/test","headers":[]}}{"type":"spanOpen","name":"durable_object_storage_setAlarm","spanId":"0000000000000001","spanKind":"producer"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"durable_object_storage_getAlarm","spanId":"0000000000000002","spanKind":"client"}{"type":"spanClose","outcome":"ok"}{"type":"return","info":{"type":"fetch","statusCode":200}}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', + '{"type":"onset","executionModel":"durableObject","spanId":"0000000000000000","entrypoint":"DurableObjectExample","scriptTags":[],"info":{"type":"alarm","scheduledTime":"1970-01-01T00:00:00.000Z"}}{"type":"spanOpen","name":"durable_object_storage_getAlarm","spanId":"0000000000000001","spanKind":"client"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"durable_object_storage_getAlarm","spanId":"0000000000000002","spanKind":"client"}{"type":"spanClose","outcome":"ok"}{"type":"return"}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', // buffered tail worker, triggered via alarm test. It would appear that these being recorded // after the onsets above is not guaranteed, but since the streaming tail worker is invoked @@ -126,16 +126,16 @@ export const test = { // tail-worker-test-jsrpc: Regression test for EW-9282 (missing onset event with // JsRpcSessionCustomEvent). This is derived from tests/js-rpc-test.js. - '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","scriptTags":[],"info":{"type":"custom"}}{"type":"spanOpen","name":"durable_object_subrequest","spanId":"0000000000000002"}{"type":"attributes","info":[{"name":"objectId","value":"af6dd8b6678e07bac992dae1bbbb3f385af19ebae7e5ea8c66d6341b246d3328"}]}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"jsRpcSession","spanId":"0000000000000003"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"jsRpcSession","spanId":"0000000000000001"}{"type":"spanClose","outcome":"ok"}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', + '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","scriptTags":[],"info":{"type":"custom"}}{"type":"spanOpen","name":"durable_object_subrequest","spanId":"0000000000000002","spanKind":"client"}{"type":"attributes","info":[{"name":"objectId","value":"af6dd8b6678e07bac992dae1bbbb3f385af19ebae7e5ea8c66d6341b246d3328"}]}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"jsRpcSession","spanId":"0000000000000003","spanKind":"client"}{"type":"spanClose","outcome":"ok"}{"type":"spanOpen","name":"jsRpcSession","spanId":"0000000000000001","spanKind":"client"}{"type":"spanClose","outcome":"ok"}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","entrypoint":"MyService","scriptTags":[],"info":{"type":"jsrpc"}}{"type":"attributes","info":[{"name":"jsrpc.method","value":"nonFunctionProperty"}]}{"type":"log","level":"log","message":["bar"]}{"type":"log","level":"log","message":["foo"]}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', '{"type":"onset","executionModel":"durableObject","spanId":"0000000000000000","entrypoint":"MyActor","scriptTags":[],"info":{"type":"jsrpc"}}{"type":"log","level":"log","message":["baz"]}{"type":"attributes","info":[{"name":"jsrpc.method","value":"functionProperty"}]}{"type":"return"}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', // Test for transient objects - getCounter returns an object with methods // All transient calls happen in a single trace event, with only the entrypoint method reported '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","entrypoint":"MyService","scriptTags":[],"info":{"type":"jsrpc"}}{"type":"attributes","info":[{"name":"jsrpc.method","value":"getCounter"}]}{"type":"log","level":"log","message":["bar"]}{"type":"log","level":"log","message":["getCounter called"]}{"type":"return"}{"type":"log","level":"log","message":["increment called on transient"]}{"type":"log","level":"log","message":["getValue called on transient"]}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', // tests/connect-handler-test.js: connect events - '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","entrypoint":"connectHandler","scriptTags":[],"info":{"type":"custom"}}{"type":"spanOpen","name":"connect","spanId":"0000000000000001"}{"type":"spanClose","outcome":"ok"}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', + '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","entrypoint":"connectHandler","scriptTags":[],"info":{"type":"custom"}}{"type":"spanOpen","name":"connect","spanId":"0000000000000001","spanKind":"client"}{"type":"spanClose","outcome":"ok"}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","scriptTags":[],"info":{"type":"connect"}}{"type":"return"}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', - '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","entrypoint":"connectHandlerProxy","scriptTags":[],"info":{"type":"custom"}}{"type":"spanOpen","name":"connect","spanId":"0000000000000001"}{"type":"spanClose","outcome":"ok"}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', + '{"type":"onset","executionModel":"stateless","spanId":"0000000000000000","entrypoint":"connectHandlerProxy","scriptTags":[],"info":{"type":"custom"}}{"type":"spanOpen","name":"connect","spanId":"0000000000000001","spanKind":"client"}{"type":"spanClose","outcome":"ok"}{"type":"outcome","outcome":"ok","cpuTime":0,"wallTime":0}', ]; assert.deepStrictEqual(response, expected); diff --git a/src/workerd/io/io-context.c++ b/src/workerd/io/io-context.c++ index 82582a0c2cc..4ef2f5d90c0 100644 --- a/src/workerd/io/io-context.c++ +++ b/src/workerd/io/io-context.c++ @@ -1108,10 +1108,12 @@ SpanBuilder IoContext::makeTraceSpan(kj::ConstString operationName) { return getCurrentTraceSpan().newChild(kj::mv(operationName)); } -TraceContext IoContext::makeUserTraceSpan(kj::ConstString operationName) { +TraceContext IoContext::makeUserTraceSpan(kj::ConstString operationName, SpanKind spanKind) { auto span = makeTraceSpan(operationName.clone()); auto userSpan = getCurrentUserTraceSpan().newChild(kj::mv(operationName)); - return TraceContext(kj::mv(span), kj::mv(userSpan)); + TraceContext ctx(kj::mv(span), kj::mv(userSpan)); + ctx.setSpanKind(spanKind); + return ctx; } void IoContext::taskFailed(kj::Exception&& exception) { diff --git a/src/workerd/io/io-context.h b/src/workerd/io/io-context.h index 25a18596c38..15e2218c212 100644 --- a/src/workerd/io/io-context.h +++ b/src/workerd/io/io-context.h @@ -880,8 +880,10 @@ class IoContext final: public kj::Refcounted, private kj::TaskSet::ErrorHandler // context, if available. [[nodiscard]] SpanBuilder makeTraceSpan(kj::ConstString operationName); // Returns both an internal and a user tracing span, this ensures that all user spans are - // available in internal tracing. - [[nodiscard]] TraceContext makeUserTraceSpan(kj::ConstString operationName); + // available in internal tracing. The spanKind defaults to CLIENT since the majority of + // auto-instrumented child spans are outbound client calls. + [[nodiscard]] TraceContext makeUserTraceSpan( + kj::ConstString operationName, SpanKind spanKind = SpanKind::CLIENT); // Implement per-IoContext rate limiting for Cache.put(). Pass the body of a Cache API PUT // request and get a possibly wrapped stream back. diff --git a/src/workerd/io/trace-stream.c++ b/src/workerd/io/trace-stream.c++ index cb7dcae0dae..fef1b52a93d 100644 --- a/src/workerd/io/trace-stream.c++ +++ b/src/workerd/io/trace-stream.c++ @@ -78,6 +78,12 @@ namespace { V(SPANCLOSE, "spanClose") \ V(SPANCONTEXT, "spanContext") \ V(SPANID, "spanId") \ + V(SPANKIND, "spanKind") \ + V(SPANKIND_CLIENT, "client") \ + V(SPANKIND_SERVER, "server") \ + V(SPANKIND_PRODUCER, "producer") \ + V(SPANKIND_CONSUMER, "consumer") \ + V(SPANKIND_INTERNAL, "internal") \ V(SPANOPEN, "spanOpen") \ V(STACK, "stack") \ V(STATUSCODE, "statusCode") \ @@ -136,6 +142,22 @@ class StringCache final { // these structs to be bidirectional. So, instead, let's just do the simple easy thing // and define a set of serializers to these types. +kj::LiteralStringConst spanKindToString(SpanKind kind) { + switch (kind) { + case SpanKind::CLIENT: + return SPANKIND_CLIENT_STR; + case SpanKind::SERVER: + return SPANKIND_SERVER_STR; + case SpanKind::PRODUCER: + return SPANKIND_PRODUCER_STR; + case SpanKind::CONSUMER: + return SPANKIND_CONSUMER_STR; + case SpanKind::INTERNAL: + return SPANKIND_INTERNAL_STR; + } + KJ_UNREACHABLE; +} + // Serialize attribute value jsg::JsValue ToJs(jsg::Lock& js, const Attribute::Value& value) { KJ_SWITCH_ONEOF(value) { @@ -443,6 +465,9 @@ jsg::JsValue ToJs(jsg::Lock& js, const SpanOpen& spanOpen, StringCache& cache) { } } } + + obj.set(js, SPANKIND_STR, cache.get(js, spanKindToString(spanOpen.spanKind))); + return obj; } diff --git a/types/defines/trace.d.ts b/types/defines/trace.d.ts index f316c6a3dee..0a60ac70bef 100644 --- a/types/defines/trace.d.ts +++ b/types/defines/trace.d.ts @@ -82,6 +82,8 @@ type EventOutcome = "ok" | "canceled" | "exception" | "unknown" | "killSwitch" | "daemonDown" | "exceededCpu" | "exceededMemory" | "loadShed" | "responseStreamDisconnected" | "scriptNotFound"; +type SpanKind = "client" | "server" | "producer" | "consumer" | "internal"; + interface ScriptVersion { readonly id: string; readonly tag?: string; @@ -118,6 +120,7 @@ interface SpanOpen { // id for the span being opened by this SpanOpen event. readonly spanId: string; readonly info?: FetchEventInfo | JsRpcEventInfo | Attributes; + readonly spanKind: SpanKind; } interface SpanClose { diff --git a/types/generated-snapshot/experimental/index.d.ts b/types/generated-snapshot/experimental/index.d.ts index 76af0ac3b01..af3218033b2 100755 --- a/types/generated-snapshot/experimental/index.d.ts +++ b/types/generated-snapshot/experimental/index.d.ts @@ -14562,6 +14562,7 @@ declare namespace TailStream { | "loadShed" | "responseStreamDisconnected" | "scriptNotFound"; + type SpanKind = "client" | "server" | "producer" | "consumer" | "internal"; interface ScriptVersion { readonly id: string; readonly tag?: string; @@ -14602,6 +14603,7 @@ declare namespace TailStream { // id for the span being opened by this SpanOpen event. readonly spanId: string; readonly info?: FetchEventInfo | JsRpcEventInfo | Attributes; + readonly spanKind: SpanKind; } interface SpanClose { readonly type: "spanClose"; diff --git a/types/generated-snapshot/experimental/index.ts b/types/generated-snapshot/experimental/index.ts index 73201172412..1420a320624 100755 --- a/types/generated-snapshot/experimental/index.ts +++ b/types/generated-snapshot/experimental/index.ts @@ -14519,6 +14519,7 @@ export declare namespace TailStream { | "loadShed" | "responseStreamDisconnected" | "scriptNotFound"; + type SpanKind = "client" | "server" | "producer" | "consumer" | "internal"; interface ScriptVersion { readonly id: string; readonly tag?: string; @@ -14559,6 +14560,7 @@ export declare namespace TailStream { // id for the span being opened by this SpanOpen event. readonly spanId: string; readonly info?: FetchEventInfo | JsRpcEventInfo | Attributes; + readonly spanKind: SpanKind; } interface SpanClose { readonly type: "spanClose"; diff --git a/types/generated-snapshot/latest/index.d.ts b/types/generated-snapshot/latest/index.d.ts index 322c3049e9f..ade7f476bc4 100755 --- a/types/generated-snapshot/latest/index.d.ts +++ b/types/generated-snapshot/latest/index.d.ts @@ -13868,6 +13868,7 @@ declare namespace TailStream { | "loadShed" | "responseStreamDisconnected" | "scriptNotFound"; + type SpanKind = "client" | "server" | "producer" | "consumer" | "internal"; interface ScriptVersion { readonly id: string; readonly tag?: string; @@ -13908,6 +13909,7 @@ declare namespace TailStream { // id for the span being opened by this SpanOpen event. readonly spanId: string; readonly info?: FetchEventInfo | JsRpcEventInfo | Attributes; + readonly spanKind: SpanKind; } interface SpanClose { readonly type: "spanClose"; diff --git a/types/generated-snapshot/latest/index.ts b/types/generated-snapshot/latest/index.ts index c12a80134a4..2f1d0084db9 100755 --- a/types/generated-snapshot/latest/index.ts +++ b/types/generated-snapshot/latest/index.ts @@ -13825,6 +13825,7 @@ export declare namespace TailStream { | "loadShed" | "responseStreamDisconnected" | "scriptNotFound"; + type SpanKind = "client" | "server" | "producer" | "consumer" | "internal"; interface ScriptVersion { readonly id: string; readonly tag?: string; @@ -13865,6 +13866,7 @@ export declare namespace TailStream { // id for the span being opened by this SpanOpen event. readonly spanId: string; readonly info?: FetchEventInfo | JsRpcEventInfo | Attributes; + readonly spanKind: SpanKind; } interface SpanClose { readonly type: "spanClose";