Bamboo 7 - Branch Plan Deletion deletes Stages and Jobs

[Florian_Brinker]

Hey everyone,

we are very confused. We've enabled Plan Branches for PRs and enabled both "Delete Plan Branch" options to clean up after a merge.

But if a branch gets merged, it deletes all Stages and Jobs of the entire Plan, not only the plan for the branch, it deletes the Master Build Stages and Jobs too..!

With the help of the audit log we could see that it happens right after a merge and therefore branch deletion and the triggered cleanup.

This is the log output:

2020-04-06 09:03:20,653 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-4] [BranchDeletedEventListener] Received stash branch deletion event [PRJ, feature/xxx-13280-yyy]
2020-04-06 09:03:20,688 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [PlanBranchTerminator] BRANCHTERMINATOR: will delete plan branches with keys PRJ-TCD5, PRJ-UT7157
2020-04-06 09:03:20,689 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-4] [ChainBranchManagerImpl] Marking VCS branch feature/xxx-13280-yyy of chain branch PRJ-TCD5 as removed because its name matches feature/xxx-13280-yyy
2020-04-06 09:03:20,690 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [DeletionServiceImpl] Deleting plan PRJ-TCD5
2020-04-06 09:03:20,694 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [DeletionServiceImpl] Stopping any running builds for PRJ-TCD5
2020-04-06 09:03:20,696 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [DeletionServiceImpl] Scheduling plan [PRJ-TCD5] for deletion
2020-04-06 09:03:20,698 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [DeletionServiceImpl] Stopping any running builds for PRJ-TCD5-PL
2020-04-06 09:03:20,705 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-4] [AbstractQuartzTriggerActivator] Scheduler job repository.change.jobs.CHAIN:PRJ-TCD5:0 not found, not deleted
2020-04-06 09:03:20,705 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-4] [ChainBranchManagerImpl] Chain branch PRJ-TCD5 was disabled because its VCS branch was deleted
2020-04-06 09:03:20,718 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [DeletionServiceImpl] Stopping any running builds for PRJ-TCD5-JL
2020-04-06 09:03:20,723 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-4] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD5
2020-04-06 09:03:20,732 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-4] [ChainBranchManagerImpl] Marking VCS branch feature/xxx-13280-yyy of chain branch PRJ-UT7157 as removed because its name matches feature/xxx-13280-yyy
2020-04-06 09:03:20,765 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [DeletionServiceImpl] Stopping any running builds for PRJ-TCD5-FT
2020-04-06 09:03:20,803 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [DeletionServiceImpl] Stopping any running builds for PRJ-TCD5-TP
2020-04-06 09:03:20,873 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [DeletionServiceImpl] Deleting plan PRJ-UT7157
2020-04-06 09:03:20,875 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [AbstractQuartzTriggerActivator] Scheduler job repository.change.jobs.CHAIN:PRJ-UT7157:0 not found, not deleted
2020-04-06 09:03:20,875 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [DeletionServiceImpl] Stopping any running builds for PRJ-UT7157
2020-04-06 09:03:20,877 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [DeletionServiceImpl] Scheduling plan [PRJ-UT7157] for deletion
2020-04-06 09:03:20,917 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [MultipleChainsDeletedEvent] Deleted chain: PRJ-TCD5
2020-04-06 09:03:20,917 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [MultipleChainsDeletedEvent] Deleted chain: PRJ-UT7157
2020-04-06 09:03:20,921 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [MultipleJobsDeletedEvent] Deleted job: PRJ-TCD5-FT
2020-04-06 09:03:20,921 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [MultipleJobsDeletedEvent] Deleted job: PRJ-TCD5-JL
2020-04-06 09:03:20,921 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [MultipleJobsDeletedEvent] Deleted job: PRJ-TCD5-PL
2020-04-06 09:03:20,921 INFO [AtlassianEvent::0-BAM::EVENTS:pool-1-thread-2] [MultipleJobsDeletedEvent] Deleted job: PRJ-TCD5-TP
2020-04-06 09:03:23,076 INFO [DelayedDeletionThread] [PlanHibernateDao] 4 jobs have incorrectly set deletion flags, updating them
2020-04-06 09:03:23,076 INFO [DelayedDeletionThread] [PlanHibernateDao] Job: PRJ-TCD-PL being updated.
2020-04-06 09:03:23,077 INFO [DelayedDeletionThread] [PlanHibernateDao] Job: PRJ-TCD-JL being updated.
2020-04-06 09:03:23,078 INFO [DelayedDeletionThread] [PlanHibernateDao] Job: PRJ-TCD-TP being updated.
2020-04-06 09:03:23,079 INFO [DelayedDeletionThread] [PlanHibernateDao] Job: PRJ-TCD-FT being updated.
2020-04-06 09:03:23,108 INFO [DelayedDeletionThread] [DeletionServiceHelper] Deleting 4 job(s) marked for deletion
2020-04-06 09:03:23,108 INFO [DelayedDeletionThread] [DeletionServiceHelper] Deleting PRJ-TCD-TP
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD10
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD12
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD11
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD17
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD9
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD14
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD8
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD13
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD16
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD15
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD4
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD7
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD6
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD1
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD0
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD3
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD2
2020-04-06 09:03:23,164 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating PRJ-TCD
2020-04-06 09:03:23,165 INFO [DelayedDeletionThread] [DeletionServiceHelper] Deleting PRJ-TCD-PL
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD10
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD12
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD11
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD17
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD9
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD14
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD8
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD13
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD16
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD15
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD4
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD7
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD6
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD1
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD0
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD3
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD2
2020-04-06 09:03:23,230 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD
2020-04-06 09:03:23,231 INFO [DelayedDeletionThread] [DeletionServiceHelper] Deleting PRJ-TCD-JL
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD10
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD12
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD11
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD17
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD9
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD14
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD8
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD13
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD16
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD15
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD4
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD7
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD6
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD1
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD0
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD3
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD2
2020-04-06 09:03:23,285 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD
2020-04-06 09:03:23,286 INFO [DelayedDeletionThread] [DeletionServiceHelper] Deleting PRJ-TCD-FT
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD10
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD12
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD11
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD17
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD9
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD14
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD8
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD13
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD16
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD15
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD4
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD7
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD6
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD1
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD0
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD3
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD2
2020-04-06 09:03:23,339 INFO [DelayedDeletionThread] [ImmutablePlanCacheServiceImpl] Invalidating, plan is not in cache or is being loaded: PRJ-TCD
2020-04-06 09:03:23,340 INFO [scheduler_Worker-7] [DeletionServiceHelper] Completed background deletion in 267.8 ms
2020-04-06 09:03:23,350 INFO [DelayedDeletionThread] [DeletionServiceHelper] Deleting 2 stage(s) marked for deletion
2020-04-06 09:03:23,351 INFO [DelayedDeletionThread] [PlanManagerImpl] Removing 2 stage(s) for plan PRJ-TCD

