Skip to content

Commit

Permalink
Merge pull request #470 from dwnusbaum/log-rotation-cleanup
Browse files Browse the repository at this point in the history
[JENKINS-73824][JENKINS-73835] Remove redundant log rotation after changes in core and add regression tests related to deleting Pipeline jobs and builds
  • Loading branch information
dwnusbaum authored Oct 15, 2024
2 parents 559bc71 + 1232095 commit 6c53109
Show file tree
Hide file tree
Showing 4 changed files with 101 additions and 23 deletions.
7 changes: 4 additions & 3 deletions pom.xml
Original file line number Diff line number Diff line change
Expand Up @@ -63,7 +63,8 @@
</pluginRepositories>
<properties>
<changelist>999999-SNAPSHOT</changelist>
<jenkins.version>2.479</jenkins.version>
<!-- TODO: Waiting for JENKINS-73824 and JENKINS-73835 to make it into an LTS line -->
<jenkins.version>2.481</jenkins.version>
<no-test-jar>false</no-test-jar>
<useBeta>true</useBeta>
<hpi.compatibleSinceVersion>2.26</hpi.compatibleSinceVersion>
Expand All @@ -73,8 +74,8 @@
<dependencies>
<dependency>
<groupId>io.jenkins.tools.bom</groupId>
<artifactId>bom-2.462.x</artifactId>
<version>3221.ve8f7b_fdd149d</version>
<artifactId>bom-2.479.x</artifactId>
<version>3482.vc10d4f6da_28a_</version>
<scope>import</scope>
<type>pom</type>
</dependency>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -660,13 +660,6 @@ private void finish(@NonNull Result r, @CheckForNull Throwable t) {
listener = null;
}
saveWithoutFailing(true);
Timer.get().submit(() -> {
try {
getParent().logRotate();
} catch (Exception x) {
LOGGER.log(Level.WARNING, "failed to perform log rotation after " + this, x);
}
});
onEndBuilding();
} finally { // Ensure this is ALWAYS removed from FlowExecutionList
FlowExecutionList.get().unregister(new Owner(this));
Expand Down
Original file line number Diff line number Diff line change
@@ -1,6 +1,8 @@
package org.jenkinsci.plugins.workflow.job;

import static org.hamcrest.MatcherAssert.assertThat;
import static org.hamcrest.Matchers.empty;
import static org.hamcrest.Matchers.nullValue;
import static org.junit.Assert.assertEquals;
import static org.junit.Assert.assertFalse;
import static org.junit.Assert.assertNotNull;
Expand All @@ -12,20 +14,30 @@
import org.htmlunit.html.HtmlCheckBoxInput;
import org.htmlunit.html.HtmlForm;
import hudson.cli.CLICommandInvoker;
import hudson.model.Executor;
import hudson.model.Result;
import hudson.plugins.git.GitSCM;
import hudson.security.WhoAmI;
import hudson.triggers.SCMTrigger;
import java.util.Objects;
import java.util.logging.Logger;
import java.util.stream.Collectors;
import java.util.stream.Stream;
import jenkins.plugins.git.GitSampleRepoRule;
import org.jenkinsci.plugins.workflow.cps.CpsFlowDefinition;
import org.jenkinsci.plugins.workflow.cps.CpsScmFlowDefinition;
import org.junit.ClassRule;
import org.junit.Rule;
import org.junit.Test;
import org.jvnet.hudson.test.BuildWatcher;
import org.jvnet.hudson.test.Issue;
import org.jvnet.hudson.test.JenkinsRule;
import org.jvnet.hudson.test.RunLoadCounter;

public class WorkflowJobTest {
private static final Logger LOGGER = Logger.getLogger(WorkflowJobTest.class.getName());

@ClassRule public static BuildWatcher watcher = new BuildWatcher();

@Rule public JenkinsRule j = new JenkinsRule();
@Rule public GitSampleRepoRule sampleRepo = new GitSampleRepoRule();
Expand Down Expand Up @@ -157,4 +169,35 @@ public void newBuildsShouldNotLoadOld() throws Throwable {
});
}

