fix: log span_id next to trace_id (#1225)

Signed-off-by: ferhat elmas <elmas.ferhat@gmail.com>

Author: ferhatelmas

src/http/plugins/log-request.test.ts

@@ -111,7 +111,7 @@ describe('log-request plugin', () => {
     expect(requestLogLine).not.toContain('"request_id"')
   })
 
-  it('threads traceId from a valid traceparent header into the request log data', async () => {
+  it('threads traceId and spanId from a valid traceparent header into the request log data', async () => {
     const response = await app.inject({
       method: 'GET',
       url: '/request-log',
@@ -127,10 +127,12 @@ describe('log-request plugin', () => {
 
     const requestLog = JSON.parse(requestLogLine ?? '{}')
     expect(requestLog.traceId).toBe('4bf92f3577b34da6a3ce929d0e0e4736')
+    expect(requestLog.spanId).toBe('00f067aa0ba902b7')
     expect(requestLog).not.toHaveProperty('trace_id')
+    expect(requestLog).not.toHaveProperty('span_id')
   })
 
-  it('logs an empty traceId when traceparent is malformed', async () => {
+  it('logs empty traceId and spanId values when traceparent is malformed', async () => {
     const response = await app.inject({
       method: 'GET',
       url: '/request-log',
@@ -146,10 +148,12 @@ describe('log-request plugin', () => {
 
     const requestLog = JSON.parse(requestLogLine ?? '{}')
     expect(requestLog.traceId).toBe('')
+    expect(requestLog.spanId).toBe('')
     expect(requestLog).not.toHaveProperty('trace_id')
+    expect(requestLog).not.toHaveProperty('span_id')
   })
 
-  it('logs an empty traceId when traceparent is missing', async () => {
+  it('logs empty traceId and spanId values when traceparent is missing', async () => {
     const response = await app.inject({
       method: 'GET',
       url: '/request-log',
@@ -162,7 +166,9 @@ describe('log-request plugin', () => {
 
     const requestLog = JSON.parse(requestLogLine ?? '{}')
     expect(requestLog.traceId).toBe('')
+    expect(requestLog.spanId).toBe('')
     expect(requestLog).not.toHaveProperty('trace_id')
+    expect(requestLog).not.toHaveProperty('span_id')
   })
 
   it('threads tenant context into the request log data', async () => {

src/http/plugins/log-request.ts

@@ -1,5 +1,5 @@
 import {
-  getTraceIdFromTraceparent,
+  getValidTraceparent,
   logSchema,
   serializeReplyLog,
   serializeRequestLog,
@@ -11,6 +11,12 @@ interface RequestLoggerOptions {
   excludeUrls?: Set<string>
 }
 
+// Fixed positions in a validated W3C traceparent value.
+const TRACE_ID_START = 3
+const TRACE_ID_END = 35
+const SPAN_ID_START = 36
+const SPAN_ID_END = 52
+
 type BivariantHandler<Args extends unknown[], Return> = {
   bivarianceHack(...args: Args): Return
 }['bivarianceHack']
@@ -152,7 +158,9 @@ function doRequestLog(req: FastifyRequest, options: LogRequestOptions) {
   const statusCode = options.statusCode
   const error = req.raw.executionError || req.executionError
   const tenantId = req.tenantId
-  const traceId = getTraceIdFromTraceparent(req.headers) ?? ''
+  const traceparent = getValidTraceparent(req.headers)
+  const traceId = traceparent?.slice(TRACE_ID_START, TRACE_ID_END) ?? ''
+  const spanId = traceparent?.slice(SPAN_ID_START, SPAN_ID_END) ?? ''
 
   let reqMetadata = '{}'
 
@@ -200,6 +208,7 @@ function doRequestLog(req: FastifyRequest, options: LogRequestOptions) {
     reqId: rId,
     sbReqId: req.sbReqId,
     traceId,
+    spanId,
     req: requestLog,
     reqMetadata,
     res: replyLog,

src/internal/monitoring/logflare.test.ts

@@ -20,7 +20,7 @@ describe('logflare helpers', () => {
     vi.resetModules()
   })
 
-  it('promotes project, sbReqId, and traceId onto the prepared payload', async () => {
+  it('promotes project, sbReqId, traceId, and spanId onto the prepared payload', async () => {
     defaultPreparePayloadMock.mockReturnValue({
       log_entry: 'hello',
       metadata: { level: 'info' },
@@ -32,6 +32,7 @@ describe('logflare helpers', () => {
       project: 'tenant-a',
       sbReqId: 'sb-req-123',
       traceId: '4bf92f3577b34da6a3ce929d0e0e4736',
+      spanId: '00f067aa0ba902b7',
       msg: { text: 'hello' },
     }
 
@@ -41,11 +42,12 @@ describe('logflare helpers', () => {
       project: 'tenant-a',
       request_id: 'sb-req-123',
       trace_id: '4bf92f3577b34da6a3ce929d0e0e4736',
+      span_id: '00f067aa0ba902b7',
     })
     expect(defaultPreparePayloadMock).toHaveBeenCalledWith(payload, meta)
   })
 
-  it('leaves project, request_id, and trace_id undefined when they are missing', async () => {
+  it('leaves project, request_id, trace_id, and span_id undefined when they are missing', async () => {
     defaultPreparePayloadMock.mockReturnValue({
       log_entry: 'hello',
       metadata: {},
@@ -62,6 +64,7 @@ describe('logflare helpers', () => {
       project: undefined,
       request_id: undefined,
       trace_id: undefined,
+      span_id: undefined,
     })
   })
 

src/internal/monitoring/logflare.ts

@@ -14,6 +14,7 @@ export function onPreparePayload(payload: Record<string, unknown>, meta: Payload
   item.project = payload.project
   item.request_id = payload.sbReqId
   item.trace_id = payload.traceId
+  item.span_id = payload.spanId
   return item
 }
 

src/internal/monitoring/logger.ts

@@ -139,6 +139,7 @@ export interface RequestLogContext {
 export interface RequestLog extends RequestLogContext {
   type: 'request'
   traceId: string
+  spanId: string
   req: SerializedRequestLog
   res?: SerializedReplyLog
   reqMetadata: string

src/internal/monitoring/request-context.test.ts

@@ -1,7 +1,7 @@
 import {
   getSbReqId,
   getSbReqIdFromPayload,
-  getTraceIdFromTraceparent,
+  getValidTraceparent,
   SUPABASE_REQUEST_ID_HEADER,
   TRACEPARENT_HEADER,
 } from './request-context'
@@ -49,19 +49,19 @@ describe('request log context helpers', () => {
     expect(getSbReqIdFromPayload(undefined)).toBeUndefined()
   })
 
-  it('extracts trace ids from valid traceparent headers', () => {
+  it('returns valid traceparent headers', () => {
     expect(
-      getTraceIdFromTraceparent({
+      getValidTraceparent({
         [TRACEPARENT_HEADER]: '00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01',
       })
-    ).toBe('4bf92f3577b34da6a3ce929d0e0e4736')
+    ).toBe('00-4bf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-01')
 
     expect(
-      getTraceIdFromTraceparent({
+      getValidTraceparent({
         [TRACEPARENT_HEADER]:
           '01-fbf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-00-future-field',
       })
-    ).toBe('fbf92f3577b34da6a3ce929d0e0e4736')
+    ).toBe('01-fbf92f3577b34da6a3ce929d0e0e4736-00f067aa0ba902b7-00-future-field')
   })
 
   it.each([
@@ -88,7 +88,7 @@ describe('request log context helpers', () => {
     ['all-zero parent id', '00-4bf92f3577b34da6a3ce929d0e0e4736-0000000000000000-01'],
   ])('ignores %s traceparent headers', (_name, traceparent) => {
     expect(
-      getTraceIdFromTraceparent({
+      getValidTraceparent({
         [TRACEPARENT_HEADER]: traceparent,
       })
     ).toBeUndefined()

src/internal/monitoring/request-context.ts

@@ -8,16 +8,14 @@ export const TRACEPARENT_HEADER = 'traceparent'
 const TRACEPARENT_PATTERN =
   /^(?!ff)[\da-f]{2}-(?!0{32})[\da-f]{32}-(?!0{16})[\da-f]{16}-[\da-f]{2}(?:-.*)?$/
 const TRACEPARENT_V0_LENGTH = 55
-const TRACE_ID_START = 3
-const TRACE_ID_END = 35
 
 export function getSbReqId(headers: IncomingHttpHeaders): string | undefined {
   const sbReqId = headers[SUPABASE_REQUEST_ID_HEADER]
 
   return getNonEmptyString(sbReqId)
 }
 
-export function getTraceIdFromTraceparent(headers: IncomingHttpHeaders): string | undefined {
+export function getValidTraceparent(headers: IncomingHttpHeaders): string | undefined {
   const traceparent = headers[TRACEPARENT_HEADER]
 
   if (
@@ -28,7 +26,7 @@ export function getTraceIdFromTraceparent(headers: IncomingHttpHeaders): string
     return undefined
   }
 
-  return traceparent.slice(TRACE_ID_START, TRACE_ID_END)
+  return traceparent
 }
 
 export function getSbReqIdFromPayload(payload: unknown): string | undefined {