From 214b5b3a40809de5d4956364b137849638dc9b04 Mon Sep 17 00:00:00 2001 From: Vincent Latombe Date: Fri, 29 Jan 2021 15:44:13 +0100 Subject: [PATCH 1/6] Capture pod events just before deleting the agent So that they can be printed in the logs --- .../kubernetes/KubernetesEventsException.java | 25 +++++++++++++++++++ .../kubernetes/KubernetesLauncher.java | 10 ++++++++ .../pipeline/KubernetesPipelineTest.java | 9 +++++++ .../pipeline/podEventsPrinted.groovy | 18 +++++++++++++ 4 files changed, 62 insertions(+) create mode 100644 src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesEventsException.java create mode 100644 src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podEventsPrinted.groovy diff --git a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesEventsException.java b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesEventsException.java new file mode 100644 index 0000000000..a6eb8bae40 --- /dev/null +++ b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesEventsException.java @@ -0,0 +1,25 @@ +package org.csanchez.jenkins.plugins.kubernetes; + +import io.fabric8.kubernetes.api.model.Event; + +import java.util.List; + +/** + * Prints + */ +public class KubernetesEventsException extends Exception { + public KubernetesEventsException(List events) { + super(toMessage(events)); + } + + private static String toMessage(List events) { + StringBuilder sb = new StringBuilder("Events follow:\n"); + for (Event event : events) { + String[] lines = event.getMessage().split("\n"); + for (String line : lines) { + sb.append(String.format("[%s][%s/%s][%s] %s%n", event.getType(), event.getInvolvedObject().getNamespace(), event.getInvolvedObject().getName(), event.getReason(), line)); + } + } + return sb.toString(); + } +} diff --git a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesLauncher.java b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesLauncher.java index 3b0bfe6084..9eef9cb850 100644 --- a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesLauncher.java +++ b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesLauncher.java @@ -38,9 +38,11 @@ import javax.annotation.CheckForNull; import edu.umd.cs.findbugs.annotations.SuppressFBWarnings; +import io.fabric8.kubernetes.api.model.Event; import io.fabric8.kubernetes.client.KubernetesClientException; import jenkins.metrics.api.Metrics; import org.apache.commons.lang.StringUtils; +import org.jenkinsci.plugins.kubernetes.auth.KubernetesAuthException; import org.kohsuke.stapler.DataBoundConstructor; import com.google.common.base.Throwables; @@ -255,6 +257,14 @@ else if (httpCode == 409 && e.getMessage().contains("Operation cannot be fulfill } Metrics.metricRegistry().counter(MetricNames.PODS_LAUNCHED).inc(); } catch (Throwable ex) { + try { + List podEvents = ((KubernetesComputer) computer).getPodEvents(); + if (!podEvents.isEmpty()) { + ex.addSuppressed(new KubernetesEventsException(podEvents)); + } + } catch (KubernetesAuthException | IOException e) { + LOGGER.log(Level.FINE, "Unable to add Kubernetes events"); + } setProblem(ex); LOGGER.log(Level.WARNING, String.format("Error in provisioning; agent=%s, template=%s", node, template), ex); LOGGER.log(Level.FINER, "Removing Jenkins node: {0}", node.getNodeName()); diff --git a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/KubernetesPipelineTest.java b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/KubernetesPipelineTest.java index 8df5014e67..ce359fab19 100644 --- a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/KubernetesPipelineTest.java +++ b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/KubernetesPipelineTest.java @@ -30,8 +30,10 @@ import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.deletePods; import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.getLabels; import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.containsString; import static org.hamcrest.Matchers.emptyIterable; import static org.hamcrest.Matchers.hasEntry; +import static org.hamcrest.Matchers.hasItem; import static org.hamcrest.Matchers.hasSize; import static org.hamcrest.Matchers.oneOf; import static org.junit.Assert.assertEquals; @@ -675,6 +677,13 @@ public void invalidPodGetsCancelled() throws Exception { r.assertLogContains("ERROR: Queue task was cancelled", b); } + @Test + public void podEventsPrinted() throws Exception { + Thread.sleep(5000); + b.doKill(); + assertThat(logs.getMessages(), hasItem(containsString("Readiness probe failed"))); + } + @Issue("SECURITY-1646") @Test public void substituteEnv() throws Exception { diff --git a/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podEventsPrinted.groovy b/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podEventsPrinted.groovy new file mode 100644 index 0000000000..9fc6ef5988 --- /dev/null +++ b/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podEventsPrinted.groovy @@ -0,0 +1,18 @@ +podTemplate(slaveConnectTimeout:10, yaml:''' + spec: + containers: + - name: neverready + image: busybox + command: ['sleep', '99999999'] + readinessProbe: + exec: + command: + - cat + - /tmp/healthy + initialDelaySeconds: 5 + periodSeconds: 5 +''') { + node(POD_LABEL) { + sh 'true' + } +} From 84bc342d1b4b21f305e1abc1f2d09bce9d4b6baa Mon Sep 17 00:00:00 2001 From: Vincent Latombe Date: Wed, 3 Feb 2021 14:40:36 +0100 Subject: [PATCH 2/6] Fixup tests, organize imports --- .../pipeline/KubernetesPipelineTest.java | 90 +++++++++++-------- .../pipeline/podEventsPrinted.groovy | 4 +- 2 files changed, 55 insertions(+), 39 deletions(-) diff --git a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/KubernetesPipelineTest.java b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/KubernetesPipelineTest.java index ce359fab19..afcb8bdf8c 100644 --- a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/KubernetesPipelineTest.java +++ b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/KubernetesPipelineTest.java @@ -24,39 +24,12 @@ package org.csanchez.jenkins.plugins.kubernetes.pipeline; -import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.CONTAINER_ENV_VAR_FROM_SECRET_VALUE; -import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.POD_ENV_VAR_FROM_SECRET_VALUE; -import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.assumeWindows; -import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.deletePods; -import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.getLabels; -import static org.hamcrest.MatcherAssert.assertThat; -import static org.hamcrest.Matchers.containsString; -import static org.hamcrest.Matchers.emptyIterable; -import static org.hamcrest.Matchers.hasEntry; -import static org.hamcrest.Matchers.hasItem; -import static org.hamcrest.Matchers.hasSize; -import static org.hamcrest.Matchers.oneOf; -import static org.junit.Assert.assertEquals; -import static org.junit.Assert.assertFalse; -import static org.junit.Assert.assertNotNull; -import static org.junit.Assert.assertNull; -import static org.junit.Assert.assertTrue; -import static org.junit.Assume.*; - -import java.io.File; -import java.util.Arrays; -import java.util.Collections; -import java.util.List; -import java.util.Map; -import java.util.Optional; -import java.util.logging.Level; -import java.util.logging.Logger; - -import hudson.model.Computer; import com.gargoylesoftware.htmlunit.html.DomNodeUtil; import com.gargoylesoftware.htmlunit.html.HtmlElement; import com.gargoylesoftware.htmlunit.html.HtmlPage; +import hudson.model.Computer; import hudson.model.Label; +import hudson.model.Result; import hudson.model.Run; import hudson.slaves.SlaveComputer; import hudson.util.VersionNumber; @@ -64,38 +37,65 @@ import io.fabric8.kubernetes.api.model.Pod; import io.fabric8.kubernetes.api.model.PodList; import io.fabric8.kubernetes.client.KubernetesClientException; +import io.fabric8.kubernetes.client.KubernetesClientTimeoutException; import jenkins.metrics.api.Metrics; import jenkins.model.Jenkins; import org.csanchez.jenkins.plugins.kubernetes.ContainerTemplate; +import org.csanchez.jenkins.plugins.kubernetes.KubernetesLauncher; import org.csanchez.jenkins.plugins.kubernetes.KubernetesSlave; import org.csanchez.jenkins.plugins.kubernetes.MetricNames; import org.csanchez.jenkins.plugins.kubernetes.PodAnnotation; import org.csanchez.jenkins.plugins.kubernetes.PodTemplate; import org.csanchez.jenkins.plugins.kubernetes.PodTemplateUtils; +import org.hamcrest.CustomTypeSafeMatcher; import org.hamcrest.MatcherAssert; import org.hamcrest.Matchers; +import org.jenkinsci.plugins.workflow.flow.FlowDurabilityHint; +import org.jenkinsci.plugins.workflow.flow.GlobalDefaultFlowDurabilityLevel; import org.jenkinsci.plugins.workflow.job.WorkflowRun; import org.jenkinsci.plugins.workflow.support.steps.ExecutorStepExecution; import org.jenkinsci.plugins.workflow.test.steps.SemaphoreStep; import org.junit.After; import org.junit.Before; +import org.junit.Ignore; import org.junit.Rule; import org.junit.Test; import org.junit.rules.TemporaryFolder; +import org.jvnet.hudson.test.FlagRule; import org.jvnet.hudson.test.Issue; import org.jvnet.hudson.test.JenkinsRule; import org.jvnet.hudson.test.JenkinsRuleNonLocalhost; import org.jvnet.hudson.test.LoggerRule; +import org.jvnet.hudson.test.MockAuthorizationStrategy; -import hudson.model.Result; +import java.io.File; +import java.util.Arrays; +import java.util.Collections; +import java.util.List; import java.util.Locale; +import java.util.Map; +import java.util.Optional; +import java.util.logging.Level; +import java.util.logging.Logger; import java.util.stream.Collectors; -import org.jenkinsci.plugins.workflow.flow.FlowDurabilityHint; -import org.jenkinsci.plugins.workflow.flow.GlobalDefaultFlowDurabilityLevel; -import org.junit.Ignore; -import org.jvnet.hudson.test.FlagRule; -import org.jvnet.hudson.test.MockAuthorizationStrategy; +import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.CONTAINER_ENV_VAR_FROM_SECRET_VALUE; +import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.POD_ENV_VAR_FROM_SECRET_VALUE; +import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.assumeWindows; +import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.deletePods; +import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.getLabels; +import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.emptyIterable; +import static org.hamcrest.Matchers.hasEntry; +import static org.hamcrest.Matchers.hasSize; +import static org.hamcrest.Matchers.oneOf; +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertNotNull; +import static org.junit.Assert.assertNull; +import static org.junit.Assert.assertTrue; +import static org.junit.Assume.assumeNoException; +import static org.junit.Assume.assumeNotNull; public class KubernetesPipelineTest extends AbstractKubernetesPipelineTest { @@ -679,9 +679,25 @@ public void invalidPodGetsCancelled() throws Exception { @Test public void podEventsPrinted() throws Exception { - Thread.sleep(5000); + warnings.record(KubernetesLauncher.class.getName(), Level.WARNING).capture(1000); + Thread.sleep(15000); b.doKill(); - assertThat(logs.getMessages(), hasItem(containsString("Readiness probe failed"))); + r.assertBuildStatus(Result.ABORTED, r.waitForCompletion(b)); + assertThat(warnings, LoggerRule.recorded(Level.WARNING, any(String.class), + new CustomTypeSafeMatcher("has \"Readiness probe failed\" in suppressed exceptions") { + @Override + protected boolean matchesSafely(Throwable item) { + if (item instanceof KubernetesClientTimeoutException) { + for (Throwable t : item.getSuppressed()) { + if (t.getMessage().contains("Readiness probe failed")) { + return true; + } + } + return false; + } + return false; + } + })); } @Issue("SECURITY-1646") diff --git a/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podEventsPrinted.groovy b/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podEventsPrinted.groovy index 9fc6ef5988..64322a7501 100644 --- a/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podEventsPrinted.groovy +++ b/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podEventsPrinted.groovy @@ -9,8 +9,8 @@ podTemplate(slaveConnectTimeout:10, yaml:''' command: - cat - /tmp/healthy - initialDelaySeconds: 5 - periodSeconds: 5 + initialDelaySeconds: 1 + periodSeconds: 1 ''') { node(POD_LABEL) { sh 'true' From 6cbb60ad61cb6002e443e27e7f1ff632540ddb0c Mon Sep 17 00:00:00 2001 From: Vincent Latombe Date: Thu, 4 Feb 2021 10:22:43 +0100 Subject: [PATCH 3/6] Apply suggestions from code review Co-authored-by: David Schott --- .../jenkins/plugins/kubernetes/KubernetesEventsException.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesEventsException.java b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesEventsException.java index a6eb8bae40..4381cea5f1 100644 --- a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesEventsException.java +++ b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesEventsException.java @@ -5,7 +5,7 @@ import java.util.List; /** - * Prints + * Custom exception which adds information about Kubernetes events. */ public class KubernetesEventsException extends Exception { public KubernetesEventsException(List events) { From 7343fa6aa472fc6ed91c7f5b2bbc18d0f472b94a Mon Sep 17 00:00:00 2001 From: Vincent Latombe Date: Thu, 4 Feb 2021 11:10:34 +0100 Subject: [PATCH 4/6] Add missing import --- .../plugins/kubernetes/pipeline/KubernetesPipelineTest.java | 1 + 1 file changed, 1 insertion(+) diff --git a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/KubernetesPipelineTest.java b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/KubernetesPipelineTest.java index afcb8bdf8c..4dfd720455 100644 --- a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/KubernetesPipelineTest.java +++ b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/KubernetesPipelineTest.java @@ -85,6 +85,7 @@ import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.deletePods; import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.getLabels; import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.any; import static org.hamcrest.Matchers.emptyIterable; import static org.hamcrest.Matchers.hasEntry; import static org.hamcrest.Matchers.hasSize; From 254d6ae1851e7f99fd92efde1cf1ef04cc85e77a Mon Sep 17 00:00:00 2001 From: Vincent Latombe Date: Thu, 4 Feb 2021 12:12:34 +0100 Subject: [PATCH 5/6] Relax the test a bit --- .../plugins/kubernetes/pipeline/KubernetesPipelineTest.java | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/KubernetesPipelineTest.java b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/KubernetesPipelineTest.java index 4dfd720455..266fd35246 100644 --- a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/KubernetesPipelineTest.java +++ b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/KubernetesPipelineTest.java @@ -681,14 +681,14 @@ public void invalidPodGetsCancelled() throws Exception { @Test public void podEventsPrinted() throws Exception { warnings.record(KubernetesLauncher.class.getName(), Level.WARNING).capture(1000); - Thread.sleep(15000); + Thread.sleep(20000); b.doKill(); r.assertBuildStatus(Result.ABORTED, r.waitForCompletion(b)); assertThat(warnings, LoggerRule.recorded(Level.WARNING, any(String.class), new CustomTypeSafeMatcher("has \"Readiness probe failed\" in suppressed exceptions") { @Override protected boolean matchesSafely(Throwable item) { - if (item instanceof KubernetesClientTimeoutException) { + if (item != null) { for (Throwable t : item.getSuppressed()) { if (t.getMessage().contains("Readiness probe failed")) { return true; From 61a655b34b5c7643c191d120af525328a58bd145 Mon Sep 17 00:00:00 2001 From: Vincent Latombe Date: Thu, 4 Feb 2021 14:07:57 +0100 Subject: [PATCH 6/6] Use a single container --- .../plugins/kubernetes/pipeline/podEventsPrinted.groovy | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podEventsPrinted.groovy b/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podEventsPrinted.groovy index 64322a7501..2d629f8050 100644 --- a/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podEventsPrinted.groovy +++ b/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podEventsPrinted.groovy @@ -1,9 +1,7 @@ podTemplate(slaveConnectTimeout:10, yaml:''' spec: containers: - - name: neverready - image: busybox - command: ['sleep', '99999999'] + - name: jnlp readinessProbe: exec: command: