Add bundles-diag
[odlparent.git] / features-test-plugin / src / main / java / org / opendaylight / odlparent / features / test / plugin / TestProbe.java
index 27905ded3638c256cf09759e98d1bbd0b9a82d68..09d42aa89b754e288582dec25548b23d7691ad0a 100644 (file)
@@ -7,23 +7,20 @@
  */
 package org.opendaylight.odlparent.features.test.plugin;
 
-import static org.apache.karaf.bundle.core.BundleState.Installed;
-import static org.apache.karaf.bundle.core.BundleState.Waiting;
-
 import java.io.File;
 import java.net.URI;
-import java.util.Arrays;
 import java.util.EnumSet;
-import java.util.HashMap;
 import java.util.Map;
 import java.util.concurrent.TimeUnit;
 import java.util.stream.Collectors;
 import javax.inject.Inject;
 import org.apache.karaf.bundle.core.BundleService;
-import org.apache.karaf.bundle.core.BundleState;
 import org.apache.karaf.features.FeaturesService;
 import org.junit.Test;
-import org.osgi.framework.Bundle;
+import org.opendaylight.odlparent.bundles.diag.ContainerState;
+import org.opendaylight.odlparent.bundles.diag.Diag;
+import org.opendaylight.odlparent.bundles.diag.DiagBundle;
+import org.opendaylight.odlparent.bundles.diag.spi.DefaultDiagProvider;
 import org.osgi.framework.BundleContext;
 import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;
