fix: run event source start on specific thread pool (#1606)

metacosm · web-flow · commit adb0963f1fda · 2022-11-25T10:36:59.000+01:00
Fixes #1603
diff --git a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/api/config/ExecutorServiceManager.java b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/api/config/ExecutorServiceManager.java
@@ -5,9 +5,13 @@
 import java.util.concurrent.Callable;
 import java.util.concurrent.ExecutionException;
 import java.util.concurrent.ExecutorService;
+import java.util.concurrent.Executors;
 import java.util.concurrent.Future;
 import java.util.concurrent.TimeUnit;
 import java.util.concurrent.TimeoutException;
+import java.util.function.Function;
+import java.util.stream.Collectors;
+import java.util.stream.Stream;
 
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
@@ -60,6 +64,31 @@ public synchronized static ExecutorServiceManager instance() {
     return instance;
   }
 
+  public static <T> void executeAndWaitForAllToComplete(Stream<T> stream,
+      Function<T, Void> task, Function<T, String> threadNamer) {
+    final var instrumented = new InstrumentedExecutorService(
+        Executors.newFixedThreadPool(Runtime.getRuntime().availableProcessors()));
+
+    try {
+      instrumented.invokeAll(stream.parallel().map(item -> (Callable<Void>) () -> {
+        // change thread name for easier debugging
+        final var thread = Thread.currentThread();
+        final var name = thread.getName();
+        thread.setName(threadNamer.apply(item));
+        try {
+          task.apply(item);
+          return null;
+        } finally {
+          // restore original name
+          thread.setName(name);
+        }
+      }).collect(Collectors.toList()));
+      shutdown(instrumented);
+    } catch (InterruptedException e) {
+      Thread.currentThread().interrupt();
+    }
+  }
+
   public ExecutorService executorService() {
     return executor;
   }
@@ -71,17 +100,18 @@ public ExecutorService workflowExecutorService() {
   private void doStop() {
     try {
       log.debug("Closing executor");
-      executor.shutdown();
-      workflowExecutor.shutdown();
-      if (!workflowExecutor.awaitTermination(terminationTimeoutSeconds, TimeUnit.SECONDS)) {
-        workflowExecutor.shutdownNow(); // if we timed out, waiting, cancel everything
-      }
-      if (!executor.awaitTermination(terminationTimeoutSeconds, TimeUnit.SECONDS)) {
-        executor.shutdownNow(); // if we timed out, waiting, cancel everything
-      }
-
+      shutdown(executor);
+      shutdown(workflowExecutor);
     } catch (InterruptedException e) {
       log.debug("Exception closing executor: {}", e.getLocalizedMessage());
+      Thread.currentThread().interrupt();
+    }
+  }
+
+  private static void shutdown(ExecutorService executorService) throws InterruptedException {
+    executorService.shutdown();
+    if (!executorService.awaitTermination(instance().terminationTimeoutSeconds, TimeUnit.SECONDS)) {
+      executorService.shutdownNow(); // if we timed out, waiting, cancel everything
     }
   }
 
diff --git a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/Controller.java b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/Controller.java
@@ -360,8 +360,8 @@ public void changeNamespaces(Set<String> namespaces) {
   }
 
   public synchronized void startEventProcessing() {
-    log.info("Started event processing for controller: {}", configuration.getName());
     eventProcessor.start();
+    log.info("Started event processing for controller: {}", configuration.getName());
   }
 
   private void throwMissingCRDException(String crdName, String specVersion, String controllerName) {
diff --git a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/EventSourceManager.java b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/EventSourceManager.java
@@ -4,6 +4,7 @@
 import java.util.List;
 import java.util.Objects;
 import java.util.Set;
+import java.util.function.Function;
 import java.util.stream.Collectors;
 import java.util.stream.Stream;
 
@@ -13,6 +14,7 @@
 import io.fabric8.kubernetes.api.model.HasMetadata;
 import io.javaoperatorsdk.operator.MissingCRDException;
 import io.javaoperatorsdk.operator.OperatorException;
+import io.javaoperatorsdk.operator.api.config.ExecutorServiceManager;
 import io.javaoperatorsdk.operator.api.config.NamespaceChangeable;
 import io.javaoperatorsdk.operator.api.reconciler.EventSourceInitializer;
 import io.javaoperatorsdk.operator.processing.Controller;
@@ -65,20 +67,36 @@ public void postProcessDefaultEventSourcesAfterProcessorInitializer() {
   @Override
   public synchronized void start() {
     startEventSource(eventSources.namedControllerResourceEventSource());
-    eventSources.additionalNamedEventSources()
-        .filter(es -> es.priority().equals(EventSourceStartPriority.RESOURCE_STATE_LOADER))
-        .parallel().forEach(this::startEventSource);
-    eventSources.additionalNamedEventSources()
-        .filter(es -> es.priority().equals(EventSourceStartPriority.DEFAULT))
-        .parallel().forEach(this::startEventSource);
+
+    ExecutorServiceManager.executeAndWaitForAllToComplete(
+        eventSources.additionalNamedEventSources()
+            .filter(es -> es.priority().equals(EventSourceStartPriority.RESOURCE_STATE_LOADER)),
+        this::startEventSource,
+        getThreadNamer("start"));
+
+    ExecutorServiceManager.executeAndWaitForAllToComplete(
+        eventSources.additionalNamedEventSources()
+            .filter(es -> es.priority().equals(EventSourceStartPriority.DEFAULT)),
+        this::startEventSource,
+        getThreadNamer("start"));
+  }
+
+  private static Function<NamedEventSource, String> getThreadNamer(String stage) {
+    return es -> {
+      final var name = es.name();
+      return es.priority() + " " + stage + " -> "
+          + (es.isNameSet() ? name + " " + es.original().getClass().getSimpleName() : name);
+    };
   }
 
   @Override
   public synchronized void stop() {
     stopEventSource(eventSources.namedControllerResourceEventSource());
-    eventSources.additionalNamedEventSources().parallel().forEach(this::stopEventSource);
+    ExecutorServiceManager.executeAndWaitForAllToComplete(
+        eventSources.additionalNamedEventSources(),
+        this::stopEventSource,
+        getThreadNamer("stop"));
     eventSources.clear();
-
   }
 
   @SuppressWarnings("rawtypes")
@@ -94,7 +112,7 @@ private void logEventSourceEvent(NamedEventSource eventSource, String event) {
     }
   }
 
-  private void startEventSource(NamedEventSource eventSource) {
+  private Void startEventSource(NamedEventSource eventSource) {
     try {
       logEventSourceEvent(eventSource, "Starting");
       eventSource.start();
@@ -104,16 +122,18 @@ private void startEventSource(NamedEventSource eventSource) {
     } catch (Exception e) {
       throw new OperatorException("Couldn't start source " + eventSource.name(), e);
     }
+    return null;
   }
 
-  private void stopEventSource(NamedEventSource eventSource) {
+  private Void stopEventSource(NamedEventSource eventSource) {
     try {
       logEventSourceEvent(eventSource, "Stopping");
       eventSource.stop();
       logEventSourceEvent(eventSource, "Stopped");
     } catch (Exception e) {
       log.warn("Error closing {} -> {}", eventSource.name(), e);
     }
+    return null;
   }
 
   public final void registerEventSource(EventSource eventSource) throws OperatorException {
diff --git a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/NamedEventSource.java b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/NamedEventSource.java
@@ -4,6 +4,7 @@
 import java.util.Optional;
 
 import io.javaoperatorsdk.operator.OperatorException;
+import io.javaoperatorsdk.operator.api.reconciler.EventSourceInitializer;
 import io.javaoperatorsdk.operator.processing.event.source.Configurable;
 import io.javaoperatorsdk.operator.processing.event.source.EventSource;
 import io.javaoperatorsdk.operator.processing.event.source.EventSourceStartPriority;
@@ -13,10 +14,12 @@ class NamedEventSource implements EventSource, EventSourceMetadata {
 
   private final EventSource original;
   private final String name;
+  private final boolean nameSet;
 
   NamedEventSource(EventSource original, String name) {
     this.original = original;
     this.name = name;
+    nameSet = !name.equals(EventSourceInitializer.generateNameFor(original));
   }
 
   @Override
@@ -95,4 +98,8 @@ public int hashCode() {
   public EventSourceStartPriority priority() {
     return original.priority();
   }
+
+  public boolean isNameSet() {
+    return nameSet;
+  }
 }
diff --git a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/InformerManager.java b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/InformerManager.java
@@ -45,7 +45,8 @@ public class InformerManager<T extends HasMetadata, C extends ResourceConfigurat
 
   @Override
   public void start() throws OperatorException {
-    sources.values().parallelStream().forEach(LifecycleAware::start);
+    // make sure informers are all started before proceeding further
+    sources.values().parallelStream().forEach(InformerWrapper::start);
   }
 
   void initSources(MixedOperation<T, KubernetesResourceList<T>, Resource<T>> client,
@@ -113,7 +114,6 @@ private InformerWrapper<T> createEventSource(
 
   @Override
   public void stop() {
-    log.info("Stopping {}", this);
     sources.forEach((ns, source) -> {
       try {
         log.debug("Stopping informer for namespace: {} -> {}", ns, source);
diff --git a/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/InformerWrapper.java b/operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/InformerWrapper.java
@@ -64,7 +64,11 @@ public void start() throws OperatorException {
       if (!configService.stopOnInformerErrorDuringStartup()) {
         informer.exceptionHandler((b, t) -> !ExceptionHandler.isDeserializationException(t));
       }
+      // change thread name for easier debugging
+      final var thread = Thread.currentThread();
+      final var name = thread.getName();
       try {
+        thread.setName(informerInfo() + " " + thread.getId());
         var start = informer.start();
         // note that in case we don't put here timeout and stopOnInformerErrorDuringStartup is
         // false, and there is a rbac issue the get never returns; therefore operator never really
@@ -81,6 +85,9 @@ public void start() throws OperatorException {
       } catch (InterruptedException e) {
         Thread.currentThread().interrupt();
         throw new IllegalStateException(e);
+      } finally {
+        // restore original name
+        thread.setName(name);
       }
 
     } catch (Exception e) {
@@ -143,6 +150,10 @@ public List<T> byIndex(String indexName, String indexKey) {
 
   @Override
   public String toString() {
-    return "InformerWrapper [" + versionedFullResourceName() + "] (" + informer + ')';
+    return informerInfo() + " (" + informer + ')';
+  }
+
+  private String informerInfo() {
+    return "InformerWrapper [" + versionedFullResourceName() + "]";
   }
 }
diff --git a/operator-framework-core/src/test/java/io/javaoperatorsdk/operator/processing/event/EventSourceManagerTest.java b/operator-framework-core/src/test/java/io/javaoperatorsdk/operator/processing/event/EventSourceManagerTest.java
@@ -4,6 +4,7 @@
 
 import org.junit.jupiter.api.Test;
 
+import io.fabric8.kubernetes.api.model.ConfigMap;
 import io.fabric8.kubernetes.api.model.HasMetadata;
 import io.javaoperatorsdk.operator.MockKubernetesClient;
 import io.javaoperatorsdk.operator.OperatorException;
@@ -171,9 +172,9 @@ void changesNamespacesOnControllerAndInformerEventSources() {
   }
 
   private EventSourceManager initManager() {
-    final var configuration = MockControllerConfiguration.forResource(HasMetadata.class);
+    final var configuration = MockControllerConfiguration.forResource(ConfigMap.class);
     final Controller controller = new Controller(mock(Reconciler.class), configuration,
-        MockKubernetesClient.client(HasMetadata.class));
+        MockKubernetesClient.client(ConfigMap.class));
     return new EventSourceManager(controller);
   }
 }
diff --git a/operator-framework-core/src/test/java/io/javaoperatorsdk/operator/processing/event/source/informer/InformerEventSourceTest.java b/operator-framework-core/src/test/java/io/javaoperatorsdk/operator/processing/event/source/informer/InformerEventSourceTest.java
@@ -10,6 +10,7 @@
 import io.fabric8.kubernetes.api.model.apps.Deployment;
 import io.fabric8.kubernetes.client.KubernetesClient;
 import io.javaoperatorsdk.operator.MockKubernetesClient;
+import io.javaoperatorsdk.operator.OperatorException;
 import io.javaoperatorsdk.operator.api.config.ConfigurationServiceProvider;
 import io.javaoperatorsdk.operator.api.config.InformerStoppedHandler;
 import io.javaoperatorsdk.operator.api.config.informer.InformerConfiguration;
@@ -259,7 +260,7 @@ void informerStoppedHandlerShouldBeCalledWhenInformerStops() {
 
       // by default informer fails to start if there is an exception in the client on start.
       // Throws the exception further.
-      assertThrows(RuntimeException.class, () -> informerEventSource.start());
+      assertThrows(OperatorException.class, () -> informerEventSource.start());
       verify(informerStoppedHandler, atLeastOnce()).onStop(any(), eq(exception));
     } finally {
       ConfigurationServiceProvider.reset();

Original file line number	Diff line number	Diff line change
`@@ -360,8 +360,8 @@ public void changeNamespaces(Set<String> namespaces) {`
`360`	`360`	`}`
`361`	`361`
`362`	`362`	`public synchronized void startEventProcessing() {`
`363`		`- log.info("Started event processing for controller: {}", configuration.getName());`
`364`	`363`	`eventProcessor.start();`
	`364`	`+ log.info("Started event processing for controller: {}", configuration.getName());`
`365`	`365`	`}`
`366`	`366`
`367`	`367`	`private void throwMissingCRDException(String crdName, String specVersion, String controllerName) {`
Original file line number	Diff line number	Diff line change
`@@ -4,6 +4,7 @@`
`4`	`4`
`5`	`5`	`import org.junit.jupiter.api.Test;`
`6`	`6`
	`7`	`+import io.fabric8.kubernetes.api.model.ConfigMap;`
`7`	`8`	`import io.fabric8.kubernetes.api.model.HasMetadata;`
`8`	`9`	`import io.javaoperatorsdk.operator.MockKubernetesClient;`
`9`	`10`	`import io.javaoperatorsdk.operator.OperatorException;`
`@@ -171,9 +172,9 @@ void changesNamespacesOnControllerAndInformerEventSources() {`
`171`	`172`	`}`
`172`	`173`
`173`	`174`	`private EventSourceManager initManager() {`
`174`		`- final var configuration = MockControllerConfiguration.forResource(HasMetadata.class);`
	`175`	`+ final var configuration = MockControllerConfiguration.forResource(ConfigMap.class);`
`175`	`176`	`final Controller controller = new Controller(mock(Reconciler.class), configuration,`
`176`		`- MockKubernetesClient.client(HasMetadata.class));`
	`177`	`+ MockKubernetesClient.client(ConfigMap.class));`
`177`	`178`	`return new EventSourceManager(controller);`
`178`	`179`	`}`
`179`	`180`	`}`