fix: improvements on informer start and logging (operator-framework#1749)

* fix: improvements on informer start and logging

* additional logging

* exception handling fix

* remove comment

* refactor: avoid retrieving name several times

---------

Co-authored-by: Chris Laprun <metacosm@gmail.com>

Author: csviri

operator-framework-core/src/main/java/io/javaoperatorsdk/operator/api/config/ExecutorServiceManager.java

@@ -16,6 +16,8 @@
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
 
+import io.javaoperatorsdk.operator.OperatorException;
+
 public class ExecutorServiceManager {
   private static final Logger log = LoggerFactory.getLogger(ExecutorServiceManager.class);
   private static ExecutorServiceManager instance;
@@ -82,7 +84,16 @@ public static <T> void executeAndWaitForAllToComplete(Stream<T> stream,
           // restore original name
           thread.setName(name);
         }
-      }).collect(Collectors.toList()));
+      }).collect(Collectors.toList())).forEach(f -> {
+        try {
+          // to find out any exceptions
+          f.get();
+        } catch (ExecutionException e) {
+          throw new OperatorException(e.getCause());
+        } catch (InterruptedException e) {
+          Thread.currentThread().interrupt();
+        }
+      });
       shutdown(instrumented);
     } catch (InterruptedException e) {
       Thread.currentThread().interrupt();

operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/Controller.java

@@ -335,7 +335,7 @@ public synchronized void start(boolean startEventProcessor) throws OperatorExcep
       if (startEventProcessor) {
         eventProcessor.start();
       }
-      log.info("'{}' controller started, pending event sources initialization", controllerName);
+      log.info("'{}' controller started", controllerName);
     } catch (MissingCRDException e) {
       stop();
       throwMissingCRDException(e.getCrdName(), e.getSpecVersion(), controllerName);

operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/EventSourceManager.java

@@ -82,7 +82,7 @@ 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);
+          + (es.isNameSet() ? name + " " + es.original().getClass() : es.original());
     };
   }
 

operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/InformerManager.java

@@ -25,6 +25,7 @@
 import io.javaoperatorsdk.operator.ReconcilerUtils;
 import io.javaoperatorsdk.operator.api.config.Cloner;
 import io.javaoperatorsdk.operator.api.config.ConfigurationServiceProvider;
+import io.javaoperatorsdk.operator.api.config.ExecutorServiceManager;
 import io.javaoperatorsdk.operator.api.config.ResourceConfiguration;
 import io.javaoperatorsdk.operator.health.InformerHealthIndicator;
 import io.javaoperatorsdk.operator.processing.LifecycleAware;
@@ -58,7 +59,13 @@ public InformerManager(MixedOperation<T, KubernetesResourceList<T>, Resource<T>>
   public void start() throws OperatorException {
     initSources();
     // make sure informers are all started before proceeding further
-    sources.values().parallelStream().forEach(InformerWrapper::start);
+    ExecutorServiceManager.executeAndWaitForAllToComplete(sources.values().stream(),
+        iw -> {
+          iw.start();
+          return null;
+        },
+        iw -> "InformerStarter-" + iw.getTargetNamespace() + "-"
+            + configuration.getResourceClass().getSimpleName());
   }
 
   private void initSources() {

operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/InformerWrapper.java

@@ -73,12 +73,19 @@ public void start() throws OperatorException {
       final var name = thread.getName();
       try {
         thread.setName(informerInfo() + " " + thread.getId());
+        final var resourceName = informer.getApiTypeClass().getSimpleName();
+        log.debug("Starting informer for namespace: {} resource: {}", namespaceIdentifier,
+            resourceName);
         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
         // starts
+        log.trace("Waiting informer to start namespace: {} resource: {}", namespaceIdentifier,
+            resourceName);
         start.toCompletableFuture().get(configService.cacheSyncTimeout().toMillis(),
             TimeUnit.MILLISECONDS);
+        log.debug("Started informer for namespace: {} resource: {}", namespaceIdentifier,
+            resourceName);
       } catch (TimeoutException | ExecutionException e) {
         if (configService.stopOnInformerErrorDuringStartup()) {
           log.error("Informer startup error. Operator will be stopped. Informer: {}", informer, e);

operator-framework-core/src/main/java/io/javaoperatorsdk/operator/processing/event/source/informer/ManagedInformerEventSource.java

@@ -163,4 +163,11 @@ public ResourceConfiguration<R> getInformerConfiguration() {
   public C configuration() {
     return manager().configuration();
   }
+
+  @Override
+  public String toString() {
+    return getClass().getSimpleName() + "{" +
+        "resourceClass: " + configuration.getResourceClass().getSimpleName() +
+        "}";
+  }
 }