More detailed subscriber event logging

Change-Id: I21de8a93d0c4973a29b210dcf857f36ba08a84db
Signed-off-by: Lorand Jakab <lojakab@cisco.com>

diff --git a/integrationtest/src/test/java/org/opendaylight/lispflowmapping/integrationtest/MultiSiteScenario.java b/integrationtest/src/test/java/org/opendaylight/lispflowmapping/integrationtest/MultiSiteScenario.java
index 3b15d204ab5e5fa33ab3fccb7c5eaeddcb2bb76a..bde37275f61f086d4730ef4541b28f060ad5c15d 100644 (file)
--- a/integrationtest/src/test/java/org/opendaylight/lispflowmapping/integrationtest/MultiSiteScenario.java
+++ b/integrationtest/src/test/java/org/opendaylight/lispflowmapping/integrationtest/MultiSiteScenario.java
@@ -443,6 +443,10 @@ class MultiSiteScenario {
     private List<MapRequest> translateBuffersToMapRequest(byte[][] buffers) {
         final List<MapRequest> mapRequests = new ArrayList<>();
         for (byte[] buffer : buffers) {
+            if (isBufferEmpty(buffer)) {
+                LOG.error("Empty buffer while translating Map-Request");
+                continue;
+            }
             final MapRequest mapRequest = MapRequestSerializer.getInstance().deserialize(ByteBuffer.wrap(buffer), null);
             assertNotNull(mapRequest);
             mapRequests.add(mapRequest);
@@ -472,9 +476,14 @@ class MultiSiteScenario {
             fail("No SMR received!");
         }
         List<MapRequest> mapRequests = translateBuffersToMapRequest(buffers);
+        if (hosts.length != mapRequests.size()) {
+            LOG.error("Expected {} SMRs, received {}", hosts.length, mapRequests.size());
+            fail("Unexpected number of SMRs received");
+        }
         final Set<Eid> eids = prepareExpectedEid(hosts);
         final SourceEid expectedSourceEid = prepareSourceEid(site);
         for(MapRequest mapRequest : mapRequests) {
+            LOG.trace("Map-Request: {}", mapRequest);
             assertTrue(mapRequest.isSmr());
             final SourceEid receivedSourceEid = mapRequest.getSourceEid();
             assertEquals(expectedSourceEid, receivedSourceEid);
@@ -497,12 +506,19 @@ class MultiSiteScenario {
         return true;
     }
 
+    private static boolean isBufferEmpty(byte[] buffer) {
+        for (byte b : buffer) {
+            if (b != 0) {
+                return false;
+            }
+        }
+        return true;
+    }
+
     protected static boolean areBuffersEmpty(byte[][] buffers) {
         for (byte[] buffer : buffers) {
-            for (byte b : buffer) {
-                if (b != 0) {
-                    return false;
-                }
+            if (!isBufferEmpty(buffer)) {
+                return false;
             }
         }
         return true;

diff --git a/mappingservice/implementation/src/main/java/org/opendaylight/lispflowmapping/implementation/lisp/MapResolver.java b/mappingservice/implementation/src/main/java/org/opendaylight/lispflowmapping/implementation/lisp/MapResolver.java
index 1be9e16b5191f69ed27840c1691c78537ee178f1..c74b69fefaa4a0ccd5226b76facae20ddefd9424 100644 (file)
--- a/mappingservice/implementation/src/main/java/org/opendaylight/lispflowmapping/implementation/lisp/MapResolver.java
+++ b/mappingservice/implementation/src/main/java/org/opendaylight/lispflowmapping/implementation/lisp/MapResolver.java
@@ -198,7 +198,10 @@ public class MapResolver implements IMapResolverAsync {
             subscribers.remove(subscriber);
         }
         if (LOG.isTraceEnabled()) {
-            LOG.trace("Adding new subscriber: " + LispAddressStringifier.getString(subscriber.getSrcRloc()));
+            LOG.trace("Adding new subscriber {} for EID {}, source EID {}",
+                    LispAddressStringifier.getString(subscriber.getSrcRloc()),
+                    LispAddressStringifier.getString(subscribedEid),
+                    LispAddressStringifier.getString(subscriber.getSrcEid()));
         }
         subscribers.add(subscriber);
         addSubscribers(subscribedEid, subscribers);

diff --git a/mappingservice/implementation/src/main/java/org/opendaylight/lispflowmapping/implementation/lisp/MapServer.java b/mappingservice/implementation/src/main/java/org/opendaylight/lispflowmapping/implementation/lisp/MapServer.java
index 799def39cdb2521b98c2c4f805759e425d365842..ed5427d7c05664ba61c390ccd77a7bfaccc3825c 100644 (file)
--- a/mappingservice/implementation/src/main/java/org/opendaylight/lispflowmapping/implementation/lisp/MapServer.java
+++ b/mappingservice/implementation/src/main/java/org/opendaylight/lispflowmapping/implementation/lisp/MapServer.java
@@ -31,6 +31,7 @@ import java.util.concurrent.TimeUnit;
 import org.apache.commons.lang3.BooleanUtils;
 import org.opendaylight.controller.md.sal.binding.api.NotificationService;
 import org.opendaylight.lispflowmapping.config.ConfigIni;
+import org.opendaylight.lispflowmapping.implementation.util.LoggingUtil;
 import org.opendaylight.lispflowmapping.implementation.util.MSNotificationInputUtil;
 import org.opendaylight.lispflowmapping.interfaces.dao.SubKeys;
 import org.opendaylight.lispflowmapping.interfaces.dao.Subscriber;
@@ -48,7 +49,6 @@ import org.opendaylight.lispflowmapping.lisp.util.MapNotifyBuilderHelper;
 import org.opendaylight.lispflowmapping.lisp.util.MapRequestUtil;
 import org.opendaylight.lispflowmapping.lisp.util.MappingRecordUtil;
 import org.opendaylight.lispflowmapping.lisp.util.SourceDestKeyHelper;
-import org.opendaylight.lispflowmapping.mapcache.lisp.LispMapCacheStringifier;
 import org.opendaylight.yang.gen.v1.urn.ietf.params.xml.ns.yang.ietf.inet.types.rev130715.PortNumber;
 import org.opendaylight.yang.gen.v1.urn.ietf.params.xml.ns.yang.ietf.lisp.address.types.rev151105.lisp.address.address.SourceDestKey;
 import org.opendaylight.yang.gen.v1.urn.opendaylight.lfm.inet.binary.types.rev160303.IpAddressBinary;
@@ -145,9 +145,11 @@ public class MapServer implements IMapServerAsync, OdlMappingserviceListener, IS
                     if (oldMapping != null && !oldMapping.getEid().equals(eid)) {
                         subscribers = addParentSubscribers(eid, subscribers);
                     }
+                    LoggingUtil.logSubscribers(LOG, eid, subscribers);
                     handleSmr(eid, subscribers);
                     if (oldMapping != null && oldMappingRemoved && !oldMapping.getEid().equals(eid)) {
                         subscribers = getSubscribers(oldMapping.getEid());
+                        LoggingUtil.logSubscribers(LOG, oldMapping.getEid(), subscribers);
                         handleSmr(oldMapping.getEid(), subscribers);
                     }
                     mappingUpdated = true;
@@ -214,17 +216,17 @@ public class MapServer implements IMapServerAsync, OdlMappingserviceListener, IS
 
     @Override
     public void onMappingChanged(MappingChanged notification) {
-        LOG.trace("MappingChanged event of type {}", notification.getChangeType());
+        LOG.trace("MappingChanged event of type: `{}'", notification.getChangeType());
         if (subscriptionService) {
             Eid eid = notification.getMappingRecord().getEid();
             Set<Subscriber> subscribers = MSNotificationInputUtil.toSubscriberSet(notification.getSubscriberItem());
-            LOG.trace("Subscribers:\n{}", LispMapCacheStringifier.prettyPrintSubscriberSet(subscribers, 0));
+            LoggingUtil.logSubscribers(LOG, eid, subscribers);
             if (mapService.isMaster()) {
                 sendSmrs(eid, subscribers);
                 if (eid.getAddress() instanceof SourceDestKey) {
                     Set<Subscriber> dstSubscribers = MSNotificationInputUtil.toSubscriberSetFromDst(
                             notification.getDstSubscriberItem());
-                    LOG.trace("DstSubscribers:\n{}", LispMapCacheStringifier.prettyPrintSubscriberSet(subscribers, 0));
+                    LoggingUtil.logSubscribers(LOG, SourceDestKeyHelper.getDstBinary(eid), dstSubscribers);
                     sendSmrs(SourceDestKeyHelper.getDstBinary(eid), dstSubscribers);
                 }
             }
@@ -309,7 +311,7 @@ public class MapServer implements IMapServerAsync, OdlMappingserviceListener, IS
             Enumeration<NetworkInterface> interfaces = NetworkInterface.getNetworkInterfaces();
             while (interfaces.hasMoreElements()) {
                 NetworkInterface current = interfaces.nextElement();
-                LOG.debug("Interface " + current.toString());
+                LOG.trace("Interface " + current.toString());
                 if (!current.isUp() || current.isLoopback() || current.isVirtual()) {
                     continue;
                 }

diff --git a/mappingservice/implementation/src/main/java/org/opendaylight/lispflowmapping/implementation/mdsal/MappingDataListener.java b/mappingservice/implementation/src/main/java/org/opendaylight/lispflowmapping/implementation/mdsal/MappingDataListener.java
index aedf49deae54bdaf2e8327e5fa837b5cf99745f6..fdca1eac6792aaa9e7203198124e83b76b1f1ba7 100644 (file)
--- a/mappingservice/implementation/src/main/java/org/opendaylight/lispflowmapping/implementation/mdsal/MappingDataListener.java
+++ b/mappingservice/implementation/src/main/java/org/opendaylight/lispflowmapping/implementation/mdsal/MappingDataListener.java
@@ -16,6 +16,7 @@ import org.opendaylight.controller.md.sal.binding.api.DataObjectModification;
 import org.opendaylight.controller.md.sal.binding.api.DataObjectModification.ModificationType;
 import org.opendaylight.controller.md.sal.binding.api.DataTreeModification;
 import org.opendaylight.controller.md.sal.binding.api.NotificationPublishService;
+import org.opendaylight.lispflowmapping.implementation.util.LoggingUtil;
 import org.opendaylight.lispflowmapping.implementation.util.MSNotificationInputUtil;
 import org.opendaylight.lispflowmapping.interfaces.dao.SubKeys;
 import org.opendaylight.lispflowmapping.interfaces.dao.Subscriber;
@@ -124,12 +125,15 @@ public class MappingDataListener extends AbstractDataListener<Mapping> {
                         new MappingData(convertedMapping.getMappingRecord()));
                 Set<Subscriber> subscribers = (Set<Subscriber>) mapSystem.getData(MappingOrigin.Southbound,
                         convertedEid, SubKeys.SUBSCRIBERS);
+                LoggingUtil.logSubscribers(LOG, convertedEid, subscribers);
+
                 Set<Subscriber> dstSubscribers = null;
                 // For SrcDst LCAF also send SMRs to Dst prefix
                 if (convertedEid.getAddress() instanceof SourceDestKey) {
                     Eid dstAddr = SourceDestKeyHelper.getDstBinary(convertedEid);
                     dstSubscribers = (Set<Subscriber>) mapSystem.getData(MappingOrigin.Southbound,
                             dstAddr, SubKeys.SUBSCRIBERS);
+                    LoggingUtil.logSubscribers(LOG, dstAddr, dstSubscribers);
                 }
 
                 try {

diff --git a/mappingservice/implementation/src/main/java/org/opendaylight/lispflowmapping/implementation/util/LoggingUtil.java b/mappingservice/implementation/src/main/java/org/opendaylight/lispflowmapping/implementation/util/LoggingUtil.java
new file mode 100644 (file)
index 0000000..f8b09cf
--- /dev/null
+++ b/mappingservice/implementation/src/main/java/org/opendaylight/lispflowmapping/implementation/util/LoggingUtil.java
@@ -0,0 +1,35 @@
+/*
+ * Copyright (c) 2017 Cisco Systems, Inc.  All rights reserved.
+ *
+ * This program and the accompanying materials are made available under the
+ * terms of the Eclipse Public License v1.0 which accompanies this distribution,
+ * and is available at http://www.eclipse.org/legal/epl-v10.html
+ */
+package org.opendaylight.lispflowmapping.implementation.util;
+
+import java.util.Set;
+import org.opendaylight.lispflowmapping.interfaces.dao.Subscriber;
+import org.opendaylight.lispflowmapping.lisp.util.LispAddressStringifier;
+import org.opendaylight.lispflowmapping.mapcache.lisp.LispMapCacheStringifier;
+import org.opendaylight.yang.gen.v1.urn.opendaylight.lfm.lisp.proto.rev151105.eid.container.Eid;
+import org.slf4j.Logger;
+
+/**
+ * Static utility methods for common logging patterns.
+ *
+ * @author Lorand Jakab
+ *
+ */
+public class LoggingUtil {
+    // Utility class, should not be instantiated
+    private LoggingUtil() {
+    }
+
+    public static void logSubscribers(Logger log, Eid eid, Set<Subscriber> subscribers) {
+        if (log.isTraceEnabled()) {
+            log.trace("Subscribers for EID {}\n{}",
+                    LispAddressStringifier.getString(eid),
+                    LispMapCacheStringifier.prettyPrintSubscriberSet(subscribers, 0));
+        }
+    }
+}