sharder: emit misplaced stats to statsd

Send some existing misplaced objects stats to statsd as well as the
recon file:
  misplaced_placed
  misplaced_unplaced
  misplaced_success
  misplaced_failure

Change-Id: I22ed81cce5d8c6fcb9028fcc0403c6e5e5110df8

swift/container/sharder.py

@@ -853,11 +853,15 @@ class ContainerSharder(ContainerSharderConf, ContainerReplicator):
         else:
             self.stats['sharding'][category][key] = max(current, value)
 
-    def _increment_stat(self, category, key, step=1, statsd=False):
+    def _increment_stat(self, category, key, statsd=False):
-        self.stats['sharding'][category][key] += step
+        self._update_stat(category, key, step=1, statsd=statsd)
-        if statsd:
+
-            statsd_key = '%s_%s' % (category, key)
+    def _update_stat(self, category, key, step=1, statsd=False):
-            self.logger.increment(statsd_key)
+        if step:
+            self.stats['sharding'][category][key] += step
+            if statsd:
+                statsd_key = '%s_%s' % (category, key)
+                self.logger.update_stats(statsd_key, step)
 
     def _make_stats_info(self, broker, node, own_shard_range):
         try:
@@ -1148,8 +1152,8 @@ class ContainerSharder(ContainerSharderConf, ContainerReplicator):
             overlaps = find_overlapping_ranges(shard_ranges)
             if overlaps:
                 self._increment_stat('audit_root', 'has_overlap')
-                self._increment_stat('audit_root', 'num_overlap',
+                self._update_stat('audit_root', 'num_overlap',
-                                     step=len(overlaps))
+                                  step=len(overlaps))
                 all_overlaps = ', '.join(
                     [' '.join(['%s-%s' % (sr.lower, sr.upper)
                                for sr in overlapping_ranges])
@@ -1488,8 +1492,8 @@ class ContainerSharder(ContainerSharderConf, ContainerReplicator):
             success &= self._replicate_and_delete(
                 src_broker, dest_shard_range, **dest_args)
 
-        self._increment_stat('misplaced', 'placed', step=placed)
+        self._update_stat('misplaced', 'placed', step=placed, statsd=True)
-        self._increment_stat('misplaced', 'unplaced', step=unplaced)
+        self._update_stat('misplaced', 'unplaced', step=unplaced, statsd=True)
         return success, placed, unplaced
 
     def _make_shard_range_fetcher(self, broker, src_shard_range):
@@ -1591,7 +1595,8 @@ class ContainerSharder(ContainerSharderConf, ContainerReplicator):
             self._increment_stat('misplaced', 'found', statsd=True)
             self.logger.debug('Placed %s misplaced objects (%s unplaced)',
                               num_placed, num_unplaced)
-        self._increment_stat('misplaced', 'success' if success else 'failure')
+        self._increment_stat('misplaced', 'success' if success else 'failure',
+                             statsd=True)
         self.logger.debug('Finished handling misplaced objects')
         return success
 
@@ -1639,7 +1644,7 @@ class ContainerSharder(ContainerSharderConf, ContainerReplicator):
         num_found = len(shard_ranges)
         self.logger.info(
             "Completed scan for shard ranges: %d found", num_found)
-        self._increment_stat('scanned', 'found', step=num_found)
+        self._update_stat('scanned', 'found', step=num_found)
         self._min_stat('scanned', 'min_time', round(elapsed / num_found, 3))
         self._max_stat('scanned', 'max_time', round(elapsed / num_found, 3))
 

test/debug_logger.py

@@ -134,6 +134,9 @@ class FakeLogger(logging.Logger, CaptureLog):
         return [call[0][0] for call in self.log_dict['increment']]
 
     def get_increment_counts(self):
+        # note: this method reports the sum of stats sent via the increment
+        # method only; consider using get_stats_counts instead to get the sum
+        # of stats sent via both the increment and update_stats methods
         counts = {}
         for metric in self.get_increments():
             if metric not in counts:
@@ -144,6 +147,16 @@ class FakeLogger(logging.Logger, CaptureLog):
     def get_update_stats(self):
         return [call[0] for call in self.log_dict['update_stats']]
 
+    def get_stats_counts(self):
+        # return dict key->count for stats, aggregating calls to both the
+        # increment and update methods
+        counts = self.get_increment_counts()
+        for metric, step in self.get_update_stats():
+            if metric not in counts:
+                counts[metric] = 0
+            counts[metric] += step
+        return counts
+
     def setFormatter(self, obj):
         self.formatter = obj
 

test/unit/container/test_sharder.py

@@ -432,13 +432,11 @@ class TestSharder(BaseTestSharder):
             sharder._increment_stat('visited', 'failure')
             sharder._increment_stat('visited', 'completed')
             sharder._increment_stat('cleaved', 'success')
-            sharder._increment_stat('scanned', 'found', step=4)
         expected = {'success': 2,
                     'failure': 1,
                     'completed': 1}
         self._assert_stats(expected, sharder, 'visited')
         self._assert_stats({'success': 1}, sharder, 'cleaved')
-        self._assert_stats({'found': 4}, sharder, 'scanned')
 
     def test_increment_stats_with_statsd(self):
         with self._mock_sharder() as sharder:
@@ -451,11 +449,23 @@ class TestSharder(BaseTestSharder):
                     'failure': 2,
                     'completed': 1}
         self._assert_stats(expected, sharder, 'visited')
-        counts = sharder.logger.get_increment_counts()
+        counts = sharder.logger.get_stats_counts()
         self.assertEqual(2, counts.get('visited_success'))
         self.assertEqual(1, counts.get('visited_failure'))
         self.assertIsNone(counts.get('visited_completed'))
 
+    def test_update_stat(self):
+        with self._mock_sharder() as sharder:
+            sharder._update_stat('scanned', 'found', step=4)
+        self._assert_stats({'found': 4}, sharder, 'scanned')
+        with self._mock_sharder() as sharder:
+            sharder._update_stat('scanned', 'found', step=4)
+            sharder._update_stat('misplaced', 'placed', step=456, statsd=True)
+        self._assert_stats({'found': 4}, sharder, 'scanned')
+        self._assert_stats({'placed': 456}, sharder, 'misplaced')
+        self.assertEqual({'misplaced_placed': 456},
+                         sharder.logger.get_stats_counts())
+
     def test_run_forever(self):
         conf = {'recon_cache_path': self.tempdir,
                 'devices': self.tempdir}
@@ -3300,7 +3310,11 @@ class TestSharder(BaseTestSharder):
                           'found': 0, 'placed': 0, 'unplaced': 0}
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertFalse(
-            sharder.logger.get_increment_counts().get('misplaced_found'))
+            sharder.logger.get_stats_counts().get('misplaced_found'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_placed'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_unplaced'))
 
         # sharding - no misplaced objects
         self.assertTrue(broker.set_sharding_state())
