From 3a4bf578ddf141622ac40d5bd7346f7f1cfb2970 Mon Sep 17 00:00:00 2001 From: Arne Juul Date: Thu, 30 Nov 2017 11:02:27 +0000 Subject: update metrics library after reviews * use slimmer handle subclasses * new tick abstraction * gc unused time supplier * rename current bucket concept to current samples * rename TimeStamp type * add padding making old metrics visible * improve test, now with less debug printing. --- .../src/tests/metrics/simple_metrics_test.cpp | 144 +++++++++++++++------ .../src/vespa/vespalib/metrics/CMakeLists.txt | 7 +- .../src/vespa/vespalib/metrics/bucket.cpp | 50 +++++++ .../src/vespa/vespalib/metrics/bucket.h | 7 +- .../src/vespa/vespalib/metrics/clock.cpp | 12 -- .../src/vespa/vespalib/metrics/clock.h | 36 +++++- .../vespa/vespalib/metrics/counter_aggregator.cpp | 2 +- .../src/vespa/vespalib/metrics/dimension.h | 11 +- .../vespa/vespalib/metrics/dummy_time_supplier.cpp | 2 - .../vespa/vespalib/metrics/dummy_time_supplier.h | 14 -- .../vespa/vespalib/metrics/gauge_aggregator.cpp | 12 +- .../src/vespa/vespalib/metrics/handle.h | 3 +- .../src/vespa/vespalib/metrics/label.h | 11 +- .../src/vespa/vespalib/metrics/metric_identifier.h | 2 +- .../src/vespa/vespalib/metrics/metric_name.h | 11 +- .../src/vespa/vespalib/metrics/mock_tick.cpp | 71 ++++++++++ .../src/vespa/vespalib/metrics/mock_tick.h | 32 +++++ .../src/vespa/vespalib/metrics/point.h | 4 +- .../src/vespa/vespalib/metrics/point_map.cpp | 20 +-- .../vespalib/metrics/simple_metrics_manager.cpp | 88 ++++++++----- .../vespalib/metrics/simple_metrics_manager.h | 32 +++-- .../src/vespa/vespalib/metrics/simple_tick.cpp | 49 +++++++ .../src/vespa/vespalib/metrics/simple_tick.h | 23 ++++ .../src/vespa/vespalib/metrics/snapshots.h | 2 +- .../vespa/vespalib/metrics/test_time_supplier.cpp | 2 - .../vespa/vespalib/metrics/test_time_supplier.h | 20 --- .../src/vespa/vespalib/metrics/ticker_thread.cpp | 39 ------ .../src/vespa/vespalib/metrics/ticker_thread.h | 35 ----- .../src/vespa/vespalib/metrics/time_supplier.cpp | 20 --- .../src/vespa/vespalib/metrics/time_supplier.h | 32 ----- .../vespalib/metrics/wallclock_time_supplier.cpp | 2 - .../vespalib/metrics/wallclock_time_supplier.h | 23 ---- 32 files changed, 477 insertions(+), 341 deletions(-) delete mode 100644 staging_vespalib/src/vespa/vespalib/metrics/dummy_time_supplier.cpp delete mode 100644 staging_vespalib/src/vespa/vespalib/metrics/dummy_time_supplier.h create mode 100644 staging_vespalib/src/vespa/vespalib/metrics/mock_tick.cpp create mode 100644 staging_vespalib/src/vespa/vespalib/metrics/mock_tick.h create mode 100644 staging_vespalib/src/vespa/vespalib/metrics/simple_tick.cpp create mode 100644 staging_vespalib/src/vespa/vespalib/metrics/simple_tick.h delete mode 100644 staging_vespalib/src/vespa/vespalib/metrics/test_time_supplier.cpp delete mode 100644 staging_vespalib/src/vespa/vespalib/metrics/test_time_supplier.h delete mode 100644 staging_vespalib/src/vespa/vespalib/metrics/time_supplier.cpp delete mode 100644 staging_vespalib/src/vespa/vespalib/metrics/time_supplier.h delete mode 100644 staging_vespalib/src/vespa/vespalib/metrics/wallclock_time_supplier.cpp delete mode 100644 staging_vespalib/src/vespa/vespalib/metrics/wallclock_time_supplier.h diff --git a/staging_vespalib/src/tests/metrics/simple_metrics_test.cpp b/staging_vespalib/src/tests/metrics/simple_metrics_test.cpp index d0a7ca4c4a9..6af03177ed8 100644 --- a/staging_vespalib/src/tests/metrics/simple_metrics_test.cpp +++ b/staging_vespalib/src/tests/metrics/simple_metrics_test.cpp @@ -1,9 +1,12 @@ // Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. #include +#include +#include #include #include #include #include +#include #include #include @@ -67,13 +70,60 @@ TEST("require that simple metrics gauge merge works") EXPECT_EQUAL(a.lastValue, 1.0); } +bool compare_json(const vespalib::string &a, const vespalib::string &b) +{ + using vespalib::Memory; + using vespalib::slime::JsonFormat; + + Slime slimeA, slimeB; + if (! JsonFormat::decode(a, slimeA)) { +fprintf(stderr, "bad json a:\n>>>%s\n<<<\n", a.c_str()); + return false; + } + if (! JsonFormat::decode(b, slimeB)) { +fprintf(stderr, "bad json b\n"); + return false; + } + return slimeA == slimeB; +} + +void check_json(const vespalib::string &actual) +{ + vespalib::string expect = "{" + " \"snapshot\": { \"from\": 1, \"to\": 4 }," + " \"values\": [ { \"name\": \"foo\"," + " \"values\": { \"count\": 17, \"rate\": 4.85714 }" + " }, {" + " \"name\": \"foo\"," + " \"dimensions\": { \"chain\": \"default\", \"documenttype\": \"music\", \"thread\": \"0\" }," + " \"values\": { \"count\": 4, \"rate\": 1.14286 }" + " }, {" + " \"name\": \"bar\"," + " \"values\": { \"count\": 4, \"rate\": 1.14286, \"average\": 42, \"min\": 41, \"max\": 43, \"last\": 42 }" + " }, {" + " \"name\": \"bar\"," + " \"dimensions\": { \"chain\": \"vespa\", \"documenttype\": \"blogpost\", \"thread\": \"1\" }," + " \"values\": { \"count\": 1, \"rate\": 0.285714, \"average\": 14, \"min\": 14, \"max\": 14, \"last\": 14 }" + " }, {" + " \"name\": \"bar\"," + " \"dimensions\": { \"chain\": \"vespa\", \"documenttype\": \"blogpost\", \"thread\": \"2\" }," + " \"values\": { \"count\": 1, \"rate\": 0.285714, \"average\": 11, \"min\": 11, \"max\": 11, \"last\": 11 }" + " } ]" + "}"; + EXPECT_TRUE(compare_json(expect, actual)); +} + TEST("use simple_metrics_collector") { using namespace vespalib::metrics; SimpleManagerConfig cf; cf.sliding_window_seconds = 5; - auto manager = SimpleMetricsManager::create(cf); + std::shared_ptr ticker = std::make_shared(); + ticker->provide(TimeStamp(1.0)); + auto manager = SimpleMetricsManager::createForTest(cf, std::make_unique(ticker)); + EXPECT_EQUAL(1.0, ticker->waitUntilBlocked().count()); + Counter myCounter = manager->counter("foo"); myCounter.add(); myCounter.add(16); @@ -84,6 +134,25 @@ TEST("use simple_metrics_collector") myGauge.sample(43.0); myGauge.sample(42.0); + EXPECT_EQUAL(1.0, ticker->waitUntilBlocked().count()); + ticker->provide(TimeStamp(2.0)); + EXPECT_EQUAL(2.0, ticker->waitUntilBlocked().count()); + + Snapshot snap1 = manager->snapshot(); + EXPECT_EQUAL(1.0, snap1.startTime()); + EXPECT_EQUAL(2.0, snap1.endTime()); + + EXPECT_EQUAL(1u, snap1.counters().size()); + EXPECT_EQUAL("foo", snap1.counters()[0].name()); + EXPECT_EQUAL(17u, snap1.counters()[0].count()); + + EXPECT_EQUAL(1u, snap1.gauges().size()); + EXPECT_EQUAL("bar", snap1.gauges()[0].name()); + EXPECT_EQUAL(4u, snap1.gauges()[0].observedCount()); + EXPECT_EQUAL(41.0, snap1.gauges()[0].minValue()); + EXPECT_EQUAL(43.0, snap1.gauges()[0].maxValue()); + EXPECT_EQUAL(42.0, snap1.gauges()[0].lastValue()); + Point one = manager->pointBuilder() .bind("chain", "default") .bind("documenttype", "music") @@ -109,44 +178,45 @@ TEST("use simple_metrics_collector") myGauge.sample(14.0, two); myGauge.sample(11.0, three); - for (int i = 0; i < 61; ++i) { - ((SimpleMetricsManager &)*manager).tick(); - } + EXPECT_EQUAL(2.0, ticker->waitUntilBlocked().count()); + ticker->provide(TimeStamp(4.5)); + EXPECT_EQUAL(4.5, ticker->waitUntilBlocked().count()); - Snapshot snap = manager->totalSnapshot(); - fprintf(stdout, "snap begin: %15f\n", snap.startTime()); - fprintf(stdout, "snap end: %15f\n", snap.endTime()); - - // for (const auto& entry : snap.points()) { - // fprintf(stdout, "snap point: %zd dimension(s)\n", entry.dimensions.size()); - // for (const auto& dim : entry.dimensions) { - // fprintf(stdout, " label: [%s] = '%s'\n", - // dim.dimensionName().c_str(), dim.labelValue().c_str()); - // } - // } - for (const auto& entry : snap.counters()) { - fprintf(stdout, "snap counter: '%s'\n", entry.name().c_str()); - for (const auto& dim : entry.point().dimensions) { - fprintf(stdout, " label: [%s] = '%s'\n", - dim.dimensionName().c_str(), dim.labelValue().c_str()); - } - fprintf(stdout, " count: %zd\n", entry.count()); - } - for (const auto& entry : snap.gauges()) { - fprintf(stdout, "snap gauge: '%s'\n", entry.name().c_str()); - for (const auto& dim : entry.point().dimensions) { - fprintf(stdout, " label: [%s] = '%s'\n", - dim.dimensionName().c_str(), dim.labelValue().c_str()); - } - fprintf(stdout, " observed: %zd\n", entry.observedCount()); - fprintf(stdout, " avg: %f\n", entry.averageValue()); - fprintf(stdout, " min: %f\n", entry.minValue()); - fprintf(stdout, " max: %f\n", entry.maxValue()); - fprintf(stdout, " last: %f\n", entry.lastValue()); - } + Snapshot snap2 = manager->snapshot(); + EXPECT_EQUAL(1.0, snap2.startTime()); + EXPECT_EQUAL(4.5, snap2.endTime()); + EXPECT_EQUAL(2u, snap2.counters().size()); + EXPECT_EQUAL(3u, snap2.gauges().size()); - JsonFormatter fmt(snap); - fprintf(stdout, "JSON format:\n>>>\n%s\n<<<\n", fmt.asString().c_str()); + JsonFormatter fmt2(snap2); + check_json(fmt2.asString()); + + // flush sliding window + for (int i = 5; i <= 10; ++i) { + ticker->provide(TimeStamp(i)); + ticker->waitUntilBlocked(); + } + Snapshot snap3 = manager->snapshot(); + EXPECT_EQUAL(5.0, snap3.startTime()); + EXPECT_EQUAL(10.0, snap3.endTime()); + EXPECT_EQUAL(2u, snap3.counters().size()); + EXPECT_EQUAL(0u, snap3.counters()[0].count()); + EXPECT_EQUAL(0u, snap3.counters()[1].count()); + EXPECT_EQUAL(3u, snap3.gauges().size()); + EXPECT_EQUAL(0u, snap3.gauges()[0].observedCount()); + EXPECT_EQUAL(0u, snap3.gauges()[1].observedCount()); + EXPECT_EQUAL(0u, snap3.gauges()[2].observedCount()); + + Snapshot snap4 = manager->totalSnapshot(); + EXPECT_EQUAL(1.0, snap4.startTime()); + EXPECT_EQUAL(10.0, snap4.endTime()); + EXPECT_EQUAL(2u, snap4.counters().size()); + EXPECT_NOT_EQUAL(0u, snap4.counters()[0].count()); + EXPECT_NOT_EQUAL(0u, snap4.counters()[1].count()); + EXPECT_EQUAL(3u, snap4.gauges().size()); + EXPECT_NOT_EQUAL(0u, snap4.gauges()[0].observedCount()); + EXPECT_NOT_EQUAL(0u, snap4.gauges()[1].observedCount()); + EXPECT_NOT_EQUAL(0u, snap4.gauges()[2].observedCount()); } TEST_MAIN() { TEST_RUN_ALL(); } diff --git a/staging_vespalib/src/vespa/vespalib/metrics/CMakeLists.txt b/staging_vespalib/src/vespa/vespalib/metrics/CMakeLists.txt index d641a768d57..6fec0900b06 100644 --- a/staging_vespalib/src/vespa/vespalib/metrics/CMakeLists.txt +++ b/staging_vespalib/src/vespa/vespalib/metrics/CMakeLists.txt @@ -8,7 +8,6 @@ vespa_add_library(staging_vespalib_vespalib_metrics OBJECT current_samples.cpp dimension.cpp dummy_metrics_manager.cpp - dummy_time_supplier.cpp gauge_aggregator.cpp gauge.cpp handle.cpp @@ -18,6 +17,7 @@ vespa_add_library(staging_vespalib_vespalib_metrics OBJECT metric_name.cpp metrics_manager.cpp metric_types.cpp + mock_tick.cpp name_collection.cpp point_builder.cpp point.cpp @@ -26,12 +26,9 @@ vespa_add_library(staging_vespalib_vespalib_metrics OBJECT producer.cpp simple_metrics.cpp simple_metrics_manager.cpp + simple_tick.cpp snapshots.cpp stable_store.cpp - test_time_supplier.cpp - ticker_thread.cpp - time_supplier.cpp - wallclock_time_supplier.cpp DEPENDS ) diff --git a/staging_vespalib/src/vespa/vespalib/metrics/bucket.cpp b/staging_vespalib/src/vespa/vespalib/metrics/bucket.cpp index 9062066fc84..52e95e1ac3f 100644 --- a/staging_vespalib/src/vespa/vespalib/metrics/bucket.cpp +++ b/staging_vespalib/src/vespa/vespalib/metrics/bucket.cpp @@ -67,6 +67,39 @@ mergeVectors(const std::vector &a, return result; } +template +std::vector +findMissing(const std::vector &already, + const std::vector &complete) +{ + std::vector result; + auto a_iter = already.begin(); + auto c_iter = complete.begin(); + while (a_iter != already.end() && + c_iter != complete.end()) + { + if (a_iter->idx < c_iter->idx) { + // missing from "complete", should not happen + ++a_iter; + } else if (c_iter->idx < a_iter->idx) { + // missing this + result.push_back(*c_iter); + ++c_iter; + } else { + // already have this + ++a_iter; + ++c_iter; + } + } + while (c_iter != complete.end()) { + // missing this + result.push_back(*c_iter); + ++c_iter; + } + return result; +} + + } // namespace void Bucket::merge(const CurrentSamples &samples) @@ -89,5 +122,22 @@ void Bucket::merge(const Bucket &other) gauges = std::move(nextGauges); } +void Bucket::padMetrics(const Bucket &source) +{ + std::vector missingC = findMissing(counters, source.counters); + for (CounterAggregator aggr : missingC) { + aggr.count = 0; + counters.push_back(aggr); + } + std::vector missingG = findMissing(gauges, source.gauges); + for (GaugeAggregator aggr : missingG) { + aggr.observedCount = 0; + aggr.sumValue = 0; + aggr.minValue = 0; + aggr.maxValue = 0; + gauges.push_back(aggr); + } +} + } // namespace vespalib::metrics } // namespace vespalib diff --git a/staging_vespalib/src/vespa/vespalib/metrics/bucket.h b/staging_vespalib/src/vespa/vespalib/metrics/bucket.h index a0a35e9240d..5a88e435502 100644 --- a/staging_vespalib/src/vespa/vespalib/metrics/bucket.h +++ b/staging_vespalib/src/vespa/vespalib/metrics/bucket.h @@ -17,15 +17,16 @@ namespace metrics { // internal struct Bucket { size_t genCnt; - InternalTimeStamp startTime; - InternalTimeStamp endTime; + TimeStamp startTime; + TimeStamp endTime; std::vector counters; std::vector gauges; void merge(const CurrentSamples &other); void merge(const Bucket &other); + void padMetrics(const Bucket &source); - Bucket(size_t generation, InternalTimeStamp started, InternalTimeStamp ended) + Bucket(size_t generation, TimeStamp started, TimeStamp ended) : genCnt(generation), startTime(started), endTime(ended), diff --git a/staging_vespalib/src/vespa/vespalib/metrics/clock.cpp b/staging_vespalib/src/vespa/vespalib/metrics/clock.cpp index 9d38d48b281..82144da895d 100644 --- a/staging_vespalib/src/vespa/vespalib/metrics/clock.cpp +++ b/staging_vespalib/src/vespa/vespalib/metrics/clock.cpp @@ -1,14 +1,2 @@ // Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. #include "clock.h" - -namespace vespalib { -namespace metrics { - -std::chrono::microseconds since_epoch(InternalTimeStamp stamp) -{ - using namespace std::chrono; - return duration_cast(stamp.time_since_epoch()); -} - -} // namespace metrics -} // namespace vespalib diff --git a/staging_vespalib/src/vespa/vespalib/metrics/clock.h b/staging_vespalib/src/vespa/vespalib/metrics/clock.h index d29c79bb927..ae67b542fcd 100644 --- a/staging_vespalib/src/vespa/vespalib/metrics/clock.h +++ b/staging_vespalib/src/vespa/vespalib/metrics/clock.h @@ -1,12 +1,36 @@ // Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. #pragma once -#include "wallclock_time_supplier.h" +#include +#include -namespace vespalib { -namespace metrics { +namespace vespalib::metrics { -using InternalTimeStamp = WallclockTimeSupplier::TimeStamp; +using TimeStamp = std::chrono::duration>; -} // namespace metrics -} // namespace vespalib +/** + * Simple interface abstracting both timing and time measurement for + * threads wanting to do stuff at regular intervals and also knowing + * at what time stuff was done. The 'next' function blocks until the + * next tick is due and returns the current number of seconds since + * epoch. The parameter passed to the 'next' function should be its + * previous return value, except the first time it is called, then 0 + * should be used. A convenience function called 'first' is added for + * this purpose. + **/ +struct Tick { + using UP = std::unique_ptr; + virtual TimeStamp next(TimeStamp prev) = 0; + TimeStamp first() { return next(TimeStamp(0.0)); } + virtual void kill() = 0; + virtual ~Tick() {} +}; + +struct TickProxy : Tick { + std::shared_ptr tick; + TickProxy(std::shared_ptr tick_in) : tick(std::move(tick_in)) {} + TimeStamp next(TimeStamp prev) override { return tick->next(prev); } + void kill() override { tick->kill(); } +}; + +} // namespace vespalib::metrics diff --git a/staging_vespalib/src/vespa/vespalib/metrics/counter_aggregator.cpp b/staging_vespalib/src/vespa/vespalib/metrics/counter_aggregator.cpp index 5102ebb121b..a02cc1e7a7e 100644 --- a/staging_vespalib/src/vespa/vespalib/metrics/counter_aggregator.cpp +++ b/staging_vespalib/src/vespa/vespalib/metrics/counter_aggregator.cpp @@ -7,7 +7,7 @@ namespace vespalib { namespace metrics { CounterAggregator::CounterAggregator(const Counter::Increment &increment) - : idx(increment.idx), count(increment.value) + : idx(increment.idx), count(increment.value) {} void diff --git a/staging_vespalib/src/vespa/vespalib/metrics/dimension.h b/staging_vespalib/src/vespa/vespalib/metrics/dimension.h index 680370ba84c..ee16bc6f98a 100644 --- a/staging_vespalib/src/vespa/vespalib/metrics/dimension.h +++ b/staging_vespalib/src/vespa/vespalib/metrics/dimension.h @@ -4,18 +4,15 @@ #include #include "handle.h" -namespace vespalib { -namespace metrics { +namespace vespalib::metrics { using DimensionName = vespalib::string; +struct DimensionTag {}; + /** * Opaque handle representing an uniquely named dimension. **/ -class Dimension : public Handle { -public: - explicit Dimension(size_t id) : Handle(id) {} -}; +using Dimension = Handle; } // namespace vespalib::metrics -} // namespace vespalib diff --git a/staging_vespalib/src/vespa/vespalib/metrics/dummy_time_supplier.cpp b/staging_vespalib/src/vespa/vespalib/metrics/dummy_time_supplier.cpp deleted file mode 100644 index 53032d2b0c3..00000000000 --- a/staging_vespalib/src/vespa/vespalib/metrics/dummy_time_supplier.cpp +++ /dev/null @@ -1,2 +0,0 @@ -// Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. -#include "dummy_time_supplier.h" diff --git a/staging_vespalib/src/vespa/vespalib/metrics/dummy_time_supplier.h b/staging_vespalib/src/vespa/vespalib/metrics/dummy_time_supplier.h deleted file mode 100644 index 9e74f1006ce..00000000000 --- a/staging_vespalib/src/vespa/vespalib/metrics/dummy_time_supplier.h +++ /dev/null @@ -1,14 +0,0 @@ -// Copyright 2017 Yahoo Holdings. Licensed under the terms of the Apache 2.0 license. See LICENSE in the project root. -#pragma once - -namespace vespalib { -namespace metrics { - -struct DummyTimeSupplier { - typedef int TimeStamp; - TimeStamp now_stamp() const { return 0; } - double stamp_to_s(TimeStamp) const { return 0.0; } -}; - -} // namespace vespalib::metrics -} // namespace vespalib diff --git a/staging_vespalib/src/vespa/vespalib/metrics/gauge_aggregator.cpp b/staging_vespalib/src/vespa/vespalib/metrics/gauge_aggregator.cpp index d7bafb54d0f..84ce8aef28d 100644 --- a/staging_vespalib/src/vespa/vespalib/metrics/gauge_aggregator.cpp +++ b/staging_vespalib/src/vespa/vespalib/metrics/gauge_aggregator.cpp @@ -7,12 +7,12 @@ namespace vespalib { namespace metrics { GaugeAggregator::GaugeAggregator(const Gauge::Measurement &sample) - : idx(sample.idx), - observedCount(1), - sumValue(sample.value), - minValue(sample.value), - maxValue(sample.value), - lastValue(sample.value) + : idx(sample.idx), + observedCount(1), + sumValue(sample.value), + minValue(sample.value), + maxValue(sample.value), + lastValue(sample.value) {} void diff --git a/staging_vespalib/src/vespa/vespalib/metrics/handle.h b/staging_vespalib/src/vespa/vespalib/metrics/handle.h index 416b50f0bcd..94a9ee33830 100644 --- a/staging_vespalib/src/vespa/vespalib/metrics/handle.h +++ b/staging_vespalib/src/vespa/vespalib/metrics/handle.h @@ -15,9 +15,8 @@ template class Handle { private: const size_t _id; -protected: - explicit Handle(size_t id) : _id(id) {} public: + explicit Handle(size_t id) : _id(id) {} size_t id() const { return _id; } }; diff --git a/staging_vespalib/src/vespa/vespalib/metrics/label.h b/staging_vespalib/src/vespa/vespalib/metrics/label.h index 81e96728c27..e2356415fd6 100644 --- a/staging_vespalib/src/vespa/vespalib/metrics/label.h +++ b/staging_vespalib/src/vespa/vespalib/metrics/label.h @@ -4,18 +4,15 @@ #include #include "handle.h" -namespace vespalib { -namespace metrics { +namespace vespalib::metrics { using LabelValue = vespalib::string; +struct LabelTag {}; + /** * Opaque handle representing an uniquely named label. **/ -class Label : public Handle