#1380

Hub startup spends seconds to minutes in managed-thread PMA recovery after restart

OpenGit-on-my-levelopened 6mo ago

Observed on the hub process (codex-autorunner hub serve) after restart: CPU spikes to ~98-100% during deferred startup, and the startup phase repeatedly spends most of its time in managed_thread_restore.

Evidence:

  • Hub log shows repeated deferred startup runs with large managed_thread_restore durations: 6.8s, 12.4s, 23.5s, 93.0s, 105.5s, 55.5s, etc.
  • The same log shows discord.turn.progress_reconcile_startup_finished after startup, which suggests the Discord PMA recovery path is also active on restart.
  • A live sample of the hot hub PID showed time in JSON parsing and SQLite execution, not an obvious recursion stack. That points to expensive startup/state scanning rather than a tight call recursion.

Likely hot paths:

  • src/codex_autorunner/surfaces/web/app.py deferred startup: recover_orphaned_managed_thread_executions(), restart_managed_thread_queue_workers(), reap_managed_processes(), and mount_manager.start_repo_lifespans().
  • src/codex_autorunner/surfaces/web/routes/pma_routes/managed_thread_runtime_control.py: recover_orphaned_executions() scans list_thread_ids_with_running_executions(); restart_queue_workers() scans list_thread_ids_with_pending_queue().
  • src/codex_autorunner/integrations/discord/service.py: startup reconciliation runs reconcile_discord_turn_progress_leases() and _resume_interaction_recovery().
  • src/codex_autorunner/integrations/discord/message_turns.py: reconcile_discord_turn_progress_leases() walks leases and may perform per-lease lookups + message edits.

Existing tests that exercise pieces of this path:

  • tests/test_hub_issue_1266.py::test_hub_health_serves_before_deferred_startup_work_finishes
  • tests/surfaces/web/routes/pma_routes/test_managed_thread_runtime.py::test_restart_managed_thread_queue_workers_restores_pending_threads
  • tests/surfaces/web/routes/pma_routes/test_managed_thread_runtime.py::test_recover_orphaned_managed_thread_executions_unblocks_restart_queue
  • tests/surfaces/web/routes/pma_routes/test_managed_thread_runtime.py::test_recover_orphaned_managed_thread_executions_recovers_pma_runs_on_chat_bound_threads
  • tests/test_discord_message_turn_background_failures.py::test_startup_reconciles_orphaned_progress_leases
  • tests/test_discord_message_turn_background_failures.py::test_startup_reconciles_progress_leases_stuck_in_retiring_state

Gap:

  • I do not yet have a repro that proves a specific infinite loop or re-entrant restart cycle. Current evidence looks more like repeated expensive scans / recovery passes on restart, amplified by the size of orchestration state.

Activity

1
Git-on-my-level6mo ago

Additional evidence from local profiling/state inspection:

  • /Users/dazheng/car-workspace/.codex-autorunner/orchestration.sqlite3 is 2.1 GB.
  • dbstat shows orch_event_projections alone is about 1789.4 MB, with indexes adding another ~325 MB.
  • orch_event_projections is almost entirely event_family='turn.timeline': 1,610,583 rows / 1211.7 MB.
  • By event type, the biggest contributors are:
    • output_delta: 1,530,177 rows / 739.0 MB
    • run_notice: 45,769 rows / 445.6 MB
  • One execution (f6a7def0-1a2a-4edd-8626-ba3c857b18f1) alone accounts for 35,811 timeline rows / 413.9 MB, of which 34,096 are run_notice rows averaging 12.3 KB each.
  • A sampled run_notice payload contains a long model thinking/audit message body, not just metadata. The same string fragment ("Now I have all the data. Let me compile a comprehensive audit...") appears in 10,137 persisted run_notice rows for that single execution.

This suggests a second amplifier beyond restart-time scans: we are persisting large, repeated notice/thinking bodies into turn.timeline, likely without dedupe/compaction and possibly with cumulative text rather than small deltas. That both inflates the DB and makes restart recovery / resume / timeline reads progressively more expensive.

Relevant code paths to inspect next:

  • src/codex_autorunner/core/orchestration/turn_timeline.py (persist_turn_timeline stores full RunNotice.message into payload_json)
  • src/codex_autorunner/core/orchestration/runtime_thread_events.py (maps agent_thought_chunk / ACP progress into RunNotice)
  • src/codex_autorunner/core/acp_lifecycle.py and agent backends that may surface cumulative thinking/progress text rather than bounded deltas.