Record exceptions on spans when callbacks throw or reject (#102)

Author: petyosi

.changeset/span-record-exceptions.md

@@ -0,0 +1,7 @@
+---
+"logfire": patch
+---
+
+Record exceptions on spans when callbacks throw or reject
+
+`span()` now automatically records exception details (event, ERROR status, log level, fingerprint) when the callback throws synchronously or the returned promise rejects, matching the Python SDK's behavior.

packages/logfire-api/src/index.test.ts

@@ -1,32 +1,40 @@
-import { trace } from '@opentelemetry/api'
+import { SpanStatusCode, trace } from '@opentelemetry/api'
 import { beforeEach, describe, expect, test, vi } from 'vitest'
 
 import {
+  ATTRIBUTES_EXCEPTION_FINGERPRINT_KEY,
   ATTRIBUTES_LEVEL_KEY,
   ATTRIBUTES_MESSAGE_KEY,
   ATTRIBUTES_MESSAGE_TEMPLATE_KEY,
   ATTRIBUTES_SPAN_TYPE_KEY,
   ATTRIBUTES_TAGS_KEY,
 } from './constants'
-import { info } from './index'
+import { info, span } from './index'
 
-vi.mock('@opentelemetry/api', () => {
+const { spanMock } = vi.hoisted(() => {
   const spanMock = {
     end: vi.fn(),
+    recordException: vi.fn(),
     setAttribute: vi.fn(),
     setStatus: vi.fn(),
   }
+  return { spanMock }
+})
 
+vi.mock('@opentelemetry/api', () => {
   const tracerMock = {
+    startActiveSpan: vi.fn((_name: string, _options: unknown, _context: unknown, fn: (s: typeof spanMock) => unknown) => fn(spanMock)),
     startSpan: vi.fn(() => spanMock),
   }
 
   return {
     context: {
       active: vi.fn(),
     },
+    SpanStatusCode: { ERROR: 2 },
     trace: {
       getTracer: vi.fn(() => tracerMock),
+      setSpan: vi.fn(),
     },
   }
 })
@@ -80,3 +88,105 @@ describe('info', () => {
     )
   })
 })
