SEBA-726 suppress not-useful duplicate k8s synchronizer messages

Change-Id: I8435677345ea18bb11ae5241e4dacb70778c6afd
diff --git a/VERSION b/VERSION
index f0bb29e..625610e 100644
--- a/VERSION
+++ b/VERSION
@@ -1 +1 @@
-1.3.0
+1.3.1-dev
diff --git a/xos/synchronizer/helpers.py b/xos/synchronizer/helpers.py
new file mode 100644
index 0000000..7f0a231
--- /dev/null
+++ b/xos/synchronizer/helpers.py
@@ -0,0 +1,36 @@
+# Copyright 2017-present Open Networking Foundation
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+from xosconfig import Config
+from multistructlog import create_logger
+
+log = create_logger(Config().get('logging'))
+
+squelched_messages = {}
+
+
+def debug_once(msg, *args, **kwargs):
+    """ Output a given debug message only once. If we see the same messag
+        again, then ignore it.
+    """
+    count = squelched_messages.get(msg, 0)
+
+    if count == 0:
+        # This is the first time we've seen this message.
+        log.debug(msg, *args, **kwargs)
+    elif count == 1:
+        # We've seen a duplicate. Let the user know we're supressing.
+        log.debug("[Further messages suppressed] " + msg, *args, **kwargs)
+
+    squelched_messages[msg] = count + 1
diff --git a/xos/synchronizer/pull_steps/pull_pods.py b/xos/synchronizer/pull_steps/pull_pods.py
index 0a92581..140ed94 100644
--- a/xos/synchronizer/pull_steps/pull_pods.py
+++ b/xos/synchronizer/pull_steps/pull_pods.py
@@ -27,6 +27,7 @@
 from xosconfig import Config
 from multistructlog import create_logger
 from xoskafka import XOSKafkaProducer
+from helpers import debug_once
 
 log = create_logger(Config().get('logging'))
 
@@ -74,7 +75,7 @@
             resource = None
         return resource
 
-    def get_controller_from_obj(self, obj, trust_domain, depth=0):
+    def get_controller_from_obj(self, pod_name, obj, trust_domain, depth=0):
         """ Given an object, Search for its controller. Strategy is to walk backward until we find some object that
             is marked as a controller, but does not have any owners.
 
@@ -96,19 +97,19 @@
             if not owner:
                 # Failed to fetch the owner, probably because the owner's kind is something we do not understand. An
                 # example is the etcd-cluser pod, which is owned by a deployment of kind "EtcdCluster".
-                log.debug("failed to fetch owner", owner_reference=owner_reference)
+                debug_once("Pod %s: Failed to fetch owner" % pod_name, owner_reference=owner_reference)
                 continue
-            controller = self.get_controller_from_obj(owner, trust_domain, depth+1)
+            controller = self.get_controller_from_obj(pod_name, owner, trust_domain, depth+1)
             if controller:
                 return controller
 
         return None
 
-    def get_slice_from_pod(self, pod, trust_domain, principal):
+    def get_slice_from_pod(self, pod_name, pod, trust_domain, principal):
         """ Given a pod, determine which XOS Slice goes with it
             If the Slice doesn't exist, create it.
         """
-        controller = self.get_controller_from_obj(pod, trust_domain)
+        controller = self.get_controller_from_obj(pod_name, pod, trust_domain)
         if not controller:
             return None
 
@@ -242,7 +243,7 @@
         kubernetes_service = kubernetes_services[0]
 
         # For each k8s pod, see if there is an xos pod. If there is not, then create the xos pod.
-        for (k,pod) in k8s_pods_by_name.items():
+        for (k, pod) in k8s_pods_by_name.items():
             try:
                 if not k in xos_pods_by_name:
                     trust_domain = self.get_trustdomain_from_pod(pod, owner_service=kubernetes_service)
@@ -253,14 +254,14 @@
                         continue
 
                     principal = self.get_principal_from_pod(pod, trust_domain)
-                    slice = self.get_slice_from_pod(pod, trust_domain=trust_domain, principal=principal)
+                    slice = self.get_slice_from_pod(k, pod, trust_domain=trust_domain, principal=principal)
                     image = self.get_image_from_pod(pod)
 
                     if not slice:
                         # We could get here if the pod doesn't have a controller, or if the controller is of a kind
                         # that we don't understand (such as the Etcd controller). If so, the pod is not something we
                         # are interested in.
-                        log.debug("Unable to determine slice for pod %s. Ignoring." % k)
+                        debug_once("Pod %s: Unable to determine slice. Ignoring." % k)
                         continue
 
                     xos_pod = KubernetesServiceInstance(name=k,
diff --git a/xos/synchronizer/steps/sync_service.py b/xos/synchronizer/steps/sync_service.py
index 9c483b1..1aa9266 100644
--- a/xos/synchronizer/steps/sync_service.py
+++ b/xos/synchronizer/steps/sync_service.py
@@ -25,9 +25,11 @@
 
 from xosconfig import Config
 from multistructlog import create_logger
+from helpers import debug_once
 
 log = create_logger(Config().get('logging'))
 
+
 class SyncService(SyncStep):
 
     """
@@ -65,11 +67,11 @@
                     # If this happens, then either the Service has no Slices, or it does have slices but none of
                     # those slices are associated with a TrustDomain. Assume the developer has done this on purpose
                     # and ignore the Service.
-                    log.debug("Unable to determine Trust Domain for service %s. Ignoring." % model.name)
+                    debug_once("Service %s: Unable to determine Trust Domain. Ignoring." % model.name)
                     models.remove(model)
                 elif not model.serviceports.exists():
                     # If there are not ServicePorts, then there's not much for us to do at this time...
-                    log.debug("Service %s has no serviceports. Ignoring." % model.name)
+                    debug_once("Service %s: Has no serviceports. Ignoring." % model.name)
                     models.remove(model)
 
         return models
diff --git a/xos/synchronizer/tests/test_pull_pods.py b/xos/synchronizer/tests/test_pull_pods.py
index 588e979..dec8116 100644
--- a/xos/synchronizer/tests/test_pull_pods.py
+++ b/xos/synchronizer/tests/test_pull_pods.py
@@ -96,7 +96,7 @@
             pull_step.v1apps.read_namespaced_stateful_set.return_value = ss_obj
             pull_step.v1apps.read_namespaced_deployment.return_value = dep_obj
 
-            controller = pull_step.get_controller_from_obj(leaf_obj, self.trust_domain)
+            controller = pull_step.get_controller_from_obj("mypod", leaf_obj, self.trust_domain)
             self.assertEqual(controller, dep_obj)
 
     def test_get_slice_from_pod_exists(self):
@@ -115,7 +115,7 @@
 
             pod = MagicMock()
 
-            slice = pull_step.get_slice_from_pod(pod, self.trust_domain, self.principal)
+            slice = pull_step.get_slice_from_pod("mypod", pod, self.trust_domain, self.principal)
             self.assertEqual(slice, myslice)
 
     def test_get_slice_from_pod_noexist(self):
@@ -135,7 +135,7 @@
 
             pod = MagicMock()
 
-            slice = pull_step.get_slice_from_pod(pod, self.trust_domain, self.principal)
+            slice = pull_step.get_slice_from_pod("mypod", pod, self.trust_domain, self.principal)
             self.assertEqual(slice.name, "my_other_slice")
             self.assertEqual(slice.trust_domain, self.trust_domain)
             self.assertEqual(slice.principal, self.principal)