diff --git a/.changeset/serious-beans-hug.md b/.changeset/serious-beans-hug.md new file mode 100644 index 000000000000..25c772cf1873 --- /dev/null +++ b/.changeset/serious-beans-hug.md @@ -0,0 +1,18 @@ +--- +"wrangler": minor +--- + +Support TailEvent messages in Tail sessions + +When tailing a tail worker, messages previously had a null event +property. Following https://github.com/cloudflare/workerd/pull/1248, +these events have a valid event, specifying which scripts produced +events that caused your tail worker to run. + +As part of rolling this out, we're filtering out tail events in the +internal tail infrastructure, so we control when these new messages are +forward to tail sessions, and can merge this freely. + +One idiosyncracy to note, however, is that tail workers always report an +"OK" status, even if they run out of memory or throw. That is being +tracked and worked on separately. diff --git a/packages/wrangler/src/__tests__/pages-deployment-tail.test.ts b/packages/wrangler/src/__tests__/pages-deployment-tail.test.ts index e4aa6750cf47..d7f190c4aa87 100644 --- a/packages/wrangler/src/__tests__/pages-deployment-tail.test.ts +++ b/packages/wrangler/src/__tests__/pages-deployment-tail.test.ts @@ -13,6 +13,7 @@ import type { ScheduledEvent, AlarmEvent, EmailEvent, + TailEvent, TailInfo, } from "../tail/createTail"; import type { RequestInit } from "undici"; @@ -663,6 +664,7 @@ function isRequest( | RequestEvent | AlarmEvent | EmailEvent + | TailEvent | TailInfo | undefined | null diff --git a/packages/wrangler/src/__tests__/tail.test.ts b/packages/wrangler/src/__tests__/tail.test.ts index c637fdfdb8df..99b66936bac8 100644 --- a/packages/wrangler/src/__tests__/tail.test.ts +++ b/packages/wrangler/src/__tests__/tail.test.ts @@ -14,6 +14,7 @@ import type { ScheduledEvent, AlarmEvent, EmailEvent, + TailEvent, TailInfo, } from "../tail/createTail"; import type { RequestInit } from "undici"; @@ -426,6 +427,18 @@ describe("tail", () => { expect(std.out).toMatch(deserializeToJson(serializedMessage)); }); + it("logs tail messages in json format", async () => { + const api = mockWebsocketAPIs(); + await runWrangler("tail test-worker --format json"); + + const event = generateMockTailEvent(["some-worker", "some-worker"]); + const message = generateMockEventMessage({ event }); + const serializedMessage = serialize(message); + + api.ws.send(serializedMessage); + expect(std.out).toMatch(deserializeToJson(serializedMessage)); + }); + it("logs request messages in pretty format", async () => { const api = mockWebsocketAPIs(); await runWrangler("tail test-worker --format pretty"); @@ -518,6 +531,32 @@ describe("tail", () => { `); }); + it("logs tail messages in pretty format", async () => { + const api = mockWebsocketAPIs(); + await runWrangler("tail test-worker --format pretty"); + + const event = generateMockTailEvent(["some-worker", "other-worker", ""]); + const message = generateMockEventMessage({ event }); + const serializedMessage = serialize(message); + + api.ws.send(serializedMessage); + expect( + std.out + .replace( + new Date(mockEventTimestamp).toLocaleString(), + "[mock event timestamp]" + ) + .replace( + new Date(mockTailExpiration).toISOString(), + "[mock expiration date]" + ) + ).toMatchInlineSnapshot(` + "Successfully created tail, expires at [mock expiration date] + Connected to test-worker, waiting for logs... + Tailing some-worker,other-worker - Ok @ [mock event timestamp]" + `); + }); + it("logs tail overload message", async () => { const api = mockWebsocketAPIs(); await runWrangler("tail test-worker --format pretty"); @@ -710,6 +749,7 @@ function isRequest( | RequestEvent | AlarmEvent | EmailEvent + | TailEvent | TailInfo | undefined | null @@ -993,6 +1033,14 @@ function generateMockEmailEvent(opts?: Partial): EmailEvent { }; } +function generateMockTailEvent(tailing: string[]): TailEvent { + return { + consumedEvents: tailing.map((tailedScript) => { + return { scriptName: tailedScript }; + }), + }; +} + function generateTailInfo(overload: boolean): TailInfo { return overload ? { diff --git a/packages/wrangler/src/tail/createTail.ts b/packages/wrangler/src/tail/createTail.ts index 89d470726155..9d5143370585 100644 --- a/packages/wrangler/src/tail/createTail.ts +++ b/packages/wrangler/src/tail/createTail.ts @@ -252,6 +252,7 @@ export type TailEventMessage = { | ScheduledEvent | AlarmEvent | EmailEvent + | TailEvent | TailInfo | undefined | null; @@ -406,6 +407,22 @@ export type EmailEvent = { rawSize: number; }; +/** + * An event that was triggered for a tail receiving TailEventMessages + * Only seen when tailing a tail worker + */ +export type TailEvent = { + /** + * A minimal representation of the TailEventMessages that were delivered to the tail handler + */ + consumedEvents: { + /** + * The name of script being tailed + */ + scriptName?: string; + }[]; +}; + /** * Message from tail with information about the tail itself */ diff --git a/packages/wrangler/src/tail/printing.ts b/packages/wrangler/src/tail/printing.ts index 05d8fd6d3152..f2be8cae2a0c 100644 --- a/packages/wrangler/src/tail/printing.ts +++ b/packages/wrangler/src/tail/printing.ts @@ -5,6 +5,7 @@ import type { EmailEvent, RequestEvent, ScheduledEvent, + TailEvent, TailInfo, TailEventMessage, } from "./createTail"; @@ -50,6 +51,20 @@ export function prettyPrintLogs(data: WebSocket.RawData): void { ).toLocaleString(); logger.log(`Alarm @ ${datetime} - ${outcome}`); + } else if (isTailEvent(eventMessage.event)) { + const outcome = prettifyOutcome(eventMessage.outcome); + const datetime = new Date(eventMessage.eventTimestamp).toLocaleString(); + const tailedScripts = new Set( + eventMessage.event.consumedEvents + .map((consumedEvent) => consumedEvent.scriptName) + .filter((scriptName) => !!scriptName) + ); + + logger.log( + `Tailing ${Array.from(tailedScripts).join( + "," + )} - ${outcome} @ ${datetime}` + ); } else if (isTailInfo(eventMessage.event)) { if (eventMessage.event.type === "overload") { logger.log(`${chalk.red.bold(eventMessage.event.message)}`); @@ -111,6 +126,10 @@ function isAlarmEvent(event: TailEventMessage["event"]): event is AlarmEvent { return Boolean(event && "scheduledTime" in event && !("cron" in event)); } +function isTailEvent(event: TailEventMessage["event"]): event is TailEvent { + return Boolean(event && "consumedEvents" in event); +} + function isTailInfo(event: TailEventMessage["event"]): event is TailInfo { return Boolean(event && "message" in event && "type" in event); }