@@ -3309,7 +3323,11 @@ class TestSharder(BaseTestSharder):
         sharder._replicate_object.assert_not_called()
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertFalse(
-            sharder.logger.get_increment_counts().get('misplaced_found'))
+            sharder.logger.get_stats_counts().get('misplaced_found'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_placed'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_unplaced'))
 
         # pretend we cleaved up to end of second shard range
         context = CleavingContext.load(broker)
@@ -3320,7 +3338,11 @@ class TestSharder(BaseTestSharder):
         sharder._replicate_object.assert_not_called()
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertFalse(
-            sharder.logger.get_increment_counts().get('misplaced_found'))
+            sharder.logger.get_stats_counts().get('misplaced_found'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_placed'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_unplaced'))
 
         # sharding - misplaced objects
         for obj in objects:
@@ -3333,7 +3355,11 @@ class TestSharder(BaseTestSharder):
         sharder._replicate_object.assert_not_called()
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertFalse(
-            sharder.logger.get_increment_counts().get('misplaced_found'))
+            sharder.logger.get_stats_counts().get('misplaced_found'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_placed'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_unplaced'))
         self.assertFalse(os.path.exists(expected_shard_dbs[0]))
         self.assertFalse(os.path.exists(expected_shard_dbs[1]))
         self.assertFalse(os.path.exists(expected_shard_dbs[2]))
@@ -3352,7 +3378,10 @@ class TestSharder(BaseTestSharder):
                           'found': 1, 'placed': 2, 'unplaced': 0}
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertEqual(
-            1, sharder.logger.get_increment_counts()['misplaced_found'])
+            1, sharder.logger.get_stats_counts()['misplaced_found'])
+        self.assertEqual(
+            2, sharder.logger.get_stats_counts()['misplaced_placed'])
+
         # check misplaced objects were moved
         self._check_objects(objects[:2], expected_shard_dbs[1])
         # ... and removed from the source db
@@ -3387,7 +3416,9 @@ class TestSharder(BaseTestSharder):
         )
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertEqual(
-            1, sharder.logger.get_increment_counts()['misplaced_found'])
+            1, sharder.logger.get_stats_counts()['misplaced_found'])
+        self.assertEqual(
+            4, sharder.logger.get_stats_counts()['misplaced_placed'])
 
         # check misplaced objects were moved
         self._check_objects(new_objects, expected_shard_dbs[0])
