debug

Author: RulaKhaled

packages/cloudflare/test/request.test.ts

@@ -91,36 +91,80 @@ describe('withSentry', () => {
   });
 
   test('flush must be called when all waitUntil are done', async () => {
-    // Reset all mocks to ensure clean state
-    vi.clearAllMocks();
-    vi.restoreAllMocks();
+    const flushSpy = vi.spyOn(SentryCore.Client.prototype, 'flush').mockImplementation(async function (this: any) {
+      const callNum = flushSpy.mock.calls.length;
+      console.log(`[FLUSH #${callNum}] Client: ${this?.constructor?.name || 'unknown'}`);
+      const stack = new Error().stack?.split('\n').slice(2, 7).join('\n  ');
+      console.log(`  Stack:\n  ${stack}`);
+      return true;
+    });
+    flushSpy.mockClear(); // Explicitly clear before test
 
-    const flushSpy = vi.spyOn(SentryCore.Client.prototype, 'flush').mockResolvedValue(true);
     vi.useFakeTimers();
     onTestFinished(() => {
       vi.useRealTimers();
       flushSpy.mockRestore();
     });
     const waits: Promise<unknown>[] = [];
-    const waitUntil = vi.fn(promise => waits.push(promise));
+    const waitUntil = vi.fn(promise => {
+      const callNum = waitUntil.mock.calls.length;
+      console.log(`[WAITUNTIL #${callNum}]`);
+      const stack = new Error().stack?.split('\n').slice(2, 5).join('\n  ');
+      console.log(`  Stack:\n  ${stack}`);
+      waits.push(promise);
+    });
 
     const context = {
       waitUntil,
     } as unknown as ExecutionContext;
 
+    console.log('\n=== TEST START ===');
     await wrapRequestHandler({ options: MOCK_OPTIONS, request: new Request('https://example.com'), context }, () => {
       addDelayedWaitUntil(context);
       const response = new Response('test');
       // Add Content-Length to skip probing
       response.headers.set('content-length', '4');
       return response;
     });
-    expect(flushSpy).not.toBeCalled();
+
+    console.log('\n=== AFTER HANDLER ===');
+    console.log(`waitUntil calls: ${waitUntil.mock.calls.length}`);
+    console.log(`flush calls: ${flushSpy.mock.calls.length}`);
+
+    const callsBeforeResolve = flushSpy.mock.calls.length;
+    expect(callsBeforeResolve).toBe(0); // flush not called during handler
     expect(waitUntil).toBeCalled();
+
+    console.log('\n=== ADVANCING TIMERS ===');
     await vi.advanceTimersToNextTimerAsync();
     vi.runAllTimers();
+
+    console.log('\n=== WAITING FOR PROMISES ===');
     await Promise.all(waits);
-    expect(flushSpy).toHaveBeenCalledOnce();
+
+    console.log('\n=== TEST END ===');
+    console.log(`Total waitUntil calls: ${waitUntil.mock.calls.length}`);
+    console.log(`Total flush calls: ${flushSpy.mock.calls.length}`);
+    console.log(`Flush calls before resolve: ${callsBeforeResolve}`);
+
+    // Check that flush was called at least once after waitUntils resolved
+    const callsAfterResolve = flushSpy.mock.calls.length;
+    expect(callsAfterResolve).toBeGreaterThanOrEqual(1);
+
+    // Log detailed failure info if the delta assertion will fail
+    const delta = callsAfterResolve - callsBeforeResolve;
+    if (delta !== 1) {
+      console.error('\n=== ASSERTION FAILURE ===');
+      console.error(`Expected exactly 1 NEW flush call, but got ${delta}`);
+      console.error(`Calls before: ${callsBeforeResolve}, Calls after: ${callsAfterResolve}`);
+      console.error('\nAll flush call arguments:');
+      flushSpy.mock.calls.forEach((call, i) => {
+        console.error(`  Call ${i + 1}:`, call);
+      });
+    }
+
+    // Ideally it should be exactly 1, but verify the delta to avoid CI flakiness
+    expect(callsAfterResolve - callsBeforeResolve).toBe(1);
   });
 
   describe('scope instrumentation', () => {