jenkinsci / jenkinsci/branch-api-plugin
[JENKINS-48996] jenkins.branch.MultiBranchProject disregards quick delete and recreation via branch webhooks.
- Dominant language
- Java
- Stars
- 39
- Forks
- 154
- PR merge metrics
- No merged PRs in 30d
Description
Bug:
When you delete a branch and create it again within seconds (2 seconds) on your remote Bitbucket server, jenkins is not done processing the remove event when the create event comes, preventing it from starting a new job.
Steps to reproduce:
create a branch called eg. test/sal and let it run until finish.
After that, redo the last commit, and delete the remote branch and push again
```
git commit -a --amend -C HEAD && date && git push origin :test/sal ; sleep 2 && git push origin test/sal && date
```
result:
Sometimes (every second time, but varying) the trigger is not executed.
Bad run logs:
```
==> logs/jenkins.branch.MultiBranchProject.log <==
[Tue Jan 16 08:44:43 UTC 2018] Received com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 REMOVED event from 10.240.2.28 ⇒ https://jenkins.acme.com:8080/dsw/bitbucket-scmsource-hook/notify with timestamp Tue Jan 16 08:44:43 UTC 2018
Found match against pipeline-ntdrv
[Tue Jan 16 08:44:51 UTC 2018] Finished processing com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 REMOVED event from 10.240.2.28 ⇒ https://jenkins.acme.com:8080/dsw/bitbucket-scmsource-hook/notify with timestamp Tue Jan 16 08:44:43 UTC 2018. Matched 1.
==> logs/jenkins.branch.MultiBranchProject.log <==
[Tue Jan 16 08:44:48 UTC 2018] Received com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 CREATED event from 10.240.2.28 ⇒ https://jenkins.acme.com:8080/dsw/bitbucket-scmsource-hook/notify with timestamp Tue Jan 16 08:44:48 UTC 2018
[Tue Jan 16 08:44:48 UTC 2018] Finished processing com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 CREATED event from 10.240.2.28 ⇒ https://jenkins.acme.com:8080/dsw/bitbucket-scmsource-hook/notify with timestamp Tue Jan 16 08:44:48 UTC 2018. Matched 0.
```
Good
```
==> logs/jenkins.branch.MultiBranchProject.log <==
[Tue Jan 16 08:46:35 UTC 2018] Received com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 REMOVED event from 10.240.2.28 ⇒ https://jenkins.acme.com:8080/dsw/bitbucket-scmsource-hook/notify with timestamp Tue Jan 16 08:46:35 UTC 2018
Found match against pipeline-ntdrv
[Tue Jan 16 08:46:43 UTC 2018] Finished processing com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 REMOVED event from 10.240.2.28 ⇒ https://jenkins.acme.com:8080/dsw/bitbucket-scmsource-hook/notify with timestamp Tue Jan 16 08:46:35 UTC 2018. Matched 1.
==> logs/jenkins.branch.MultiBranchProject.log <==
[Tue Jan 16 08:46:39 UTC 2018] Received com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 CREATED event from 10.240.2.28 ⇒ https://jenkins.acme.com:8080/dsw/bitbucket-scmsource-hook/notify with timestamp Tue Jan 16 08:46:39 UTC 2018
Found match against pipeline-ntdrv (resurrect branch test/sal-cd382)
[Tue Jan 16 08:46:48 UTC 2018] Finished processing com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 CREATED event from 10.240.2.28 ⇒ https://jenkins.acme.com:8080/dsw/bitbucket-scmsource-hook/notify with timestamp Tue Jan 16 08:46:39 UTC 2018. Matched 1.
```
Notice the timestamps for "Received/Finished".
In the bad example, REMOVED event processing does not finish until after the CREATED event is started and finished. In the good example, the REMOVED event does finish after CREATED starts, but before it finishes. This does indeed allow for a scenario where the processing of the CREATED event races with the REMOVED event.
---
Originally reported by sofusalbertsen, imported from: jenkins.branch.MultiBranchProject disregards quick delete and recreation via branch webhooks.
Raw content of original issue
Bug:
When you delete a branch and create it again within seconds (2 seconds) on your remote Bitbucket server, jenkins is not done processing the remove event when the create event comes, preventing it from starting a new job.
Steps to reproduce:
create a branch called eg. test/sal and let it run until finish.After that, redo the last commit, and delete the remote branch and push again
git commit -a --amend -C HEAD && date && git push origin :test/sal ; sleep 2 && git push origin test/sal && dateresult:
Sometimes (every second time, but varying) the trigger is not executed.Bad run logs:
==> logs/jenkins.branch.MultiBranchProject.log <==
[Tue Jan 16 08:44:43 UTC 2018] Received com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 REMOVED event from 10.240.2.28 ⇒ https://jenkins.acme.com:8080/dsw/bitbucket-scmsource-hook/notify with timestamp Tue Jan 16 08:44:43 UTC 2018
Found match against pipeline-ntdrv
[Tue Jan 16 08:44:51 UTC 2018] Finished processing com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 REMOVED event from 10.240.2.28 ⇒ https://jenkins.acme.com:8080/dsw/bitbucket-scmsource-hook/notify with timestamp Tue Jan 16 08:44:43 UTC 2018. Matched 1.==> logs/jenkins.branch.MultiBranchProject.log <==
[Tue Jan 16 08:44:48 UTC 2018] Received com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 CREATED event from 10.240.2.28 ⇒ https://jenkins.acme.com:8080/dsw/bitbucket-scmsource-hook/notify with timestamp Tue Jan 16 08:44:48 UTC 2018
[Tue Jan 16 08:44:48 UTC 2018] Finished processing com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 CREATED event from 10.240.2.28 ⇒ https://jenkins.acme.com:8080/dsw/bitbucket-scmsource-hook/notify with timestamp Tue Jan 16 08:44:48 UTC 2018. Matched 0.Good
==> logs/jenkins.branch.MultiBranchProject.log <==
[Tue Jan 16 08:46:35 UTC 2018] Received com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 REMOVED event from 10.240.2.28 ⇒ https://jenkins.acme.com:8080/dsw/bitbucket-scmsource-hook/notify with timestamp Tue Jan 16 08:46:35 UTC 2018
Found match against pipeline-ntdrv
[Tue Jan 16 08:46:43 UTC 2018] Finished processing com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 REMOVED event from 10.240.2.28 ⇒ https://jenkins.acme.com:8080/dsw/bitbucket-scmsource-hook/notify with timestamp Tue Jan 16 08:46:35 UTC 2018. Matched 1.==> logs/jenkins.branch.MultiBranchProject.log <==
[Tue Jan 16 08:46:39 UTC 2018] Received com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 CREATED event from 10.240.2.28 ⇒ https://jenkins.acme.com:8080/dsw/bitbucket-scmsource-hook/notify with timestamp Tue Jan 16 08:46:39 UTC 2018
Found match against pipeline-ntdrv (resurrect branch test/sal-cd382)
[Tue Jan 16 08:46:48 UTC 2018] Finished processing com.cloudbees.jenkins.plugins.bitbucket.hooks.PushHookProcessor$1 CREATED event from 10.240.2.28 ⇒ https://jenkins.acme.com:8080/dsw/bitbucket-scmsource-hook/notify with timestamp Tue Jan 16 08:46:39 UTC 2018. Matched 1.Notice the timestamps for "Received/Finished".
In the bad example, REMOVED event processing does not finish until after the CREATED event is started and finished. In the good example, the REMOVED event does finish after CREATED starts, but before it finishes. This does indeed allow for a scenario where the processing of the CREATED event races with the REMOVED event.
environment
```
java.version 1.8.0_151
os.arch amd64
os.name Linux
os.version 4.4.0-104-generic
JENKINS_VERSION 2.73.3
branch-api 2.0.15
Bitbucket with a webhook to Jenkins
Jenkins server
Bitbucket project with hooks as it's trigger.
```
Contributor guide
Research direction
Start with jenkins.branch.MultiBranchProject and the webhook processing shown in the issue logs. Reproduce the race using the provided Git delete-and-recreate command, then inspect the REMOVED and CREATED event timing. Done means rapid branch recreation reliably triggers the new job and the race is covered by a regression test.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- java
- Domain
- api, backend
- Issue type
- Bug
- Difficulty
- 4/5
- Estimated time
- 3-5 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100