Track stale ActiveContainer instances

6 files changed, 238 insertions, 6 deletions

diff --git a/jdisc_core/src/main/java/com/yahoo/jdisc/core/ApplicationEnvironmentModule.java b/jdisc_core/src/main/java/com/yahoo/jdisc/core/ApplicationEnvironmentModule.java
index c6d6efd0ee9..c6acde814eb 100644
--- a/jdisc_core/src/main/java/com/yahoo/jdisc/core/ApplicationEnvironmentModule.java
+++ b/jdisc_core/src/main/java/com/yahoo/jdisc/core/ApplicationEnvironmentModule.java
@@ -8,6 +8,7 @@ import com.yahoo.jdisc.application.ContainerBuilder;
 import com.yahoo.jdisc.application.ContainerThread;
 import com.yahoo.jdisc.application.OsgiFramework;
 import com.yahoo.jdisc.service.CurrentContainer;
+import com.yahoo.jdisc.statistics.ActiveContainerStatistics;
 
 import java.util.concurrent.ThreadFactory;
 
@@ -28,6 +29,7 @@ class ApplicationEnvironmentModule extends AbstractModule {
         bind(CurrentContainer.class).toInstance(loader);
         bind(OsgiFramework.class).toInstance(loader.osgiFramework());
         bind(ThreadFactory.class).to(ContainerThread.Factory.class);
+        bind(ActiveContainerStatistics.class).toInstance(loader.getActiveContainerStatistics());
     }
 
     @Provides
diff --git a/jdisc_core/src/main/java/com/yahoo/jdisc/core/ApplicationLoader.java b/jdisc_core/src/main/java/com/yahoo/jdisc/core/ApplicationLoader.java
index 2dd7f7eb879..4e63bc77c9a 100644
--- a/jdisc_core/src/main/java/com/yahoo/jdisc/core/ApplicationLoader.java
+++ b/jdisc_core/src/main/java/com/yahoo/jdisc/core/ApplicationLoader.java
@@ -5,9 +5,17 @@ import com.google.inject.AbstractModule;
 import com.google.inject.Injector;
 import com.google.inject.Module;
 import com.yahoo.jdisc.AbstractResource;
-import com.yahoo.jdisc.application.*;
+import com.yahoo.jdisc.application.Application;
+import com.yahoo.jdisc.application.ApplicationNotReadyException;
+import com.yahoo.jdisc.application.ContainerActivator;
+import com.yahoo.jdisc.application.ContainerBuilder;
+import com.yahoo.jdisc.application.DeactivatedContainer;
+import com.yahoo.jdisc.application.GuiceRepository;
+import com.yahoo.jdisc.application.OsgiFramework;
+import com.yahoo.jdisc.application.OsgiHeader;
 import com.yahoo.jdisc.service.ContainerNotReadyException;
 import com.yahoo.jdisc.service.CurrentContainer;
+import com.yahoo.jdisc.statistics.ActiveContainerStatistics;
 import org.osgi.framework.Bundle;
 import org.osgi.framework.BundleContext;
 import org.osgi.framework.BundleException;
@@ -28,11 +36,13 @@ import java.util.logging.Logger;
 public class ApplicationLoader implements BootstrapLoader, ContainerActivator, CurrentContainer {
 
     private static final Logger log = Logger.getLogger(ApplicationLoader.class.getName());
+
     private final OsgiFramework osgiFramework;
     private final GuiceRepository guiceModules = new GuiceRepository();
     private final AtomicReference<ActiveContainer> containerRef = new AtomicReference<>();
     private final Object appLock = new Object();
     private final List<Bundle> appBundles = new ArrayList<>();
+    private final ActiveContainerStatistics statistics = new ActiveContainerStatistics();
     private Application application;
     private ApplicationInUseTracker applicationInUseTracker;
 
@@ -62,9 +72,11 @@ public class ApplicationLoader implements BootstrapLoader, ContainerActivator, C
             }
 
             prev = containerRef.getAndSet(next);
+            statistics.onActivated(next);
             if (prev == null) {
                 return null;
             }
