From 4a298226f447bf69571a01631249cd29065ade7a Mon Sep 17 00:00:00 2001 From: Samuel Beaulieu Date: Mon, 25 Apr 2022 11:20:06 -0500 Subject: [PATCH 01/10] initial commit with logging and all --- .../AllContainersRunningPodWatcher.java | 36 +++++---- .../kubernetes/KubernetesLauncher.java | 75 +++++++++++++++++-- 2 files changed, 90 insertions(+), 21 deletions(-) diff --git a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/AllContainersRunningPodWatcher.java b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/AllContainersRunningPodWatcher.java index 3432a8d80a..ddb81ccffe 100644 --- a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/AllContainersRunningPodWatcher.java +++ b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/AllContainersRunningPodWatcher.java @@ -1,14 +1,5 @@ package org.csanchez.jenkins.plugins.kubernetes; -import static java.util.stream.Collectors.joining; - -import java.util.List; -import java.util.concurrent.CountDownLatch; -import java.util.concurrent.TimeUnit; -import java.util.concurrent.atomic.AtomicReference; -import java.util.logging.Level; -import java.util.logging.Logger; - import io.fabric8.kubernetes.api.model.ContainerStatus; import io.fabric8.kubernetes.api.model.Pod; import io.fabric8.kubernetes.api.model.PodStatus; @@ -18,6 +9,15 @@ import io.fabric8.kubernetes.client.WatcherException; import io.fabric8.kubernetes.client.utils.Serialization; +import java.util.List; +import java.util.concurrent.CountDownLatch; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicReference; +import java.util.logging.Level; +import java.util.logging.Logger; + +import static java.util.stream.Collectors.joining; + /** * A pod watcher reporting when all containers are running */ @@ -39,7 +39,7 @@ public AllContainersRunningPodWatcher(KubernetesClient client, Pod pod) { @Override public void eventReceived(Action action, Pod pod) { - LOGGER.log(Level.FINEST, "[{0}] {1}", new Object[]{action, pod.getMetadata().getName()}); + LOGGER.log(Level.INFO, "[{0}] {1}", new Object[]{action, pod.getMetadata().getName()}); switch (action) { case MODIFIED: updateState(pod); @@ -48,11 +48,13 @@ public void eventReceived(Action action, Pod pod) { } } - private void updateState(Pod pod) { + public void updateState(Pod pod) { if (areAllContainersRunning(pod)) { - LOGGER.log(Level.FINE, "All containers are running for pod {0}", new Object[] {pod.getMetadata().getName()}); + LOGGER.log(Level.INFO, "All containers are running for pod {0}", new Object[] {pod.getMetadata().getName()}); reference.set(pod); latch.countDown(); + } else { + LOGGER.log(Level.INFO, "Not all containers are running for pod {0}", new Object[] {pod.getMetadata().getName()}); } } @@ -75,15 +77,18 @@ public void onClose(WatcherException cause) { * if time ran out */ public Pod await(long amount, TimeUnit timeUnit) throws PodNotRunningException { + LOGGER.log(Level.INFO, "Await started for pod {0}", new Object[] {pod.getMetadata().getName()}); long started = System.currentTimeMillis(); long alreadySpent = System.currentTimeMillis() - started; long remaining = timeUnit.toMillis(amount) - alreadySpent; if (remaining <= 0) { + LOGGER.log(Level.INFO, "Await remaining <= 0 for pod {0}", new Object[] {pod.getMetadata().getName()}); return periodicAwait(0, System.currentTimeMillis(), 0, 0); } try { long interval = Math.min(10000L, Math.max(remaining / 10, 1000L)); long retries = remaining / interval; + LOGGER.log(Level.INFO, "Calling periodicAwait with {1}} for pod {0}", new Object[] {pod.getMetadata().getName(), retries}); return periodicAwait(retries, System.currentTimeMillis(), interval, remaining); } catch (KubernetesClientTimeoutException e) { // Wrap using the right timeout @@ -112,13 +117,14 @@ private Pod awaitWatcher(long amount, TimeUnit timeUnit) { * if time ran out */ private Pod periodicAwait(long i, long started, long interval, long amount) throws PodNotRunningException { + LOGGER.info(() -> "Periodic await #" + Long.toString(i) + " " + this.pod.getMetadata().getName()); Pod pod = client.pods().inNamespace(this.pod.getMetadata().getNamespace()) .withName(this.pod.getMetadata().getName()).get(); if (pod == null) { throw new PodNotRunningException(String.format("Pod is no longer available: %s/%s", this.pod.getMetadata().getNamespace(), this.pod.getMetadata().getName())); } else { - LOGGER.finest(() -> "Updating pod for " + this.pod.getMetadata().getNamespace() + "/" + this.pod.getMetadata().getName() + " : " + Serialization.asYaml(pod)); + LOGGER.info(() -> "Updating pod for " + this.pod.getMetadata().getNamespace() + "/" + this.pod.getMetadata().getName() + " : " + Serialization.asYaml(pod)); this.pod = pod; } List terminatedContainers = PodUtils.getTerminatedContainers(pod); @@ -137,12 +143,16 @@ private Pod periodicAwait(long i, long started, long interval, long amount) thro throw x; } if (areAllContainersRunning(pod)) { + LOGGER.info(() -> "Periodic await all running! " + this.pod.getMetadata().getName()); return pod; } try { + LOGGER.info(() -> "Calling awaitWatcher with interval " + interval); return awaitWatcher(interval, TimeUnit.MILLISECONDS); } catch (KubernetesClientTimeoutException e) { + LOGGER.info(() -> "KubernetesClientTimeoutException awaitWatcher thrown and swallowed"); if (i <= 0) { + LOGGER.info(() -> "KubernetesClientTimeoutException awaitWatcher i <= 0"); throw e; } } 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 98d5f05932..5458a5d477 100644 --- a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesLauncher.java +++ b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesLauncher.java @@ -31,11 +31,21 @@ import hudson.slaves.JNLPLauncher; import hudson.slaves.SlaveComputer; import io.fabric8.kubernetes.api.model.ContainerStatus; +import io.fabric8.kubernetes.api.model.Event; +import io.fabric8.kubernetes.api.model.EventList; import io.fabric8.kubernetes.api.model.ObjectMeta; import io.fabric8.kubernetes.api.model.Pod; import io.fabric8.kubernetes.client.KubernetesClient; import io.fabric8.kubernetes.client.KubernetesClientException; +import io.fabric8.kubernetes.client.KubernetesClientTimeoutException; import io.fabric8.kubernetes.client.Watch; +import io.fabric8.kubernetes.client.dsl.FilterWatchListDeletable; +import io.fabric8.kubernetes.client.internal.readiness.Readiness; +import jenkins.metrics.api.Metrics; +import org.apache.commons.lang.StringUtils; +import org.csanchez.jenkins.plugins.kubernetes.pod.retention.Reaper; +import org.kohsuke.stapler.DataBoundConstructor; + import java.io.IOException; import java.util.ArrayList; import java.util.Arrays; @@ -46,10 +56,6 @@ import java.util.logging.Level; import java.util.logging.Logger; import java.util.stream.Collectors; -import jenkins.metrics.api.Metrics; -import org.apache.commons.lang.StringUtils; -import org.csanchez.jenkins.plugins.kubernetes.pod.retention.Reaper; -import org.kohsuke.stapler.DataBoundConstructor; import static java.util.logging.Level.FINE; import static java.util.logging.Level.INFO; @@ -166,12 +172,60 @@ else if (httpCode == 409 && e.getMessage().contains("Operation cannot be fulfill ObjectMeta podMetadata = pod.getMetadata(); template.getWorkspaceVolume().createVolume(client, podMetadata); template.getVolumes().forEach(volume -> volume.createVolume(client, podMetadata)); - watcher = new AllContainersRunningPodWatcher(client, pod); - try (Watch w1 = client.pods().inNamespace(namespace).withName(podName).watch(watcher); - Watch w2 = eventWatch(client, podName, namespace, runListener)) { +/* watcher = new AllContainersRunningPodWatcher(client, pod); + LOGGER.log(INFO, () -> "watcher set"); + PodResource mypodtemp = client.pods().inNamespace(namespace).withName(podName); + LOGGER.log(INFO, () -> "mypodtemp: " + mypodtemp); + Watch w1 = mypodtemp.watch(watcher); + LOGGER.log(INFO, () -> "w1: done" + mypodtemp); + Watch w2 = eventWatch(client, podName, namespace, runListener); + LOGGER.log(INFO, () -> "w2: done" + mypodtemp); +*//* try (Watch w1 = mypodtemp.watch(watcher); + Watch w2 = eventWatch(client, podName, namespace, runListener)) {*//* assert watcher != null; // assigned 3 lines above + watcher.updateState(pod); watcher.await(template.getSlaveConnectTimeout(), TimeUnit.SECONDS); +// } + w1.close(); + w2.close();*/ + +/* boolean done = false; + watcher = new AllContainersRunningPodWatcher(client, pod); + for (int i = 0; i < template.getSlaveConnectTimeout(); i++) { + watcher.updateState(pod); + if (watcher.areAllContainersRunning(pod)) { + LOGGER.log(INFO, "areAllContainersRunning: true " + podName); + done = true; + break; + } else { + LOGGER.log(INFO, "areAllContainersRunning: false " + podName); + } + Thread.sleep(1000); + } + if (!done) { + throw new KubernetesClientTimeoutException(pod, template.getSlaveConnectTimeout(), TimeUnit.SECONDS); + }*/ + + Pod checkPod = client.pods().inNamespace(namespace).withName(podName).waitUntilReady(template.getSlaveConnectTimeout(), TimeUnit.SECONDS); + if (!Readiness.isPodReady(checkPod)) { + throw new KubernetesClientTimeoutException(pod, template.getSlaveConnectTimeout(), TimeUnit.SECONDS); } + +/* boolean done = false; + for (int minutes = 0; minutes < TimeUnit.SECONDS.toMinutes(template.getSlaveConnectTimeout()); minutes++) { + Pod checkPod = client.pods().inNamespace(namespace).withName(podName).waitUntilReady(1, TimeUnit.MINUTES); + if (Readiness.isPodReady(checkPod)) { + LOGGER.log(INFO, "Pod ready: true " + podName); + done = true; + break; + } else { + LOGGER.log(INFO, "Pod ready: false " + minutes + " minutes and timeout:" + template.getSlaveConnectTimeout() + " pod: " + podName); + } + } + if (!done) { + throw new KubernetesClientTimeoutException(pod, template.getSlaveConnectTimeout(), TimeUnit.SECONDS); + }*/ + LOGGER.log(INFO, () -> "Pod is running: " + cloudName + " " + namespace + "/" + podName); // We need the pod to be running and connected before returning @@ -279,7 +333,12 @@ else if (httpCode == 409 && e.getMessage().contains("Operation cannot be fulfill private Watch eventWatch(KubernetesClient client, String podName, String namespace, TaskListener runListener) { try { - return client.v1().events().inNamespace(namespace).withField("involvedObject.name", podName).watch(new TaskListenerEventWatcher(podName, runListener)); + LOGGER.log(Level.INFO, "in eventWatch"); + FilterWatchListDeletable yo = client.v1().events().inNamespace(namespace).withField("involvedObject.name", podName); + LOGGER.log(Level.INFO, "FilterWatchListDeletable done"); + Watch toreturn = yo.watch(new TaskListenerEventWatcher(podName, runListener)); + LOGGER.log(Level.INFO, "toreturn done"); + return toreturn; } catch (KubernetesClientException e) { LOGGER.log(Level.INFO, e, () -> "Cannot watch events on " + namespace + "/" +podName); } From 7d52b4420ca8c1bda40d0fed04ee3e8c9433186a Mon Sep 17 00:00:00 2001 From: Samuel Beaulieu Date: Mon, 25 Apr 2022 11:24:58 -0500 Subject: [PATCH 02/10] remove AllContainersRunningPodWatcher --- .../kubernetes/KubernetesLauncher.java | 86 +------------------ .../pipeline/ContainerExecDecoratorTest.java | 85 +++++++++--------- .../ContainerExecDecoratorWindowsTest.java | 27 +++--- 3 files changed, 52 insertions(+), 146 deletions(-) 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 5458a5d477..68429a805b 100644 --- a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesLauncher.java +++ b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesLauncher.java @@ -31,15 +31,11 @@ import hudson.slaves.JNLPLauncher; import hudson.slaves.SlaveComputer; import io.fabric8.kubernetes.api.model.ContainerStatus; -import io.fabric8.kubernetes.api.model.Event; -import io.fabric8.kubernetes.api.model.EventList; import io.fabric8.kubernetes.api.model.ObjectMeta; import io.fabric8.kubernetes.api.model.Pod; import io.fabric8.kubernetes.client.KubernetesClient; import io.fabric8.kubernetes.client.KubernetesClientException; import io.fabric8.kubernetes.client.KubernetesClientTimeoutException; -import io.fabric8.kubernetes.client.Watch; -import io.fabric8.kubernetes.client.dsl.FilterWatchListDeletable; import io.fabric8.kubernetes.client.internal.readiness.Readiness; import jenkins.metrics.api.Metrics; import org.apache.commons.lang.StringUtils; @@ -68,9 +64,6 @@ public class KubernetesLauncher extends JNLPLauncher { // Report progress every 30 seconds private static final long REPORT_INTERVAL = TimeUnit.SECONDS.toMillis(30L); - @CheckForNull - private transient AllContainersRunningPodWatcher watcher; - private static final Logger LOGGER = Logger.getLogger(KubernetesLauncher.class.getName()); private boolean launched; @@ -172,60 +165,13 @@ else if (httpCode == 409 && e.getMessage().contains("Operation cannot be fulfill ObjectMeta podMetadata = pod.getMetadata(); template.getWorkspaceVolume().createVolume(client, podMetadata); template.getVolumes().forEach(volume -> volume.createVolume(client, podMetadata)); -/* watcher = new AllContainersRunningPodWatcher(client, pod); - LOGGER.log(INFO, () -> "watcher set"); - PodResource mypodtemp = client.pods().inNamespace(namespace).withName(podName); - LOGGER.log(INFO, () -> "mypodtemp: " + mypodtemp); - Watch w1 = mypodtemp.watch(watcher); - LOGGER.log(INFO, () -> "w1: done" + mypodtemp); - Watch w2 = eventWatch(client, podName, namespace, runListener); - LOGGER.log(INFO, () -> "w2: done" + mypodtemp); -*//* try (Watch w1 = mypodtemp.watch(watcher); - Watch w2 = eventWatch(client, podName, namespace, runListener)) {*//* - assert watcher != null; // assigned 3 lines above - watcher.updateState(pod); - watcher.await(template.getSlaveConnectTimeout(), TimeUnit.SECONDS); -// } - w1.close(); - w2.close();*/ - -/* boolean done = false; - watcher = new AllContainersRunningPodWatcher(client, pod); - for (int i = 0; i < template.getSlaveConnectTimeout(); i++) { - watcher.updateState(pod); - if (watcher.areAllContainersRunning(pod)) { - LOGGER.log(INFO, "areAllContainersRunning: true " + podName); - done = true; - break; - } else { - LOGGER.log(INFO, "areAllContainersRunning: false " + podName); - } - Thread.sleep(1000); - } - if (!done) { - throw new KubernetesClientTimeoutException(pod, template.getSlaveConnectTimeout(), TimeUnit.SECONDS); - }*/ + // Removed watcher because of load issues making the fabric8 library wait indefinitely https://issues.jenkins.io/browse/JENKINS-68126 Pod checkPod = client.pods().inNamespace(namespace).withName(podName).waitUntilReady(template.getSlaveConnectTimeout(), TimeUnit.SECONDS); if (!Readiness.isPodReady(checkPod)) { throw new KubernetesClientTimeoutException(pod, template.getSlaveConnectTimeout(), TimeUnit.SECONDS); } -/* boolean done = false; - for (int minutes = 0; minutes < TimeUnit.SECONDS.toMinutes(template.getSlaveConnectTimeout()); minutes++) { - Pod checkPod = client.pods().inNamespace(namespace).withName(podName).waitUntilReady(1, TimeUnit.MINUTES); - if (Readiness.isPodReady(checkPod)) { - LOGGER.log(INFO, "Pod ready: true " + podName); - done = true; - break; - } else { - LOGGER.log(INFO, "Pod ready: false " + minutes + " minutes and timeout:" + template.getSlaveConnectTimeout() + " pod: " + podName); - } - } - if (!done) { - throw new KubernetesClientTimeoutException(pod, template.getSlaveConnectTimeout(), TimeUnit.SECONDS); - }*/ - LOGGER.log(INFO, () -> "Pod is running: " + cloudName + " " + namespace + "/" + podName); // We need the pod to be running and connected before returning @@ -310,17 +256,7 @@ else if (httpCode == 409 && e.getMessage().contains("Operation cannot be fulfill Metrics.metricRegistry().counter(MetricNames.PODS_LAUNCHED).inc(); } catch (Throwable ex) { setProblem(ex); - if (ex instanceof AllContainersRunningPodWatcher.PodNotRunningException) { - Throwable[] suppressed = ex.getSuppressed(); - if (suppressed.length > 0 && suppressed[0] instanceof ContainerLogs) { - runListener.getLogger().println("Unable to provision agent " + node.getNodeName() + " :"); - runListener.getLogger().print(suppressed[0].getMessage()); - } - LOGGER.log(Level.WARNING, String.format("Error in provisioning: %s; agent=%s, template=%s", ex.getMessage(), node, template)); - LOGGER.log(Level.FINE, null, ex); - } else { - LOGGER.log(Level.WARNING, String.format("Error in provisioning; agent=%s, template=%s", node, template), 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()); try { node.terminate(); @@ -331,20 +267,6 @@ else if (httpCode == 409 && e.getMessage().contains("Operation cannot be fulfill } } - private Watch eventWatch(KubernetesClient client, String podName, String namespace, TaskListener runListener) { - try { - LOGGER.log(Level.INFO, "in eventWatch"); - FilterWatchListDeletable yo = client.v1().events().inNamespace(namespace).withField("involvedObject.name", podName); - LOGGER.log(Level.INFO, "FilterWatchListDeletable done"); - Watch toreturn = yo.watch(new TaskListenerEventWatcher(podName, runListener)); - LOGGER.log(Level.INFO, "toreturn done"); - return toreturn; - } catch (KubernetesClientException e) { - LOGGER.log(Level.INFO, e, () -> "Cannot watch events on " + namespace + "/" +podName); - } - return () -> {}; - } - private void checkTerminatedContainers(List terminatedContainers, String podId, String namespace, KubernetesSlave slave, KubernetesClient client) { if (!terminatedContainers.isEmpty()) { @@ -389,8 +311,4 @@ public void setProblem(@CheckForNull Throwable problem) { this.problem = problem; } - public AllContainersRunningPodWatcher getWatcher() { - return watcher; - } - } diff --git a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorTest.java b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorTest.java index cab62a167c..53020abfb5 100644 --- a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorTest.java +++ b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorTest.java @@ -24,39 +24,24 @@ package org.csanchez.jenkins.plugins.kubernetes.pipeline; -import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.*; -import static org.hamcrest.MatcherAssert.assertThat; -import static org.hamcrest.Matchers.arrayContaining; -import static org.hamcrest.Matchers.isA; -import static org.junit.Assert.assertEquals; -import static org.junit.Assert.assertFalse; -import static org.junit.Assert.assertTrue; -import static org.mockito.Mockito.doReturn; -import static org.mockito.Mockito.mock; -import static org.mockito.Mockito.when; - -import io.fabric8.kubernetes.client.http.WebSocketHandshakeException; -import java.io.ByteArrayOutputStream; -import java.util.ArrayList; -import java.util.Collections; -import java.util.HashMap; -import java.util.List; -import java.util.Map; -import java.util.Optional; -import java.util.concurrent.TimeUnit; -import java.util.concurrent.atomic.AtomicInteger; -import java.util.logging.Level; -import java.util.logging.Logger; -import java.util.regex.Pattern; - import hudson.EnvVars; +import hudson.Launcher; +import hudson.Launcher.DummyLauncher; +import hudson.Launcher.ProcStarter; import hudson.model.Computer; +import hudson.model.Node; +import hudson.slaves.DumbSlave; +import hudson.util.StreamTaskListener; +import io.fabric8.kubernetes.api.model.ContainerBuilder; +import io.fabric8.kubernetes.api.model.Pod; +import io.fabric8.kubernetes.api.model.PodBuilder; +import io.fabric8.kubernetes.client.HttpClientAware; +import io.fabric8.kubernetes.client.KubernetesClient; import io.fabric8.kubernetes.client.KubernetesClientException; -import io.fabric8.kubernetes.client.Watch; +import io.fabric8.kubernetes.client.http.WebSocketHandshakeException; import org.apache.commons.io.output.TeeOutputStream; import org.apache.commons.lang.RandomStringUtils; import org.apache.commons.lang.StringUtils; -import org.csanchez.jenkins.plugins.kubernetes.AllContainersRunningPodWatcher; import org.csanchez.jenkins.plugins.kubernetes.KubernetesClientProvider; import org.csanchez.jenkins.plugins.kubernetes.KubernetesCloud; import org.csanchez.jenkins.plugins.kubernetes.KubernetesSlave; @@ -65,27 +50,42 @@ import org.junit.After; import org.junit.Before; import org.junit.BeforeClass; +import org.junit.Ignore; import org.junit.Rule; import org.junit.Test; import org.junit.rules.ExpectedException; import org.junit.rules.TestName; import org.junit.rules.Timeout; import org.jvnet.hudson.test.Issue; +import org.jvnet.hudson.test.JenkinsRule; import org.jvnet.hudson.test.LoggerRule; -import hudson.Launcher; -import hudson.Launcher.DummyLauncher; -import hudson.Launcher.ProcStarter; -import hudson.model.Node; -import hudson.slaves.DumbSlave; -import hudson.util.StreamTaskListener; -import io.fabric8.kubernetes.api.model.ContainerBuilder; -import io.fabric8.kubernetes.api.model.Pod; -import io.fabric8.kubernetes.api.model.PodBuilder; -import io.fabric8.kubernetes.client.HttpClientAware; -import io.fabric8.kubernetes.client.KubernetesClient; -import org.junit.Ignore; -import org.jvnet.hudson.test.JenkinsRule; +import java.io.ByteArrayOutputStream; +import java.util.ArrayList; +import java.util.Collections; +import java.util.HashMap; +import java.util.List; +import java.util.Map; +import java.util.Optional; +import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicInteger; +import java.util.logging.Level; +import java.util.logging.Logger; +import java.util.regex.Pattern; + +import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.assumeKubernetes; +import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.deletePods; +import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.getLabels; +import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.setupCloud; +import static org.hamcrest.MatcherAssert.assertThat; +import static org.hamcrest.Matchers.arrayContaining; +import static org.hamcrest.Matchers.isA; +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertTrue; +import static org.mockito.Mockito.doReturn; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.when; /** * @author Carlos Sanchez @@ -155,11 +155,6 @@ public void configureCloud() throws Exception { .endSpec().build()); System.out.println("Created pod: " + pod.getMetadata().getName()); - AllContainersRunningPodWatcher watcher = new AllContainersRunningPodWatcher(client, pod); - try (Watch w1 = client.pods().withName(podName).watch(watcher);) { - assert watcher != null; // assigned 3 lines above - watcher.await(30, TimeUnit.SECONDS); - } PodTemplate template = new PodTemplate(); template.setName(pod.getMetadata().getName()); agent = mock(KubernetesSlave.class); diff --git a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorWindowsTest.java b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorWindowsTest.java index f1ad81d866..62167e09e5 100644 --- a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorWindowsTest.java +++ b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorWindowsTest.java @@ -33,20 +33,8 @@ import io.fabric8.kubernetes.api.model.Pod; import io.fabric8.kubernetes.api.model.PodBuilder; import io.fabric8.kubernetes.client.KubernetesClient; -import io.fabric8.kubernetes.client.Watch; -import java.io.ByteArrayOutputStream; -import java.io.OutputStream; -import java.nio.charset.StandardCharsets; -import java.util.HashMap; -import java.util.Map; -import java.util.Optional; -import java.util.concurrent.TimeUnit; -import java.util.logging.Level; -import java.util.logging.Logger; -import java.util.regex.Pattern; import org.apache.commons.io.output.TeeOutputStream; import org.apache.commons.lang.RandomStringUtils; -import org.csanchez.jenkins.plugins.kubernetes.AllContainersRunningPodWatcher; import org.csanchez.jenkins.plugins.kubernetes.KubernetesClientProvider; import org.csanchez.jenkins.plugins.kubernetes.KubernetesCloud; import org.csanchez.jenkins.plugins.kubernetes.KubernetesSlave; @@ -63,6 +51,16 @@ import org.jvnet.hudson.test.LoggerRule; import org.jvnet.hudson.test.recipes.WithTimeout; +import java.io.ByteArrayOutputStream; +import java.io.OutputStream; +import java.nio.charset.StandardCharsets; +import java.util.HashMap; +import java.util.Map; +import java.util.Optional; +import java.util.logging.Level; +import java.util.logging.Logger; +import java.util.regex.Pattern; + import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.WINDOWS_1809_BUILD; import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.assumeKubernetes; import static org.csanchez.jenkins.plugins.kubernetes.KubernetesTestUtil.assumeWindows; @@ -131,11 +129,6 @@ public void configureCloud() throws Exception { .endSpec().build()); System.out.println("Created pod: " + pod.getMetadata().getName()); - AllContainersRunningPodWatcher watcher = new AllContainersRunningPodWatcher(client, pod); - try (Watch w1 = client.pods().withName(podName).watch(watcher);) { - assert watcher != null; // assigned 3 lines above - watcher.await(10, TimeUnit.MINUTES); - } PodTemplate template = new PodTemplate(); template.setName(pod.getMetadata().getName()); agent = mock(KubernetesSlave.class); From 48ad48613c9b57d79d8527ea7eecf25ed877584e Mon Sep 17 00:00:00 2001 From: Samuel Beaulieu Date: Mon, 25 Apr 2022 13:08:22 -0500 Subject: [PATCH 03/10] delete the class AllContainersRunningPodWatcher --- .../AllContainersRunningPodWatcher.java | 176 ------------------ 1 file changed, 176 deletions(-) delete mode 100644 src/main/java/org/csanchez/jenkins/plugins/kubernetes/AllContainersRunningPodWatcher.java diff --git a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/AllContainersRunningPodWatcher.java b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/AllContainersRunningPodWatcher.java deleted file mode 100644 index ddb81ccffe..0000000000 --- a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/AllContainersRunningPodWatcher.java +++ /dev/null @@ -1,176 +0,0 @@ -package org.csanchez.jenkins.plugins.kubernetes; - -import io.fabric8.kubernetes.api.model.ContainerStatus; -import io.fabric8.kubernetes.api.model.Pod; -import io.fabric8.kubernetes.api.model.PodStatus; -import io.fabric8.kubernetes.client.KubernetesClient; -import io.fabric8.kubernetes.client.KubernetesClientTimeoutException; -import io.fabric8.kubernetes.client.Watcher; -import io.fabric8.kubernetes.client.WatcherException; -import io.fabric8.kubernetes.client.utils.Serialization; - -import java.util.List; -import java.util.concurrent.CountDownLatch; -import java.util.concurrent.TimeUnit; -import java.util.concurrent.atomic.AtomicReference; -import java.util.logging.Level; -import java.util.logging.Logger; - -import static java.util.stream.Collectors.joining; - -/** - * A pod watcher reporting when all containers are running - */ -public class AllContainersRunningPodWatcher implements Watcher { - private static final Logger LOGGER = Logger.getLogger(AllContainersRunningPodWatcher.class.getName()); - - private final CountDownLatch latch = new CountDownLatch(1); - private final AtomicReference reference = new AtomicReference<>(); - - private Pod pod; - - private KubernetesClient client; - - public AllContainersRunningPodWatcher(KubernetesClient client, Pod pod) { - this.client = client; - this.pod = pod; - updateState(pod); - } - - @Override - public void eventReceived(Action action, Pod pod) { - LOGGER.log(Level.INFO, "[{0}] {1}", new Object[]{action, pod.getMetadata().getName()}); - switch (action) { - case MODIFIED: - updateState(pod); - break; - default: - } - } - - public void updateState(Pod pod) { - if (areAllContainersRunning(pod)) { - LOGGER.log(Level.INFO, "All containers are running for pod {0}", new Object[] {pod.getMetadata().getName()}); - reference.set(pod); - latch.countDown(); - } else { - LOGGER.log(Level.INFO, "Not all containers are running for pod {0}", new Object[] {pod.getMetadata().getName()}); - } - } - - boolean areAllContainersRunning(Pod pod) { - return pod.getSpec().getContainers().size() == pod.getStatus().getContainerStatuses().size() && PodUtils.getContainerStatus(pod).stream().allMatch(ContainerStatus::getReady); - } - - @Override - public void onClose(WatcherException cause) { - - } - - /** - * Wait until all pod containers are running - * - * @return the pod - * @throws PodNotRunningException - * if pod or containers are no longer running - * @throws KubernetesClientTimeoutException - * if time ran out - */ - public Pod await(long amount, TimeUnit timeUnit) throws PodNotRunningException { - LOGGER.log(Level.INFO, "Await started for pod {0}", new Object[] {pod.getMetadata().getName()}); - long started = System.currentTimeMillis(); - long alreadySpent = System.currentTimeMillis() - started; - long remaining = timeUnit.toMillis(amount) - alreadySpent; - if (remaining <= 0) { - LOGGER.log(Level.INFO, "Await remaining <= 0 for pod {0}", new Object[] {pod.getMetadata().getName()}); - return periodicAwait(0, System.currentTimeMillis(), 0, 0); - } - try { - long interval = Math.min(10000L, Math.max(remaining / 10, 1000L)); - long retries = remaining / interval; - LOGGER.log(Level.INFO, "Calling periodicAwait with {1}} for pod {0}", new Object[] {pod.getMetadata().getName(), retries}); - return periodicAwait(retries, System.currentTimeMillis(), interval, remaining); - } catch (KubernetesClientTimeoutException e) { - // Wrap using the right timeout - throw new KubernetesClientTimeoutException(pod, amount, timeUnit); - } - } - - private Pod awaitWatcher(long amount, TimeUnit timeUnit) { - try { - if (latch.await(amount, timeUnit)) { - return reference.get(); - } - throw new KubernetesClientTimeoutException(pod, amount, timeUnit); - } catch (InterruptedException e) { - throw new KubernetesClientTimeoutException(pod, amount, timeUnit); - } - } - - /** - * Wait until all pod containers are running - * - * @return the pod - * @throws PodNotRunningException - * if pod or containers are no longer running - * @throws KubernetesClientTimeoutException - * if time ran out - */ - private Pod periodicAwait(long i, long started, long interval, long amount) throws PodNotRunningException { - LOGGER.info(() -> "Periodic await #" + Long.toString(i) + " " + this.pod.getMetadata().getName()); - Pod pod = client.pods().inNamespace(this.pod.getMetadata().getNamespace()) - .withName(this.pod.getMetadata().getName()).get(); - if (pod == null) { - throw new PodNotRunningException(String.format("Pod is no longer available: %s/%s", - this.pod.getMetadata().getNamespace(), this.pod.getMetadata().getName())); - } else { - LOGGER.info(() -> "Updating pod for " + this.pod.getMetadata().getNamespace() + "/" + this.pod.getMetadata().getName() + " : " + Serialization.asYaml(pod)); - this.pod = pod; - } - List terminatedContainers = PodUtils.getTerminatedContainers(pod); - if (!terminatedContainers.isEmpty()) { - PodNotRunningException x = new PodNotRunningException(String.format("Pod has terminated containers: %s/%s (%s)", - this.pod.getMetadata().getNamespace(), - this.pod.getMetadata().getName(), - terminatedContainers.stream() - .map(ContainerStatus::getName) - .collect(joining(", ") - ))); - String logs = PodUtils.logLastLines(this.pod, client); - if (logs != null) { - x.addSuppressed(new ContainerLogs(logs)); - } - throw x; - } - if (areAllContainersRunning(pod)) { - LOGGER.info(() -> "Periodic await all running! " + this.pod.getMetadata().getName()); - return pod; - } - try { - LOGGER.info(() -> "Calling awaitWatcher with interval " + interval); - return awaitWatcher(interval, TimeUnit.MILLISECONDS); - } catch (KubernetesClientTimeoutException e) { - LOGGER.info(() -> "KubernetesClientTimeoutException awaitWatcher thrown and swallowed"); - if (i <= 0) { - LOGGER.info(() -> "KubernetesClientTimeoutException awaitWatcher i <= 0"); - throw e; - } - } - - long remaining = (started + amount) - System.currentTimeMillis(); - long next = Math.max(0, Math.min(remaining, interval)); - return periodicAwait(i - 1, started, next, amount); - } - - public PodStatus getPodStatus() { - return this.pod.getStatus(); - } - - /** @see #await */ - public static final class PodNotRunningException extends Exception { - PodNotRunningException(String s) { - super(s); - } - } - -} From a8923bd9f583a71a54ddecb4fa9b2b3302da86a7 Mon Sep 17 00:00:00 2001 From: Samuel Beaulieu Date: Tue, 3 May 2022 15:01:27 -0500 Subject: [PATCH 04/10] fix tests by adding a check ready pod step --- .../plugins/kubernetes/pipeline/ContainerExecDecoratorTest.java | 1 + .../kubernetes/pipeline/ContainerExecDecoratorWindowsTest.java | 2 ++ 2 files changed, 3 insertions(+) diff --git a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorTest.java b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorTest.java index 53020abfb5..a1fd76cf41 100644 --- a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorTest.java +++ b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorTest.java @@ -155,6 +155,7 @@ public void configureCloud() throws Exception { .endSpec().build()); System.out.println("Created pod: " + pod.getMetadata().getName()); + Pod checkPod = client.pods().withName(podName).waitUntilReady(30, TimeUnit.SECONDS); PodTemplate template = new PodTemplate(); template.setName(pod.getMetadata().getName()); agent = mock(KubernetesSlave.class); diff --git a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorWindowsTest.java b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorWindowsTest.java index 62167e09e5..59d8fa22bc 100644 --- a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorWindowsTest.java +++ b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorWindowsTest.java @@ -57,6 +57,7 @@ import java.util.HashMap; import java.util.Map; import java.util.Optional; +import java.util.concurrent.TimeUnit; import java.util.logging.Level; import java.util.logging.Logger; import java.util.regex.Pattern; @@ -129,6 +130,7 @@ public void configureCloud() throws Exception { .endSpec().build()); System.out.println("Created pod: " + pod.getMetadata().getName()); + Pod checkPod = client.pods().withName(podName).waitUntilReady(10, TimeUnit.MINUTES); PodTemplate template = new PodTemplate(); template.setName(pod.getMetadata().getName()); agent = mock(KubernetesSlave.class); From c08c95b1d82712d620a6a0c8df345997f923088d Mon Sep 17 00:00:00 2001 From: Samuel Date: Tue, 31 May 2022 10:47:00 -0500 Subject: [PATCH 05/10] Update src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesLauncher.java Co-authored-by: Jesse Glick --- .../csanchez/jenkins/plugins/kubernetes/KubernetesLauncher.java | 1 - 1 file changed, 1 deletion(-) 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 68429a805b..337275eb28 100644 --- a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesLauncher.java +++ b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesLauncher.java @@ -166,7 +166,6 @@ else if (httpCode == 409 && e.getMessage().contains("Operation cannot be fulfill template.getWorkspaceVolume().createVolume(client, podMetadata); template.getVolumes().forEach(volume -> volume.createVolume(client, podMetadata)); - // Removed watcher because of load issues making the fabric8 library wait indefinitely https://issues.jenkins.io/browse/JENKINS-68126 Pod checkPod = client.pods().inNamespace(namespace).withName(podName).waitUntilReady(template.getSlaveConnectTimeout(), TimeUnit.SECONDS); if (!Readiness.isPodReady(checkPod)) { throw new KubernetesClientTimeoutException(pod, template.getSlaveConnectTimeout(), TimeUnit.SECONDS); From 8c3b4501ca3bfabcb221f8139cd9a1858402318b Mon Sep 17 00:00:00 2001 From: Vincent Latombe Date: Wed, 1 Jun 2022 09:52:02 +0200 Subject: [PATCH 06/10] Remove this assertion as event streaming has been removed --- .../plugins/kubernetes/pipeline/KubernetesPipelineTest.java | 1 - 1 file changed, 1 deletion(-) 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 8e9cae66e4..1f90660a44 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 @@ -201,7 +201,6 @@ public void runInPod() throws Exception { r.assertBuildStatusSuccess(r.waitForCompletion(b)); r.assertLogContains("container=busybox", b); r.assertLogContains("script file contents: ", b); - r.assertLogContains("Created container jnlp", b); assertFalse("There are pods leftover after test execution, see previous logs", deletePods(cloud.connect(), getLabels(cloud, this, name), true)); assertThat("routine build should not issue warnings", From c4f2d1f41d5e883e72d88938a873fdbde86f7275 Mon Sep 17 00:00:00 2001 From: Vincent Latombe Date: Wed, 1 Jun 2022 09:52:45 +0200 Subject: [PATCH 07/10] Remove dead code as a consequence of this PR --- .../plugins/kubernetes/ContainerLogs.java | 25 ------------------- 1 file changed, 25 deletions(-) delete mode 100644 src/main/java/org/csanchez/jenkins/plugins/kubernetes/ContainerLogs.java diff --git a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/ContainerLogs.java b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/ContainerLogs.java deleted file mode 100644 index 998d955a8b..0000000000 --- a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/ContainerLogs.java +++ /dev/null @@ -1,25 +0,0 @@ -package org.csanchez.jenkins.plugins.kubernetes; - -/** - * Exception class used to convey container logs after a failure for information - */ -public class ContainerLogs extends Exception { - public ContainerLogs() { - } - - public ContainerLogs(String message) { - super(message); - } - - public ContainerLogs(String message, Throwable cause) { - super(message, cause); - } - - public ContainerLogs(Throwable cause) { - super(cause); - } - - public ContainerLogs(String message, Throwable cause, boolean enableSuppression, boolean writableStackTrace) { - super(message, cause, enableSuppression, writableStackTrace); - } -} From ffee1614263c7d7788cf6f8b27ca39484f8863ea Mon Sep 17 00:00:00 2001 From: Vincent Latombe Date: Tue, 7 Jun 2022 12:34:42 +0200 Subject: [PATCH 08/10] Fix more tests --- .../plugins/kubernetes/pipeline/KubernetesPipelineTest.java | 2 -- 1 file changed, 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 881a2ff4dc..61dd8f92d5 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 @@ -243,7 +243,6 @@ public void runIn2Pods() throws Exception { SemaphoreStep.success("pod2/1", null); r.assertBuildStatusSuccess(r.waitForCompletion(b)); r.assertLogContains("script file contents: ", b); - r.assertLogContains("Started container jnlp", b); assertFalse("There are pods leftover after test execution, see previous logs", deletePods(cloud.connect(), getLabels(cloud, this, name), true)); } @@ -287,7 +286,6 @@ public void inheritFrom() throws Exception { standard.setName("standard"); cloud.addTemplate(standard); r.assertBuildStatusSuccess(r.waitForCompletion(b)); - r.assertLogContains("Created container jnlp", b); } @Test From b670fc337e1065388021a077bdf0a0060bdbbbe6 Mon Sep 17 00:00:00 2001 From: Vincent Latombe Date: Wed, 8 Jun 2022 09:10:40 +0200 Subject: [PATCH 09/10] Apply suggestions from code review Co-authored-by: Jesse Glick --- .../plugins/kubernetes/pipeline/ContainerExecDecoratorTest.java | 2 +- .../kubernetes/pipeline/ContainerExecDecoratorWindowsTest.java | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorTest.java b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorTest.java index a1fd76cf41..bfd8e24972 100644 --- a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorTest.java +++ b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorTest.java @@ -155,7 +155,7 @@ public void configureCloud() throws Exception { .endSpec().build()); System.out.println("Created pod: " + pod.getMetadata().getName()); - Pod checkPod = client.pods().withName(podName).waitUntilReady(30, TimeUnit.SECONDS); + client.pods().withName(podName).waitUntilReady(30, TimeUnit.SECONDS); PodTemplate template = new PodTemplate(); template.setName(pod.getMetadata().getName()); agent = mock(KubernetesSlave.class); diff --git a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorWindowsTest.java b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorWindowsTest.java index 59d8fa22bc..b49b0b7207 100644 --- a/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorWindowsTest.java +++ b/src/test/java/org/csanchez/jenkins/plugins/kubernetes/pipeline/ContainerExecDecoratorWindowsTest.java @@ -130,7 +130,7 @@ public void configureCloud() throws Exception { .endSpec().build()); System.out.println("Created pod: " + pod.getMetadata().getName()); - Pod checkPod = client.pods().withName(podName).waitUntilReady(10, TimeUnit.MINUTES); + client.pods().withName(podName).waitUntilReady(10, TimeUnit.MINUTES); PodTemplate template = new PodTemplate(); template.setName(pod.getMetadata().getName()); agent = mock(KubernetesSlave.class); From 5700cb9fed08bf1ebb503fef0bc8c14eea088088 Mon Sep 17 00:00:00 2001 From: Vincent Latombe Date: Wed, 8 Jun 2022 09:12:53 +0200 Subject: [PATCH 10/10] Apply suggestions from code review Co-authored-by: Jesse Glick --- .../jenkins/plugins/kubernetes/KubernetesLauncher.java | 5 +---- 1 file changed, 1 insertion(+), 4 deletions(-) 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 337275eb28..04151f0b57 100644 --- a/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesLauncher.java +++ b/src/main/java/org/csanchez/jenkins/plugins/kubernetes/KubernetesLauncher.java @@ -166,10 +166,7 @@ else if (httpCode == 409 && e.getMessage().contains("Operation cannot be fulfill template.getWorkspaceVolume().createVolume(client, podMetadata); template.getVolumes().forEach(volume -> volume.createVolume(client, podMetadata)); - Pod checkPod = client.pods().inNamespace(namespace).withName(podName).waitUntilReady(template.getSlaveConnectTimeout(), TimeUnit.SECONDS); - if (!Readiness.isPodReady(checkPod)) { - throw new KubernetesClientTimeoutException(pod, template.getSlaveConnectTimeout(), TimeUnit.SECONDS); - } + client.pods().inNamespace(namespace).withName(podName).waitUntilReady(template.getSlaveConnectTimeout(), TimeUnit.SECONDS); LOGGER.log(INFO, () -> "Pod is running: " + cloudName + " " + namespace + "/" + podName);