+
+describe('span', () => {
+  beforeEach(() => {
+    vi.clearAllMocks()
+  })
+
+  test('sync callback succeeds - span ends normally', () => {
+    const result = span('test {x}', { attributes: { x: 1 }, callback: () => 'ok' })
+
+    expect(result).toBe('ok')
+    expect(spanMock.end).toHaveBeenCalledOnce()
+    expect(spanMock.recordException).not.toHaveBeenCalled()
+    expect(spanMock.setStatus).not.toHaveBeenCalled()
+  })
+
+  test('sync callback throws Error - records exception and re-throws', () => {
+    const error = new Error('boom')
+
+    expect(() =>
+      span('test {x}', {
+        attributes: { x: 1 },
+        callback: () => {
+          throw error
+        },
+      })
+    ).toThrow(error)
+
+    expect(spanMock.recordException).toHaveBeenCalledWith(error)
+    expect(spanMock.setStatus).toHaveBeenCalledWith({ code: SpanStatusCode.ERROR, message: 'Error: boom' })
+    expect(spanMock.setAttribute).toHaveBeenCalledWith(ATTRIBUTES_LEVEL_KEY, 17)
+    expect(spanMock.setAttribute).toHaveBeenCalledWith(ATTRIBUTES_EXCEPTION_FINGERPRINT_KEY, expect.any(String))
+    expect(spanMock.end).toHaveBeenCalledOnce()
+  })
+
+  test('sync callback throws string - records exception without fingerprint', () => {
+    expect(() =>
+      span('test', {
+        callback: () => {
+          // eslint-disable-next-line no-throw-literal, @typescript-eslint/only-throw-error
+          throw 'oops'
+        },
+      })
+    ).toThrow('oops')
+
+    expect(spanMock.recordException).toHaveBeenCalledWith('oops')
+    expect(spanMock.setStatus).toHaveBeenCalledWith({ code: SpanStatusCode.ERROR, message: 'Error: oops' })
+    expect(spanMock.setAttribute).toHaveBeenCalledWith(ATTRIBUTES_LEVEL_KEY, 17)
+    expect(spanMock.setAttribute).not.toHaveBeenCalledWith(ATTRIBUTES_EXCEPTION_FINGERPRINT_KEY, expect.anything())
+    expect(spanMock.end).toHaveBeenCalledOnce()
+  })
+
+  test('async callback resolves - span ends normally', async () => {
+    const result = span('test', { callback: () => Promise.resolve('async-ok') })
+    await expect(result).resolves.toBe('async-ok')
+
+    expect(spanMock.end).toHaveBeenCalledOnce()
+    expect(spanMock.recordException).not.toHaveBeenCalled()
+    expect(spanMock.setStatus).not.toHaveBeenCalled()
+  })
+
+  test('async callback rejects with Error - records exception', async () => {
+    const error = new Error('async-boom')
+    const result = span('test', { callback: () => Promise.reject(error) })
+
+    await expect(result).rejects.toThrow(error)
+
+    // Allow microtask for the .then() handler to run
+    await new Promise((resolve) => setTimeout(resolve, 0))
+
+    expect(spanMock.recordException).toHaveBeenCalledWith(error)
+    expect(spanMock.setStatus).toHaveBeenCalledWith({ code: SpanStatusCode.ERROR, message: 'Error: async-boom' })
+    expect(spanMock.setAttribute).toHaveBeenCalledWith(ATTRIBUTES_LEVEL_KEY, 17)
+    expect(spanMock.setAttribute).toHaveBeenCalledWith(ATTRIBUTES_EXCEPTION_FINGERPRINT_KEY, expect.any(String))
+    expect(spanMock.end).toHaveBeenCalledOnce()
+  })
+
+  test('async callback rejects with string - records exception without fingerprint', async () => {
+    // eslint-disable-next-line prefer-promise-reject-errors, @typescript-eslint/prefer-promise-reject-errors
+    const result = span('test', { callback: () => Promise.reject('async-oops') })
+
+    await expect(result).rejects.toBe('async-oops')
+
+    await new Promise((resolve) => setTimeout(resolve, 0))
+
+    expect(spanMock.recordException).toHaveBeenCalledWith('async-oops')
+    expect(spanMock.setStatus).toHaveBeenCalledWith({ code: SpanStatusCode.ERROR, message: 'Error: async-oops' })
+    expect(spanMock.setAttribute).toHaveBeenCalledWith(ATTRIBUTES_LEVEL_KEY, 17)
+    expect(spanMock.setAttribute).not.toHaveBeenCalledWith(ATTRIBUTES_EXCEPTION_FINGERPRINT_KEY, expect.anything())
+    expect(spanMock.end).toHaveBeenCalledOnce()
+  })
+
+  test('thenable callback result is returned untouched', () => {
+    const then = vi.fn()
+    const lazyThenable = { then }
+
+    const result = span('test', { callback: () => lazyThenable })
+
+    expect(result).toBe(lazyThenable)
+    expect(then).not.toHaveBeenCalled()
+    expect(spanMock.end).toHaveBeenCalledOnce()
+  })
+})

packages/logfire-api/src/index.ts

@@ -144,10 +144,27 @@ export function span<R>(msgTemplate: string, ...args: SpanArgsVariant1<R> | Span
     },
     context,
     (span: Span) => {
-      const result = callback(span)
+      let result: R
+      try {
+        result = callback(span)
+      } catch (thrown) {
+        recordSpanException(span, thrown)
+        span.end()
+        throw thrown
+      }
 
-      // we need this clunky detection because of zone.js promises
-      if (typeof result === 'object' && result !== null && 'finally' in result && typeof result.finally === 'function') {
+      if (result instanceof Promise) {
+        result.then(
+          () => {
+            span.end()
+          },
+          (reason: unknown) => {
+            recordSpanException(span, reason)
+            span.end()
+          }
+        )
+        // we need this clunky detection because of zone.js promises
+      } else if (typeof result === 'object' && result !== null && 'finally' in result && typeof result.finally === 'function') {
         // eslint-disable-next-line @typescript-eslint/no-unsafe-call
         result.finally(() => {
           span.end()
@@ -192,6 +209,20 @@ export function warning(message: string, attributes: Record<string, unknown> = {
   log(message, attributes, { ...options, level: Level.Warning })
 }
 
+function recordSpanException(span: Span, thrown: unknown): void {
+  const isError = thrown instanceof Error
+  const errorMessage = isError ? thrown.message : String(thrown)
+  const errorName = isError ? thrown.name : 'Error'
+
+  span.recordException(isError ? thrown : String(thrown))
+  span.setStatus({ code: SpanStatusCode.ERROR, message: `${errorName}: ${errorMessage}` })
+  span.setAttribute(ATTRIBUTES_LEVEL_KEY, Level.Error)
+
+  if (isError && logfireApiConfig.enableErrorFingerprinting) {
+    span.setAttribute(ATTRIBUTES_EXCEPTION_FINGERPRINT_KEY, computeFingerprint(thrown))
+  }
+}
+
 /**
  * Use this method to report an error to Logfire.
  * Captures the error stack trace and message in the respective semantic attributes and sets the correct level and status.