Augur "forgets" about a running task

[MoralCode]

What Happens/symptoms:

1. a task begins running in augur
2. something happens
3. rabbitmq logs show the following error (could also be logged as a warning):

2025-10-14 15:37:05.560429+00:00 [error] <0.1187.0> Error on AMQP connection <0.1187.0> (172.18.0.5:48982 -> 172.18.0.3:5672, vhost: 'augur_vhost', user: 'augur', state: running), channel 0:
2025-10-14 15:37:05.560429+00:00 [error] <0.1187.0>  operation none caused a connection exception connection_forced: "broker forced connection closure with reason 'shutdown'"

4. the task remains in a "started" state in flower forever. counting flower tasks shows processed = failed + succeeded - 1
5. according to Augur's DB the task is still running (i.e.
   SELECT cs.* FROM augur_operations.collection_status AS cs WHERE (core_status <> 'Success') or (secondary_status <> 'Success') or (facade_status <> 'Success') shows atask "collecting"

This seems to affect facade

So far all instances of this have been on rabbitmq 3.12.14 since the fix for #3255 hasnt fully shipped yet

[MoralCode]

this discussion on rabbits repo seems to suggest that something about the application code may be preventing rabbit heartbeats for 2 minutes and causing this. unsure if that applies here because we see this anywhere from a few to a dozen times a month or so, so its probably somewhat intermittent. the logs also dont indicate missing heartbeats

[MoralCode]

this google groups thread seems to also start drilling down into the "broker forced connection closure" part: https://groups.google.com/g/rabbitmq-users/c/a_zJuidbHic?pli=1

[MoralCode]

@sgoggins posted this SQL query in the 10/28 augur meeting as a band-aid/way to fix (by marking as collected) facade tasks that may have been forgotten about if theres a rabbit connection issue (i.e. the tasks keep running and the commit counts match between the clone and what GH says they should be, but because rabbit forgets about it, they maybe dont get marked as completed)

Use with caution

WITH counts AS (
    SELECT c.repo_id, COUNT(DISTINCT c.cmt_commit_hash)::bigint AS commits_captured
    FROM augur_data.commits c
    GROUP BY c.repo_id
),
eligible AS (
    SELECT a.repo_id
    FROM augur_operations.collection_status a
    LEFT JOIN counts cnt ON cnt.repo_id = a.repo_id
    WHERE a.facade_status = 'Collecting'
    AND COALESCE(cnt.commits_captured, 0) >= a.commit_sum
)
UPDATE augur_operations.collection_status cs
SET facade_status = 'Success',
    facade_data_last_collected = NOW(),
    facade_task_id = NULL
FROM eligible e
WHERE cs.repo_id = e.repo_id
RETURNING cs.repo_id;

[shlokgilda]

I think I found the cause here, and it's also causing #3321.

The issue is in analyze_commits_in_parallel (facade_tasks.py:227-338). This task processes all missing commits in one blocking loop - for large repos, this can take 30+ minutes without yielding control back to Celery. The worker can't send heartbeats during this, so RabbitMQ times out and closes the connection with that "broker forced connection closure" error.

The problem is that when the connection closes, the task stays in "started" state in Flower and the database never gets update from facade_status = 'Collecting'. The on_failure handler doesn't trigger for connection losses, only for actual exceptions.

What makes this worse: augur_collection_monitor counts repos with facade_status = 'Collecting' to check capacity (max 30). So these orphaned tasks make it think workers are busy, and it refuses to schedule new facade tasks. That's why #3321 happens - restart runs clean_collection_status() which clears the orphaned states.

Quick fixes I'd suggest:

1. Add heartbeat config: broker_heartbeat = 120, task_time_limit = 7200 in celery_app.py
2. Chunk the commit processing loop to yield every 'X' commits (maybe 500, 1000? not sure what the right config should be here?)
3. Add a periodic cleanup task (every 15 min) to reset tasks stuck in Collecting for >1 hour

The startup cleanup at backend.py:393 already has the right logic, we just need it running periodically instead of only at
restart.

Please correct me if I misunderstood the flow of operations. Happy to discuss further.

[MoralCode]

for large repos, this can take 30+ minutes without yielding control back to Celery.

This is a really interesting idea that I think could be worth testing. I havent personally seen this rabbit "forgetting" issue in a while though.

[shlokgilda]

After re-looking at the code more carefully - by "forgetting" I meant that when RabbitMQ closes the connection due to missing heartbeats, the task might stay in "started" state in Flower while the database stays at facade_status='Collecting'.

I think the issue might be In analyze_commits_in_parallel (facade_tasks.py:300-332). There's a for loop that processes all missing commits without breaking. There's no broker_heartbeat configured in celery_app.py (defaults to 2 seconds), so my theory is that during long git operations in analyze_commit, the worker can't send heartbeats and RabbitMQ closes the connection.

When the connection closes during execution, I think the task chain breaks. Even if the actual facade work completes (commits get collected), the success handler facade_task_success_util() at the end of the chain might not run, so the database doesn't get updated to facade_status='Success'. This could explain the SQL workaround you posted - repos with all commits collected but stuck in 'Collecting' status.

If you haven't seen this recently though, maybe it's rare enough that it's not worth fixing? Could check if there are any repos currently stuck in facade_status='Collecting' where commits_captured >= commit_sum to see if it's still occurring.

[shlokgilda]

Update: I can confirm this is happening on my system. I have 10 repos stuck in facade_status='Collecting' where actual_commits = expected_commits (work is complete) but facade_data_last_collected IS NULL (success handler never ran).

Example:
https://github.com/apache/commons-codec | Collecting | 3221 expected | 3221 collected | last_collected: NULL

All 10 have task IDs, so they were marked as started. The commits are in the database, so the facade work completed. But they never got marked as 'Success', which I think matches the theory that the success handler facade_task_success_util() at the end of the task chain never executed.

Here's the SQL query I ran. Could someone verify if my query makes sense?

WITH counts AS (
    SELECT c.repo_id, COUNT(DISTINCT c.cmt_commit_hash)::bigint AS commits_captured
    FROM augur_data.commits c
    GROUP BY c.repo_id
)
SELECT
    r.repo_git,
    a.facade_status,
    a.commit_sum as expected_commits,
    COALESCE(cnt.commits_captured, 0) as actual_commits,
    CASE
        WHEN COALESCE(cnt.commits_captured, 0) >= a.commit_sum THEN 'STUCK (work complete)'
        ELSE 'Still processing'
    END as status,
    a.facade_data_last_collected as last_collected,
    a.facade_task_id
FROM augur_operations.collection_status a
LEFT JOIN counts cnt ON cnt.repo_id = a.repo_id
LEFT JOIN augur_data.repo r ON r.repo_id = a.repo_id
WHERE a.facade_status = 'Collecting'
ORDER BY COALESCE(cnt.commits_captured, 0) >= a.commit_sum DESC, r.repo_git;