From f0a86cd48d5c3f78156d52a6c172b9e9fd09c769 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Antonio=20Mu=C3=B1iz?= Date: Fri, 13 Dec 2024 13:32:53 +0100 Subject: [PATCH] [JENKINS-74992] Print relevant pod provisioning events in build logs --- .../kubernetes/KubernetesLauncher.java | 15 ++++ .../watch/PodStatusEventHandler.java | 85 +++++++++++++++++++ .../PodProvisioningStatusLogsTest.java | 38 +++++++++ .../pipeline/containerStatusErrorLogs.groovy | 26 ++++++ .../pipeline/podStatusErrorLogs.groovy | 28 ++++++ .../pipeline/podStatusNoErrorLogs.groovy | 26 ++++++ 6 files changed, 218 insertions(+) create mode 100644 src/main/java/org/csanchez/jenkins/plugins/kubernetes/watch/PodStatusEventHandler.java create mode 100644 src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/PodProvisioningStatusLogsTest.java create mode 100644 src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/containerStatusErrorLogs.groovy create mode 100644 src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podStatusErrorLogs.groovy create mode 100644 src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podStatusNoErrorLogs.groovy 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 93c2d34a2..8f9bd24ee 100644 --- a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesLauncher.java +++ b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesLauncher.java @@ -42,6 +42,7 @@ import io.fabric8.kubernetes.api.model.Pod; import io.fabric8.kubernetes.client.KubernetesClient; import io.fabric8.kubernetes.client.KubernetesClientException; +import io.fabric8.kubernetes.client.informers.SharedIndexInformer; import java.io.IOException; import java.util.ArrayList; import java.util.Arrays; @@ -49,6 +50,7 @@ import java.util.Collections; import java.util.List; import java.util.Map; +import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.TimeUnit; import java.util.logging.Level; import java.util.logging.Logger; @@ -57,6 +59,7 @@ import org.apache.commons.lang.StringUtils; import org.csanchez.jenkins.plugins.kubernetes.pod.decorator.PodDecoratorException; import org.csanchez.jenkins.plugins.kubernetes.pod.retention.Reaper; +import org.csanchez.jenkins.plugins.kubernetes.watch.PodStatusEventHandler; import org.kohsuke.stapler.DataBoundConstructor; /** @@ -73,6 +76,9 @@ public class KubernetesLauncher extends JNLPLauncher { private volatile boolean launched = false; + // namespace -> informer + private static final Map> informers = new ConcurrentHashMap<>(); + /** * Provisioning exception if any. */ @@ -145,6 +151,15 @@ public synchronized void launch(SlaveComputer computer, TaskListener listener) { .orElse(null); node.setNamespace(namespace); + // register a namespace informer (if not registered yet) show relevant pod events in build logs + if (informers.get(namespace) == null) { + SharedIndexInformer inform = client.pods() + .inNamespace(namespace) + .inform(new PodStatusEventHandler(), TimeUnit.SECONDS.toMillis(30)); + LOGGER.info("Registered informer to watch events on namespace: " + namespace); + informers.put(namespace, inform); + } + // if the controller was interrupted after creating the pod but before it connected back, then // the pod might already exist and the creating logic must be skipped. Pod existingPod = diff --git a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/watch/PodStatusEventHandler.java b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/watch/PodStatusEventHandler.java new file mode 100644 index 000000000..c8afc3221 --- /dev/null +++ b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/watch/PodStatusEventHandler.java @@ -0,0 +1,85 @@ +package org.csanchez.jenkins.plugins.kubernetes.watch; + +import hudson.model.Node; +import hudson.model.TaskListener; +import hudson.slaves.SlaveComputer; +import io.fabric8.kubernetes.api.model.ContainerState; +import io.fabric8.kubernetes.api.model.ContainerStatus; +import io.fabric8.kubernetes.api.model.Pod; +import io.fabric8.kubernetes.api.model.PodCondition; +import io.fabric8.kubernetes.client.informers.ResourceEventHandler; +import java.util.Optional; +import java.util.logging.Logger; +import jenkins.model.Jenkins; +import org.csanchez.jenkins.plugins.kubernetes.KubernetesSlave; + +/** + * Process pod events and print relevant information in build logs. + * Registered as an informer in {@link org.csanchez.jenkins.plugins.kubernetes.KubernetesLauncher#launch(SlaveComputer, TaskListener)}). + */ +public class PodStatusEventHandler implements ResourceEventHandler { + + private static final Logger LOGGER = Logger.getLogger(PodStatusEventHandler.class.getName()); + + @Override + public void onUpdate(Pod unused, Pod pod) { + Optional found = Jenkins.get().getNodes().stream() + .filter(n -> n.getNodeName().equals(pod.getMetadata().getName())) + .findFirst(); + if (found.isPresent()) { + final StringBuilder sb = new StringBuilder(); + pod.getStatus().getContainerStatuses().forEach(s -> sb.append(formatContainerStatus(s))); + pod.getStatus().getConditions().forEach(c -> sb.append(formatPodStatus(c, pod.getStatus().getPhase()))); + if (!sb.toString().isEmpty()) { + ((KubernetesSlave) found.get()) + .getRunListener() + .getLogger() + .println("[PodInfo] " + pod.getMetadata().getName() + sb); + } + } else { + LOGGER.fine(() -> "Event received for non-existent node: [" + + pod.getMetadata().getName() + "]"); + } + } + + private String formatPodStatus(PodCondition c, String phase) { + if (c.getReason() == null) { + // not interesting + return ""; + } + return String.format("%n\tPod [%s][%s] %s", phase, c.getReason(), c.getMessage()); + } + + private String formatContainerStatus(ContainerStatus s) { + ContainerState state = s.getState(); + if (state.getRunning() != null) { + // don't care about running + return ""; + } + StringBuilder sb = new StringBuilder(); + sb.append(String.format("%n\tContainer [%s]", s.getName())); + if (state.getTerminated() != null) { + String message = state.getTerminated().getMessage(); + sb.append(String.format( + " terminated [%s] %s", + state.getTerminated().getReason(), message != null ? message : "No message")); + } + if (state.getWaiting() != null) { + String message = state.getWaiting().getMessage(); + sb.append(String.format( + " waiting [%s] %s", + state.getWaiting().getReason(), message != null ? message : "No message")); + } + return sb.toString(); + } + + @Override + public void onDelete(Pod pod, boolean deletedFinalStateUnknown) { + // no-op + } + + @Override + public void onAdd(Pod pod) { + // no-op + } +} diff --git a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/PodProvisioningStatusLogsTest.java b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/PodProvisioningStatusLogsTest.java new file mode 100644 index 000000000..c0454008b --- /dev/null +++ b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/PodProvisioningStatusLogsTest.java @@ -0,0 +1,38 @@ +package org.csanchez.jenkins.plugins.kubernetes.pipeline; + +import hudson.model.Result; +import org.junit.Test; + +import static org.junit.Assert.assertNotNull; + +public class PodProvisioningStatusLogsTest extends AbstractKubernetesPipelineTest { + + @Test + public void podStatusErrorLogs() throws Exception { + assertNotNull(createJobThenScheduleRun()); + // pod not schedulable + // build never finishes, so just checking the message and killing + r.waitForMessage("Pod [Pending][Unschedulable] 0/1 nodes are available", b); + b.doKill(); + r.waitUntilNoActivity(); + } + + @Test + public void podStatusNoErrorLogs() throws Exception { + assertNotNull(createJobThenScheduleRun()); + r.assertBuildStatusSuccess(r.waitForCompletion(b)); + // regular logs when starting containers + r.assertLogContains("Container [jnlp] waiting [ContainerCreating]", b); + r.assertLogContains("Pod [Pending][ContainersNotReady] containers with unready status: [shell jnlp]", b); + } + + @Test + public void containerStatusErrorLogs() throws Exception { + assertNotNull(createJobThenScheduleRun()); + r.assertBuildStatus(Result.ABORTED, r.waitForCompletion(b)); + // error starting container + r.assertLogContains("Container [shell] terminated [StartError]", b); + r.assertLogContains("exec: \"oops\": executable file not found", b); + r.assertLogContains("Pod [Running][ContainersNotReady] containers with unready status: [shell]", b); + } +} diff --git a/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/containerStatusErrorLogs.groovy b/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/containerStatusErrorLogs.groovy new file mode 100644 index 000000000..fd723dbc2 --- /dev/null +++ b/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/containerStatusErrorLogs.groovy @@ -0,0 +1,26 @@ +//noinspection GrPackage +pipeline { + agent { + kubernetes { + yaml ''' +apiVersion: v1 +kind: Pod +spec: + containers: + - name: shell + image: ubuntu + command: + - oops + args: + - infinity +''' + } + } + stages { + stage('Run') { + steps { + sh 'hostname' + } + } + } +} \ No newline at end of file diff --git a/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podStatusErrorLogs.groovy b/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podStatusErrorLogs.groovy new file mode 100644 index 000000000..061dcce9d --- /dev/null +++ b/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podStatusErrorLogs.groovy @@ -0,0 +1,28 @@ +//noinspection GrPackage +pipeline { + agent { + kubernetes { + yaml ''' +apiVersion: v1 +kind: Pod +spec: + containers: + - name: shell + image: ubuntu + command: + - sleep + args: + - infinity + nodeSelector: + disktype: ssd +''' + } + } + stages { + stage('Run') { + steps { + sh 'hostname' + } + } + } +} \ No newline at end of file diff --git a/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podStatusNoErrorLogs.groovy b/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podStatusNoErrorLogs.groovy new file mode 100644 index 000000000..a96bad012 --- /dev/null +++ b/src/test/resources/org/csanchez/jenkins/plugins/kubernetes/pipeline/podStatusNoErrorLogs.groovy @@ -0,0 +1,26 @@ +//noinspection GrPackage +pipeline { + agent { + kubernetes { + yaml ''' +apiVersion: v1 +kind: Pod +spec: + containers: + - name: shell + image: ubuntu + command: + - sleep + args: + - infinity +''' + } + } + stages { + stage('Run') { + steps { + sh 'hostname' + } + } + } +} \ No newline at end of file