Jest测试中Stripe subscription.deleted Webhook延迟触发异常排查

测试用例代码 #

test("HTTP POST on /invites/:code/accept returns 400 for accepting invite to a cancelled subscription", async () => {
    const clock = new StripeTestClock(stripe);
    clock.create()

    const inviterContext = await generateContext(true); // First account (inviter)
    const inviteeContext = await generateContext(true); // Second account (invitee)

    // Create a duo subscription for the inviter
    const { subscriptionId, customer } = await createActiveCustomer(
        inviterContext.nonAdminUser,
        inviterContext.axiosAuthHeaders,
        createdCustomers,
        SubscriptionType.DUO_MONTHLY,
        clock.getClockId()
    );

    await delay(ENDPOINT_DELAY)
    const inviteCode = await sendDuoInvite(inviterContext, inviteeContext)

    // Cancel sub
    await assertEndpointResponse("post", "cancel-subscription", HttpStatus.OK, inviterContext.axiosAuthHeaders);
    await clock.advanceDays(40); 
    await delay(CLOCK_ADVANCE_DELAY); 
    await delay(ENDPOINT_DELAY)

    await verifyGetSubscription(customer.id, SubscriptionType.DUO_MONTHLY, "canceled", inviterContext.axiosAuthHeaders)

    // Now, we should get a 400
    await assertEndpointResponse(
        "post",
        `invites/${inviteCode}/accept`,
        HttpStatus.BAD_REQUEST,
        inviteeContext.axiosAuthHeaders
    );
}, JEST_TIMEOUT);

业务流程 #

• 通过StripeTestClock创建测试时钟
• 为邀请者创建DUO_MONTHLY订阅
• 发送邀请后调用cancel-subscription端点，设置cancel_at_period_end: true
• 将测试时钟推进40天，等待固定时长后验证订阅状态，最后测试邀请接受接口的返回

StripeTestClock实现代码 #

import Stripe from "stripe";

export default class StripeTestClock {
    private stripe: Stripe;
    private clockId?: string;
    private frozenTime: number=0;

    constructor(stripeInstance: Stripe) {
        this.stripe = stripeInstance;
    }

    /**
     * Creates a Stripe test clock starting at the given frozen time.
     * If no frozen time is provided, it defaults to the current Unix timestamp.
     * 
     * @param frozenTime - The initial time for the test clock (in seconds since Unix epoch).
     * @returns The ID of the created test clock.
     */
    async create(frozenTime: number = Math.floor(Date.now() / 1000)): Promise<string> {
        if (this.clockId) {
            console.warn("A test clock already exists. Reusing existing clock.");
            return this.clockId;
        }

        try {
            const clock = await this.stripe.testHelpers.testClocks.create({
                frozen_time: frozenTime,
            });
            this.clockId = clock.id;
            this.frozenTime = frozenTime;
            return this.clockId;
        } catch (error) {
            console.error("Failed to create Stripe test clock:", (error as Error).message);
            throw error;
        }
    }

    /**
     * Advances the test clock to a new frozen time.
     * 
     * @param advanceToTime - The new time to advance the test clock to (in seconds since Unix epoch).
     * @throws If the clock ID is not set or the Stripe API call fails.
     */
    async advance(advanceToTime: number): Promise<void> {
        if (!this.clockId) {
            throw new Error("Cannot advance test clock: Clock ID is not set.");
        }

        try {
            await this.stripe.testHelpers.testClocks.advance(this.clockId, {
                frozen_time: advanceToTime,
            });
            this.frozenTime = advanceToTime; // Update the frozen time
        } catch (error) {
            console.error("Failed to advance Stripe test clock:", (error as Error).message);
            throw error;
        }
    }

    /**
     * Advances the test clock by the specified number of days.
     * 
     * @param days - The number of days to advance the clock.
     * @throws If the clock ID is not set or the Stripe API call fails.
     */
    async advanceDays(days: number): Promise<void> {
        if (!this.clockId) {
            throw new Error("Cannot advance test clock: Clock ID or is not set.");
        }

        const advanceToTime = this.frozenTime + days * 24 * 60 * 60; // Advance by days in seconds
        await this.advance(advanceToTime);
    }

    /**
     * Deletes the current test clock to clean up resources.
     * 
     * @throws If the clock ID is not set or the Stripe API call fails.
     */
    async delete(): Promise<void> {
        if (!this.clockId) {
            console.warn("No test clock to delete. Skipping deletion.");
            return;
        }

        try {
            await this.stripe.testHelpers.testClocks.del(this.clockId);
            this.clockId = undefined;
            this.frozenTime = 0;
        } catch (error) {
            console.error("Failed to delete Stripe test clock:", (error as Error).message);
            throw error;
        }
    }

    /**
     * Retrieves the ID of the current test clock.
     * 
     * @returns The ID of the current test clock, or undefined if no clock is set.
     */
    getClockId(): string | undefined {
        return this.clockId;
    }

    /**
     * Retrieves the current frozen time of the test clock.
     * 
     * @returns The current frozen time of the test clock, or undefined if no clock is set.
     */
    getFrozenTime(): number {
        return this.frozenTime;
    }

    /**
     * Refreshes the current frozen time by fetching the latest test clock state.
     * 
     * @throws If the clock ID is not set or the Stripe API call fails.
     */
    async refreshFrozenTime(): Promise<void> {
        if (!this.clockId) {
            throw new Error("Cannot refresh frozen time: Clock ID is not set.");
        }

        try {
            const clock = await this.stripe.testHelpers.testClocks.retrieve(this.clockId);
            this.frozenTime = clock.frozen_time;
        } catch (error) {
            console.error("Failed to refresh frozen time:", (error as Error).message);
            throw error;
        }
    }
}

cancel-subscription端点逻辑 #

await stripe.subscriptions.update(subscriptionId, {
     cancel_at_period_end: true
})

异常现象 #

无论设置多长的delay(CLOCK_ADVANCE_DELAY + ENDPOINT_DELAY)等待时长，stripe.subscription.deleted Webhook总是在该等待结束后约500毫秒才收到：

• 等待10秒时，Webhook在10秒+约500毫秒后触发
• 等待5秒时，触发时间为5秒+约500毫秒
• 等待30秒时，触发时间为30秒+约500毫秒

原因分析 #

1. Stripe测试时钟的异步处理特性：调用clock.advanceDays()后，Stripe API会立即返回，但后台需要时间处理时钟推进后的一系列操作——包括将订阅状态从cancel_at_period_end: true转换为canceled，并生成subscription.deleted Webhook事件。这个处理过程的耗时不是固定的。
2. 固定等待的局限性：你当前用固定时长的delay()等待，相当于给Stripe预留了一段处理时间，但这段时间刚好不足以让Stripe完成所有操作。当固定等待结束后，Stripe的后台处理刚好在几百毫秒内完成，所以Webhook会在等待结束后延迟触发。
3. 轮询验证的误导：你在等待后调用verifyGetSubscription验证订阅状态为canceled，这只能说明Stripe已经更新了订阅的数据库状态，但Webhook事件的生成和推送是独立的后续流程，状态更新完成不代表Webhook已经发出。

解决建议 #

• 放弃固定时长的delay()，改为监听stripe.subscription.deleted Webhook事件，直到事件触发后再执行后续测试逻辑。
• 或者，在验证订阅状态为canceled后，继续轮询Stripe的Webhook事件日志（或本地事件接收队列），直到目标事件出现，再进行下一步测试。

内容的提问来源于stack exchange，提问作者M. Chak