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=7103a007680b1fe42db06eee13de17cbe64c976a;hb=634dfac8eead60f443bf75e749c70d1f2bb29198;hp=c01c1d9cd3b36bae78ecb03c0bf2fc00173091ef;hpb=0792888092341cbb7db5f851a5e3bcbca9609e73;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 c01c1d9cd3..7103a00768 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,21 @@ */ 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 java.util.Set; import javax.annotation.Nonnull; - -import org.opendaylight.controller.md.sal.common.api.data.AsyncDataBroker; 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,7 +30,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; @@ -49,7 +53,7 @@ import org.slf4j.LoggerFactory; * *

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 - * results from transactions which were not closed. + * 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 @@ -62,17 +66,19 @@ import org.slf4j.LoggerFactory; * {@code * * org.opendaylight.controller - * mdsal-trace-features + * features-mdsal-trace + * 1.7.0-SNAPSHOT * features * xml * runtime - * 0.1.6-SNAPSHOT * * } * * *
  • - * 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. *
    • * * This works because the mdsaltrace-impl bundle registers its service implementing DOMDataBroker with a higher @@ -95,11 +101,12 @@ import org.slf4j.LoggerFactory; * */ 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 final List registrationWatches = new ArrayList<>(); @@ -141,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; @@ -168,9 +168,10 @@ 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) { @@ -178,10 +179,11 @@ public class TracingBroker implements TracingDOMDataBroker { } else { this.isDebugging = false; } - this.transactionChainsRegistry = new CloseTrackedRegistry<>(this, "createTransactionChain", isDebugging); - this.readOnlyTransactionsRegistry = new CloseTrackedRegistry<>(this, "newReadOnlyTransaction", isDebugging); - this.writeTransactionsRegistry = new CloseTrackedRegistry<>(this, "newWriteOnlyTransaction", isDebugging); - this.readWriteTransactionsRegistry = new CloseTrackedRegistry<>(this, "newReadWriteTransaction", isDebugging); + 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) { @@ -223,14 +225,13 @@ public class TracingBroker implements TracingDOMDataBroker { writeWatches.add(watch); } - private boolean isRegistrationWatched(YangInstanceIdentifier iid, - LogicalDatastoreType store, DataChangeScope scope) { + 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; } } @@ -307,17 +308,6 @@ public class TracingBroker implements TracingDOMDataBroker { return new TracingWriteTransaction(delegate.newWriteOnlyTransaction(), this, writeTransactionsRegistry); } - @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); - } - @Override public DOMTransactionChain createTransactionChain(TransactionChainListener transactionChainListener) { return new TracingTransactionChain( @@ -326,7 +316,7 @@ public class TracingBroker implements TracingDOMDataBroker { @Override public DOMDataReadOnlyTransaction newReadOnlyTransaction() { - return new TracingReadOnlyTransaction(delegate.newReadOnlyTransaction(), this, readOnlyTransactionsRegistry); + return new TracingReadOnlyTransaction(delegate.newReadOnlyTransaction(), readOnlyTransactionsRegistry); } @Nonnull @@ -346,8 +336,9 @@ public class TracingBroker implements TracingDOMDataBroker { public ListenerRegistration registerDataTreeChangeListener( @Nonnull DOMDataTreeIdentifier domDataTreeIdentifier, @Nonnull 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); @@ -356,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"); + } }