@@ -3407,7 +3438,9 @@ class TestSharder(BaseTestSharder):
                           'found': 0, 'placed': 0, 'unplaced': 0}
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertFalse(
-            sharder.logger.get_increment_counts().get('misplaced_found'))
+            sharder.logger.get_stats_counts().get('misplaced_found'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_placed'))
 
         # and then more misplaced updates arrive
         newer_objects = [
@@ -3432,7 +3465,9 @@ class TestSharder(BaseTestSharder):
                           'found': 1, 'placed': 3, 'unplaced': 0}
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertEqual(
-            1, sharder.logger.get_increment_counts()['misplaced_found'])
+            1, sharder.logger.get_stats_counts()['misplaced_found'])
+        self.assertEqual(
+            3, sharder.logger.get_stats_counts()['misplaced_placed'])
 
         # check new misplaced objects were moved
         self._check_objects(newer_objects[:1] + new_objects,
@@ -3623,7 +3658,7 @@ class TestSharder(BaseTestSharder):
                           'found': 1, 'placed': 4, 'unplaced': 0}
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertEqual(
-            1, sharder.logger.get_increment_counts()['misplaced_found'])
+            1, sharder.logger.get_stats_counts()['misplaced_found'])
         # check misplaced objects were moved
         self._check_objects(objects[:2], expected_dbs[1])
         self._check_objects(objects[2:3], expected_dbs[2])
@@ -3656,7 +3691,7 @@ class TestSharder(BaseTestSharder):
                           'placed': 4, 'unplaced': 0}
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertEqual(
-            1, sharder.logger.get_increment_counts()['misplaced_found'])
+            1, sharder.logger.get_stats_counts()['misplaced_found'])
         # check misplaced objects were moved to shard dbs
         self._check_objects(objects[:2], expected_dbs[1])
         self._check_objects(objects[2:3], expected_dbs[2])
@@ -3689,7 +3724,7 @@ class TestSharder(BaseTestSharder):
                           'placed': 4, 'unplaced': 0}
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertEqual(
-            1, sharder.logger.get_increment_counts()['misplaced_found'])
+            1, sharder.logger.get_stats_counts()['misplaced_found'])
         # check misplaced objects were moved to shard dbs
         self._check_objects(objects[:2], expected_dbs[1])
         self._check_objects(objects[2:3], expected_dbs[2])
@@ -3722,7 +3757,7 @@ class TestSharder(BaseTestSharder):
                           'placed': 4, 'unplaced': 0}
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertEqual(
-            1, sharder.logger.get_increment_counts()['misplaced_found'])
+            1, sharder.logger.get_stats_counts()['misplaced_found'])
         # check misplaced objects were moved to shard dbs
         self._check_objects(objects[:2], expected_dbs[1])
         self._check_objects(objects[2:3], expected_dbs[2])
@@ -3775,8 +3810,16 @@ class TestSharder(BaseTestSharder):
         expected_stats = {'attempted': 1, 'success': 1, 'failure': 0,
                           'found': 0, 'placed': 0, 'unplaced': 0}
         self._assert_stats(expected_stats, sharder, 'misplaced')
