Issue Summary

There are inaccurate DEBUG log entries when the endpoint for triggering a "full indexing sync" for code search (POST /rest/indexing/latest/sync) is called more than once.

This is reproducible on Data Center: yes

Steps to Reproduce

• Enable debug logging for Bitbucket
• Call the POST /rest/indexing/latest/sync endpoint to trigger a full indexing sync
  • Note the job id written in the atlassian-bitbucket.log file:

    2025-02-17 12:01:31,720 DEBUG [Caesium-1-8]  c.a.b.i.s.c.cluster.ClusterJobRunner Job has started: 818e8a09-e8a5-4fab-b9b5-269079591854
    

• While the first job is still running, call the  POST /rest/indexing/latest/sync endpoint again.
  • A log entry is written indicating that the first job with id 818e8a09-e8a5-4fab-b9b5-269079591854 has not run and is being 'un-scheduled'

    2025-02-17 12:20:33,621 DEBUG [http-nio-127.0.0.1-7990-exec-1] admin *1UEBNH5x740x6620060x15 127.0.0.1 "POST /rest/indexing/latest/sync HTTP/1.1" c.a.b.i.s.c.c.ClusterJobScheduler Un-scheduling job that has not been run.  Job key: com.atlassian.bitbucket.internal.search.indexing.jobs.SearchSynchronizeJob  Job ID: 818e8a09-e8a5-4fab-b9b5-269079591854
    

  • Another log entry is written for the second job indicating that the job has started

    2025-02-17 12:20:33,626 DEBUG [Caesium-1-3]  c.a.b.i.s.c.cluster.ClusterJobRunner Job has started: e1d2c855-e2a9-4036-9511-c1171d495eed
    2025-02-17 12:20:33,627 DEBUG [Caesium-1-3]  c.a.b.i.s.c.cluster.ClusterJobRunner Job is already taken, no action is required. Job key: com.atlassian.bitbucket.internal.search.indexing.jobs.SearchSynchronizeJob
    

     

The log entries after the second job was triggered are inaccurate because:

• the first job is still running, so the logs should not indicate that is has not run (" Un-scheduling job that has not been run")
• the second job did not run at all, so the logs should not indicate it has started ("Job has started")

Expected Results

Logs should not indicate that the first job has not run and that the second job has started.

Actual Results

A log entry is written indicating that the first job has not run and is being 'un-scheduled', even though it has actually run:

2025-02-17 12:20:33,621 DEBUG [http-nio-127.0.0.1-7990-exec-1] admin *1UEBNH5x740x6620060x15 127.0.0.1 "POST /rest/indexing/latest/sync HTTP/1.1" c.a.b.i.s.c.c.ClusterJobScheduler Un-scheduling job that has not been run.  Job key: com.atlassian.bitbucket.internal.search.indexing.jobs.SearchSynchronizeJob  Job ID: 818e8a09-e8a5-4fab-b9b5-269079591854

Another log entry is written for the second job indicating that the job has started, even though it did not run because the job is already taken by the first one

2025-02-17 12:20:33,626 DEBUG [Caesium-1-3]  c.a.b.i.s.c.cluster.ClusterJobRunner Job has started: e1d2c855-e2a9-4036-9511-c1171d495eed
2025-02-17 12:20:33,627 DEBUG [Caesium-1-3]  c.a.b.i.s.c.cluster.ClusterJobRunner Job is already taken, no action is required. Job key: com.atlassian.bitbucket.internal.search.indexing.jobs.SearchSynchronizeJob

Workaround

Currently there is no known workaround for this behavior. A workaround will be added here when available