@Issue("JENKINS-73824")
@Test
public void deletionShouldWaitForBuildsToComplete() throws Throwable {
var p = j.createProject(WorkflowJob.class);
p.setDefinition(new CpsFlowDefinition(
"""
try {
echo 'about to sleep'
sleep 999
} catch(e) {
echo 'aborting soon'
sleep 3
}
""", true));
var b = p.scheduleBuild2(0).waitForStart();
j.waitForMessage("about to sleep", b);
// The build isn't done and catches the interruption, so ItemDeletion.cancelBuildsInProgress should have to wait at least 3 seconds for it to complete.
LOGGER.info(() -> "Deleting " + p);
p.delete();
LOGGER.info(() -> "Deleted " + p);
// Make sure that the job really has been deleted.
assertThat(j.jenkins.getItemByFullName(p.getFullName()), nullValue());
// ItemDeletion.cancelBuildsInProgress should guarantee that the queue is empty at this point.
var executables = Stream.of(j.jenkins.getComputers())
.flatMap(c -> c.getAllExecutors().stream())
.map(Executor::getCurrentExecutable)
.filter(Objects::nonNull)
.collect(Collectors.toList());
assertThat(executables, empty());
}

}
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,7 @@
import static org.hamcrest.collection.IsEmptyCollection.empty;
import static org.hamcrest.MatcherAssert.assertThat;
import static org.hamcrest.Matchers.containsString;
import static org.hamcrest.Matchers.emptyArray;
import static org.hamcrest.Matchers.equalTo;
import static org.hamcrest.Matchers.notNullValue;
import static org.hamcrest.Matchers.nullValue;
Expand Down Expand Up @@ -58,6 +59,7 @@
import hudson.slaves.EnvironmentVariablesNodeProperty;
import hudson.slaves.NodeProperty;
import hudson.slaves.NodePropertyDescriptor;
import hudson.tasks.LogRotator;
import hudson.util.DescribableList;
import hudson.util.StreamTaskListener;
import java.io.File;
Expand All @@ -73,6 +75,7 @@
import java.util.TreeSet;
import java.util.concurrent.TimeUnit;
import java.util.logging.Level;
import java.util.logging.Logger;
import jenkins.model.CauseOfInterruption;
import jenkins.model.InterruptedBuildAction;
import jenkins.model.Jenkins;
Expand Down Expand Up @@ -109,6 +112,7 @@
import org.xml.sax.SAXException;

