Loading...

Type: Bug
Resolution: Fixed
Priority: High
Fix Version/s: 8.19.19, 9.4.7
Affects Version/s: 9.0.0, 9.1.0, 9.2.0, 9.3.0, 9.4.0, 8.19.12, 9.4.1, 9.4.2, 9.4.3, 8.9.26, 9.4.5, 8.19.18, 9.4.6
Component/s: Maintenance - Backup / Restore
Labels:
- dob-pr
- ewt-rtb-service-operations-and-tech-entropy

Support reference count:
8
Symptom Severity:
Severity 3 - Minor
UIS:
47
Bug Fix Policy:
View Atlassian Server bug fix policy

Issue Summary

Before finishing the backup task, the DIY backup script sometimes fails to unlock Bitbucket's maintenance mode even though the disk and database backup were successful. This issue arises when Bitbucket returns an HTTP error code 409 in response to the "DELETE /mvc/maintenance/lock?token=<token-id>" API request called by DIY backup script.

This is reproducible on Data Center: yes

Steps to Reproduce

Configure DIY script with rsync for the filesystem backup and postgres DB.

INSTANCE_NAME=bitbucket
INSTANCE_TYPE=bitbucket-dc
BITBUCKET_URL=http://127.0.0.1:7990
BITBUCKET_UID=bitbucket
BITBUCKET_GID=bitbucket
BACKUP_DISK_TYPE=rsync
BACKUP_DATABASE_TYPE=postgresql
BACKUP_ARCHIVE_TYPE=tar
BITBUCKET_HOME=/opt/atlassian/application-data/bitbucket

BITBUCKET_DB=bitbucket
POSTGRES_HOST=127.0.0.1
POSTGRES_USERNAME=bitbucket
export PGPASSWORD=bitbucket
POSTGRES_PORT=5432

Run the DIY script bitbucket.diy-backup.sh a few times. While it usually succeeds, it occasionally fails to unlock Bitbucket. Below is the output when it fails to unlock the Bitbucket instance.

[bitbucket.diy-backup.sh:136 -> wait_for_bg_jobs][server] DEBUG: Disk backup finished successfully (PID=343828)
[common.sh:85 -> update_backup_progress][server] DEBUG: Running curl -L -s -f -u ******:****** http://127.0.0.1:7990/mvc/admin/backups/progress/client?token=e7600014ee7fea30cb454a7e612d7340498011f9&percentage=50
[bitbucket.diy-backup.sh:136 -> wait_for_bg_jobs][server] DEBUG: Waiting for Database backup (PID=343823)
[bitbucket.diy-backup.sh:136 -> wait_for_bg_jobs][server] DEBUG: Database backup finished successfully (PID=343823)
[common.sh:85 -> update_backup_progress][server] DEBUG: Running curl -L -s -f -u ******:****** http://127.0.0.1:7990/mvc/admin/backups/progress/client?token=e7600014ee7fea30cb454a7e612d7340498011f9&percentage=50
[bitbucket.diy-backup.sh:136 -> wait_for_bg_jobs][server] DEBUG: Waiting for Elasticsearch backup (PID=343441)
[bitbucket.diy-backup.sh:136 -> wait_for_bg_jobs][server] DEBUG: Elasticsearch backup finished successfully (PID=343441)
[common.sh:85 -> update_backup_progress][server] DEBUG: Running curl -L -s -f -u ******:****** http://127.0.0.1:7990/mvc/admin/backups/progress/client?token=e7600014ee7fea30cb454a7e612d7340498011f9&percentage=50
[common.sh:146 -> update_backup_progress][server] DEBUG: Running curl -L -s -f -u ******:****** http://127.0.0.1:7990/mvc/admin/backups/progress/client?token=e7600014ee7fea30cb454a7e612d7340498011f9&percentage=100
[common.sh:147 -> unlock_bitbucket][server] DEBUG: Running curl -L -s -f -u ******:****** http://127.0.0.1:7990/mvc/maintenance/lock?token=e7600014ee7fea30cb454a7e612d7340498011f9
[utils.sh:202 -> run][server] DEBUG: Running cleanup jobs...
[root@server atlassian-bitbucket-diy-backup]#

Expected Results

The script should successfully unlock Bitbucket once the backup is completed. A successful execution of the script produces the following events.

