langfuse-trace.test.ts 30 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887888889890891892893894895896897898899900901902903904905906907908909910911912913914915916917918919920921922923924925926927928929930931932933934935936937938939940941942943944945946947948949950951952953954955956957958959960961962963964965966967968969970971972973974975976977978979980981982983984985986987988989990991992993994995996
  1. import { describe, expect, test, vi, beforeEach, afterEach } from "vitest";
  2. // Mock the langfuse modules at the top level
  3. const mockStartObservation = vi.fn();
  4. const mockPropagateAttributes = vi.fn();
  5. const mockSpanEnd = vi.fn();
  6. const mockGenerationEnd = vi.fn();
  7. const mockGenerationUpdate = vi.fn();
  8. const mockGuardSpanEnd = vi.fn();
  9. const mockEventEnd = vi.fn();
  10. const mockGeneration: any = {
  11. update: (...args: unknown[]) => {
  12. mockGenerationUpdate(...args);
  13. return mockGeneration;
  14. },
  15. end: mockGenerationEnd,
  16. };
  17. const mockGuardSpan: any = {
  18. end: mockGuardSpanEnd,
  19. };
  20. const mockEventObs: any = {
  21. end: mockEventEnd,
  22. };
  23. const mockUpdateTrace = vi.fn();
  24. const mockRootSpan = {
  25. startObservation: vi.fn(),
  26. updateTrace: mockUpdateTrace,
  27. end: mockSpanEnd,
  28. };
  29. // Default: route by observation name
  30. function setupDefaultStartObservation() {
  31. mockRootSpan.startObservation.mockImplementation((name: string) => {
  32. if (name === "guard-pipeline") return mockGuardSpan;
  33. if (name === "provider-attempt") return mockEventObs;
  34. return mockGeneration; // "llm-call"
  35. });
  36. }
  37. vi.mock("@langfuse/tracing", () => ({
  38. startObservation: (...args: unknown[]) => {
  39. mockStartObservation(...args);
  40. return mockRootSpan;
  41. },
  42. propagateAttributes: async (attrs: unknown, fn: () => Promise<void>) => {
  43. mockPropagateAttributes(attrs);
  44. await fn();
  45. },
  46. }));
  47. vi.mock("@/lib/logger", () => ({
  48. logger: {
  49. info: vi.fn(),
  50. warn: vi.fn(),
  51. error: vi.fn(),
  52. debug: vi.fn(),
  53. },
  54. }));
  55. let langfuseEnabled = true;
  56. vi.mock("@/lib/langfuse/index", () => ({
  57. isLangfuseEnabled: () => langfuseEnabled,
  58. }));
  59. function createMockSession(overrides: Record<string, unknown> = {}) {
  60. const startTime = (overrides.startTime as number) ?? Date.now() - 500;
  61. return {
  62. startTime,
  63. method: "POST",
  64. headers: new Headers({
  65. "content-type": "application/json",
  66. "x-api-key": "test-mock-key-not-real",
  67. "user-agent": "claude-code/1.0",
  68. }),
  69. request: {
  70. message: {
  71. model: "claude-sonnet-4-20250514",
  72. messages: [{ role: "user", content: "Hello" }],
  73. stream: true,
  74. max_tokens: 4096,
  75. tools: [{ name: "tool1" }],
  76. },
  77. model: "claude-sonnet-4-20250514",
  78. },
  79. originalFormat: "claude",
  80. userAgent: "claude-code/1.0",
  81. sessionId: "sess_abc12345_def67890",
  82. provider: {
  83. id: 1,
  84. name: "anthropic-main",
  85. providerType: "claude",
  86. },
  87. messageContext: {
  88. id: 42,
  89. user: { id: 7, name: "testuser" },
  90. key: { name: "default-key" },
  91. },
  92. ttfbMs: 200,
  93. forwardStartTime: startTime + 5,
  94. forwardedRequestBody: null,
  95. getEndpoint: () => "/v1/messages",
  96. getRequestSequence: () => 3,
  97. getMessagesLength: () => 1,
  98. getCurrentModel: () => "claude-sonnet-4-20250514",
  99. getOriginalModel: () => "claude-sonnet-4-20250514",
  100. isModelRedirected: () => false,
  101. getProviderChain: () => [
  102. {
  103. id: 1,
  104. name: "anthropic-main",
  105. providerType: "claude",
  106. reason: "initial_selection",
  107. timestamp: startTime + 2,
  108. },
  109. ],
  110. getSpecialSettings: () => null,
  111. getCacheTtlResolved: () => null,
  112. getContext1mApplied: () => false,
  113. ...overrides,
  114. } as any;
  115. }
  116. describe("traceProxyRequest", () => {
  117. beforeEach(() => {
  118. vi.clearAllMocks();
  119. langfuseEnabled = true;
  120. setupDefaultStartObservation();
  121. });
  122. test("should not trace when Langfuse is disabled", async () => {
  123. langfuseEnabled = false;
  124. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  125. await traceProxyRequest({
  126. session: createMockSession(),
  127. responseHeaders: new Headers(),
  128. durationMs: 500,
  129. statusCode: 200,
  130. isStreaming: false,
  131. });
  132. expect(mockStartObservation).not.toHaveBeenCalled();
  133. });
  134. test("should trace when Langfuse is enabled with actual bodies", async () => {
  135. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  136. const responseBody = { content: "Hi there" };
  137. await traceProxyRequest({
  138. session: createMockSession(),
  139. responseHeaders: new Headers({ "content-type": "application/json" }),
  140. durationMs: 500,
  141. statusCode: 200,
  142. isStreaming: false,
  143. responseText: JSON.stringify(responseBody),
  144. });
  145. // Root span should have actual request body as input (not summary)
  146. const rootCall = mockStartObservation.mock.calls[0];
  147. expect(rootCall[0]).toBe("proxy-request");
  148. // Input should be the actual request message (since forwardedRequestBody is null)
  149. expect(rootCall[1].input).toEqual(
  150. expect.objectContaining({
  151. model: "claude-sonnet-4-20250514",
  152. messages: expect.any(Array),
  153. })
  154. );
  155. // Output should be actual response body
  156. expect(rootCall[1].output).toEqual(responseBody);
  157. // Should have level
  158. expect(rootCall[1].level).toBe("DEFAULT");
  159. // Should have metadata with former summaries
  160. expect(rootCall[1].metadata).toEqual(
  161. expect.objectContaining({
  162. endpoint: "/v1/messages",
  163. method: "POST",
  164. statusCode: 200,
  165. durationMs: 500,
  166. })
  167. );
  168. // Should have child observations
  169. const callNames = mockRootSpan.startObservation.mock.calls.map((c: unknown[]) => c[0]);
  170. expect(callNames).toContain("guard-pipeline");
  171. expect(callNames).toContain("llm-call");
  172. expect(mockSpanEnd).toHaveBeenCalledWith(expect.any(Date));
  173. expect(mockGenerationEnd).toHaveBeenCalledWith(expect.any(Date));
  174. });
  175. test("should use actual request messages as generation input", async () => {
  176. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  177. const session = createMockSession();
  178. await traceProxyRequest({
  179. session,
  180. responseHeaders: new Headers(),
  181. durationMs: 500,
  182. statusCode: 200,
  183. isStreaming: false,
  184. responseText: '{"content": "response"}',
  185. });
  186. // Find the llm-call invocation
  187. const llmCall = mockRootSpan.startObservation.mock.calls.find(
  188. (c: unknown[]) => c[0] === "llm-call"
  189. );
  190. expect(llmCall).toBeDefined();
  191. expect(llmCall[1].input).toEqual(session.request.message);
  192. });
  193. test("should use actual response body as generation output", async () => {
  194. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  195. const responseBody = { content: [{ type: "text", text: "Hello!" }] };
  196. await traceProxyRequest({
  197. session: createMockSession(),
  198. responseHeaders: new Headers(),
  199. durationMs: 500,
  200. statusCode: 200,
  201. isStreaming: false,
  202. responseText: JSON.stringify(responseBody),
  203. });
  204. const llmCall = mockRootSpan.startObservation.mock.calls.find(
  205. (c: unknown[]) => c[0] === "llm-call"
  206. );
  207. expect(llmCall[1].output).toEqual(responseBody);
  208. });
  209. test("should pass raw headers without redaction", async () => {
  210. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  211. await traceProxyRequest({
  212. session: createMockSession(),
  213. responseHeaders: new Headers({ "x-api-key": "secret-mock" }),
  214. durationMs: 500,
  215. statusCode: 200,
  216. isStreaming: false,
  217. });
  218. const llmCall = mockRootSpan.startObservation.mock.calls.find(
  219. (c: unknown[]) => c[0] === "llm-call"
  220. );
  221. const metadata = llmCall[1].metadata;
  222. expect(metadata.requestHeaders["x-api-key"]).toBe("test-mock-key-not-real");
  223. expect(metadata.requestHeaders["content-type"]).toBe("application/json");
  224. expect(metadata.responseHeaders["x-api-key"]).toBe("secret-mock");
  225. });
  226. test("should include provider name and model in tags", async () => {
  227. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  228. await traceProxyRequest({
  229. session: createMockSession(),
  230. responseHeaders: new Headers(),
  231. durationMs: 500,
  232. statusCode: 200,
  233. isStreaming: false,
  234. });
  235. expect(mockPropagateAttributes).toHaveBeenCalledWith(
  236. expect.objectContaining({
  237. userId: "testuser",
  238. sessionId: "sess_abc12345_def67890",
  239. tags: expect.arrayContaining([
  240. "claude",
  241. "anthropic-main",
  242. "claude-sonnet-4-20250514",
  243. "2xx",
  244. ]),
  245. })
  246. );
  247. });
  248. test("should include usage details when provided", async () => {
  249. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  250. await traceProxyRequest({
  251. session: createMockSession(),
  252. responseHeaders: new Headers(),
  253. durationMs: 500,
  254. statusCode: 200,
  255. isStreaming: false,
  256. usageMetrics: {
  257. input_tokens: 100,
  258. output_tokens: 50,
  259. cache_read_input_tokens: 20,
  260. },
  261. costUsd: "0.0015",
  262. });
  263. const llmCall = mockRootSpan.startObservation.mock.calls.find(
  264. (c: unknown[]) => c[0] === "llm-call"
  265. );
  266. expect(llmCall[1].usageDetails).toEqual({
  267. input: 100,
  268. output: 50,
  269. cache_read_input_tokens: 20,
  270. });
  271. expect(llmCall[1].costDetails).toEqual({
  272. total: 0.0015,
  273. });
  274. });
  275. test("should include providerChain, specialSettings, and model in metadata", async () => {
  276. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  277. const providerChain = [
  278. {
  279. id: 1,
  280. name: "anthropic-main",
  281. providerType: "claude",
  282. reason: "initial_selection",
  283. timestamp: Date.now(),
  284. },
  285. ];
  286. await traceProxyRequest({
  287. session: createMockSession({
  288. getSpecialSettings: () => ({ maxThinking: 8192 }),
  289. getProviderChain: () => providerChain,
  290. }),
  291. responseHeaders: new Headers(),
  292. durationMs: 500,
  293. statusCode: 200,
  294. isStreaming: false,
  295. });
  296. const llmCall = mockRootSpan.startObservation.mock.calls.find(
  297. (c: unknown[]) => c[0] === "llm-call"
  298. );
  299. const metadata = llmCall[1].metadata;
  300. expect(metadata.providerChain).toEqual(providerChain);
  301. expect(metadata.specialSettings).toEqual({ maxThinking: 8192 });
  302. expect(metadata.model).toBe("claude-sonnet-4-20250514");
  303. expect(metadata.originalModel).toBe("claude-sonnet-4-20250514");
  304. expect(metadata.providerName).toBe("anthropic-main");
  305. expect(metadata.requestSummary).toEqual(
  306. expect.objectContaining({
  307. model: "claude-sonnet-4-20250514",
  308. messageCount: 1,
  309. })
  310. );
  311. });
  312. test("should handle model redirect metadata", async () => {
  313. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  314. await traceProxyRequest({
  315. session: createMockSession({
  316. isModelRedirected: () => true,
  317. getOriginalModel: () => "claude-sonnet-4-20250514",
  318. getCurrentModel: () => "glm-4",
  319. request: {
  320. message: { model: "glm-4", messages: [] },
  321. model: "glm-4",
  322. },
  323. }),
  324. responseHeaders: new Headers(),
  325. durationMs: 500,
  326. statusCode: 200,
  327. isStreaming: false,
  328. });
  329. const llmCall = mockRootSpan.startObservation.mock.calls.find(
  330. (c: unknown[]) => c[0] === "llm-call"
  331. );
  332. expect(llmCall[1].metadata.modelRedirected).toBe(true);
  333. expect(llmCall[1].metadata.originalModel).toBe("claude-sonnet-4-20250514");
  334. });
  335. test("should set completionStartTime from ttfbMs", async () => {
  336. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  337. const startTime = Date.now() - 500;
  338. await traceProxyRequest({
  339. session: createMockSession({ startTime, ttfbMs: 200 }),
  340. responseHeaders: new Headers(),
  341. durationMs: 500,
  342. statusCode: 200,
  343. isStreaming: false,
  344. });
  345. expect(mockGenerationUpdate).toHaveBeenCalledWith({
  346. completionStartTime: new Date(startTime + 200),
  347. });
  348. });
  349. test("should pass correct startTime and endTime to observations", async () => {
  350. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  351. const startTime = 1700000000000;
  352. const durationMs = 5000;
  353. await traceProxyRequest({
  354. session: createMockSession({ startTime, forwardStartTime: startTime + 5 }),
  355. responseHeaders: new Headers(),
  356. durationMs,
  357. statusCode: 200,
  358. isStreaming: false,
  359. });
  360. const expectedStart = new Date(startTime);
  361. const expectedEnd = new Date(startTime + durationMs);
  362. const expectedForwardStart = new Date(startTime + 5);
  363. // Root span gets startTime in options (3rd arg)
  364. expect(mockStartObservation).toHaveBeenCalledWith("proxy-request", expect.any(Object), {
  365. startTime: expectedStart,
  366. });
  367. // Generation gets forwardStartTime in options (3rd arg)
  368. const llmCall = mockRootSpan.startObservation.mock.calls.find(
  369. (c: unknown[]) => c[0] === "llm-call"
  370. );
  371. expect(llmCall[2]).toEqual({
  372. asType: "generation",
  373. startTime: expectedForwardStart,
  374. });
  375. // Both end() calls receive the computed endTime
  376. expect(mockGenerationEnd).toHaveBeenCalledWith(expectedEnd);
  377. expect(mockSpanEnd).toHaveBeenCalledWith(expectedEnd);
  378. });
  379. test("should handle errors gracefully without throwing", async () => {
  380. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  381. // Make startObservation throw
  382. mockStartObservation.mockImplementationOnce(() => {
  383. throw new Error("SDK error");
  384. });
  385. await expect(
  386. traceProxyRequest({
  387. session: createMockSession(),
  388. responseHeaders: new Headers(),
  389. durationMs: 500,
  390. statusCode: 200,
  391. isStreaming: false,
  392. })
  393. ).resolves.toBeUndefined();
  394. });
  395. test("should include correct tags for error responses", async () => {
  396. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  397. await traceProxyRequest({
  398. session: createMockSession(),
  399. responseHeaders: new Headers(),
  400. durationMs: 500,
  401. statusCode: 502,
  402. isStreaming: false,
  403. errorMessage: "upstream error",
  404. });
  405. expect(mockPropagateAttributes).toHaveBeenCalledWith(
  406. expect.objectContaining({
  407. tags: expect.arrayContaining(["5xx"]),
  408. })
  409. );
  410. });
  411. test("should pass large input/output without truncation", async () => {
  412. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  413. // Generate a large response text
  414. const largeContent = "x".repeat(200_000);
  415. await traceProxyRequest({
  416. session: createMockSession(),
  417. responseHeaders: new Headers(),
  418. durationMs: 500,
  419. statusCode: 200,
  420. isStreaming: false,
  421. responseText: largeContent,
  422. });
  423. const llmCall = mockRootSpan.startObservation.mock.calls.find(
  424. (c: unknown[]) => c[0] === "llm-call"
  425. );
  426. const output = llmCall[1].output as string;
  427. // Should be the full content, no truncation
  428. expect(output).toBe(largeContent);
  429. expect(output).not.toContain("...[truncated]");
  430. });
  431. test("should show streaming output with sseEventCount when no responseText", async () => {
  432. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  433. await traceProxyRequest({
  434. session: createMockSession(),
  435. responseHeaders: new Headers(),
  436. durationMs: 500,
  437. statusCode: 200,
  438. isStreaming: true,
  439. sseEventCount: 42,
  440. });
  441. const llmCall = mockRootSpan.startObservation.mock.calls.find(
  442. (c: unknown[]) => c[0] === "llm-call"
  443. );
  444. expect(llmCall[1].output).toEqual({
  445. streaming: true,
  446. sseEventCount: 42,
  447. });
  448. });
  449. test("should include costUsd in root span metadata", async () => {
  450. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  451. await traceProxyRequest({
  452. session: createMockSession(),
  453. responseHeaders: new Headers(),
  454. durationMs: 500,
  455. statusCode: 200,
  456. isStreaming: false,
  457. costUsd: "0.05",
  458. });
  459. const rootCall = mockStartObservation.mock.calls[0];
  460. expect(rootCall[1].metadata).toEqual(
  461. expect.objectContaining({
  462. costUsd: "0.05",
  463. })
  464. );
  465. });
  466. test("should set trace-level input/output via updateTrace with actual bodies", async () => {
  467. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  468. const responseBody = { result: "ok" };
  469. await traceProxyRequest({
  470. session: createMockSession(),
  471. responseHeaders: new Headers(),
  472. durationMs: 500,
  473. statusCode: 200,
  474. isStreaming: false,
  475. responseText: JSON.stringify(responseBody),
  476. costUsd: "0.05",
  477. });
  478. expect(mockUpdateTrace).toHaveBeenCalledWith({
  479. input: expect.objectContaining({
  480. model: "claude-sonnet-4-20250514",
  481. messages: expect.any(Array),
  482. }),
  483. output: responseBody,
  484. });
  485. });
  486. // --- New tests for multi-span hierarchy ---
  487. test("should create guard-pipeline span with correct timing", async () => {
  488. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  489. const startTime = 1700000000000;
  490. const forwardStartTime = startTime + 8; // 8ms guard pipeline
  491. await traceProxyRequest({
  492. session: createMockSession({ startTime, forwardStartTime }),
  493. responseHeaders: new Headers(),
  494. durationMs: 500,
  495. statusCode: 200,
  496. isStreaming: false,
  497. });
  498. const guardCall = mockRootSpan.startObservation.mock.calls.find(
  499. (c: unknown[]) => c[0] === "guard-pipeline"
  500. );
  501. expect(guardCall).toBeDefined();
  502. expect(guardCall[1]).toEqual({
  503. output: { durationMs: 8, passed: true },
  504. });
  505. expect(guardCall[2]).toEqual({ startTime: new Date(startTime) });
  506. // Guard span should end at forwardStartTime
  507. expect(mockGuardSpanEnd).toHaveBeenCalledWith(new Date(forwardStartTime));
  508. });
  509. test("should skip guard-pipeline span when forwardStartTime is null", async () => {
  510. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  511. await traceProxyRequest({
  512. session: createMockSession({ forwardStartTime: null }),
  513. responseHeaders: new Headers(),
  514. durationMs: 500,
  515. statusCode: 200,
  516. isStreaming: false,
  517. });
  518. const guardCall = mockRootSpan.startObservation.mock.calls.find(
  519. (c: unknown[]) => c[0] === "guard-pipeline"
  520. );
  521. expect(guardCall).toBeUndefined();
  522. expect(mockGuardSpanEnd).not.toHaveBeenCalled();
  523. });
  524. test("should create provider-attempt events for failed chain items", async () => {
  525. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  526. const startTime = 1700000000000;
  527. const failTimestamp = startTime + 100;
  528. await traceProxyRequest({
  529. session: createMockSession({
  530. startTime,
  531. getProviderChain: () => [
  532. {
  533. id: 1,
  534. name: "provider-a",
  535. providerType: "claude",
  536. reason: "retry_failed",
  537. errorMessage: "502 Bad Gateway",
  538. statusCode: 502,
  539. attemptNumber: 1,
  540. timestamp: failTimestamp,
  541. },
  542. {
  543. id: 2,
  544. name: "provider-b",
  545. providerType: "claude",
  546. reason: "system_error",
  547. errorMessage: "ECONNREFUSED",
  548. timestamp: failTimestamp + 50,
  549. },
  550. {
  551. id: 3,
  552. name: "provider-c",
  553. providerType: "claude",
  554. reason: "request_success",
  555. timestamp: failTimestamp + 200,
  556. },
  557. ],
  558. }),
  559. responseHeaders: new Headers(),
  560. durationMs: 500,
  561. statusCode: 200,
  562. isStreaming: false,
  563. });
  564. const eventCalls = mockRootSpan.startObservation.mock.calls.filter(
  565. (c: unknown[]) => c[0] === "provider-attempt"
  566. );
  567. // 2 failed items (retry_failed + system_error), success is skipped
  568. expect(eventCalls).toHaveLength(2);
  569. // First event: retry_failed -> WARNING level
  570. expect(eventCalls[0][1]).toEqual(
  571. expect.objectContaining({
  572. level: "WARNING",
  573. input: expect.objectContaining({
  574. providerId: 1,
  575. providerName: "provider-a",
  576. attempt: 1,
  577. }),
  578. output: expect.objectContaining({
  579. reason: "retry_failed",
  580. errorMessage: "502 Bad Gateway",
  581. statusCode: 502,
  582. }),
  583. })
  584. );
  585. expect(eventCalls[0][2]).toEqual({
  586. asType: "event",
  587. startTime: new Date(failTimestamp),
  588. });
  589. // Second event: system_error -> ERROR level
  590. expect(eventCalls[1][1].level).toBe("ERROR");
  591. expect(eventCalls[1][1].output.reason).toBe("system_error");
  592. });
  593. test("should set generation startTime to forwardStartTime", async () => {
  594. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  595. const startTime = 1700000000000;
  596. const forwardStartTime = startTime + 10;
  597. await traceProxyRequest({
  598. session: createMockSession({ startTime, forwardStartTime }),
  599. responseHeaders: new Headers(),
  600. durationMs: 500,
  601. statusCode: 200,
  602. isStreaming: false,
  603. });
  604. const llmCall = mockRootSpan.startObservation.mock.calls.find(
  605. (c: unknown[]) => c[0] === "llm-call"
  606. );
  607. expect(llmCall[2]).toEqual({
  608. asType: "generation",
  609. startTime: new Date(forwardStartTime),
  610. });
  611. });
  612. test("should fall back to requestStartTime when forwardStartTime is null", async () => {
  613. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  614. const startTime = 1700000000000;
  615. await traceProxyRequest({
  616. session: createMockSession({ startTime, forwardStartTime: null }),
  617. responseHeaders: new Headers(),
  618. durationMs: 500,
  619. statusCode: 200,
  620. isStreaming: false,
  621. });
  622. const llmCall = mockRootSpan.startObservation.mock.calls.find(
  623. (c: unknown[]) => c[0] === "llm-call"
  624. );
  625. expect(llmCall[2]).toEqual({
  626. asType: "generation",
  627. startTime: new Date(startTime),
  628. });
  629. });
  630. test("should include timingBreakdown in root span metadata and generation metadata", async () => {
  631. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  632. const startTime = 1700000000000;
  633. const forwardStartTime = startTime + 5;
  634. await traceProxyRequest({
  635. session: createMockSession({
  636. startTime,
  637. forwardStartTime,
  638. ttfbMs: 105,
  639. getProviderChain: () => [
  640. { id: 1, name: "p1", reason: "retry_failed", timestamp: startTime + 50 },
  641. { id: 2, name: "p2", reason: "request_success", timestamp: startTime + 100 },
  642. ],
  643. }),
  644. responseHeaders: new Headers(),
  645. durationMs: 500,
  646. statusCode: 200,
  647. isStreaming: false,
  648. });
  649. const expectedTimingBreakdown = {
  650. guardPipelineMs: 5,
  651. upstreamTotalMs: 495,
  652. ttfbFromForwardMs: 100, // ttfbMs(105) - guardPipelineMs(5)
  653. tokenGenerationMs: 395, // durationMs(500) - ttfbMs(105)
  654. failedAttempts: 1, // only retry_failed is non-success
  655. providersAttempted: 2, // 2 unique provider ids
  656. };
  657. // Root span metadata should have timingBreakdown
  658. const rootCall = mockStartObservation.mock.calls[0];
  659. expect(rootCall[1].metadata.timingBreakdown).toEqual(expectedTimingBreakdown);
  660. // Generation metadata should also have timingBreakdown
  661. const llmCall = mockRootSpan.startObservation.mock.calls.find(
  662. (c: unknown[]) => c[0] === "llm-call"
  663. );
  664. expect(llmCall[1].metadata.timingBreakdown).toEqual(expectedTimingBreakdown);
  665. });
  666. test("should not create provider-attempt events when all providers succeeded", async () => {
  667. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  668. await traceProxyRequest({
  669. session: createMockSession({
  670. getProviderChain: () => [
  671. { id: 1, name: "p1", reason: "initial_selection", timestamp: Date.now() },
  672. { id: 1, name: "p1", reason: "request_success", timestamp: Date.now() },
  673. ],
  674. }),
  675. responseHeaders: new Headers(),
  676. durationMs: 500,
  677. statusCode: 200,
  678. isStreaming: false,
  679. });
  680. const eventCalls = mockRootSpan.startObservation.mock.calls.filter(
  681. (c: unknown[]) => c[0] === "provider-attempt"
  682. );
  683. expect(eventCalls).toHaveLength(0);
  684. });
  685. // --- New tests for input/output, level, and cost breakdown ---
  686. test("should use forwardedRequestBody as trace input when available", async () => {
  687. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  688. const forwardedBody = JSON.stringify({
  689. model: "claude-sonnet-4-20250514",
  690. messages: [{ role: "user", content: "Preprocessed Hello" }],
  691. stream: true,
  692. });
  693. await traceProxyRequest({
  694. session: createMockSession({
  695. forwardedRequestBody: forwardedBody,
  696. }),
  697. responseHeaders: new Headers(),
  698. durationMs: 500,
  699. statusCode: 200,
  700. isStreaming: false,
  701. responseText: '{"ok": true}',
  702. });
  703. // Root span input should be the forwarded body (parsed JSON)
  704. const rootCall = mockStartObservation.mock.calls[0];
  705. expect(rootCall[1].input).toEqual(JSON.parse(forwardedBody));
  706. // updateTrace should also use forwarded body
  707. expect(mockUpdateTrace).toHaveBeenCalledWith({
  708. input: JSON.parse(forwardedBody),
  709. output: { ok: true },
  710. });
  711. });
  712. test("should set root span level to DEFAULT for successful request", async () => {
  713. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  714. await traceProxyRequest({
  715. session: createMockSession(),
  716. responseHeaders: new Headers(),
  717. durationMs: 500,
  718. statusCode: 200,
  719. isStreaming: false,
  720. });
  721. const rootCall = mockStartObservation.mock.calls[0];
  722. expect(rootCall[1].level).toBe("DEFAULT");
  723. });
  724. test("should set root span level to WARNING when retries occurred", async () => {
  725. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  726. const startTime = Date.now() - 500;
  727. await traceProxyRequest({
  728. session: createMockSession({
  729. startTime,
  730. getProviderChain: () => [
  731. { id: 1, name: "p1", reason: "retry_failed", timestamp: startTime + 50 },
  732. { id: 2, name: "p2", reason: "request_success", timestamp: startTime + 200 },
  733. ],
  734. }),
  735. responseHeaders: new Headers(),
  736. durationMs: 500,
  737. statusCode: 200,
  738. isStreaming: false,
  739. });
  740. const rootCall = mockStartObservation.mock.calls[0];
  741. expect(rootCall[1].level).toBe("WARNING");
  742. });
  743. test("should set root span level to ERROR for non-200 status", async () => {
  744. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  745. await traceProxyRequest({
  746. session: createMockSession(),
  747. responseHeaders: new Headers(),
  748. durationMs: 500,
  749. statusCode: 502,
  750. isStreaming: false,
  751. });
  752. const rootCall = mockStartObservation.mock.calls[0];
  753. expect(rootCall[1].level).toBe("ERROR");
  754. });
  755. test("should set root span level to ERROR for 499 client abort", async () => {
  756. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  757. await traceProxyRequest({
  758. session: createMockSession(),
  759. responseHeaders: new Headers(),
  760. durationMs: 500,
  761. statusCode: 499,
  762. isStreaming: false,
  763. });
  764. const rootCall = mockStartObservation.mock.calls[0];
  765. expect(rootCall[1].level).toBe("ERROR");
  766. });
  767. test("should include cost breakdown in costDetails when provided", async () => {
  768. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  769. const costBreakdown = {
  770. input: 0.001,
  771. output: 0.002,
  772. cache_creation: 0.0005,
  773. cache_read: 0.0001,
  774. total: 0.0036,
  775. };
  776. await traceProxyRequest({
  777. session: createMockSession(),
  778. responseHeaders: new Headers(),
  779. durationMs: 500,
  780. statusCode: 200,
  781. isStreaming: false,
  782. costUsd: "0.0036",
  783. costBreakdown,
  784. });
  785. const llmCall = mockRootSpan.startObservation.mock.calls.find(
  786. (c: unknown[]) => c[0] === "llm-call"
  787. );
  788. expect(llmCall[1].costDetails).toEqual(costBreakdown);
  789. });
  790. test("should fallback to total-only costDetails when no breakdown", async () => {
  791. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  792. await traceProxyRequest({
  793. session: createMockSession(),
  794. responseHeaders: new Headers(),
  795. durationMs: 500,
  796. statusCode: 200,
  797. isStreaming: false,
  798. costUsd: "0.05",
  799. });
  800. const llmCall = mockRootSpan.startObservation.mock.calls.find(
  801. (c: unknown[]) => c[0] === "llm-call"
  802. );
  803. expect(llmCall[1].costDetails).toEqual({ total: 0.05 });
  804. });
  805. test("should include former summaries in root span metadata", async () => {
  806. const { traceProxyRequest } = await import("@/lib/langfuse/trace-proxy-request");
  807. await traceProxyRequest({
  808. session: createMockSession(),
  809. responseHeaders: new Headers(),
  810. durationMs: 500,
  811. statusCode: 200,
  812. isStreaming: false,
  813. costUsd: "0.05",
  814. });
  815. const rootCall = mockStartObservation.mock.calls[0];
  816. const metadata = rootCall[1].metadata;
  817. // Former input summary fields
  818. expect(metadata.endpoint).toBe("/v1/messages");
  819. expect(metadata.method).toBe("POST");
  820. expect(metadata.model).toBe("claude-sonnet-4-20250514");
  821. expect(metadata.clientFormat).toBe("claude");
  822. expect(metadata.providerName).toBe("anthropic-main");
  823. // Former output summary fields
  824. expect(metadata.statusCode).toBe(200);
  825. expect(metadata.durationMs).toBe(500);
  826. expect(metadata.costUsd).toBe("0.05");
  827. expect(metadata.timingBreakdown).toBeDefined();
  828. });
  829. });
  830. describe("isLangfuseEnabled", () => {
  831. const originalPublicKey = process.env.LANGFUSE_PUBLIC_KEY;
  832. const originalSecretKey = process.env.LANGFUSE_SECRET_KEY;
  833. afterEach(() => {
  834. // Restore env
  835. if (originalPublicKey !== undefined) {
  836. process.env.LANGFUSE_PUBLIC_KEY = originalPublicKey;
  837. } else {
  838. delete process.env.LANGFUSE_PUBLIC_KEY;
  839. }
  840. if (originalSecretKey !== undefined) {
  841. process.env.LANGFUSE_SECRET_KEY = originalSecretKey;
  842. } else {
  843. delete process.env.LANGFUSE_SECRET_KEY;
  844. }
  845. });
  846. test("should return false when env vars are not set", () => {
  847. delete process.env.LANGFUSE_PUBLIC_KEY;
  848. delete process.env.LANGFUSE_SECRET_KEY;
  849. // Direct function test (not using the mock)
  850. const isEnabled = !!(process.env.LANGFUSE_PUBLIC_KEY && process.env.LANGFUSE_SECRET_KEY);
  851. expect(isEnabled).toBe(false);
  852. });
  853. test("should return true when both keys are set", () => {
  854. process.env.LANGFUSE_PUBLIC_KEY = "pk-lf-test-mock";
  855. process.env.LANGFUSE_SECRET_KEY = "test-mock-not-real";
  856. const isEnabled = !!(process.env.LANGFUSE_PUBLIC_KEY && process.env.LANGFUSE_SECRET_KEY);
  857. expect(isEnabled).toBe(true);
  858. });
  859. });