X-Git-Url: https://git.opendaylight.org/gerrit/gitweb?a=blobdiff_plain;f=opendaylight%2Fmd-sal%2Fmdsal-trace%2Fdom-impl%2Fsrc%2Fmain%2Fjava%2Forg%2Fopendaylight%2Fcontroller%2Fmd%2Fsal%2Ftrace%2Fdom%2Fimpl%2FTracingBroker.java;h=45e9c6503b34fe3917ce01ed15a4f2077795d711;hb=aaea3e9a92ae9d6fac04c4a065db4b35cbca9ed0;hp=a30d3e065eb8f9c8de7ed7725062ce7fe743eb09;hpb=2625c4b5cd121c448de8f5c050cfb98a0db3775d;p=controller.git diff --git a/opendaylight/md-sal/mdsal-trace/dom-impl/src/main/java/org/opendaylight/controller/md/sal/trace/dom/impl/TracingBroker.java b/opendaylight/md-sal/mdsal-trace/dom-impl/src/main/java/org/opendaylight/controller/md/sal/trace/dom/impl/TracingBroker.java index a30d3e065e..45e9c6503b 100644 --- a/opendaylight/md-sal/mdsal-trace/dom-impl/src/main/java/org/opendaylight/controller/md/sal/trace/dom/impl/TracingBroker.java +++ b/opendaylight/md-sal/mdsal-trace/dom-impl/src/main/java/org/opendaylight/controller/md/sal/trace/dom/impl/TracingBroker.java @@ -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. + * + *

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. + * *

Wiring:

* 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: *
    *
  1. * Simply add the dependency "mdsaltrace-features" to - * your karaf pom: + * your Karaf pom: * 
      * {@code
  *  
  *    org.opendaylight.controller
- *    mdsal-trace-features
+ *    features-mdsal-trace
+ *    1.7.0-SNAPSHOT
  *    features
  *    xml
  *    runtime
- *    0.1.6-SNAPSHOT
  *  
  * }
  *
    *
    2. *
  2. - * 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 Bug 9068 + * you'll probably have to use feature:install's --no-auto-refresh flag when installing your "real" feature. *
    3. *
* This works because the mdsaltrace-impl bundle registers its service implementing DOMDataBroker with a higher @@ -88,17 +99,24 @@ import org.slf4j.LoggerFactory; * * */ +@Deprecated(forRemoval = true) 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 registrationWatches = new ArrayList<>(); - private List writeWatches = new ArrayList<>(); + private final List registrationWatches = new ArrayList<>(); + private final List writeWatches = new ArrayList<>(); + private final boolean isDebugging; + private final CloseTrackedRegistry transactionChainsRegistry; + private final CloseTrackedRegistry readOnlyTransactionsRegistry; + private final CloseTrackedRegistry writeTransactionsRegistry; + private final CloseTrackedRegistry readWriteTransactionsRegistry; private class Watch { final String iidString; @@ -130,24 +148,17 @@ public class TracingBroker implements TracingDOMDataBroker { 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; @@ -157,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) { @@ -202,14 +225,15 @@ public class TracingBroker implements TracingDOMDataBroker { 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; } } @@ -244,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 { @@ -253,7 +277,7 @@ public class TracingBroker implements TracingDOMDataBroker { } } - private void reconstructIidPathString(YangInstanceIdentifier yiid, StringBuilder sb) { + private static void reconstructIidPathString(YangInstanceIdentifier yiid, StringBuilder sb) { sb.append(""); for (YangInstanceIdentifier.PathArgument pathArg : yiid.getPathArguments()) { if (pathArg instanceof YangInstanceIdentifier.AugmentationIdentifier) { @@ -278,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 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, DOMDataBrokerExtension> getSupportedExtensions() { Map, DOMDataBrokerExtension> res = delegate.getSupportedExtensions(); @@ -319,13 +332,13 @@ public class TracingBroker implements TracingDOMDataBroker { res = new HashMap<>(res); res.put(DOMDataTreeChangeService.class, new DOMDataTreeChangeService() { - @Nonnull @Override public ListenerRegistration 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); @@ -334,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> + entries = transactionChainsRegistry.getAllUnique(); + if (!entries.isEmpty()) { + ps.println(" " + transactionChainsRegistry.getAnchor() + " : " + + transactionChainsRegistry.getCreateDescription()); + } + for (CloseTrackedRegistryReportEntry 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 > boolean print( + CloseTrackedRegistry registry, PrintStream ps, String indent, int minOpenTransactions) { + Set> unsorted = registry.getAllUnique(); + if (unsorted.size() < minOpenTransactions) { + return false; + } + + List> 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 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"); + } }