[bitbucket.diy-backup.sh:136 -> wait_for_bg_jobs][server] DEBUG: Disk backup finished successfully (PID=349714)
[common.sh:85 -> update_backup_progress][server] DEBUG: Running curl -L -s -f -u ******:****** http://127.0.0.1:7990/mvc/admin/backups/progress/client?token=6d876a41b00e6fea17026c3d983d9b419f3cbb48&percentage=50
[bitbucket.diy-backup.sh:136 -> wait_for_bg_jobs][server] DEBUG: Waiting for Database backup (PID=349709)
[bitbucket.diy-backup.sh:136 -> wait_for_bg_jobs][server] DEBUG: Database backup finished successfully (PID=349709)
[common.sh:85 -> update_backup_progress][server] DEBUG: Running curl -L -s -f -u ******:****** http://127.0.0.1:7990/mvc/admin/backups/progress/client?token=6d876a41b00e6fea17026c3d983d9b419f3cbb48&percentage=50
[bitbucket.diy-backup.sh:136 -> wait_for_bg_jobs][server] DEBUG: Waiting for Elasticsearch backup (PID=349684)
[bitbucket.diy-backup.sh:136 -> wait_for_bg_jobs][server] DEBUG: Elasticsearch backup finished successfully (PID=349684)
[common.sh:85 -> update_backup_progress][server] DEBUG: Running curl -L -s -f -u ******:****** http://127.0.0.1:7990/mvc/admin/backups/progress/client?token=6d876a41b00e6fea17026c3d983d9b419f3cbb48&percentage=50
[common.sh:146 -> update_backup_progress][server] DEBUG: Running curl -L -s -f -u ******:****** http://127.0.0.1:7990/mvc/admin/backups/progress/client?token=6d876a41b00e6fea17026c3d983d9b419f3cbb48&percentage=100
[common.sh:147 -> unlock_bitbucket][server] DEBUG: Running curl -L -s -f -u ******:****** http://127.0.0.1:7990/mvc/maintenance/lock?token=6d876a41b00e6fea17026c3d983d9b419f3cbb48
[server]  SUCC: Successfully completed the backup of your Bitbucket instance
[bitbucket.diy-backup.sh:0 -> main][server]  INFO: Archiving backups and cleaning up old archives
[archive-tar.sh:158 -> archive_backup][server] DEBUG: Running tar -czf /opt/backup_root/bitbucket-20241210-111101.tar.gz -C /opt/backup .
[common.sh:1 -> run_cleanup][server] DEBUG: Running cleanup jobs...
[root@server atlassian-bitbucket-diy-backup]#

Actual Results

Bitbucket returns HTTP error code 409 when DIY script send the "DELETE <Bitbucket-Base-URL>/mvc/maintenance/lock?token=<token-id>" API and Bitbucket remains in maintenance mode.
This issue happens when Bitbucket sends a successful status response to the /mvc/admin/backups/progress/client?token=<token>&percentage=100 API call, and the subsequent unlock API request arrives before Bitbucket has had a chance to release the cluster latch. It can be verified from the following access.log and atlassian-bitbucket.log.

2024-12-09 21:48:35,733 DEBUG [threadpool:thread-1] aman @SE02BOx1308x2x0 127.0.0.1 "POST /mvc/admin/backups HTTP/1.1" c.a.s.i.m.b.BackupClientPlaceholderStep Waiting for client backup progress to reach 100. Current progress: 0
2024-12-09 21:48:36,250 DEBUG [http-nio-7991-exec-6] @SE02BOx1308x4x0 127.0.0.1 "POST /mvc/admin/backups/progress/client HTTP/1.1" c.a.s.i.m.b.BackupClientPlaceholderStep New progress upd
ate from backup client: 50
2024-12-09 21:48:36,638 DEBUG [http-nio-7991-exec-7] @SE02BOx1308x5x0 127.0.0.1 "POST /mvc/admin/backups/progress/client HTTP/1.1" c.a.s.i.m.b.BackupClientPlaceholderStep New progress upd
ate from backup client: 50
2024-12-09 21:48:36,660 DEBUG [http-nio-7991-exec-10] @SE02BOx1308x6x0 127.0.0.1 "POST /mvc/admin/backups/progress/client HTTP/1.1" c.a.s.i.m.b.BackupClientPlaceholderStep New progress up
date from backup client: 50
2024-12-09 21:48:36,676 DEBUG [http-nio-7991-exec-9] @SE02BOx1308x7x0 127.0.0.1 "POST /mvc/admin/backups/progress/client HTTP/1.1" c.a.s.i.m.b.BackupClientPlaceholderStep New progress upd
ate from backup client: 100
2024-12-09 21:48:36,685 DEBUG [ForkJoinPool.commonPool-worker-2]  c.a.s.i.m.l.ClusterableLatch$UnlatchCallback Success executing on Member [10.255.0.1]:5701 - bb3c3f6b-d475-4800-a0fe-bd2953a56b30 this. Result: null
2024-12-09 21:48:36,685 DEBUG [ForkJoinPool.commonPool-worker-2]  c.a.s.i.m.l.ClusterableLatch$UnlatchCallback Execution complete. Successful - true
2024-12-09 21:48:36,685 DEBUG [threadpool:thread-1] aman @SE02BOx1308x2x0 127.0.0.1 "POST /mvc/admin/backups HTTP/1.1" c.a.s.i.m.latch.ClusterableLatch Cluster unlatch completed successfully
2024-12-09 21:48:36,685 DEBUG [ForkJoinPool.commonPool-worker-1]  c.a.s.i.m.l.ClusterableLatch$UnlatchCallback Success executing on Member [10.255.0.1]:5701 - bb3c3f6b-d475-4800-a0fe-bd2953a56b30 this. Result: null
2024-12-09 21:48:36,686 DEBUG [ForkJoinPool.commonPool-worker-1]  c.a.s.i.m.l.ClusterableLatch$UnlatchCallback Execution complete. Successful - true
2024-12-09 21:48:36,686 DEBUG [threadpool:thread-1] aman @SE02BOx1308x2x0 127.0.0.1 "POST /mvc/admin/backups HTTP/1.1" c.a.s.i.m.latch.ClusterableLatch Cluster unlatch completed successfully
2024-12-09 21:48:36,696 DEBUG [threadpool:thread-1] aman @SE02BOx1308x2x0 127.0.0.1 "POST /mvc/admin/backups HTTP/1.1" c.a.s.i.m.DefaultMaintenanceTaskMonitor BACKUP maintenance has completed successfully (Canceled: false)

