From 21fab529c9f0d1681b88aa6b847696717dd34065 Mon Sep 17 00:00:00 2001 From: Alistair Coles Date: Mon, 25 Jul 2022 16:06:08 +0100 Subject: [PATCH] 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 | 27 +++--- test/debug_logger.py | 13 +++ test/unit/container/test_sharder.py | 127 ++++++++++++++++++++++------ 3 files changed, 130 insertions(+), 37 deletions(-) diff --git a/swift/container/sharder.py b/swift/container/sharder.py index 6205c0bc25..bbbe6ccf12 100644 --- a/swift/container/sharder.py +++ b/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): - self.stats['sharding'][category][key] += step - if statsd: - statsd_key = '%s_%s' % (category, key) - self.logger.increment(statsd_key) + def _increment_stat(self, category, key, statsd=False): + self._update_stat(category, key, step=1, statsd=statsd) + + def _update_stat(self, category, key, step=1, statsd=False): + 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', - step=len(overlaps)) + self._update_stat('audit_root', 'num_overlap', + 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._increment_stat('misplaced', 'unplaced', step=unplaced) + self._update_stat('misplaced', 'placed', step=placed, statsd=True) + 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)) diff --git a/test/debug_logger.py b/test/debug_logger.py index e1fc84e69c..21b3cb7a6b 100644 --- a/test/debug_logger.py +++ b/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 diff --git a/test/unit/container/test_sharder.py b/test/unit/container/test_sharder.py index e0beaceb2b..9e76d32a6c 100644 --- a/test/unit/container/test_sharder.py +++ b/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])