Bump odlparent to 6.0.0
[controller.git] / opendaylight / md-sal / mdsal-trace / dom-impl / src / main / java / org / opendaylight / controller / md / sal / trace / dom / impl / TracingBroker.java
index c971ec300d905bdacbafb79b96badc3c748c6f30..ab633a22b77c60943528b2f8e7cdeff43c17bdce 100644 (file)
@@ -7,19 +7,20 @@
  */
 package org.opendaylight.controller.md.sal.trace.dom.impl;
 
+import static java.util.Objects.requireNonNull;
+
+import edu.umd.cs.findbugs.annotations.SuppressFBWarnings;
+import java.io.PrintStream;
 import java.util.ArrayList;
 import java.util.HashMap;
 import java.util.List;
 import java.util.Map;
-import java.util.Objects;
-import javax.annotation.Nonnull;
-
-import org.opendaylight.controller.md.sal.common.api.data.AsyncDataBroker;
+import java.util.Set;
 import org.opendaylight.controller.md.sal.common.api.data.LogicalDatastoreType;
 import org.opendaylight.controller.md.sal.common.api.data.TransactionChainListener;
+import org.opendaylight.controller.md.sal.dom.api.ClusteredDOMDataTreeChangeListener;
 import org.opendaylight.controller.md.sal.dom.api.DOMDataBroker;
 import org.opendaylight.controller.md.sal.dom.api.DOMDataBrokerExtension;
-import org.opendaylight.controller.md.sal.dom.api.DOMDataChangeListener;
 import org.opendaylight.controller.md.sal.dom.api.DOMDataReadOnlyTransaction;
 import org.opendaylight.controller.md.sal.dom.api.DOMDataReadWriteTransaction;
 import org.opendaylight.controller.md.sal.dom.api.DOMDataTreeChangeListener;
@@ -28,6 +29,9 @@ import org.opendaylight.controller.md.sal.dom.api.DOMDataTreeIdentifier;
 import org.opendaylight.controller.md.sal.dom.api.DOMDataWriteTransaction;
 import org.opendaylight.controller.md.sal.dom.api.DOMTransactionChain;
 import org.opendaylight.controller.md.sal.trace.api.TracingDOMDataBroker;
+import org.opendaylight.controller.md.sal.trace.closetracker.impl.CloseTracked;
+import org.opendaylight.controller.md.sal.trace.closetracker.impl.CloseTrackedRegistry;
+import org.opendaylight.controller.md.sal.trace.closetracker.impl.CloseTrackedRegistryReportEntry;
 import org.opendaylight.mdsal.binding.dom.codec.api.BindingNormalizedNodeSerializer;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.mdsaltrace.rev160908.Config;
 import org.opendaylight.yangtools.concepts.ListenerRegistration;
@@ -45,28 +49,35 @@ import org.slf4j.LoggerFactory;
  * the objects themselves, as well as the stack trace of the call invoking the registration or write operation.
  * It works by operating as a "bump on the stack" between the application and actual DataBroker, intercepting write
  * and registration calls and writing to the log.
+ *
+ * <p>In addition, it (optionally) can also keep track of the stack trace of all new transaction allocations
+ * (including TransactionChains, and transactions created in turn from them), in order to detect and report leaks
+ * from transactions which were not closed.
+ *
  * <h1>Wiring:</h1>
  * TracingBroker is designed to be easy to use. In fact, for bundles using Blueprint to inject their DataBroker
  * TracingBroker can be used without modifying your code at all in two simple steps:
  * <ol>
  * <li>
  * Simply add the dependency "mdsaltrace-features" to
- * your karaf pom:
+ * your Karaf pom:
  * <pre>
  * {@code
  *  <dependency>
  *    <groupId>org.opendaylight.controller</groupId>
- *    <artifactId>mdsal-trace-features</artifactId>
+ *    <artifactId>features-mdsal-trace</artifactId>
+ *    <version>1.7.0-SNAPSHOT</version>
  *    <classifier>features</classifier>
  *    <type>xml</type>
  *    <scope>runtime</scope>
- *    <version>0.1.5-SNAPSHOT</version>
  *  </dependency>
  * }
  * </pre>
  * </li>
  * <li>
