improvement(table): debug logs at every cascade decision branch

Author: TheodoreSpeaks

apps/sim/lib/table/deps.ts

@@ -4,8 +4,11 @@
  * can import it without pulling in `@sim/db` and other server-only deps.
  */
 
+import { createLogger } from '@sim/logger'
 import type { RowData, RowExecutionMetadata, RowExecutions, TableRow, WorkflowGroup } from './types'
 
+const logger = createLogger('OptimisticCascade')
+
 /**
  * True when the cell has a worker actively reserved — `queued` / `running`,
  * or `pending` after the scheduler stamped a jobId. Single source of truth
@@ -93,28 +96,38 @@ export function optimisticallyScheduleNewlyEligibleGroups(
 
   let next: RowExecutions | null = null
   for (const group of groups) {
-    // autoRun=false groups don't auto-fire on dep-fill — leave them empty.
-    if (group.autoRun === false) continue
-    if (!areGroupDepsSatisfied(group, afterRow)) continue
+    const tag = `[OptimisticCascade] row=${beforeRow.id} group=${group.id}`
+    if (group.autoRun === false) {
+      logger.debug(`${tag} → skip: autoRun=false`)
+      continue
+    }
+    if (!areGroupDepsSatisfied(group, afterRow)) {
+      logger.debug(`${tag} → skip: deps unmet on afterRow`)
+      continue
+    }
 
     const exec = beforeRow.executions?.[group.id]
-    // Don't overwrite an in-flight state.
-    if (exec?.status === 'queued' || exec?.status === 'running') continue
-    if (exec?.status === 'pending' && exec.jobId) continue
+    if (exec?.status === 'queued' || exec?.status === 'running') {
+      logger.debug(`${tag} → skip: already ${exec.status}`)
+      continue
+    }
+    if (exec?.status === 'pending' && exec.jobId) {
+      logger.debug(`${tag} → skip: pending+jobId (worker reserved)`)
+      continue
+    }
 
-    // "completed" with all outputs filled = genuinely done; don't re-fire.
-    // "completed" with any output cleared = stale; treat as never-run.
     const isStaleCompleted = exec?.status === 'completed' && !areOutputsFilled(group, afterRow)
-
-    // Whether this group could fire is the union of:
-    //   - dep-fill: deps were unmet before, now met (the classic cascade)
-    //   - output-cleared: user wiped a previously-completed output
-    //   - retry: prior run ended in error / cancelled
     const wasSatisfied = areGroupDepsSatisfied(group, beforeRow)
     const becameSatisfied = !wasSatisfied
     const isRetryable = exec?.status === 'cancelled' || exec?.status === 'error'
-    if (!becameSatisfied && !isStaleCompleted && !isRetryable && exec) continue
+    if (!becameSatisfied && !isStaleCompleted && !isRetryable && exec) {
+      logger.debug(`${tag} → skip: no fire reason (status=${exec?.status})`)
+      continue
+    }
 
+    logger.debug(
+      `${tag} → flip to pending (becameSatisfied=${becameSatisfied} stale=${isStaleCompleted} retry=${isRetryable})`
+    )
     if (next === null) next = { ...(beforeRow.executions ?? {}) }
     const pending: RowExecutionMetadata = {
       status: 'pending',

apps/sim/lib/table/workflow-columns.ts

@@ -54,22 +54,45 @@ export function isGroupEligible(
 ): boolean {
   const isManualRun = opts?.isManualRun ?? false
   const mode = opts?.mode ?? 'all'
-  if (group.autoRun === false && !isManualRun) return false
+  const tag = `[Eligibility] row=${row.id} group=${group.id} manual=${isManualRun} mode=${mode}`
+
+  if (group.autoRun === false && !isManualRun) {
+    logger.debug(`${tag} → skip: autoRun=false on auto-fire`)
+    return false
+  }
 
   const exec = row.executions?.[group.id]
-  if (isExecInFlight(exec)) return false
+  if (isExecInFlight(exec)) {
+    logger.debug(`${tag} → skip: in-flight (status=${exec?.status})`)
+    return false
+  }
   const status = exec?.status
 
   const completedAndFilled = status === 'completed' && areOutputsFilled(group, row)
-  if (!isManualRun && completedAndFilled) return false
-  if (!isManualRun && (status === 'error' || status === 'cancelled')) return false
-  // `mode: 'incomplete'` (manual): re-runs only rows whose outputs are missing
-  // or whose last run failed. A genuinely completed cell (status + filled
-  // outputs) is skipped; error / cancelled remain runnable.
-  if (mode === 'incomplete' && completedAndFilled) return false
-
-  if (isManualRun && group.autoRun === false) return true
-  return areGroupDepsSatisfied(group, row)
+  if (!isManualRun && completedAndFilled) {
+    logger.debug(`${tag} → skip: completed+filled on auto-fire`)
+    return false
+  }
+  // Auto-fire skips `error` to avoid infinite-retry loops on a deterministic
+  // failure. `cancelled` doesn't get the same treatment — cancellation is
+  // user-initiated, and once an upstream dep re-fires the cascade, the user
+  // almost certainly wants the chain to continue.
+  if (!isManualRun && status === 'error') {
+    logger.debug(`${tag} → skip: terminal status=error on auto-fire`)
+    return false
+  }
+  if (mode === 'incomplete' && completedAndFilled) {
+    logger.debug(`${tag} → skip: completed+filled on mode=incomplete`)
+    return false
+  }
+
+  if (isManualRun && group.autoRun === false) {
+    logger.debug(`${tag} → eligible: manual on autoRun=false group (deps bypassed)`)
+    return true
+  }
+  const depsOk = areGroupDepsSatisfied(group, row)
+  logger.debug(`${tag} → ${depsOk ? 'eligible: deps satisfied' : 'skip: deps unmet'}`)
+  return depsOk
 }
 
 /**
@@ -107,6 +130,10 @@ export async function scheduleRunsForRows(
     const groups = groupIdFilter ? allGroups.filter((g) => groupIdFilter.has(g.id)) : allGroups
     if (groups.length === 0) return { triggered: 0 }
 
+    logger.debug(
+      `[Cascade] scheduleRunsForRows table=${table.id} rows=${rows.length} groups=${groups.length} manual=${opts?.isManualRun ?? false} mode=${opts?.mode ?? 'all'} scoped=${groupIdFilter ? 'yes' : 'no'}`
+    )
+
     const orderedRows = rows.length <= 1 ? rows : [...rows].sort((a, b) => a.position - b.position)
 
     const pendingRuns: RunGroupCellOptions[] = []
@@ -410,6 +437,10 @@ async function runWorkflowGroupsInternal(opts: {
   const targetGroups = groupIds ? allGroups.filter((g) => groupIds.includes(g.id)) : allGroups
   if (targetGroups.length === 0) return { triggered: 0 }
 
+  logger.info(
+    `[Cascade] [${requestId}] runWorkflowColumn table=${tableId} groups=[${targetGroups.map((g) => g.id).join(',')}] rows=${rowIds ? `[${rowIds.join(',')}]` : 'all'} mode=${mode}`
+  )
+
   const filters = [eq(userTableRows.tableId, tableId), eq(userTableRows.workspaceId, workspaceId)]
   if (rowIds && rowIds.length > 0) {
     filters.push(inArray(userTableRows.id, rowIds))