-
Bug
-
Resolution: Fixed
-
High
-
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
-
8
-
Severity 3 - Minor
-
47
-
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}" }