public class WorkflowRunTest {
private static final Logger LOGGER = Logger.getLogger(WorkflowRunTest.class.getName());

@ClassRule public static BuildWatcher buildWatcher = new BuildWatcher();
@Rule public JenkinsRule r = new JenkinsRule();
Expand Down Expand Up @@ -520,7 +524,7 @@ private void assertCulprits(WorkflowRun b, String... expectedIds) throws IOExcep
assertThat(await().until(() -> ExtensionList.lookupSingleton(CheckCompletedFlag.class).buildXml.get(b.getExternalizableId()), notNullValue()),
containsString("<completed>true</completed>"));
}
@TestExtension public static final class CheckCompletedFlag extends RunListener<WorkflowRun> {
@TestExtension("completedFlag") public static final class CheckCompletedFlag extends RunListener<WorkflowRun> {
final Map<String, String> buildXml = new HashMap<>();
@Override public void onFinalized(WorkflowRun r) {
try {
Expand Down Expand Up @@ -600,6 +604,20 @@ private void assertCulprits(WorkflowRun b, String... expectedIds) throws IOExcep
assertPollingBaselines(b3.checkouts(listener), nullValue(), nullValue());
}

@SafeVarargs
private static void assertPollingBaselines(List<WorkflowRun.SCMCheckout> checkouts, Matcher<Object>... indexedMatchers) {
assertThat("Number of checkouts should match number of matchers", checkouts.size(), equalTo(indexedMatchers.length));
for (int i = 0; i < checkouts.size(); i++) {
assertThat("Unexpected baseline for checkout at index " + i, checkouts.get(i).pollingBaseline, indexedMatchers[i]);
}
}

private static String checkoutString(GitSampleRepoRule repo, boolean changelog, boolean polling) {
return " checkout(changelog:" + changelog +", poll:" + polling +
", scm: [$class: 'GitSCM', branches: [[name: '*/master']], " +
", userRemoteConfigs: [[url: $/" + repo.fileUrl() + "/$]]])\n";
}

// This test is to ensure that the shortDescription on the CancelCause is escaped properly on summary.jelly
@Issue("SECURITY-3042")
@Test public void escapedDisplayNameAfterAbort() throws Exception {
Expand Down Expand Up @@ -667,19 +685,42 @@ public void onInitialize(Run run) {

}


@SafeVarargs
private static void assertPollingBaselines(List<WorkflowRun.SCMCheckout> checkouts, Matcher<Object>... indexedMatchers) {
assertThat("Number of checkouts should match number of matchers", checkouts.size(), equalTo(indexedMatchers.length));
for (int i = 0; i < checkouts.size(); i++) {
assertThat("Unexpected baseline for checkout at index " + i, checkouts.get(i).pollingBaseline, indexedMatchers[i]);
@Issue("JENKINS-73835")
@Test public void logRotationOnlyProcessesCompletedBuilds() throws Throwable {
logging.record(LogRotator.class, Level.FINER);
var p = r.createProject(WorkflowJob.class);
p.setDefinition(new CpsFlowDefinition(
"echo params.FOO; semaphore 'wait'", true));
p.addProperty(new ParametersDefinitionProperty(List.of(new StringParameterDefinition("FOO"))));
// Keep 0 builds, i.e. delete all builds immediately.
LogRotator logRotator = new LogRotator(-1, 0, -1, -1);
logRotator.setRemoveLastBuild(true);
p.setBuildDiscarder(logRotator);
int buildsToRun = 10; // Increase this number to reproduce the issue more easily prior to the fix.
Run[] builds = new Run[buildsToRun];
File[] buildDirs = new File[buildsToRun];
// Run a large number of builds that should finish around the same time to check race conditions with log rotation and build completion.
for (int i = 0; i < buildsToRun; i++) {
var b = p.scheduleBuild2(0, new ParametersAction(List.of(new StringParameterValue("FOO", "b" + i)))).waitForStart();
builds[i] = b;
buildDirs[i] = b.getRootDir();
SemaphoreStep.waitForStart("wait/" + (i+1), b);
}
for (int i = 0; i < buildsToRun; i++) {
SemaphoreStep.success("wait/" + (i+1), null);
}
LOGGER.info("Waiting for all builds to complete");
for (int i = 0; i < buildsToRun; i++) {
r.waitForCompletion(builds[i]);
}
LOGGER.info("Checking that all build directories are empty");
for (int i = 0; i < buildsToRun; i++) {
String[] filesInBuildDir = buildDirs[i].list();
if (filesInBuildDir == null) {
filesInBuildDir = new String[0];
}
assertThat("Expected " + buildDirs[i] + " to be empty but saw: " + Arrays.toString(filesInBuildDir), filesInBuildDir, emptyArray());
}
}

private static String checkoutString(GitSampleRepoRule repo, boolean changelog, boolean polling) {
return " checkout(changelog:" + changelog +", poll:" + polling +
", scm: [$class: 'GitSCM', branches: [[name: '*/master']], " +
", userRemoteConfigs: [[url: $/" + repo.fileUrl() + "/$]]])\n";
}

}

0 comments on commit 6c53109

Please sign in to comment.