@@ -60,15 +57,9 @@ public final class TestProbe {
         {FEATURE_FILE_URI_PROP, BUNDLE_CHECK_SKIP, BUNDLE_CHECK_TIMEOUT_SECONDS, BUNDLE_CHECK_INTERVAL_SECONDS};
 
     private static final Logger LOG = LoggerFactory.getLogger(TestProbe.class);
-    private static final Map<Integer, String> OSGI_STATES = Map.of(
-        Bundle.INSTALLED, "Installed", Bundle.RESOLVED, "Resolved",
-        Bundle.STARTING, "Starting", Bundle.ACTIVE, "Active",
-        Bundle.STOPPING, "Stopping", Bundle.UNINSTALLED, "Uninstalled");
-    private static final Map<String, BundleState> ELIGIBLE_STATES = Map.of(
-        "slf4j.log4j12", Installed,
-        "org.apache.karaf.scr.management", Waiting);
-
-    private final Map<Long, CheckResult> bundleCheckResults = new HashMap<>();
+    private static final Map<String, ContainerState> ELIGIBLE_STATES = Map.of(
+        "slf4j.log4j12", ContainerState.INSTALLED,
+        "org.apache.karaf.scr.management", ContainerState.WAITING);
 
     @Inject
     private BundleContext bundleContext;
@@ -134,50 +125,58 @@ public final class TestProbe {
     }
 
     private void checkBundleStates() throws InterruptedException {
-        if ("true".equals(System.getProperty(BUNDLE_CHECK_SKIP))) {
+        if (Boolean.getBoolean(BUNDLE_CHECK_SKIP)) {
+            LOG.warn("SKIPPING bundle check because system property {} is set to true", BUNDLE_CHECK_SKIP);
             return;
         }
+
         final int timeout = Integer.parseInt(System.getProperty(BUNDLE_CHECK_TIMEOUT_SECONDS, DEFAULT_TIMEOUT));
         final int interval = Integer.parseInt(System.getProperty(BUNDLE_CHECK_INTERVAL_SECONDS, DEFAULT_INTERVAL));
-        LOG.info("Checking bundle states. Interval = {} second(s). Timeout = {} second(s).", interval, timeout);
+        LOG.info("Bundle check started. Interval = {} second(s). Timeout = {} second(s).", interval, timeout);
 
+        final var intervalNanos = TimeUnit.SECONDS.toNanos(interval);
         final var maxNanos = TimeUnit.SECONDS.toNanos(timeout);
         final var started = System.nanoTime();
+        final var diagProvider = new DefaultDiagProvider(bundleService, bundleContext);
+
+        Diag prevDiag = null;
         while (true) {
-            Arrays.stream(bundleContext.getBundles()).forEach(this::captureBundleState);
-            final var result = aggregatedCheckResults();
-            if (result == CheckResult.IN_PROGRESS) {
-                final var now = System.nanoTime();
-                if (now - started >= maxNanos) {
-                    logNokBundleDetails();
-                    throw new IllegalStateException("Bundles states check timeout");
+            final var diag = diagProvider.currentDiag();
+            LOG.info("Bundle check {}", diag.containerStateFrequencies());
+            if (prevDiag != null) {
+                diag.logDelta(LOG, prevDiag);
+            }
+            prevDiag = diag;
+
+            final var bundleCheckResults = diag.bundles().stream()
+                .collect(Collectors.toMap(DiagBundle::bundleId,
+                    bundle -> checkResultOf(bundle.symbolicName(), bundle.serviceState().containerState())));
+            final var result = aggregatedCheckResults(bundleCheckResults);
+            final var elapsed = System.nanoTime() - started;
+
+            if (result != CheckResult.IN_PROGRESS) {
+                LOG.info("Bundle check completed with result {} after {}s", result,
+                    TimeUnit.NANOSECONDS.toSeconds(elapsed));
+                if (result != CheckResult.SUCCESS) {
+                    diag.logState(LOG);
+                    throw new IllegalStateException("Bundle states check failure");
                 }
-
-                TimeUnit.SECONDS.sleep(interval);
-                continue;
+                break;
             }
 
-            LOG.info("Bundle state check completed with result {}", result);
-            if (result != CheckResult.SUCCESS) {
-                logNokBundleDetails();
-                throw new IllegalStateException("Bundle states check failure");
-            }
-            break;
-        }
-    }
+            // FIXME: log remaining
 
-    private void captureBundleState(final Bundle bundle) {
-        if (bundle != null) {
-            final var info = bundleService.getInfo(bundle);
-            final var checkResult = checkResultOf(info.getSymbolicName(), info.getState());
-            if (checkResult != bundleCheckResults.get(bundle.getBundleId())) {
-                LOG.info("Bundle {} -> State: {} ({})", info.getSymbolicName(), info.getState(), checkResult);
-                bundleCheckResults.put(bundle.getBundleId(), checkResult);
+            final var remainingNanos = maxNanos - elapsed;
+            if (remainingNanos <= 0) {
+                diag.logState(LOG);
+                throw new IllegalStateException("Bundles states check timeout");
             }
+
+            TimeUnit.NANOSECONDS.sleep(Math.min(remainingNanos, intervalNanos));
         }
     }
 
-    private CheckResult aggregatedCheckResults() {
+    private static CheckResult aggregatedCheckResults(final Map<Long, CheckResult> bundleCheckResults) {
         final var resultStats = bundleCheckResults.entrySet().stream()
             .collect(Collectors.groupingBy(Map.Entry::getValue, Collectors.counting()));
         LOG.info("Bundle states check results: total={}, byResult={}", bundleCheckResults.size(), resultStats);
@@ -188,38 +187,23 @@ public final class TestProbe {
         if (resultStats.getOrDefault(CheckResult.STOPPING, 0L) > 0) {
             return CheckResult.STOPPING;
         }
-        return resultStats.getOrDefault(CheckResult.IN_PROGRESS, 0L) == 0
-            ? CheckResult.SUCCESS : CheckResult.IN_PROGRESS;
-    }
-
-    private void logNokBundleDetails() {
-        final var nokBundles = bundleCheckResults.entrySet().stream()
-            .filter(entry -> CheckResult.SUCCESS != entry.getValue())
-            .map(Map.Entry::getKey).collect(Collectors.toSet());
-
-        for (var bundle : bundleContext.getBundles()) {
-            if (nokBundles.contains(bundle.getBundleId())) {
-                final var info = bundleService.getInfo(bundle);
-                final var diag = bundleService.getDiag(bundle);
-                final var diagText = diag.isEmpty() ? "" : ", diag: " + diag;
-                final var osgiState = OSGI_STATES.getOrDefault(bundle.getState(), "Unknown");
-                LOG.warn("NOK Bundle {}:{} -> OSGi state: {}, Karaf bundle state: {}{}",
-                    info.getSymbolicName(), info.getVersion(), osgiState, info.getState(), diagText);
-            }
+        if (resultStats.getOrDefault(CheckResult.IN_PROGRESS, 0L) > 0) {
+            return CheckResult.IN_PROGRESS;
         }
+        return CheckResult.SUCCESS;
     }
 
-    static CheckResult checkResultOf(final String bundleName, final BundleState state) {
+    static CheckResult checkResultOf(final String bundleName, final ContainerState state) {
         if (bundleName != null && state == ELIGIBLE_STATES.get(bundleName)) {
             return CheckResult.SUCCESS;
         }
-        if (state == BundleState.Stopping) {
+        if (state == ContainerState.STOPPING) {
             return CheckResult.STOPPING;
         }
-        if (state == BundleState.Failure) {
+        if (state == ContainerState.FAILURE) {
             return CheckResult.FAILURE;
         }
-        if (state == BundleState.Resolved || state == BundleState.Active) {
+        if (state == ContainerState.RESOLVED || state == ContainerState.ACTIVE) {
             return CheckResult.SUCCESS;
         }
         return CheckResult.IN_PROGRESS;