fix(sandbox): loop small cleanup batches (8s cap is real), clear last FK blockers (#1452)
* fix(sandbox): loop small cleanup batches (8s cap is real), clear last FK blockers Draining the prod backlog exposed two final issues: - The function-level statement_timeout shipped in 20260807150000 does NOT lift authenticator's 8s cap: the timer arms when the top-level statement starts (verified empirically on prod: SET LOCAL 2s canceled the RPC despite its 290s proconfig; matches the 2026-08-04 SIE-import finding). The route now loops batches of 10 (~220ms/user with the account_id index, so ~2.2s per batch), each rpc() call being its own statement with its own 8s window. The loop stops when a batch makes no progress or the 240s time budget nears; capacity is 250 users/night. - processing_history.company_id and invoice_deliveries.company_id are plain NO ACTION FKs, so sandboxes whose visitor produced AI telemetry or sent a demo invoice could never be deleted (7 of ~510 backlog users). A data-driven sweep of every NO ACTION FK into companies confirms these two plus the already-handled audit_log are the only such tables with sandbox rows. cleanup_sandbox_user (migration 20260807160000) deletes them explicitly; the pg fixture now seeds a processing_history row. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> * fix(test): use valid processing_history aggregate_type/event_type in sandbox fixture aggregate_type is CHECK-constrained and event_type is an FK to the seeded processing_event_types lookup; the guessed values failed all five fixture-dependent pg tests in CI. Validated against staging: Document/DocumentIngested inserts and tears down cleanly. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> * fix(sandbox): bypass invoice-delivery delete guard in teardown, cover both blocker tables in pg fixture CodeRabbit's fixture ask exposed a real gap: enforce_invoice_delivery_immutability silently swallows DELETEs (RETURN NULL plus a SECURITY_EVENT audit row) for terminal rows, so the explicit invoice_deliveries delete was a no-op and the companies FK still blocked teardown for sandboxes that sent a demo invoice. The trigger's DELETE branch now honors the gnubok.sandbox_cleanup flag with the same per-row sandbox re-verification as every other guard; base definition 20260803224000, all other branches untouched. The pg fixture seeds an invoice plus a marked_sent manual delivery, and a new test pins the zero-settings refusal path the Swedish review asked about. Validated on staging end-to-end. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com> --------- Co-authored-by: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
Mattsson
co-authored by
Claude Fable 5
Claude Fable 5
parent
858ad49852
commit
526f0315d0
@@ -1,9 +1,10 @@
|
||||
/**
|
||||
* Tests for the sandbox cleanup cron route: the RPC's jsonb summary
|
||||
* ({cleaned, failed, orphans_removed}, migration 20260807130000) is passed
|
||||
* through, the legacy bare-integer shape is still accepted (deploy/migration
|
||||
* ordering), and per-user failures are logged at error level: the failure
|
||||
* mode this fixes was months of silently swallowed cleanup errors.
|
||||
* Tests for the sandbox cleanup cron route: the run loops small RPC batches
|
||||
* (each PostgREST statement gets its own 8s window; a function-level
|
||||
* statement_timeout cannot lift it), stops when a batch makes no progress,
|
||||
* aggregates totals across batches, accepts the legacy bare-integer return
|
||||
* shape, and logs failures at error level: the failure mode this route
|
||||
* chain fixes was months of silently swallowed cleanup errors.
|
||||
*/
|
||||
import { describe, it, expect, vi, beforeEach } from 'vitest'
|
||||
|
||||
@@ -33,48 +34,67 @@ function cronRequest(): Request {
|
||||
return new Request('http://localhost:3000/api/sandbox/cleanup/cron')
|
||||
}
|
||||
|
||||
describe('GET /api/sandbox/cleanup/cron', () => {
|
||||
it('reserves enough function time for a full batch', () => {
|
||||
// 60 users at ~3s each must fit inside the route budget and the RPC's
|
||||
// 290s statement_timeout (migration 20260807150000).
|
||||
expect(maxDuration).toBe(300)
|
||||
})
|
||||
function batch(cleaned: number, failed = 0, orphans = 0) {
|
||||
return { data: { cleaned, failed, orphans_removed: orphans }, error: null }
|
||||
}
|
||||
|
||||
describe('GET /api/sandbox/cleanup/cron', () => {
|
||||
beforeEach(() => {
|
||||
vi.clearAllMocks()
|
||||
process.env.NEXT_PUBLIC_SUPABASE_URL = 'https://example.supabase.co'
|
||||
process.env.SUPABASE_SERVICE_ROLE_KEY = 'service-role-key'
|
||||
})
|
||||
|
||||
it('passes the jsonb summary through and logs at info level when nothing failed', async () => {
|
||||
h.rpc.mockResolvedValue({
|
||||
data: { cleaned: 3, failed: 0, orphans_removed: 2 },
|
||||
error: null,
|
||||
})
|
||||
it('reserves enough function time for the batch loop', () => {
|
||||
expect(maxDuration).toBe(300)
|
||||
})
|
||||
|
||||
it('loops full batches and stops on the first partial one, aggregating totals', async () => {
|
||||
h.rpc
|
||||
.mockResolvedValueOnce(batch(10))
|
||||
.mockResolvedValueOnce(batch(10, 0, 0))
|
||||
.mockResolvedValueOnce(batch(3, 1, 2))
|
||||
.mockResolvedValueOnce(batch(0))
|
||||
|
||||
const res = await GET(cronRequest())
|
||||
const body = await res.json()
|
||||
|
||||
expect(h.rpc).toHaveBeenCalledWith('cleanup_expired_sandbox_users', {
|
||||
p_max_age_hours: 24,
|
||||
p_limit: 60,
|
||||
p_limit: 10,
|
||||
})
|
||||
// Third batch still made progress (cleaned + orphans > 0), so a fourth
|
||||
// call runs and returns zero progress, ending the loop.
|
||||
expect(h.rpc).toHaveBeenCalledTimes(4)
|
||||
expect(res.status).toBe(200)
|
||||
expect(body).toEqual({ success: true, cleaned: 3, failed: 0, orphans_removed: 2 })
|
||||
expect(h.logInfo).toHaveBeenCalled()
|
||||
expect(h.logError).not.toHaveBeenCalled()
|
||||
expect(body).toEqual({
|
||||
success: true,
|
||||
cleaned: 23,
|
||||
failed: 1,
|
||||
orphans_removed: 2,
|
||||
batches: 4,
|
||||
})
|
||||
})
|
||||
|
||||
it('logs at error level when the summary reports failures', async () => {
|
||||
h.rpc.mockResolvedValue({
|
||||
data: { cleaned: 1, failed: 4, orphans_removed: 0 },
|
||||
error: null,
|
||||
})
|
||||
it('stops immediately when the backlog is empty', async () => {
|
||||
h.rpc.mockResolvedValue(batch(0))
|
||||
|
||||
const res = await GET(cronRequest())
|
||||
const body = await res.json()
|
||||
|
||||
expect(res.status).toBe(200)
|
||||
expect(h.rpc).toHaveBeenCalledTimes(1)
|
||||
expect(body.batches).toBe(1)
|
||||
expect(h.logInfo).toHaveBeenCalled()
|
||||
expect(h.logError).not.toHaveBeenCalled()
|
||||
})
|
||||
|
||||
it('stops when a batch yields only failures, and logs at error level', async () => {
|
||||
h.rpc.mockResolvedValueOnce(batch(0, 4, 0))
|
||||
|
||||
const res = await GET(cronRequest())
|
||||
const body = await res.json()
|
||||
|
||||
expect(h.rpc).toHaveBeenCalledTimes(1)
|
||||
expect(body.failed).toBe(4)
|
||||
expect(h.logError).toHaveBeenCalledWith(
|
||||
'sandbox cleanup completed with failures',
|
||||
@@ -83,20 +103,19 @@ describe('GET /api/sandbox/cleanup/cron', () => {
|
||||
})
|
||||
|
||||
it('still accepts the legacy bare-integer return shape', async () => {
|
||||
h.rpc.mockResolvedValue({ data: 5, error: null })
|
||||
h.rpc.mockResolvedValueOnce({ data: 5, error: null }).mockResolvedValueOnce(batch(0))
|
||||
|
||||
const res = await GET(cronRequest())
|
||||
const body = await res.json()
|
||||
|
||||
expect(res.status).toBe(200)
|
||||
expect(body).toEqual({ success: true, cleaned: 5, failed: 0, orphans_removed: 0 })
|
||||
expect(body.cleaned).toBe(5)
|
||||
})
|
||||
|
||||
it('returns an error envelope when the RPC fails', async () => {
|
||||
h.rpc.mockResolvedValue({
|
||||
data: null,
|
||||
error: { message: 'boom', code: 'XX000' },
|
||||
})
|
||||
it('returns an error envelope when the RPC fails mid-loop', async () => {
|
||||
h.rpc
|
||||
.mockResolvedValueOnce(batch(10))
|
||||
.mockResolvedValueOnce({ data: null, error: { message: 'boom', code: 'XX000' } })
|
||||
|
||||
const res = await GET(cronRequest())
|
||||
const body = await res.json()
|
||||
|
||||
@@ -7,16 +7,22 @@ import { errorResponse, errorResponseFromCode } from '@/lib/errors/get-structure
|
||||
* GET /api/sandbox/cleanup/cron: daily 04:00 UTC.
|
||||
* Removes expired sandbox users (>24h old).
|
||||
*
|
||||
* One teardown costs ~3s on prod (the auth.users delete fans out over ~250
|
||||
* FK triggers), so the run is bounded: BATCH_LIMIT users per night, sized to
|
||||
* finish inside both the RPC's 290s statement_timeout (migration
|
||||
* 20260807150000) and this route's maxDuration. The nightly intake is a
|
||||
* fraction of this; a backlog drains over a few nights instead of timing
|
||||
* out and rolling back wholesale.
|
||||
* Every PostgREST statement runs under authenticator's statement_timeout of
|
||||
* 8s, and a function-level SET statement_timeout does NOT lift it (the timer
|
||||
* arms when the top-level statement starts; verified empirically on prod
|
||||
* 2026-08-07, same finding as the SIE import RPCs). One teardown costs
|
||||
* ~220ms with the account_id index, so the run loops SMALL batches: each
|
||||
* rpc() call is its own statement with its own 8s window, and the loop
|
||||
* stops when a batch makes no progress (nothing left, or only failing
|
||||
* users remain) or the route's time budget nears. Capacity per night is
|
||||
* MAX_BATCHES * BATCH_LIMIT users; the nightly intake is a small fraction
|
||||
* of that.
|
||||
*/
|
||||
export const maxDuration = 300
|
||||
|
||||
const BATCH_LIMIT = 60
|
||||
const BATCH_LIMIT = 10
|
||||
const MAX_BATCHES = 25
|
||||
const TIME_BUDGET_MS = 240_000
|
||||
|
||||
export const GET = withCronContext('cron.sandbox_cleanup', async (_request, ctx) => {
|
||||
const supabaseUrl = process.env.NEXT_PUBLIC_SUPABASE_URL
|
||||
@@ -31,35 +37,52 @@ export const GET = withCronContext('cron.sandbox_cleanup', async (_request, ctx)
|
||||
|
||||
const supabase = createClient(supabaseUrl, supabaseServiceKey)
|
||||
|
||||
const { data, error } = await supabase.rpc('cleanup_expired_sandbox_users', {
|
||||
p_max_age_hours: 24,
|
||||
p_limit: BATCH_LIMIT,
|
||||
})
|
||||
const started = Date.now()
|
||||
const totals = { cleaned: 0, failed: 0, orphans_removed: 0, batches: 0 }
|
||||
|
||||
if (error) {
|
||||
ctx.log.error('sandbox cleanup rpc failed', error)
|
||||
return errorResponse(error, ctx.log, { requestId: ctx.requestId })
|
||||
for (let i = 0; i < MAX_BATCHES; i++) {
|
||||
if (Date.now() - started > TIME_BUDGET_MS) break
|
||||
|
||||
const { data, error } = await supabase.rpc('cleanup_expired_sandbox_users', {
|
||||
p_max_age_hours: 24,
|
||||
p_limit: BATCH_LIMIT,
|
||||
})
|
||||
|
||||
if (error) {
|
||||
ctx.log.error('sandbox cleanup rpc failed', { error, ...totals })
|
||||
return errorResponse(error, ctx.log, { requestId: ctx.requestId })
|
||||
}
|
||||
|
||||
// Migration 20260807130000 changed the RPC's return from a bare integer
|
||||
// to a {cleaned, failed, orphans_removed} summary; accept both shapes so
|
||||
// deploy/migration ordering cannot break the cron.
|
||||
const batch =
|
||||
typeof data === 'number'
|
||||
? { cleaned: data, failed: 0, orphans_removed: 0 }
|
||||
: {
|
||||
cleaned: Number(data?.cleaned ?? 0),
|
||||
failed: Number(data?.failed ?? 0),
|
||||
orphans_removed: Number(data?.orphans_removed ?? 0),
|
||||
}
|
||||
|
||||
totals.cleaned += batch.cleaned
|
||||
totals.failed += batch.failed
|
||||
totals.orphans_removed += batch.orphans_removed
|
||||
totals.batches += 1
|
||||
|
||||
// No progress means only permanently-failing users (retried nightly and
|
||||
// reported below) or an empty backlog: looping further would spin on the
|
||||
// same rows.
|
||||
if (batch.cleaned + batch.orphans_removed === 0) break
|
||||
}
|
||||
|
||||
// Migration 20260807130000 changed the RPC's return from a bare integer to
|
||||
// a {cleaned, failed, orphans_removed} summary; accept both shapes so
|
||||
// deploy/migration ordering cannot break the cron.
|
||||
const summary =
|
||||
typeof data === 'number'
|
||||
? { cleaned: data, failed: 0, orphans_removed: 0 }
|
||||
: {
|
||||
cleaned: Number(data?.cleaned ?? 0),
|
||||
failed: Number(data?.failed ?? 0),
|
||||
orphans_removed: Number(data?.orphans_removed ?? 0),
|
||||
}
|
||||
|
||||
// Per-user failures used to be swallowed as Postgres WARNINGs, which is how
|
||||
// the cleanup sat broken for months; surface them at error level instead.
|
||||
if (summary.failed > 0) {
|
||||
ctx.log.error('sandbox cleanup completed with failures', summary)
|
||||
if (totals.failed > 0) {
|
||||
ctx.log.error('sandbox cleanup completed with failures', totals)
|
||||
} else {
|
||||
ctx.log.info('sandbox cleanup summary', summary)
|
||||
ctx.log.info('sandbox cleanup summary', totals)
|
||||
}
|
||||
|
||||
return NextResponse.json({ success: true, ...summary })
|
||||
return NextResponse.json({ success: true, ...totals })
|
||||
})
|
||||
|
||||
Reference in New Issue
Block a user