+            statistics.onDeactivated(prev);
         }
         prev.release();
         DeactivatedContainer deactivatedContainer = prev.shutdown();
@@ -82,11 +94,9 @@ public class ApplicationLoader implements BootstrapLoader, ContainerActivator, C
                                 Thread.sleep(TimeUnit.MILLISECONDS.convert(currentWaitTimeSeconds, TimeUnit.SECONDS))
                 );
 
+                statistics.printSummaryToLog();
                 final ActiveContainer prevContainer = prevContainerReference.get();
-                if (prevContainer == null) {
-                    return;
-                }
-                if (prevContainer.retainCount() == 0) {
+                if (prevContainer == null || prevContainer.retainCount() == 0) {
                     return;
                 }
                 log.warning("Previous container not terminated in the last " + totalTimeWaited + " seconds."
@@ -231,6 +241,10 @@ public class ApplicationLoader implements BootstrapLoader, ContainerActivator, C
         }
     }
 
+    public ActiveContainerStatistics getActiveContainerStatistics() {
+        return statistics;
+    }
+
     public OsgiFramework osgiFramework() {
         return osgiFramework;
     }
@@ -258,4 +272,5 @@ public class ApplicationLoader implements BootstrapLoader, ContainerActivator, C
             }
         }
     }
+
 }
diff --git a/jdisc_core/src/main/java/com/yahoo/jdisc/core/ExportPackages.java b/jdisc_core/src/main/java/com/yahoo/jdisc/core/ExportPackages.java
index afe43718bc5..3dbc4af5422 100644
--- a/jdisc_core/src/main/java/com/yahoo/jdisc/core/ExportPackages.java
+++ b/jdisc_core/src/main/java/com/yahoo/jdisc/core/ExportPackages.java
@@ -1,7 +1,6 @@
 // Copyright 2016 Yahoo Inc. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
 package com.yahoo.jdisc.core;
 
-import com.yahoo.container.plugin.bundle.AnalyzeBundle;
 import com.yahoo.container.plugin.bundle.TransformExportPackages;
 import com.yahoo.container.plugin.osgi.ExportPackages.Export;
 import org.apache.felix.framework.util.Util;