The most interesting part is the following, and what happens afterwards:

2020-04-06 09:03:23,076 INFO [DelayedDeletionThread] [PlanHibernateDao] 4 jobs have incorrectly set deletion flags, updating them

And it deletes the main jobs afterwards. Why!?

[Marcin Gardias · Accepted solution]

What is PlanBranchTerminator? It's not part of Bamboo, is it?

In any case, it looks like a bug, but I think the bug is only triggered because of the 'Terminator' plugin.

Workaround:

- disable the plugin until the bug is fixed

- if you, by chance, are in control of the plugin, modify it so that it doesn't call deletionsService using 'ImmutablePlanBranch'. Use mutable object instead, like this:

PlanManager planManager; //not cachedPlanManager!

//......
private void deleteMutableRepresentationOfBranch(final ImmutableChainBranch chainBranch) {
    final Plan mutableBranch = planManager.getPlanById(chainBranch.getId());
    if (mutableBranch != null) {
        try {
            deletionService.deletePlan(mutableBranch);
        } catch (final RuntimeException e) {
            log.warn("Unable to delete chain branch " + chainBranch.getPlanKey(), e);
        }
    }
}

,Public issue for you to track: https://jira.atlassian.com/browse/BAM-20889

[Florian_Brinker]

Thank you!

Since I'm a new admin for this bamboo instance I didn't recognize it as an addon, but it is. I've disabled it and the master plan is still intact.