diff options
author | Henning Baldersheim <balder@yahoo-inc.com> | 2023-02-28 17:28:30 +0100 |
---|---|---|
committer | GitHub <noreply@github.com> | 2023-02-28 17:28:30 +0100 |
commit | 384f309eb8d5340ede3de02fa884cf74ce0e573e (patch) | |
tree | c5bedd46beb3c233623f1977855b1faf32900b1f /metrics | |
parent | f726cda8e4df7d76cece8640f931304bc3d87471 (diff) | |
parent | f08a1a0269fe4df06acc3d88088092d251668fac (diff) |
Merge pull request #26224 from vespa-engine/balder/use-steady-time-for-metric-manager
Unify on steady time
Diffstat (limited to 'metrics')
-rw-r--r-- | metrics/src/tests/metricmanagertest.cpp | 53 | ||||
-rw-r--r-- | metrics/src/tests/snapshottest.cpp | 14 | ||||
-rw-r--r-- | metrics/src/vespa/metrics/metricmanager.cpp | 21 | ||||
-rw-r--r-- | metrics/src/vespa/metrics/metricmanager.h | 4 | ||||
-rw-r--r-- | metrics/src/vespa/metrics/updatehook.h | 2 |
5 files changed, 45 insertions, 49 deletions
diff --git a/metrics/src/tests/metricmanagertest.cpp b/metrics/src/tests/metricmanagertest.cpp index 1ba1cad9463..6d6f21ea7b0 100644 --- a/metrics/src/tests/metricmanagertest.cpp +++ b/metrics/src/tests/metricmanagertest.cpp @@ -364,10 +364,10 @@ class FakeTimer : public MetricManager::Timer { std::atomic<time_t> _time; public: FakeTimer(time_t startTime = 0) : _time(startTime) {} - time_t getTime() const override { return load_relaxed(_time); } + time_point getTime() const override { return time_point(vespalib::from_s(load_relaxed(_time))); } void set_time(time_t t) noexcept { store_relaxed(_time, t); } // Not safe for multiple writers, only expected to be called by test. - void add_time(time_t t) noexcept { set_time(getTime() + t); } + void add_time(time_t t) noexcept { set_time(load_relaxed(_time) + t); } }; struct BriefValuePrinter : public MetricVisitor { @@ -556,8 +556,8 @@ TEST_F(MetricManagerTest, test_snapshots) TEST_F(MetricManagerTest, test_json_output) { - FakeTimer* timer = new FakeTimer(1000); - std::unique_ptr<MetricManager::Timer> timerImpl(timer); + auto timerImpl = std::make_unique<FakeTimer>(1000); + FakeTimer & timer = *timerImpl; MetricManager mm(std::move(timerImpl)); TestMetricSet mySet; { @@ -582,7 +582,7 @@ TEST_F(MetricManagerTest, test_json_output) mySet.val10.a.val2.addValue(2); mySet.val10.b.val1.addValue(1); - timer->set_time(1300); + timer.set_time(1300); takeSnapshots(mm, 1300); // Create json output @@ -879,9 +879,7 @@ TEST_F(MetricManagerTest, json_output_can_have_multiple_sets_with_same_name) TEST_F(MetricManagerTest, test_text_output) { - FakeTimer* timer = new FakeTimer(1000); - std::unique_ptr<MetricManager::Timer> timerImpl(timer); - MetricManager mm(std::move(timerImpl)); + MetricManager mm(std::make_unique<FakeTimer>(1000)); TestMetricSet mySet; { MetricLockGuard lockGuard(mm.getMetricLock()); @@ -954,10 +952,7 @@ namespace { std::mutex& _output_mutex; FakeTimer& _timer; - MyUpdateHook(std::ostringstream& output, - std::mutex& output_mutex, - const char* name, - FakeTimer& timer) + MyUpdateHook(std::ostringstream& output, std::mutex& output_mutex, const char* name, FakeTimer& timer) : UpdateHook(name), _output(output), _output_mutex(output_mutex), @@ -967,7 +962,7 @@ namespace { void updateMetrics(const MetricLockGuard & ) override { std::lock_guard lock(_output_mutex); // updateMetrics() called from metric manager thread - _output << _timer.getTime() << ": " << getName() << " called\n"; + _output << vespalib::count_s(_timer.getTime().time_since_epoch()) << ": " << getName() << " called\n"; } }; } @@ -976,8 +971,8 @@ TEST_F(MetricManagerTest, test_update_hooks) { std::mutex output_mutex; std::ostringstream output; - FakeTimer* timer = new FakeTimer(1000); - std::unique_ptr<MetricManager::Timer> timerImpl(timer); + auto timerImpl = std::make_unique<FakeTimer>(1000); + FakeTimer & timer = *timerImpl; // Add a metric set just so one exist TestMetricSet mySet; MetricManager mm(std::move(timerImpl)); @@ -986,9 +981,9 @@ TEST_F(MetricManagerTest, test_update_hooks) mm.registerMetric(lockGuard, mySet.set); } - MyUpdateHook preInitShort(output, output_mutex, "BIS", *timer); - MyUpdateHook preInitLong(output, output_mutex, "BIL", *timer); - MyUpdateHook preInitInfinite(output, output_mutex, "BII", *timer); + MyUpdateHook preInitShort(output, output_mutex, "BIS", timer); + MyUpdateHook preInitLong(output, output_mutex, "BIL", timer); + MyUpdateHook preInitInfinite(output, output_mutex, "BII", timer); mm.addMetricUpdateHook(preInitShort, 5); mm.addMetricUpdateHook(preInitLong, 300); mm.addMetricUpdateHook(preInitInfinite, 0); @@ -1007,55 +1002,55 @@ TEST_F(MetricManagerTest, test_update_hooks) "consumer[1].tags[0] snaptest\n")); output << "Init done\n"; - MyUpdateHook postInitShort(output, output_mutex, "AIS", *timer); - MyUpdateHook postInitLong(output, output_mutex, "AIL", *timer); - MyUpdateHook postInitInfinite(output, output_mutex, "AII", *timer); + MyUpdateHook postInitShort(output, output_mutex, "AIS", timer); + MyUpdateHook postInitLong(output, output_mutex, "AIL", timer); + MyUpdateHook postInitInfinite(output, output_mutex, "AII", timer); mm.addMetricUpdateHook(postInitShort, 5); mm.addMetricUpdateHook(postInitLong, 400); mm.addMetricUpdateHook(postInitInfinite, 0); // After 5 seconds the short ones should get another. - timer->set_time(1006); + timer.set_time(1006); waitForTimeProcessed(mm, 1006); // After 4 more seconds the short ones should get another // since last update was a second late. (Stable periods, process time // should not affect how often they are updated) - timer->set_time(1010); + timer.set_time(1010); waitForTimeProcessed(mm, 1010); // Bumping considerably ahead, such that next update is in the past, // we should only get one update called in this period. - timer->set_time(1200); + timer.set_time(1200); waitForTimeProcessed(mm, 1200); // No updates at this time. - timer->set_time(1204); + timer.set_time(1204); waitForTimeProcessed(mm, 1204); // Give all hooks an update mm.updateMetrics(true); // Last update should not have interfered with periods - timer->set_time(1205); + timer.set_time(1205); waitForTimeProcessed(mm, 1205); // Time is just ahead of a snapshot. - timer->set_time(1299); + timer.set_time(1299); waitForTimeProcessed(mm, 1299); // At time 1300 we are at a 5 minute snapshot bump // All hooks should thus get an update. The one with matching period // should only get one - timer->set_time(1300); + timer.set_time(1300); waitForTimeProcessed(mm, 1300); // The snapshot time currently doesn't count for the metric at period // 400. It will get an event at this time. - timer->set_time(1450); + timer.set_time(1450); waitForTimeProcessed(mm, 1450); std::string expected( diff --git a/metrics/src/tests/snapshottest.cpp b/metrics/src/tests/snapshottest.cpp index b4eb4a1353c..4d2ea96c36d 100644 --- a/metrics/src/tests/snapshottest.cpp +++ b/metrics/src/tests/snapshottest.cpp @@ -122,15 +122,15 @@ struct TestMetricSet : public MetricSet { SubMetricSet set2; SumMetric<SubMetricSet> setSum; - TestMetricSet(vespalib::stringref name, MetricSet* owner = 0); + TestMetricSet(vespalib::stringref name); ~TestMetricSet(); void incValues(); }; -TestMetricSet::TestMetricSet(vespalib::stringref name, MetricSet* owner) - : MetricSet(name, {}, "", owner), +TestMetricSet::TestMetricSet(vespalib::stringref name) + : MetricSet(name, {}, "", nullptr), set1("set1", this), set2("set2", this), setSum("setSum", {}, "", this) @@ -149,7 +149,7 @@ TestMetricSet::incValues() { struct FakeTimer : public MetricManager::Timer { uint32_t _timeInSecs; FakeTimer() : _timeInSecs(1) {} - time_t getTime() const override { return _timeInSecs; } + time_point getTime() const override { return time_point(vespalib::from_s(_timeInSecs)); } }; void ASSERT_VALUE(int32_t value, const MetricSnapshot & snapshot, const char *name) __attribute__((noinline)); @@ -176,8 +176,7 @@ TEST_F(SnapshotTest, test_snapshot_two_days) TestMetricSet set("test"); FakeTimer* timer; - MetricManager mm( - std::unique_ptr<MetricManager::Timer>(timer = new FakeTimer)); + MetricManager mm(std::unique_ptr<MetricManager::Timer>(timer = new FakeTimer)); { MetricLockGuard lockGuard(mm.getMetricLock()); mm.registerMetric(lockGuard, set); @@ -215,10 +214,9 @@ TEST_F(SnapshotTest, test_snapshot_two_days) << "\n"; */ - const MetricSnapshot* snap = 0; // active snapshot MetricLockGuard lockGuard(mm.getMetricLock()); - snap = &mm.getActiveMetrics(lockGuard); + const MetricSnapshot* snap = &mm.getActiveMetrics(lockGuard); ASSERT_VALUE(0, *snap, "test.set1.set1.count1"); ASSERT_VALUE(0, *snap, "test.set1.set1.countSum"); diff --git a/metrics/src/vespa/metrics/metricmanager.cpp b/metrics/src/vespa/metrics/metricmanager.cpp index 9135dd86a16..df83001a4e2 100644 --- a/metrics/src/vespa/metrics/metricmanager.cpp +++ b/metrics/src/vespa/metrics/metricmanager.cpp @@ -26,13 +26,15 @@ using vespalib::IllegalStateException; using vespalib::IllegalArgumentException; using vespalib::make_string_short::fmt; using vespalib::count_ms; +using vespalib::count_s; +using vespalib::from_s; MetricManager::ConsumerSpec::ConsumerSpec() = default; MetricManager::ConsumerSpec::~ConsumerSpec() = default; -time_t +time_point MetricManager::Timer::getTime() const { - return vespalib::count_s(vespalib::system_clock::now().time_since_epoch()); + return vespalib::system_clock::now(); } void @@ -119,7 +121,7 @@ MetricManager::addMetricUpdateHook(UpdateHook& hook, uint32_t period) std::lock_guard sync(_waiter); // If we've already initialized manager, log period has been set. // In this case. Call first time after period - hook._nextCall = _timer->getTime() + period; + hook._nextCall = count_s(_timer->getTime().time_since_epoch()) + period; if (period == 0) { for (UpdateHook * sHook : _snapshotUpdateHooks) { if (sHook == &hook) { @@ -464,7 +466,7 @@ MetricManager::configure(const MetricLockGuard & , std::unique_ptr<Config> confi // Set up snapshots only first time. We don't allow live reconfig // of snapshot periods. - time_t currentTime(_timer->getTime()); + time_t currentTime = count_s(_timer->getTime().time_since_epoch()); _activeMetrics.setFromTime(currentTime); uint32_t count = 1; for (uint32_t i = 0; i< snapshotPeriods.size(); ++i) { @@ -731,7 +733,7 @@ MetricManager::run() // we constantly add next time to do something from the last timer. // For that to work, we need to initialize timers on first iteration // to set them to current time. - time_t currentTime = _timer->getTime(); + time_t currentTime = count_s(_timer->getTime().time_since_epoch()); for (auto & snapshot : _snapshots) { snapshot->setFromTime(currentTime); } @@ -741,12 +743,13 @@ MetricManager::run() // Ensure correct time for first snapshot _snapshots[0]->getSnapshot().setToTime(currentTime); while (!stop_requested()) { - currentTime = _timer->getTime(); + time_point now = _timer->getTime(); + currentTime = count_s(now.time_since_epoch()); time_t next = tick(sync, currentTime); if (currentTime < next) { - size_t ms = (next - currentTime) * 1000; - _cond.wait_for(sync, std::chrono::milliseconds(ms)); - _sleepTimes.addValue(ms); + vespalib::duration wait_time = from_s(next - currentTime); + _cond.wait_for(sync, wait_time); + _sleepTimes.addValue(count_ms(wait_time)); } else { _sleepTimes.addValue(0); } diff --git a/metrics/src/vespa/metrics/metricmanager.h b/metrics/src/vespa/metrics/metricmanager.h index 3c81d9abd6a..c3ce37b451f 100644 --- a/metrics/src/vespa/metrics/metricmanager.h +++ b/metrics/src/vespa/metrics/metricmanager.h @@ -67,8 +67,8 @@ public: struct Timer { virtual ~Timer() = default; - virtual time_t getTime() const; - time_point getTimeInMilliSecs() const { return time_point(vespalib::from_s(getTime())); } + virtual time_point getTime() const; + time_point getTimeInMilliSecs() const { return getTime(); } }; /** diff --git a/metrics/src/vespa/metrics/updatehook.h b/metrics/src/vespa/metrics/updatehook.h index f355197bbb7..58d9ef0d743 100644 --- a/metrics/src/vespa/metrics/updatehook.h +++ b/metrics/src/vespa/metrics/updatehook.h @@ -6,7 +6,7 @@ namespace metrics { -using time_point = vespalib::steady_time; +using time_point = vespalib::system_time; class MetricLockGuard { public: |