+        self.assertEqual(
+            1, sharder.logger.get_stats_counts().get('misplaced_success'))
         self.assertFalse(
-            sharder.logger.get_increment_counts().get('misplaced_found'))
+            sharder.logger.get_stats_counts().get('misplaced_failure'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_found'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_placed'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_unplaced'))
         self.assertFalse(sharder.logger.get_lines_for_level('warning'))
 
         # now put objects
@@ -3803,8 +3846,16 @@ class TestSharder(BaseTestSharder):
         expected_stats = {'attempted': 1, 'success': 0, 'failure': 1,
                           'found': 1, 'placed': 2, 'unplaced': 2}
         self._assert_stats(expected_stats, sharder, 'misplaced')
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_success'))
         self.assertEqual(
-            1, sharder.logger.get_increment_counts()['misplaced_found'])
+            1, sharder.logger.get_stats_counts().get('misplaced_failure'))
+        self.assertEqual(
+            1, sharder.logger.get_stats_counts()['misplaced_found'])
+        self.assertEqual(
+            2, sharder.logger.get_stats_counts().get('misplaced_placed'))
+        self.assertEqual(
+            2, sharder.logger.get_stats_counts().get('misplaced_unplaced'))
         # some misplaced objects could not be moved...
         warning_lines = sharder.logger.get_lines_for_level('warning')
         self.assertIn(
@@ -3840,7 +3891,15 @@ class TestSharder(BaseTestSharder):
                           'found': 1, 'placed': 2, 'unplaced': 0}
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertEqual(
-            1, sharder.logger.get_increment_counts()['misplaced_found'])
+            1, sharder.logger.get_stats_counts().get('misplaced_success'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_failure'))
+        self.assertEqual(
+            1, sharder.logger.get_stats_counts()['misplaced_found'])
+        self.assertEqual(
+            2, sharder.logger.get_stats_counts().get('misplaced_placed'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_unplaced'))
         self.assertFalse(sharder.logger.get_lines_for_level('warning'))
 
         # check misplaced objects were moved
@@ -3863,9 +3922,17 @@ class TestSharder(BaseTestSharder):
         expected_stats = {'attempted': 1, 'success': 1, 'failure': 0,
                           'found': 0, 'placed': 0, 'unplaced': 0}
         self._assert_stats(expected_stats, sharder, 'misplaced')
+        self.assertEqual(
+            1, sharder.logger.get_stats_counts().get('misplaced_success'))
         self.assertFalse(
-            sharder.logger.get_increment_counts().get('misplaced_found'))
+            sharder.logger.get_stats_counts().get('misplaced_failure'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_found'))
         self.assertFalse(sharder.logger.get_lines_for_level('warning'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_placed'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_unplaced'))
 
         # and then more misplaced updates arrive
         new_objects = [
@@ -3899,7 +3966,15 @@ class TestSharder(BaseTestSharder):
                           'found': 1, 'placed': 2, 'unplaced': 0}
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertEqual(
-            1, sharder.logger.get_increment_counts()['misplaced_found'])
+            1, sharder.logger.get_stats_counts().get('misplaced_success'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_failure'))
+        self.assertEqual(
+            1, sharder.logger.get_stats_counts()['misplaced_found'])
+        self.assertEqual(
+            2, sharder.logger.get_stats_counts().get('misplaced_placed'))
+        self.assertFalse(
+            sharder.logger.get_stats_counts().get('misplaced_unplaced'))
         self.assertFalse(sharder.logger.get_lines_for_level('warning'))
 
         # check new misplaced objects were moved
@@ -3986,7 +4061,7 @@ class TestSharder(BaseTestSharder):
                           'found': 1, 'placed': 1, 'unplaced': 2}
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertEqual(
-            1, sharder.logger.get_increment_counts()['misplaced_found'])
+            1, sharder.logger.get_stats_counts()['misplaced_found'])
         warning_lines = sharder.logger.get_lines_for_level('warning')
         self.assertIn(
             'Failed to find destination for at least 2 misplaced objects',
@@ -4021,7 +4096,7 @@ class TestSharder(BaseTestSharder):
                           'found': 1, 'placed': 2, 'unplaced': 0}
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertEqual(
-            1, sharder.logger.get_increment_counts()['misplaced_found'])
+            1, sharder.logger.get_stats_counts()['misplaced_found'])
         self.assertFalse(sharder.logger.get_lines_for_level('warning'))
 
         # check misplaced objects were moved
@@ -4072,7 +4147,7 @@ class TestSharder(BaseTestSharder):
                           'found': 1, 'placed': 5, 'unplaced': 0}
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertEqual(
-            1, sharder.logger.get_increment_counts()['misplaced_found'])
+            1, sharder.logger.get_stats_counts()['misplaced_found'])
         self.assertFalse(sharder.logger.get_lines_for_level('warning'))
 
         # check *all* the misplaced objects were moved
@@ -4128,7 +4203,7 @@ class TestSharder(BaseTestSharder):
                           'found': 1, 'placed': 2, 'unplaced': 0}
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertEqual(
-            1, sharder.logger.get_increment_counts()['misplaced_found'])
+            1, sharder.logger.get_stats_counts()['misplaced_found'])
 
         # check new misplaced objects were moved
         self._check_objects(objects[:1], expected_shard_dbs[0])
@@ -4155,7 +4230,7 @@ class TestSharder(BaseTestSharder):
         )
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertEqual(
-            1, sharder.logger.get_increment_counts()['misplaced_found'])
+            1, sharder.logger.get_stats_counts()['misplaced_found'])
 
         # check older misplaced objects were not merged to shard brokers
         self._check_objects(objects[:1], expected_shard_dbs[0])
@@ -4194,7 +4269,7 @@ class TestSharder(BaseTestSharder):
         )
         self._assert_stats(expected_stats, sharder, 'misplaced')
         self.assertEqual(
-            1, sharder.logger.get_increment_counts()['misplaced_found'])
+            1, sharder.logger.get_stats_counts()['misplaced_found'])
 
         # check only the newer misplaced object was moved
         self._check_objects([newer_object], expected_shard_dbs[0])