[JIRA] (JENKINS-61687) Exceptions due to global build discarder

Exceptions due to global build discarder

Issue Type:	Bug
Assignee:	Unassigned
Components:	core
Created:	2020-03-25 21:51
Labels:	ci.jenkins.io
Priority:	Minor
Reporter:	Daniel Beck

Messages like the following are being logged on ci.jenkins.io after updating to 2.222.1.

 
                                                                2020-03-25 19:18:34.958+0000 [id=21774]	WARNING	j.m.BackgroundGlobalBuildDiscarder#lambda$processJob$0: An exception occurred when executing Project Build Discarder
Also:   java.nio.file.NoSuchFileException: /var/jenkins_home/jobs/Infra/jobs/plugin-site-api/branches/generate-data/builds/93295 -> /var/jenkins_home/jobs/Infra/jobs/plugin-site-api/branches/generate-data/builds/.93295
		at java.base/sun.nio.fs.UnixException.translateToIOException(UnixException.java:92)
		at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111)
		at java.base/sun.nio.fs.UnixCopyFile.move(UnixCopyFile.java:417)
		at java.base/sun.nio.fs.UnixFileSystemProvider.move(UnixFileSystemProvider.java:267)
		at java.base/java.nio.file.Files.move(Files.java:1421)
		at hudson.model.Run.delete(Run.java:1621)
		at hudson.tasks.LogRotator.perform(LogRotator.java:166)
jenkins.util.io.CompositeIOException: Failed to rotate logs for [Infra/plugin-site-api/generate-data #93295]
	at hudson.tasks.LogRotator.perform(LogRotator.java:223)
	at hudson.model.Job.logRotate(Job.java:469)
	at jenkins.model.JobGlobalBuildDiscarderStrategy.apply(JobGlobalBuildDiscarderStrategy.java:54)
	at jenkins.model.BackgroundGlobalBuildDiscarder.lambda$processJob$0(BackgroundGlobalBuildDiscarder.java:67)
	at java.base/java.lang.Iterable.forEach(Iterable.java:75)
	at jenkins.model.BackgroundGlobalBuildDiscarder.processJob(BackgroundGlobalBuildDiscarder.java:61)
	at jenkins.model.GlobalBuildDiscarderListener.onFinalized(GlobalBuildDiscarderListener.java:49)
	at hudson.model.listeners.RunListener.fireFinalized(RunListener.java:255)
	at hudson.model.Run.onEndBuilding(Run.java:2018)
	at org.jenkinsci.plugins.workflow.job.WorkflowRun.finish(WorkflowRun.java:617)
	at org.jenkinsci.plugins.workflow.job.WorkflowRun.access$800(WorkflowRun.java:137)
	at org.jenkinsci.plugins.workflow.job.WorkflowRun$GraphL.onNewHead(WorkflowRun.java:1018)
	at org.jenkinsci.plugins.workflow.cps.CpsFlowExecution.notifyListeners(CpsFlowExecution.java:1463)
	at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$3.run(CpsThreadGroup.java:488)
	at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService$1.run(CpsVmExecutorService.java:38)
	at hudson.remoting.SingleLaneExecutorService$1.run(SingleLaneExecutorService.java:131)
	at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
	at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:59)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:834)  
                                                            

or

 
                                                                2020-03-25 19:28:42.053+0000 [id=56]	WARNING	o.j.p.workflow.job.WorkflowRun#lambda$finish$2: failed to perform log rotation after Infra/plugin-site-api/generate-data #93303
Also:   java.nio.file.NoSuchFileException: /var/jenkins_home/jobs/Infra/jobs/plugin-site-api/branches/generate-data/builds/93296 -> /var/jenkins_home/jobs/Infra/jobs/plugin-site-api/branches/generate-data/builds/.93296
		at java.base/sun.nio.fs.UnixException.translateToIOException(UnixException.java:92)
		at java.base/sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:111)
		at java.base/sun.nio.fs.UnixCopyFile.move(UnixCopyFile.java:417)
		at java.base/sun.nio.fs.UnixFileSystemProvider.move(UnixFileSystemProvider.java:267)
		at java.base/java.nio.file.Files.move(Files.java:1421)
		at hudson.model.Run.delete(Run.java:1621)
		at hudson.tasks.LogRotator.perform(LogRotator.java:166)
jenkins.util.io.CompositeIOException: Failed to rotate logs for [Infra/plugin-site-api/generate-data #93296]
	at hudson.tasks.LogRotator.perform(LogRotator.java:223)
	at hudson.model.Job.logRotate(Job.java:469)
	at org.jenkinsci.plugins.workflow.job.WorkflowRun.lambda$finish$2(WorkflowRun.java:612)
	at jenkins.security.ImpersonatingScheduledExecutorService$1.run(ImpersonatingScheduledExecutorService.java:58)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:834)  
                                                            

None of them occurred while background deletion was ongoing.

This message was sent by Atlassian Jira (v7.13.12#713012-sha1:6e07c38)

dbeck@cloudbees.com (JIRA)

unread,

Mar 25, 2020, 5:53:03 PM3/25/20

to jenkinsc...@googlegroups.com

Daniel Beck commented on

Obvious problem is that we call the globally configured-by-default "Job Build Discarder" when a build finishes, even though it's redundant. Unclear why there seems to be a race condition here though.

Run#delete looks reasonable enough.

dbeck@cloudbees.com (JIRA)

unread,

Mar 25, 2020, 6:08:02 PM3/25/20

to jenkinsc...@googlegroups.com

Daniel Beck commented on

https://github.com/jenkinsci/jenkins/blob/jenkins-2.222.1/core/src/main/java/hudson/model/Run.java#L1614-L1638

dbeck@cloudbees.com (JIRA)

unread,

Mar 25, 2020, 7:53:04 PM3/25/20

to jenkinsc...@googlegroups.com

Daniel Beck commented on

The problem occurs when many builds finish around the same time and is unrelated to the global build discarder. That may make it more likely to occur, unsure.

dbeck@cloudbees.com (JIRA)

unread,

Apr 1, 2020, 6:01:04 AM4/1/20

to jenkinsc...@googlegroups.com

Daniel Beck commented on

Run#delete looks reasonable enough.

Correction: This method makes absolutely no sense.

dbeck@cloudbees.com (JIRA)

unread,

Apr 11, 2020, 11:56:04 AM4/11/20

to jenkinsc...@googlegroups.com

Daniel Beck commented on

FWIW and AFAICT, the exceptions are annoying, but don't indicate actual problems affecting Jenkins during runtime. The same build is "just" being deleted twice, and one of the attempts ends up failing because there's nothing left to delete.