Improve failure reporting in IdIntsListener
[controller.git] / opendaylight / md-sal / samples / clustering-test-app / provider / src / main / java / org / opendaylight / controller / clustering / it / provider / impl / IdIntsListener.java
1 /*
2  * Copyright (c) 2017 Cisco Systems, 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
9 package org.opendaylight.controller.clustering.it.provider.impl;
10
11 import static org.opendaylight.controller.clustering.it.provider.impl.AbstractTransactionHandler.ITEM;
12
13 import com.google.common.base.Preconditions;
14 import com.google.common.util.concurrent.SettableFuture;
15 import edu.umd.cs.findbugs.annotations.SuppressFBWarnings;
16 import java.util.Collection;
17 import java.util.HashMap;
18 import java.util.Map;
19 import java.util.concurrent.Executors;
20 import java.util.concurrent.Future;
21 import java.util.concurrent.ScheduledExecutorService;
22 import java.util.concurrent.ScheduledFuture;
23 import java.util.concurrent.TimeUnit;
24 import java.util.concurrent.atomic.AtomicBoolean;
25 import java.util.concurrent.atomic.AtomicLong;
26 import javax.annotation.Nonnull;
27 import org.opendaylight.controller.md.sal.dom.api.ClusteredDOMDataTreeChangeListener;
28 import org.opendaylight.yangtools.yang.data.api.YangInstanceIdentifier;
29 import org.opendaylight.yangtools.yang.data.api.YangInstanceIdentifier.NodeIdentifierWithPredicates;
30 import org.opendaylight.yangtools.yang.data.api.schema.MapEntryNode;
31 import org.opendaylight.yangtools.yang.data.api.schema.MapNode;
32 import org.opendaylight.yangtools.yang.data.api.schema.NormalizedNode;
33 import org.opendaylight.yangtools.yang.data.api.schema.tree.DataTreeCandidate;
34 import org.slf4j.Logger;
35 import org.slf4j.LoggerFactory;
36
37 public class IdIntsListener implements ClusteredDOMDataTreeChangeListener {
38
39     private static final Logger LOG = LoggerFactory.getLogger(IdIntsListener.class);
40     private static final long SECOND_AS_NANO = 1000000000;
41
42     private volatile NormalizedNode<?, ?> localCopy;
43     private final AtomicLong lastNotifTimestamp = new AtomicLong(0);
44     private ScheduledExecutorService executorService;
45     private ScheduledFuture<?> scheduledFuture;
46     private final AtomicBoolean loggedIgnoredNotificationDiff = new AtomicBoolean();
47
48     @Override
49     public void onDataTreeChanged(@Nonnull final Collection<DataTreeCandidate> changes) {
50
51         // There should only be one candidate reported
52         Preconditions.checkState(changes.size() == 1);
53
54         lastNotifTimestamp.set(System.nanoTime());
55
56         // do not log the change into debug, only use trace since it will lead to OOM on default heap settings
57         LOG.debug("Received data tree changed");
58
59         changes.forEach(change -> {
60             if (change.getRootNode().getDataAfter().isPresent()) {
61                 LOG.trace("Received change, data before: {}, data after: {}",
62                         change.getRootNode().getDataBefore().isPresent()
63                                 ? change.getRootNode().getDataBefore().get() : "",
64                         change.getRootNode().getDataAfter().get());
65
66                 if (localCopy == null || checkEqual(change.getRootNode().getDataBefore().get())) {
67                     localCopy = change.getRootNode().getDataAfter().get();
68                 } else {
69                     LOG.warn("Ignoring notification {}", loggedIgnoredNotificationDiff.compareAndSet(false, true)
70                         ? diffWithLocalCopy(change.getRootNode().getDataBefore().get()) : "");
71                     LOG.trace("Ignored notification content: {}", change);
72                 }
73             } else {
74                 LOG.warn("getDataAfter() is missing from notification. change: {}", change);
75             }
76         });
77     }
78
79     public boolean hasTriggered() {
80         return localCopy != null;
81     }
82
83     public boolean checkEqual(final NormalizedNode<?, ?> expected) {
84         return localCopy.equals(expected);
85     }
86
87     @SuppressFBWarnings("BC_UNCONFIRMED_CAST")
88     public String diffWithLocalCopy(final NormalizedNode<?, ?> expected) {
89         return diffNodes((MapNode)expected, (MapNode)localCopy);
90     }
91
92     public Future<Void> tryFinishProcessing() {
93         executorService = Executors.newSingleThreadScheduledExecutor();
94         final SettableFuture<Void> settableFuture = SettableFuture.create();
95
96         scheduledFuture = executorService.scheduleAtFixedRate(new CheckFinishedTask(settableFuture),
97                 0, 1, TimeUnit.SECONDS);
98         return settableFuture;
99     }
100
101     public static String diffNodes(final MapNode expected, final MapNode actual) {
102         StringBuilder builder = new StringBuilder("MapNodes diff:");
103
104         final YangInstanceIdentifier.NodeIdentifier itemNodeId = new YangInstanceIdentifier.NodeIdentifier(ITEM);
105
106         Map<NodeIdentifierWithPredicates, MapEntryNode> expIdIntMap = new HashMap<>();
107         expected.getValue().forEach(node -> expIdIntMap.put(node.getIdentifier(), node));
108
109         actual.getValue().forEach(actIdInt -> {
110             final MapEntryNode expIdInt = expIdIntMap.remove(actIdInt.getIdentifier());
111             if (expIdInt == null) {
112                 builder.append('\n').append("  Unexpected id-int entry for ").append(actIdInt.getIdentifier());
113                 return;
114             }
115
116             Map<NodeIdentifierWithPredicates, MapEntryNode> expItemMap = new HashMap<>();
117             ((MapNode)expIdInt.getChild(itemNodeId).get()).getValue()
118                 .forEach(node -> expItemMap.put(node.getIdentifier(), node));
119
120             ((MapNode)actIdInt.getChild(itemNodeId).get()).getValue().forEach(actItem -> {
121                 final MapEntryNode expItem = expItemMap.remove(actItem.getIdentifier());
122                 if (expItem == null) {
123                     builder.append('\n').append("  Unexpected item entry ").append(actItem.getIdentifier())
124                         .append(" for id-int entry ").append(actIdInt.getIdentifier());
125                 }
126             });
127
128             expItemMap.values().forEach(node -> builder.append('\n')
129                 .append("  Actual is missing item entry ").append(node.getIdentifier())
130                     .append(" for id-int entry ").append(actIdInt.getIdentifier()));
131         });
132
133         expIdIntMap.values().forEach(node -> builder.append('\n')
134             .append("  Actual is missing id-int entry for ").append(node.getIdentifier()));
135
136         return builder.toString();
137     }
138
139     private class CheckFinishedTask implements Runnable {
140
141         private final SettableFuture<Void> future;
142
143         CheckFinishedTask(final SettableFuture<Void> future) {
144             this.future = future;
145         }
146
147         @Override
148         public void run() {
149             if (System.nanoTime() - lastNotifTimestamp.get() > SECOND_AS_NANO * 4) {
150                 scheduledFuture.cancel(false);
151                 future.set(null);
152
153                 executorService.shutdown();
154             }
155         }
156     }
157 }