Skip to content

fix: add debug logging to AI lifecycle loop #2110

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
marcusquinn merged 2 commits into from
Feb 21, 2026
Merged

fix: add debug logging to AI lifecycle loop #2110

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
4a8f39b
fix: skip Phase 4b2 legacy pr_review recovery when AI lifecycle is ac…
marcusquinn Feb 21, 2026
1e5adb7
fix: add debug logging to AI lifecycle loop to diagnose 1-per-pulse b…
marcusquinn Feb 21, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
7 changes: 7 additions & 0 deletions .agents/scripts/supervisor/ai-lifecycle.sh
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -912,6 +912,10 @@ process_ai_lifecycle() {
local merged_parents=""
local repos_with_changes=""

local total_eligible=0
total_eligible=$(printf '%s\n' "$eligible_tasks" | grep -c '.' || echo "0")
Copy link
Copy Markdown

@gemini-code-assist gemini-code-assist bot Feb 21, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

medium

The use of || echo "0" as a guard for grep -c is functionally correct, but for commands that may fail under set -e, the recommended practice is to use || true to prevent premature script termination. While grep -c already outputs 0 to stdout even when no matches are found (though it exits with code 1), || true ensures adherence to the set -e safety pattern.

Suggested change
total_eligible=$(printf '%s\n' "$eligible_tasks" | grep -c '.' || echo "0")
total_eligible=$(printf '%s\n' "$eligible_tasks" | grep -c '.' || true)
References
  1. Use || true guards for commands that may fail under set -e (grep, arithmetic) (link)
  2. In shell scripts with 'set -e' enabled, use '|| true' to prevent the script from exiting when a command like 'jq' fails on an optional lookup.

log_info "ai-lifecycle: $total_eligible eligible tasks"

while IFS='|' read -r tid tstatus tpr trepo; do
Copy link
Copy Markdown

@gemini-code-assist gemini-code-assist bot Feb 21, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

high

Regarding the issue where only one task is processed per cycle: if process_task_lifecycle (called inside this loop) executes commands that read from stdin (like gh, opencode, or ssh), it will consume the remaining lines of $eligible_tasks, causing the loop to terminate early. To prevent this, ensure all commands inside the loop have their stdin redirected from /dev/null.

[[ -z "$tid" ]] && continue

Expand Down Expand Up @@ -944,6 +948,7 @@ process_ai_lifecycle() {
# Check if a merge happened
local new_status
new_status=$(db "$SUPERVISOR_DB" "SELECT status FROM tasks WHERE id = '$(sql_escape "$tid")';" 2>/dev/null || echo "")
log_info "ai-lifecycle: $tid → $new_status"
case "$new_status" in
merged | deploying | deployed)
merged_count=$((merged_count + 1))
Expand All @@ -956,6 +961,8 @@ process_ai_lifecycle() {
fi
;;
esac
else
log_warn "ai-lifecycle: $tid failed (process_task_lifecycle returned non-zero)"
fi

# Track repos that had status tag changes
Expand Down
62 changes: 34 additions & 28 deletions .agents/scripts/supervisor/pulse.sh
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2641,45 +2641,51 @@ RULES:
fi

# Phase 4b2: Stale pr_review recovery (t1208)
# Tasks in 'pr_review' are processed by Phase 3 (process_post_pr_lifecycle) each
# pulse. However, if cmd_pr_lifecycle fails repeatedly or the PR is in an
# unexpected state, the task can get stuck in pr_review indefinitely.
# After SUPERVISOR_PR_REVIEW_STALE_SECONDS (default 3600 = 1h), force a
# re-attempt via cmd_pr_lifecycle. If that also fails, log a warning so the
# operator can investigate — do NOT auto-fail pr_review tasks since the PR
# may be legitimately waiting for CI or human review.
local pr_review_stale_seconds="${SUPERVISOR_PR_REVIEW_STALE_SECONDS:-3600}"
local stale_pr_review
stale_pr_review=$(db -separator '|' "$SUPERVISOR_DB" "
# When AI lifecycle is active, Phase 3 handles all pr_review tasks via
# process_ai_lifecycle — skip legacy cmd_pr_lifecycle to avoid clobbering
# AI decisions (e.g., marking tasks as "Merge failed" when the AI already
# decided to escalate or wait).
if [[ "${SUPERVISOR_AI_LIFECYCLE:-true}" != "true" ]]; then
# Tasks in 'pr_review' are processed by Phase 3 (process_post_pr_lifecycle) each
# pulse. However, if cmd_pr_lifecycle fails repeatedly or the PR is in an
# unexpected state, the task can get stuck in pr_review indefinitely.
# After SUPERVISOR_PR_REVIEW_STALE_SECONDS (default 3600 = 1h), force a
# re-attempt via cmd_pr_lifecycle. If that also fails, log a warning so the
# operator can investigate — do NOT auto-fail pr_review tasks since the PR
# may be legitimately waiting for CI or human review.
local pr_review_stale_seconds="${SUPERVISOR_PR_REVIEW_STALE_SECONDS:-3600}"
local stale_pr_review
stale_pr_review=$(db -separator '|' "$SUPERVISOR_DB" "
SELECT id, pr_url, updated_at
FROM tasks
WHERE status = 'pr_review'
AND updated_at < strftime('%Y-%m-%dT%H:%M:%SZ', 'now', '-${pr_review_stale_seconds} seconds')
ORDER BY updated_at ASC;
" 2>/dev/null || echo "")

if [[ -n "$stale_pr_review" ]]; then
local pr_review_recovered=0
while IFS='|' read -r spr_id spr_pr_url spr_updated; do
[[ -n "$spr_id" ]] || continue
log_warn " Stale pr_review: $spr_id (last updated: ${spr_updated:-unknown}, >${pr_review_stale_seconds}s) — re-attempting lifecycle (t1208)"
if cmd_pr_lifecycle "$spr_id" 2>>"$SUPERVISOR_LOG"; then
local spr_new_status
spr_new_status=$(db "$SUPERVISOR_DB" "SELECT status FROM tasks WHERE id = '$(sql_escape "$spr_id")';" 2>/dev/null || echo "")
if [[ "$spr_new_status" != "pr_review" ]]; then
log_info " Phase 4b2: $spr_id advanced from pr_review → $spr_new_status"
pr_review_recovered=$((pr_review_recovered + 1))
if [[ -n "$stale_pr_review" ]]; then
local pr_review_recovered=0
while IFS='|' read -r spr_id spr_pr_url spr_updated; do
[[ -n "$spr_id" ]] || continue
log_warn " Stale pr_review: $spr_id (last updated: ${spr_updated:-unknown}, >${pr_review_stale_seconds}s) — re-attempting lifecycle (t1208)"
if cmd_pr_lifecycle "$spr_id" 2>>"$SUPERVISOR_LOG"; then
local spr_new_status
spr_new_status=$(db "$SUPERVISOR_DB" "SELECT status FROM tasks WHERE id = '$(sql_escape "$spr_id")';" 2>/dev/null || echo "")
if [[ "$spr_new_status" != "pr_review" ]]; then
log_info " Phase 4b2: $spr_id advanced from pr_review → $spr_new_status"
pr_review_recovered=$((pr_review_recovered + 1))
else
log_warn " Phase 4b2: $spr_id still in pr_review after lifecycle attempt — may need manual review (PR: ${spr_pr_url:-none})"
fi
else
log_warn " Phase 4b2: $spr_id still in pr_review after lifecycle attempt — may need manual review (PR: ${spr_pr_url:-none})"
log_warn " Phase 4b2: cmd_pr_lifecycle failed for stale $spr_id — will retry next pulse (PR: ${spr_pr_url:-none})"
fi
else
log_warn " Phase 4b2: cmd_pr_lifecycle failed for stale $spr_id — will retry next pulse (PR: ${spr_pr_url:-none})"
done <<<"$stale_pr_review"
if [[ "$pr_review_recovered" -gt 0 ]]; then
log_info " Phase 4b2: $pr_review_recovered stale pr_review task(s) advanced"
fi
done <<<"$stale_pr_review"
if [[ "$pr_review_recovered" -gt 0 ]]; then
log_info " Phase 4b2: $pr_review_recovered stale pr_review task(s) advanced"
fi
fi
fi # End of Phase 4b2 legacy guard (SUPERVISOR_AI_LIFECYCLE != true)

# Phase 4c: Cancel stale diagnostic subtasks whose parent is already resolved
# Diagnostic tasks (diagnostic_of != NULL) become stale when the parent task
Expand Down
Loading