127.0.0.1 | http | i@SE02BOx1308x4x0 | - | 2024-12-09 21:48:36,223 | "POST /mvc/admin/backups/progress/client HTTP/1.1" | "" "curl/7.82.0" | - | - | - | - | - | - |
127.0.0.1 | http | o@SE02BOx1308x4x0 | - | 2024-12-09 21:48:36,251 | "POST /mvc/admin/backups/progress/client HTTP/1.1" | "" "curl/7.82.0" | 202 | 0 | 0 | - | 28 | - |
127.0.0.1 | http | i@SE02BOx1308x5x0 | - | 2024-12-09 21:48:36,636 | "POST /mvc/admin/backups/progress/client HTTP/1.1" | "" "curl/7.82.0" | - | - | - | - | - | - |
127.0.0.1 | http | o@SE02BOx1308x5x0 | - | 2024-12-09 21:48:36,639 | "POST /mvc/admin/backups/progress/client HTTP/1.1" | "" "curl/7.82.0" | 202 | 0 | 0 | - | 3 | - |
127.0.0.1 | http | i@SE02BOx1308x6x0 | - | 2024-12-09 21:48:36,658 | "POST /mvc/admin/backups/progress/client HTTP/1.1" | "" "curl/7.82.0" | - | - | - | - | - | - |
127.0.0.1 | http | o@SE02BOx1308x6x0 | - | 2024-12-09 21:48:36,661 | "POST /mvc/admin/backups/progress/client HTTP/1.1" | "" "curl/7.82.0" | 202 | 0 | 0 | - | 3 | - |
127.0.0.1 | http | i@SE02BOx1308x7x0 | - | 2024-12-09 21:48:36,674 | "POST /mvc/admin/backups/progress/client HTTP/1.1" | "" "curl/7.82.0" | - | - | - | - | - | - |
127.0.0.1 | http | o@SE02BOx1308x7x0 | - | 2024-12-09 21:48:36,677 | "POST /mvc/admin/backups/progress/client HTTP/1.1" | "" "curl/7.82.0" | 202 | 0 | 0 | - | 3 | - |
127.0.0.1 | http | i@SE02BOx1308x8x0 | - | 2024-12-09 21:48:36,695 | "DELETE /mvc/maintenance/lock HTTP/1.1" | "" "curl/7.82.0" | - | - | - | - | - | - |
127.0.0.1 | http | o@SE02BOx1308x8x0 | - | 2024-12-09 21:48:36,734 | "DELETE /mvc/maintenance/lock HTTP/1.1" | "" "curl/7.82.0" | 409 | 0 | 97 | - | 39 | - |

Workaround

Unlock the Bitbucket instance by running the same unlock API.

curl -L -s -f -u <user>:<password> -X DELETE <Bitbucket-Base-URL>/mvc/maintenance/lock?token=<token-id>

Alternatively, adjust the unlock_bitbucket function in the common.sh script to include a 1-2 second delay, as shown in the below example, before invoking the unlock API.
Note: This is just an example since DIY scripts are customised and set up by customers as per their environment, so be sure to adjust the code appropriately.

 # Unlock a previously locked Bitbucket instance
function unlock_bitbucket {
    if [ "${BACKUP_ZERO_DOWNTIME}" = "true" ]; then
        return
    fi

    remove_cleanup_routine unlock_bitbucket
    /usr/bin/sleep 2;
    run curl ${CURL_OPTIONS} -u "${BITBUCKET_BACKUP_USER}:${BITBUCKET_BACKUP_PASS}" -X DELETE -H "Accept: application/json" \
        -H "Content-type: application/json" "${BITBUCKET_URL}/mvc/maintenance/lock?token=${BITBUCKET_LOCK_TOKEN}"
}

causes: PS-177041 Loading...

mentioned in: Page Loading...; Page Loading...; Page Loading...; Page Loading...; Page Loading...

(1 mentioned in)

Details

Description

Issue Summary

Steps to Reproduce

Expected Results

Actual Results

Workaround

Attachments

Issue Links

Forms

Activity

People

Dates