Deprecate old MD-SAL APIs for removal
[controller.git] / opendaylight / md-sal / mdsal-trace / dom-impl / src / main / java / org / opendaylight / controller / md / sal / trace / dom / impl / TracingBroker.java
1 /*
2  * Copyright (c) 2016 Red Hat, Inc. and others.  All rights reserved.
3  *
4  * This program and the accompanying materials are made available under the
5  * terms of the Eclipse Public License v1.0 which accompanies this distribution,
6  * and is available at http://www.eclipse.org/legal/epl-v10.html
7  */
8 package org.opendaylight.controller.md.sal.trace.dom.impl;
9
10 import static java.util.Objects.requireNonNull;
11
12 import edu.umd.cs.findbugs.annotations.SuppressFBWarnings;
13 import java.io.PrintStream;
14 import java.util.ArrayList;
15 import java.util.HashMap;
16 import java.util.List;
17 import java.util.Map;
18 import java.util.Set;
19 import org.opendaylight.controller.md.sal.common.api.data.LogicalDatastoreType;
20 import org.opendaylight.controller.md.sal.common.api.data.TransactionChainListener;
21 import org.opendaylight.controller.md.sal.dom.api.ClusteredDOMDataTreeChangeListener;
22 import org.opendaylight.controller.md.sal.dom.api.DOMDataBroker;
23 import org.opendaylight.controller.md.sal.dom.api.DOMDataBrokerExtension;
24 import org.opendaylight.controller.md.sal.dom.api.DOMDataReadOnlyTransaction;
25 import org.opendaylight.controller.md.sal.dom.api.DOMDataReadWriteTransaction;
26 import org.opendaylight.controller.md.sal.dom.api.DOMDataTreeChangeListener;
27 import org.opendaylight.controller.md.sal.dom.api.DOMDataTreeChangeService;
28 import org.opendaylight.controller.md.sal.dom.api.DOMDataTreeIdentifier;
29 import org.opendaylight.controller.md.sal.dom.api.DOMDataWriteTransaction;
30 import org.opendaylight.controller.md.sal.dom.api.DOMTransactionChain;
31 import org.opendaylight.controller.md.sal.trace.api.TracingDOMDataBroker;
32 import org.opendaylight.controller.md.sal.trace.closetracker.impl.CloseTracked;
33 import org.opendaylight.controller.md.sal.trace.closetracker.impl.CloseTrackedRegistry;
34 import org.opendaylight.controller.md.sal.trace.closetracker.impl.CloseTrackedRegistryReportEntry;
35 import org.opendaylight.mdsal.binding.dom.codec.api.BindingNormalizedNodeSerializer;
36 import org.opendaylight.yang.gen.v1.urn.opendaylight.params.xml.ns.yang.mdsaltrace.rev160908.Config;
37 import org.opendaylight.yangtools.concepts.ListenerRegistration;
38 import org.opendaylight.yangtools.yang.binding.DataObject;
39 import org.opendaylight.yangtools.yang.binding.InstanceIdentifier;
40 import org.opendaylight.yangtools.yang.data.api.YangInstanceIdentifier;
41 import org.slf4j.Logger;
42 import org.slf4j.LoggerFactory;
43
44 @SuppressWarnings("checkstyle:JavadocStyle")
45 //...because otherwise it whines about the elements in the @code block even though it's completely valid Javadoc
46
47 /**
48  * TracingBroker logs "write" operations and listener registrations to the md-sal. It logs the instance identifier path,
49  * the objects themselves, as well as the stack trace of the call invoking the registration or write operation.
50  * It works by operating as a "bump on the stack" between the application and actual DataBroker, intercepting write
51  * and registration calls and writing to the log.
52  *
53  * <p>In addition, it (optionally) can also keep track of the stack trace of all new transaction allocations
54  * (including TransactionChains, and transactions created in turn from them), in order to detect and report leaks
55  * from transactions which were not closed.
56  *
57  * <h1>Wiring:</h1>
58  * TracingBroker is designed to be easy to use. In fact, for bundles using Blueprint to inject their DataBroker
59  * TracingBroker can be used without modifying your code at all in two simple steps:
60  * <ol>
61  * <li>
62  * Simply add the dependency "mdsaltrace-features" to
63  * your Karaf pom:
64  * <pre>
65  * {@code
66  *  <dependency>
67  *    <groupId>org.opendaylight.controller</groupId>
68  *    <artifactId>features-mdsal-trace</artifactId>
69  *    <version>1.7.0-SNAPSHOT</version>
70  *    <classifier>features</classifier>
71  *    <type>xml</type>
72  *    <scope>runtime</scope>
73  *  </dependency>
74  * }
75  * </pre>
76  * </li>
77  * <li>
78  * Then just "feature:install odl-mdsal-trace" before you install your "real" feature(s) and you're done.
79  * Beware that with Karaf 4 due to <a href="https://bugs.opendaylight.org/show_bug.cgi?id=9068">Bug 9068</a>
80  * you'll probably have to use feature:install's --no-auto-refresh flag when installing your "real" feature.
81  * </li>
82  * </ol>
83  * This works because the mdsaltrace-impl bundle registers its service implementing DOMDataBroker with a higher
84  * rank than sal-binding-broker. As such, any OSGi service lookup for DataBroker will receive the TracingBroker.
85  * <p> </p>
86  * <h1>Avoiding log bloat:</h1>
87  * TracingBroker can be configured to only print registrations or write ops pertaining to certain subtrees of the
88  * md-sal. This can be done in the code via the methods of this class or via a config file. TracingBroker uses a more
89  * convenient but non-standard representation of the instance identifiers. Each instance identifier segment's
90  * class.getSimpleName() is used separated by a '/'.
91  * <p> </p>
92  * <h1>Known issues</h1>
93  * <ul>
94  *     <li>
95  *        Filtering by paths. For some registrations the codec that converts back from the DOM to binding paths is
96  *        busted. As such, an aproximated path is used in the output. For now it is recommended not to use
97  *        watchRegistrations and allow all registrations to be logged.
98  *     </li>
99  * </ul>
100  *
101  */
102 @Deprecated(forRemoval = true)
103 public class TracingBroker implements TracingDOMDataBroker {
104     @SuppressFBWarnings("SLF4J_LOGGER_SHOULD_BE_PRIVATE")
105     static final Logger LOG = LoggerFactory.getLogger(TracingBroker.class);
106
107     private static final int STACK_TRACE_FIRST_RELEVANT_FRAME = 2;
108
109     private final String type; // "default" VS "pingpong"
110     private final BindingNormalizedNodeSerializer codec;
111     private final DOMDataBroker delegate;
112     private final List<Watch> registrationWatches = new ArrayList<>();
113     private final List<Watch> writeWatches = new ArrayList<>();
114
115     private final boolean isDebugging;
116     private final CloseTrackedRegistry<TracingTransactionChain> transactionChainsRegistry;
117     private final CloseTrackedRegistry<TracingReadOnlyTransaction> readOnlyTransactionsRegistry;
118     private final CloseTrackedRegistry<TracingWriteTransaction> writeTransactionsRegistry;
119     private final CloseTrackedRegistry<TracingReadWriteTransaction> readWriteTransactionsRegistry;
120
121     private class Watch {
122         final String iidString;
123         final LogicalDatastoreType store;
124
125         Watch(String iidString, LogicalDatastoreType storeOrNull) {
126             this.store = storeOrNull;
127             this.iidString = iidString;
128         }
129
130         private String toIidCompString(YangInstanceIdentifier iid) {
131             StringBuilder builder = new StringBuilder();
132             toPathString(iid, builder);
133             builder.append('/');
134             return builder.toString();
135         }
136
137         private boolean isParent(String parent, String child) {
138             int parentOffset = 0;
139             if (parent.length() > 0 && parent.charAt(0) == '<') {
140                 parentOffset = parent.indexOf('>') + 1;
141             }
142
143             int childOffset = 0;
144             if (child.length() > 0 && child.charAt(0) == '<') {
145                 childOffset = child.indexOf('>') + 1;
146             }
147
148             return child.startsWith(parent.substring(parentOffset), childOffset);
149         }
150
151         @SuppressWarnings({ "checkstyle:hiddenField", "hiding" })
152         public boolean subtreesOverlap(YangInstanceIdentifier iid, LogicalDatastoreType store) {
153             if (this.store != null && !this.store.equals(store)) {
154                 return false;
155             }
156
157             String otherIidString = toIidCompString(iid);
158             return isParent(iidString, otherIidString) || isParent(otherIidString, iidString);
159         }
160
161         @SuppressWarnings({ "checkstyle:hiddenField", "hiding" })
162         public boolean eventIsOfInterest(YangInstanceIdentifier iid, LogicalDatastoreType store) {
163             if (this.store != null && !this.store.equals(store)) {
164                 return false;
165             }
166
167             return isParent(iidString, toPathString(iid));
168         }
169     }
170
171     public TracingBroker(String type, DOMDataBroker delegate, Config config, BindingNormalizedNodeSerializer codec) {
172         this.type = requireNonNull(type, "type");
173         this.delegate = requireNonNull(delegate, "delegate");
174         this.codec = requireNonNull(codec, "codec");
175         configure(config);
176
177         if (config.isTransactionDebugContextEnabled() != null) {
178             this.isDebugging = config.isTransactionDebugContextEnabled();
179         } else {
180             this.isDebugging = false;
181         }
182         final String db = "DataBroker";
183         this.transactionChainsRegistry     = new CloseTrackedRegistry<>(db, "createTransactionChain()", isDebugging);
184         this.readOnlyTransactionsRegistry  = new CloseTrackedRegistry<>(db, "newReadOnlyTransaction()", isDebugging);
185         this.writeTransactionsRegistry     = new CloseTrackedRegistry<>(db, "newWriteOnlyTransaction()", isDebugging);
186         this.readWriteTransactionsRegistry = new CloseTrackedRegistry<>(db, "newReadWriteTransaction()", isDebugging);
187     }
188
189     private void configure(Config config) {
190         registrationWatches.clear();
191         List<String> paths = config.getRegistrationWatches();
192         if (paths != null) {
193             for (String path : paths) {
194                 watchRegistrations(path, null);
195             }
196         }
197
198         writeWatches.clear();
199         paths = config.getWriteWatches();
200         if (paths != null) {
201             for (String path : paths) {
202                 watchWrites(path, null);
203             }
204         }
205     }
206
207     /**
208      * Log registrations to this subtree of the md-sal.
209      * @param iidString the iid path of the root of the subtree
210      * @param store Which LogicalDataStore? or null for both
211      */
212     public void watchRegistrations(String iidString, LogicalDatastoreType store) {
213         LOG.info("Watching registrations to {} in {}", iidString, store);
214         registrationWatches.add(new Watch(iidString, store));
215     }
216
217     /**
218      * Log writes to this subtree of the md-sal.
219      * @param iidString the iid path of the root of the subtree
220      * @param store Which LogicalDataStore? or null for both
221      */
222     public void watchWrites(String iidString, LogicalDatastoreType store) {
223         LOG.info("Watching writes to {} in {}", iidString, store);
224         Watch watch = new Watch(iidString, store);
225         writeWatches.add(watch);
226     }
227
228     @SuppressFBWarnings(value = "UPM_UNCALLED_PRIVATE_METHOD",
229             justification = "https://github.com/spotbugs/spotbugs/issues/811")
230     private boolean isRegistrationWatched(YangInstanceIdentifier iid, LogicalDatastoreType store) {
231         if (registrationWatches.isEmpty()) {
232             return true;
233         }
234
235         for (Watch regInterest : registrationWatches) {
236             if (regInterest.subtreesOverlap(iid, store)) {
237                 return true;
238             }
239         }
240
241         return false;
242     }
243
244     boolean isWriteWatched(YangInstanceIdentifier iid, LogicalDatastoreType store) {
245         if (writeWatches.isEmpty()) {
246             return true;
247         }
248
249         for (Watch watch : writeWatches) {
250             if (watch.eventIsOfInterest(iid, store)) {
251                 return true;
252             }
253         }
254
255         return false;
256     }
257
258     static void toPathString(InstanceIdentifier<? extends DataObject> iid, StringBuilder builder) {
259         for (InstanceIdentifier.PathArgument pathArg : iid.getPathArguments()) {
260             builder.append('/').append(pathArg.getType().getSimpleName());
261         }
262     }
263
264     String toPathString(YangInstanceIdentifier  yiid) {
265         StringBuilder sb = new StringBuilder();
266         toPathString(yiid, sb);
267         return sb.toString();
268     }
269
270
271     private void toPathString(YangInstanceIdentifier yiid, StringBuilder sb) {
272         InstanceIdentifier<?> iid = codec.fromYangInstanceIdentifier(yiid);
273         if (null == iid) {
274             reconstructIidPathString(yiid, sb);
275         } else {
276             toPathString(iid, sb);
277         }
278     }
279
280     private static void reconstructIidPathString(YangInstanceIdentifier yiid, StringBuilder sb) {
281         sb.append("<RECONSTRUCTED FROM: \"").append(yiid.toString()).append("\">");
282         for (YangInstanceIdentifier.PathArgument pathArg : yiid.getPathArguments()) {
283             if (pathArg instanceof YangInstanceIdentifier.AugmentationIdentifier) {
284                 sb.append('/').append("AUGMENTATION");
285                 continue;
286             }
287             sb.append('/').append(pathArg.getNodeType().getLocalName());
288         }
289     }
290
291     String getStackSummary() {
292         StackTraceElement[] stack = Thread.currentThread().getStackTrace();
293
294         StringBuilder sb = new StringBuilder();
295         for (int i = STACK_TRACE_FIRST_RELEVANT_FRAME; i < stack.length; i++) {
296             StackTraceElement frame = stack[i];
297             sb.append("\n\t(TracingBroker)\t").append(frame.getClassName()).append('.').append(frame.getMethodName());
298         }
299
300         return sb.toString();
301     }
302
303     @Override
304     public DOMDataReadWriteTransaction newReadWriteTransaction() {
305         return new TracingReadWriteTransaction(delegate.newReadWriteTransaction(), this, readWriteTransactionsRegistry);
306     }
307
308     @Override
309     public DOMDataWriteTransaction newWriteOnlyTransaction() {
310         return new TracingWriteTransaction(delegate.newWriteOnlyTransaction(), this, writeTransactionsRegistry);
311     }
312
313     @Override
314     public DOMTransactionChain createTransactionChain(TransactionChainListener transactionChainListener) {
315         return new TracingTransactionChain(
316                 delegate.createTransactionChain(transactionChainListener), this, transactionChainsRegistry);
317     }
318
319     @Override
320     public DOMDataReadOnlyTransaction newReadOnlyTransaction() {
321         return new TracingReadOnlyTransaction(delegate.newReadOnlyTransaction(), readOnlyTransactionsRegistry);
322     }
323
324     @Override
325     public Map<Class<? extends DOMDataBrokerExtension>, DOMDataBrokerExtension> getSupportedExtensions() {
326         Map<Class<? extends DOMDataBrokerExtension>, DOMDataBrokerExtension> res = delegate.getSupportedExtensions();
327         DOMDataTreeChangeService treeChangeSvc = (DOMDataTreeChangeService) res.get(DOMDataTreeChangeService.class);
328         if (treeChangeSvc == null) {
329             return res;
330         }
331
332         res = new HashMap<>(res);
333
334         res.put(DOMDataTreeChangeService.class, new DOMDataTreeChangeService() {
335             @Override
336             public <L extends DOMDataTreeChangeListener> ListenerRegistration<L> registerDataTreeChangeListener(
337                     DOMDataTreeIdentifier domDataTreeIdentifier, L listener) {
338                 if (isRegistrationWatched(domDataTreeIdentifier.getRootIdentifier(),
339                         domDataTreeIdentifier.getDatastoreType())) {
340                     LOG.warn("{} registration (registerDataTreeChangeListener) for {} from {}.",
341                             listener instanceof ClusteredDOMDataTreeChangeListener ? "Clustered" : "Non-clustered",
342                             toPathString(domDataTreeIdentifier.getRootIdentifier()), getStackSummary());
343                 }
344                 return treeChangeSvc.registerDataTreeChangeListener(domDataTreeIdentifier, listener);
345             }
346         });
347
348         return res;
349     }
350
351     @Override
352     public boolean printOpenTransactions(PrintStream ps, int minOpenTXs) {
353         if (transactionChainsRegistry.getAllUnique().isEmpty()
354             && readOnlyTransactionsRegistry.getAllUnique().isEmpty()
355             && writeTransactionsRegistry.getAllUnique().isEmpty()
356             && readWriteTransactionsRegistry.getAllUnique().isEmpty()) {
357
358             ps.println(type + ": No open transactions, great!");
359             return false;
360         }
361
362         ps.println(type + ": " + getClass().getSimpleName()
363                  + " found some not yet (or never..) closed transaction[chain]s!");
364         ps.println("[NB: If no stack traces are shown below, then "
365                  + "enable transaction-debug-context-enabled in mdsaltrace_config.xml]");
366         ps.println();
367         // Flag to track if we really found any real leaks with more (or equal) to minOpenTXs
368         boolean hasFound = print(readOnlyTransactionsRegistry, ps, "  ", minOpenTXs);
369         hasFound |= print(writeTransactionsRegistry, ps, "  ", minOpenTXs);
370         hasFound |= print(readWriteTransactionsRegistry, ps, "  ", minOpenTXs);
371
372         // Now print details for each non-closed TransactionChain
373         // incl. in turn each ones own read/Write[Only]TransactionsRegistry
374         Set<CloseTrackedRegistryReportEntry<TracingTransactionChain>>
375             entries = transactionChainsRegistry.getAllUnique();
376         if (!entries.isEmpty()) {
377             ps.println("  " + transactionChainsRegistry.getAnchor() + " : "
378                     + transactionChainsRegistry.getCreateDescription());
379         }
380         for (CloseTrackedRegistryReportEntry<TracingTransactionChain> entry : entries) {
381             ps.println("    " + entry.getNumberAddedNotRemoved() + "x TransactionChains opened but not closed here:");
382             printStackTraceElements(ps, "      ", entry.getStackTraceElements());
383             @SuppressWarnings("resource")
384             TracingTransactionChain txChain = (TracingTransactionChain) entry
385                 .getExampleCloseTracked().getRealCloseTracked();
386             hasFound |= print(txChain.getReadOnlyTransactionsRegistry(), ps, "        ", minOpenTXs);
387             hasFound |= print(txChain.getWriteTransactionsRegistry(), ps, "        ", minOpenTXs);
388             hasFound |= print(txChain.getReadWriteTransactionsRegistry(), ps, "        ", minOpenTXs);
389         }
390         ps.println();
391
392         return hasFound;
393     }
394
395     private <T extends CloseTracked<T>> boolean print(
396             CloseTrackedRegistry<T> registry, PrintStream ps, String indent, int minOpenTransactions) {
397         Set<CloseTrackedRegistryReportEntry<T>> unsorted = registry.getAllUnique();
398         if (unsorted.size() < minOpenTransactions) {
399             return false;
400         }
401
402         List<CloseTrackedRegistryReportEntry<T>> entries = new ArrayList<>(unsorted);
403         entries.sort((o1, o2) -> Long.compare(o2.getNumberAddedNotRemoved(), o1.getNumberAddedNotRemoved()));
404
405         if (!entries.isEmpty()) {
406             ps.println(indent + registry.getAnchor() + " : " + registry.getCreateDescription());
407         }
408         entries.forEach(entry -> {
409             ps.println(indent + "  " + entry.getNumberAddedNotRemoved()
410                 + "x transactions opened here, which are not closed:");
411             printStackTraceElements(ps, indent + "    ", entry.getStackTraceElements());
412         });
413         if (!entries.isEmpty()) {
414             ps.println();
415         }
416         return true;
417     }
418
419     private void printStackTraceElements(PrintStream ps, String indent, List<StackTraceElement> stackTraceElements) {
420         boolean ellipsis = false;
421         for (final StackTraceElement stackTraceElement : stackTraceElements) {
422             if (isStackTraceElementInteresting(stackTraceElement)) {
423                 ps.println(indent + stackTraceElement);
424                 ellipsis = false;
425             } else if (!ellipsis) {
426                 ps.println(indent + "(...)");
427                 ellipsis = true;
428             }
429         }
430     }
431
432     private boolean isStackTraceElementInteresting(StackTraceElement element) {
433         final String className = element.getClassName();
434         return !className.startsWith(getClass().getPackage().getName())
435             && !className.startsWith(CloseTracked.class.getPackage().getName())
436             && !className.startsWith("Proxy")
437             && !className.startsWith("akka")
438             && !className.startsWith("scala")
439             && !className.startsWith("sun.reflect")
440             && !className.startsWith("java.lang.reflect")
441             && !className.startsWith("org.apache.aries.blueprint")
442             && !className.startsWith("org.osgi.util.tracker");
443     }
444 }

©2013 OpenDaylight, A Linux Foundation Collaborative Project. All Rights Reserved.
OpenDaylight is a registered trademark of The OpenDaylight Project, Inc.
Linux Foundation and OpenDaylight are registered trademarks of the Linux Foundation.
Linux is a registered trademark of Linus Torvalds.