- * Then just load the odl-mdsal-trace feature before your feature and you're done.
+ * Then just "feature:install odl-mdsal-trace" before you install your "real" feature(s) and you're done.
+ * Beware that with Karaf 4 due to <a href="https://bugs.opendaylight.org/show_bug.cgi?id=9068">Bug 9068</a>
+ * you'll probably have to use feature:install's --no-auto-refresh flag when installing your "real" feature.
  * </li>
  * </ol>
  * This works because the mdsaltrace-impl bundle registers its service implementing DOMDataBroker with a higher
@@ -88,17 +99,24 @@ import org.slf4j.LoggerFactory;
  * </ul>
  *
  */
+@Deprecated
 public class TracingBroker implements TracingDOMDataBroker {
-
+    @SuppressFBWarnings("SLF4J_LOGGER_SHOULD_BE_PRIVATE")
     static final Logger LOG = LoggerFactory.getLogger(TracingBroker.class);
 
     private static final int STACK_TRACE_FIRST_RELEVANT_FRAME = 2;
 
+    private final String type; // "default" VS "pingpong"
     private final BindingNormalizedNodeSerializer codec;
     private final DOMDataBroker delegate;
-    private List<Watch> registrationWatches = new ArrayList<>();
-    private List<Watch> writeWatches = new ArrayList<>();
+    private final List<Watch> registrationWatches = new ArrayList<>();
+    private final List<Watch> writeWatches = new ArrayList<>();
 
+    private final boolean isDebugging;
+    private final CloseTrackedRegistry<TracingTransactionChain> transactionChainsRegistry;
+    private final CloseTrackedRegistry<TracingReadOnlyTransaction> readOnlyTransactionsRegistry;
+    private final CloseTrackedRegistry<TracingWriteTransaction> writeTransactionsRegistry;
+    private final CloseTrackedRegistry<TracingReadWriteTransaction> readWriteTransactionsRegistry;
 
     private class Watch {
         final String iidString;
@@ -117,28 +135,30 @@ public class TracingBroker implements TracingDOMDataBroker {
         }
 
         private boolean isParent(String parent, String child) {
-            return child.startsWith(parent);
+            int parentOffset = 0;
+            if (parent.length() > 0 && parent.charAt(0) == '<') {
+                parentOffset = parent.indexOf('>') + 1;
+            }
+
+            int childOffset = 0;
+            if (child.length() > 0 && child.charAt(0) == '<') {
+                childOffset = child.indexOf('>') + 1;
+            }
+
+            return child.startsWith(parent.substring(parentOffset), childOffset);
         }
 
-        public boolean subtreesOverlap(YangInstanceIdentifier iid, LogicalDatastoreType store,
-                                                                AsyncDataBroker.DataChangeScope scope) {
+        @SuppressWarnings({ "checkstyle:hiddenField", "hiding" })
+        public boolean subtreesOverlap(YangInstanceIdentifier iid, LogicalDatastoreType store) {
             if (this.store != null && !this.store.equals(store)) {
                 return false;
             }
 
             String otherIidString = toIidCompString(iid);
-
-            switch (scope) {
-                case BASE:
-                    return isParent(iidString, otherIidString);
-                case ONE: //for now just treat like SUBTREE, even though it's not
-                case SUBTREE:
-                    return isParent(iidString, otherIidString) || isParent(otherIidString, iidString);
-                default:
-                    return false;
-            }
+            return isParent(iidString, otherIidString) || isParent(otherIidString, iidString);
         }
 
+        @SuppressWarnings({ "checkstyle:hiddenField", "hiding" })
         public boolean eventIsOfInterest(YangInstanceIdentifier iid, LogicalDatastoreType store) {
             if (this.store != null && !this.store.equals(store)) {
                 return false;
@@ -148,10 +168,22 @@ public class TracingBroker implements TracingDOMDataBroker {
         }
     }
 
-    public TracingBroker(DOMDataBroker delegate, Config config, BindingNormalizedNodeSerializer codec) {
-        this.delegate = Objects.requireNonNull(delegate);
-        this.codec = Objects.requireNonNull(codec);
+    public TracingBroker(String type, DOMDataBroker delegate, Config config, BindingNormalizedNodeSerializer codec) {
+        this.type = requireNonNull(type, "type");
+        this.delegate = requireNonNull(delegate, "delegate");
+        this.codec = requireNonNull(codec, "codec");
         configure(config);
+
+        if (config.isTransactionDebugContextEnabled() != null) {
+            this.isDebugging = config.isTransactionDebugContextEnabled();
+        } else {
+            this.isDebugging = false;
+        }
+        final String db = "DataBroker";
+        this.transactionChainsRegistry     = new CloseTrackedRegistry<>(db, "createTransactionChain()", isDebugging);
+        this.readOnlyTransactionsRegistry  = new CloseTrackedRegistry<>(db, "newReadOnlyTransaction()", isDebugging);
+        this.writeTransactionsRegistry     = new CloseTrackedRegistry<>(db, "newWriteOnlyTransaction()", isDebugging);
+        this.readWriteTransactionsRegistry = new CloseTrackedRegistry<>(db, "newReadWriteTransaction()", isDebugging);
     }
 
     private void configure(Config config) {
@@ -178,6 +210,7 @@ public class TracingBroker implements TracingDOMDataBroker {
      * @param store Which LogicalDataStore? or null for both
      */
     public void watchRegistrations(String iidString, LogicalDatastoreType store) {
+        LOG.info("Watching registrations to {} in {}", iidString, store);
         registrationWatches.add(new Watch(iidString, store));
     }
 
@@ -187,18 +220,20 @@ public class TracingBroker implements TracingDOMDataBroker {
      * @param store Which LogicalDataStore? or null for both
      */
     public void watchWrites(String iidString, LogicalDatastoreType store) {
+        LOG.info("Watching writes to {} in {}", iidString, store);
         Watch watch = new Watch(iidString, store);
         writeWatches.add(watch);
     }
 
-    private boolean isRegistrationWatched(YangInstanceIdentifier iid,
-                                                            LogicalDatastoreType store, DataChangeScope scope) {
+    @SuppressFBWarnings(value = "UPM_UNCALLED_PRIVATE_METHOD",
+            justification = "https://github.com/spotbugs/spotbugs/issues/811")
+    private boolean isRegistrationWatched(YangInstanceIdentifier iid, LogicalDatastoreType store) {
         if (registrationWatches.isEmpty()) {
             return true;
         }
 
         for (Watch regInterest : registrationWatches) {
-            if (regInterest.subtreesOverlap(iid, store, scope)) {
+            if (regInterest.subtreesOverlap(iid, store)) {
                 return true;
             }
         }
@@ -233,8 +268,8 @@ public class TracingBroker implements TracingDOMDataBroker {
     }
 
 
-    void toPathString(YangInstanceIdentifier yiid, StringBuilder sb) {
-        InstanceIdentifier iid = codec.fromYangInstanceIdentifier(yiid);
+    private void toPathString(YangInstanceIdentifier yiid, StringBuilder sb) {
+        InstanceIdentifier<?> iid = codec.fromYangInstanceIdentifier(yiid);
         if (null == iid) {
             reconstructIidPathString(yiid, sb);
         } else {
@@ -242,8 +277,8 @@ public class TracingBroker implements TracingDOMDataBroker {
         }
     }
 
-    private void reconstructIidPathString(YangInstanceIdentifier yiid, StringBuilder sb) {
-        sb.append("RECONSTRUCTED: ");
+    private static void reconstructIidPathString(YangInstanceIdentifier yiid, StringBuilder sb) {
+        sb.append("<RECONSTRUCTED FROM: \"").append(yiid.toString()).append("\">");
         for (YangInstanceIdentifier.PathArgument pathArg : yiid.getPathArguments()) {
             if (pathArg instanceof YangInstanceIdentifier.AugmentationIdentifier) {
                 sb.append('/').append("AUGMENTATION");
@@ -251,7 +286,6 @@ public class TracingBroker implements TracingDOMDataBroker {
             }
             sb.append('/').append(pathArg.getNodeType().getLocalName());
         }
-        sb.append(" ->->-> [[[ ").append(yiid.toString()).append(" ]]]");
     }
 
     String getStackSummary() {
@@ -268,36 +302,25 @@ public class TracingBroker implements TracingDOMDataBroker {
 
     @Override
     public DOMDataReadWriteTransaction newReadWriteTransaction() {
-        return new TracingReadWriteTransaction(delegate.newReadWriteTransaction(), this);
+        return new TracingReadWriteTransaction(delegate.newReadWriteTransaction(), this, readWriteTransactionsRegistry);
     }
 
     @Override
     public DOMDataWriteTransaction newWriteOnlyTransaction() {
-        return new TracingWriteTransaction(delegate.newWriteOnlyTransaction(), this);
-    }
-
-    @Override
-    public ListenerRegistration<DOMDataChangeListener> registerDataChangeListener(
-                                                        LogicalDatastoreType store, YangInstanceIdentifier yiid,
-                                                        DOMDataChangeListener listener, DataChangeScope scope) {
-        if (isRegistrationWatched(yiid, store, scope)) {
-            LOG.warn("Registration (registerDataChangeListener) for {} from {}",
-                    toPathString(yiid), getStackSummary());
-        }
-        return delegate.registerDataChangeListener(store, yiid, listener, scope);
+        return new TracingWriteTransaction(delegate.newWriteOnlyTransaction(), this, writeTransactionsRegistry);
     }
 
     @Override
     public DOMTransactionChain createTransactionChain(TransactionChainListener transactionChainListener) {
-        return delegate.createTransactionChain(transactionChainListener);
+        return new TracingTransactionChain(
+                delegate.createTransactionChain(transactionChainListener), this, transactionChainsRegistry);
     }
 
     @Override
     public DOMDataReadOnlyTransaction newReadOnlyTransaction() {
-        return delegate.newReadOnlyTransaction();
+        return new TracingReadOnlyTransaction(delegate.newReadOnlyTransaction(), readOnlyTransactionsRegistry);
     }
 
-    @Nonnull
     @Override
     public Map<Class<? extends DOMDataBrokerExtension>, DOMDataBrokerExtension> getSupportedExtensions() {
         Map<Class<? extends DOMDataBrokerExtension>, DOMDataBrokerExtension> res = delegate.getSupportedExtensions();
@@ -309,13 +332,13 @@ public class TracingBroker implements TracingDOMDataBroker {
         res = new HashMap<>(res);
 
         res.put(DOMDataTreeChangeService.class, new DOMDataTreeChangeService() {
-            @Nonnull
             @Override
             public <L extends DOMDataTreeChangeListener> ListenerRegistration<L> registerDataTreeChangeListener(
-                    @Nonnull DOMDataTreeIdentifier domDataTreeIdentifier, @Nonnull L listener) {
+                    DOMDataTreeIdentifier domDataTreeIdentifier, L listener) {
                 if (isRegistrationWatched(domDataTreeIdentifier.getRootIdentifier(),
-                        domDataTreeIdentifier.getDatastoreType(), DataChangeScope.SUBTREE)) {
-                    LOG.warn("Registration (registerDataTreeChangeListener) for {} from {}",
+                        domDataTreeIdentifier.getDatastoreType())) {
+                    LOG.warn("{} registration (registerDataTreeChangeListener) for {} from {}.",
+                            listener instanceof ClusteredDOMDataTreeChangeListener ? "Clustered" : "Non-clustered",
                             toPathString(domDataTreeIdentifier.getRootIdentifier()), getStackSummary());
                 }
                 return treeChangeSvc.registerDataTreeChangeListener(domDataTreeIdentifier, listener);
@@ -324,4 +347,98 @@ public class TracingBroker implements TracingDOMDataBroker {
 
         return res;
     }
+
+    @Override
+    public boolean printOpenTransactions(PrintStream ps, int minOpenTXs) {
+        if (transactionChainsRegistry.getAllUnique().isEmpty()
+            && readOnlyTransactionsRegistry.getAllUnique().isEmpty()
+            && writeTransactionsRegistry.getAllUnique().isEmpty()
+            && readWriteTransactionsRegistry.getAllUnique().isEmpty()) {
+
+            ps.println(type + ": No open transactions, great!");
+            return false;
+        }
+
+        ps.println(type + ": " + getClass().getSimpleName()
+                 + " found some not yet (or never..) closed transaction[chain]s!");
+        ps.println("[NB: If no stack traces are shown below, then "
+                 + "enable transaction-debug-context-enabled in mdsaltrace_config.xml]");
+        ps.println();
+        // Flag to track if we really found any real leaks with more (or equal) to minOpenTXs
+        boolean hasFound = print(readOnlyTransactionsRegistry, ps, "  ", minOpenTXs);
+        hasFound |= print(writeTransactionsRegistry, ps, "  ", minOpenTXs);
+        hasFound |= print(readWriteTransactionsRegistry, ps, "  ", minOpenTXs);
+
+        // Now print details for each non-closed TransactionChain
+        // incl. in turn each ones own read/Write[Only]TransactionsRegistry
+        Set<CloseTrackedRegistryReportEntry<TracingTransactionChain>>
+            entries = transactionChainsRegistry.getAllUnique();
+        if (!entries.isEmpty()) {
+            ps.println("  " + transactionChainsRegistry.getAnchor() + " : "
+                    + transactionChainsRegistry.getCreateDescription());
+        }
+        for (CloseTrackedRegistryReportEntry<TracingTransactionChain> entry : entries) {
+            ps.println("    " + entry.getNumberAddedNotRemoved() + "x TransactionChains opened but not closed here:");
+            printStackTraceElements(ps, "      ", entry.getStackTraceElements());
+            @SuppressWarnings("resource")
+            TracingTransactionChain txChain = (TracingTransactionChain) entry
+                .getExampleCloseTracked().getRealCloseTracked();
+            hasFound |= print(txChain.getReadOnlyTransactionsRegistry(), ps, "        ", minOpenTXs);
+            hasFound |= print(txChain.getWriteTransactionsRegistry(), ps, "        ", minOpenTXs);
+            hasFound |= print(txChain.getReadWriteTransactionsRegistry(), ps, "        ", minOpenTXs);
+        }
+        ps.println();
+
+        return hasFound;
+    }
+
+    private <T extends CloseTracked<T>> boolean print(
+            CloseTrackedRegistry<T> registry, PrintStream ps, String indent, int minOpenTransactions) {
+        Set<CloseTrackedRegistryReportEntry<T>> unsorted = registry.getAllUnique();
+        if (unsorted.size() < minOpenTransactions) {
+            return false;
+        }
+
+        List<CloseTrackedRegistryReportEntry<T>> entries = new ArrayList<>(unsorted);
+        entries.sort((o1, o2) -> Long.compare(o2.getNumberAddedNotRemoved(), o1.getNumberAddedNotRemoved()));
+
+        if (!entries.isEmpty()) {
+            ps.println(indent + registry.getAnchor() + " : " + registry.getCreateDescription());
+        }
+        entries.forEach(entry -> {
+            ps.println(indent + "  " + entry.getNumberAddedNotRemoved()
+                + "x transactions opened here, which are not closed:");
+            printStackTraceElements(ps, indent + "    ", entry.getStackTraceElements());
+        });
+        if (!entries.isEmpty()) {
+            ps.println();
+        }
+        return true;
+    }
+
+    private void printStackTraceElements(PrintStream ps, String indent, List<StackTraceElement> stackTraceElements) {
+        boolean ellipsis = false;
+        for (final StackTraceElement stackTraceElement : stackTraceElements) {
+            if (isStackTraceElementInteresting(stackTraceElement)) {
+                ps.println(indent + stackTraceElement);
+                ellipsis = false;
+            } else if (!ellipsis) {
+                ps.println(indent + "(...)");
+                ellipsis = true;
+            }
+        }
+    }
+
+    private boolean isStackTraceElementInteresting(StackTraceElement element) {
+        final String className = element.getClassName();
+        return !className.startsWith(getClass().getPackage().getName())
+            && !className.startsWith(CloseTracked.class.getPackage().getName())
+            && !className.startsWith("Proxy")
+            && !className.startsWith("akka")
+            && !className.startsWith("scala")
+            && !className.startsWith("sun.reflect")
+            && !className.startsWith("java.lang.reflect")
+            && !className.startsWith("org.apache.aries.blueprint")
+            && !className.startsWith("org.osgi.util.tracker");
+    }
 }