@@ -38,6 +37,7 @@ public class ExportPackages {
            .append("com.yahoo.jdisc.application,")
            .append("com.yahoo.jdisc.handler,")
            .append("com.yahoo.jdisc.service,")
+           .append("com.yahoo.jdisc.statistics,")
            .append("javax.inject;version=1.0.0,")  // Included in guice, but not exported. Needed by container-jersey.
            .append("org.aopalliance.intercept,")
            .append("org.aopalliance.aop,")
diff --git a/jdisc_core/src/main/java/com/yahoo/jdisc/statistics/ActiveContainerStatistics.java b/jdisc_core/src/main/java/com/yahoo/jdisc/statistics/ActiveContainerStatistics.java
new file mode 100644
index 00000000000..2fac3b4024b
--- /dev/null
+++ b/jdisc_core/src/main/java/com/yahoo/jdisc/statistics/ActiveContainerStatistics.java
@@ -0,0 +1,132 @@
+// Copyright 2017 Yahoo Inc. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
+package com.yahoo.jdisc.statistics;
+
+import com.yahoo.jdisc.Metric;
+import com.yahoo.jdisc.core.ActiveContainer;
+
+import java.time.Instant;
+import java.util.List;
+import java.util.WeakHashMap;
+import java.util.logging.Logger;
+import java.util.stream.Stream;
+
+import static java.util.stream.Collectors.toList;
+
+/**
+ * Tracks statistics on stale {@link ActiveContainer} instances.
+ *
+ * @author bjorncs
+ */
+public class ActiveContainerStatistics {
+    public interface Metrics {
+        String TOTAL_DEACTIVATED_CONTAINERS = "jdisc.deactivated_containers.total";
+        String DEACTIVATED_CONTAINERS_WITH_RETAINED_REFERENCES = "jdisc.deactivated_containers.with_retained_refs";
+    }
+
+    private static final Logger log = Logger.getLogger(ActiveContainerStatistics.class.getName());
+
+    private final WeakHashMap<ActiveContainer, ActiveContainerStats> activeContainers = new WeakHashMap<>();
+    private final Object monitor = new Object();
+
+    public void emitMetrics(Metric metric) {
+        synchronized (monitor) {
+            DeactivatedContainerMetrics metrics = deactivatedContainerStream()
+                    .collect(
+                            DeactivatedContainerMetrics::new,
+                            DeactivatedContainerMetrics::aggregate,
+                            DeactivatedContainerMetrics::merge);
+
+            metric.set(Metrics.TOTAL_DEACTIVATED_CONTAINERS, metrics.deactivatedContainerCount, null);
+            metric.set(Metrics.DEACTIVATED_CONTAINERS_WITH_RETAINED_REFERENCES, metrics.deactivatedContainersWithRetainedRefsCount, null);
+        }
+    }
+
+    public void onActivated(ActiveContainer activeContainer) {
+        synchronized (monitor) {
+            activeContainers.put(activeContainer, new ActiveContainerStats(Instant.now()));
+        }
+    }
+
+    public void onDeactivated(ActiveContainer activeContainer) {
+        synchronized (monitor) {
+            ActiveContainerStats containerStats = activeContainers.get(activeContainer);
+            if (containerStats == null) {
+                throw new IllegalStateException("onActivated() has not been called for container: " + activeContainer);
+            }
+            containerStats.timeDeactivated = Instant.now();
+        }
+    }
+
+    public void printSummaryToLog() {
+        synchronized (monitor) {
+            List<DeactivatedContainer> deactivatedContainers = deactivatedContainerStream().collect(toList());
+            if (deactivatedContainers.isEmpty()) return;
+
+            log.warning(
+                    "Multiple instances of ActiveContainer leaked! " + deactivatedContainers.size() +
+                            " instances are still present.");
+            deactivatedContainers.stream()
+                    .map(c -> " - " + c.toSummaryString())
+                    .forEach(log::warning);
+        }
+    }
+
+    private Stream<DeactivatedContainer> deactivatedContainerStream() {
+        synchronized (monitor) {
+            return activeContainers.entrySet().stream()
+                    .filter(e -> e.getValue().isDeactivated())
+                    .map(e -> new DeactivatedContainer(e.getKey(), e.getValue().timeActivated, e.getValue().timeDeactivated));
+        }
+    }
+
+    private static class ActiveContainerStats {
+        public final Instant timeActivated;
+        public Instant timeDeactivated;
+
+        public ActiveContainerStats(Instant timeActivated) {
+            this.timeActivated = timeActivated;
+        }
+
+        public boolean isDeactivated() {
+            return timeDeactivated != null;
+        }
+    }
+
+    private static class DeactivatedContainer {
+        public final ActiveContainer activeContainer;
+        public final Instant timeActivated;
+        public final Instant timeDeactivated;
+
+        public DeactivatedContainer(ActiveContainer activeContainer, Instant timeActivated, Instant timeDeactivated) {
+            this.activeContainer = activeContainer;
+            this.timeActivated = timeActivated;
+            this.timeDeactivated = timeDeactivated;
+        }
+
+        public String toSummaryString() {
+            return String.format("%s: timeActivated=%s, timeDeactivated=%s, retainCount=%d",
+                    activeContainer.toString(),
+                    timeActivated.toString(),
+                    timeDeactivated.toString(),
+                    activeContainer.retainCount());
+        }
+    }
+
+    private static class DeactivatedContainerMetrics {
+        public int deactivatedContainerCount = 0;
+        public int deactivatedContainersWithRetainedRefsCount = 0;
+
+        public void aggregate(DeactivatedContainer deactivatedContainer) {
+            ++deactivatedContainerCount;
+            if (deactivatedContainer.activeContainer.retainCount() > 0) {
+                ++deactivatedContainersWithRetainedRefsCount;
+            }
+        }
+
+        public DeactivatedContainerMetrics merge(DeactivatedContainerMetrics other) {
+            deactivatedContainerCount += other.deactivatedContainerCount;
+            deactivatedContainersWithRetainedRefsCount += other.deactivatedContainersWithRetainedRefsCount;
+            return this;
+        }
+    }
+}
diff --git a/jdisc_core/src/main/java/com/yahoo/jdisc/statistics/package-info.java b/jdisc_core/src/main/java/com/yahoo/jdisc/statistics/package-info.java
new file mode 100644
index 00000000000..4289bcbaa9d
--- /dev/null
+++ b/jdisc_core/src/main/java/com/yahoo/jdisc/statistics/package-info.java
@@ -0,0 +1,4 @@
+// Copyright 2017 Yahoo Inc. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root.
+
+@com.yahoo.osgi.annotation.ExportPackage
+package com.yahoo.jdisc.statistics;
diff --git a/jdisc_core/src/test/java/com/yahoo/jdisc/statistics/ActiveContainerStatisticsTest.java b/jdisc_core/src/test/java/com/yahoo/jdisc/statistics/ActiveContainerStatisticsTest.java
new file mode 100644
index 00000000000..0a3482b705a
--- /dev/null
+++ b/jdisc_core/src/test/java/com/yahoo/jdisc/statistics/ActiveContainerStatisticsTest.java
@@ -0,0 +1,79 @@
+package com.yahoo.jdisc.statistics;
+
+import com.yahoo.jdisc.Metric;
+import com.yahoo.jdisc.ResourceReference;
+import com.yahoo.jdisc.core.ActiveContainer;
+import com.yahoo.jdisc.test.TestDriver;
+import org.junit.Test;
+
+import java.util.Map;
+
+import static org.junit.Assert.assertEquals;
+
+/**
+ * @author bjorncs
+ */
+public class ActiveContainerStatisticsTest {
+
+    @Test
+    public void counts_deactivated_activecontainers() {
+        TestDriver driver = TestDriver.newSimpleApplicationInstanceWithoutOsgi();
+        ActiveContainerStatistics stats = new ActiveContainerStatistics();
+        MockMetric metric = new MockMetric();
+
+        ActiveContainer containerWithoutRetainedResources = new ActiveContainer(driver.newContainerBuilder());
+
+        stats.onActivated(containerWithoutRetainedResources);
+        stats.emitMetrics(metric);
+        assertEquals(0, metric.totalCount);
+        assertEquals(0, metric.withRetainedReferencesCount);
+
+        stats.onDeactivated(containerWithoutRetainedResources);
+        containerWithoutRetainedResources.release();
+        stats.emitMetrics(metric);
+        assertEquals(1, metric.totalCount);
+        assertEquals(0, metric.withRetainedReferencesCount);
+
+        ActiveContainer containerWithRetainedResources = new ActiveContainer(driver.newContainerBuilder());
+
+        try (ResourceReference ignoredRef = containerWithRetainedResources.refer()) {
+             stats.onActivated(containerWithRetainedResources);
+             stats.onDeactivated(containerWithRetainedResources);
+             containerWithRetainedResources.release();
+             stats.emitMetrics(metric);
+             assertEquals(2, metric.totalCount);
+             assertEquals(1, metric.withRetainedReferencesCount);
+        }
+
+    }
+
+    private static class MockMetric implements Metric {
+        public int totalCount;
+        public int withRetainedReferencesCount;
+
+        @Override
+        public void set(String key, Number val, Context ctx) {
+            switch (key) {
+                case ActiveContainerStatistics.Metrics.TOTAL_DEACTIVATED_CONTAINERS:
+                    totalCount = val.intValue();
+                    break;
+                case ActiveContainerStatistics.Metrics.DEACTIVATED_CONTAINERS_WITH_RETAINED_REFERENCES:
+                    withRetainedReferencesCount = val.intValue();
+                    break;
+                default:
+                    throw new UnsupportedOperationException();
+            }
+        }
+
+        @Override
+        public void add(String key, Number val, Context ctx) {
+            throw new UnsupportedOperationException();
+        }
+
+        @Override
+        public Context createContext(Map<String, ?> properties) {
+            throw new UnsupportedOperationException();
+        }
+    }
+
+}