From: Thomas Markwalder Date: Fri, 14 Jun 2024 18:00:31 +0000 (-0400) Subject: [#3328] Addressed review comments X-Git-Tag: Kea-2.7.0~38 X-Git-Url: http://git.ipfire.org/cgi-bin/gitweb.cgi?a=commitdiff_plain;h=5d86419105fc4678cbf93bfeef8992873b3f2757;p=thirdparty%2Fkea.git [#3328] Addressed review comments Revampe UTs Replaced ave and average with mean throughout --- diff --git a/doc/sphinx/arm/hooks-perfmon.rst b/doc/sphinx/arm/hooks-perfmon.rst index 3e65420cc0..cc58fca00f 100644 --- a/doc/sphinx/arm/hooks-perfmon.rst +++ b/doc/sphinx/arm/hooks-perfmon.rst @@ -170,29 +170,29 @@ statistic employs the following naming convention: {subnet-id[x]}.perfmon.-.-. There is both a global and a subnet-specific value for each. Currently, the only -value reported for a given duration key is ``averages-usecs``; this statistic is the average time +value reported for a given duration key is ``mean-usecs``; this statistic is the mean time between the duration's event pair over the most recently completed interval. In other words, if during a given interval there were seven occurrences (i.e. updates) totaling -3500us, the ``average-usecs`` reported would be 500us. Continuing with the example above, the +3500us, the ``mean-usecs`` reported would be 500us. Continuing with the example above, the statistics reported are named as follows for the subnet-level values: :: - subnet[100].perfmon.DHCPDISCOVER.DHCPOFFER.socket_received-buffer_read.average-usecs - subnet[100].perfmon.DHCPDISCOVER.DHCPOFFER.buffer_read-mt_queue.average-usecs - subnet[100].perfmon.DHCPDISCOVER.DHCPOFFER.mt_queued-process_started.average-usecs - subnet[100].perfmon.DHCPDISCOVER.DHCPOFFER.process_started-process_completed.average-usecs - subnet[100].perfmon.DHCPDISCOVER.DHCPOFFER.composite-total_response.average-usecs + subnet[100].perfmon.DHCPDISCOVER.DHCPOFFER.socket_received-buffer_read.mean-usecs + subnet[100].perfmon.DHCPDISCOVER.DHCPOFFER.buffer_read-mt_queue.mean-usecs + subnet[100].perfmon.DHCPDISCOVER.DHCPOFFER.mt_queued-process_started.mean-usecs + subnet[100].perfmon.DHCPDISCOVER.DHCPOFFER.process_started-process_completed.mean-usecs + subnet[100].perfmon.DHCPDISCOVER.DHCPOFFER.composite-total_response.mean-usecs and as shown for global values: :: - perfmon.DHCPDISCOVER.DHCPOFFER.socket_received-buffer_read.average-usecs - perfmon.DHCPDISCOVER.DHCPOFFER.buffer_read-mt_queue.average-usecs - perfmon.DHCPDISCOVER.DHCPOFFER.mt_queued-process_started.average-usecs - perfmon.DHCPDISCOVER.DHCPOFFER.process_started-process_completed.average-usecs - perfmon.DHCPDISCOVER.DHCPOFFER.composite-total_response.average-usecs + perfmon.DHCPDISCOVER.DHCPOFFER.socket_received-buffer_read.mean-usecs + perfmon.DHCPDISCOVER.DHCPOFFER.buffer_read-mt_queue.mean-usecs + perfmon.DHCPDISCOVER.DHCPOFFER.mt_queued-process_started.mean-usecs + perfmon.DHCPDISCOVER.DHCPOFFER.process_started-process_completed.mean-usecs + perfmon.DHCPDISCOVER.DHCPOFFER.composite-total_response.mean-usecs The results are reported to StatsMgr, an internal Kea component that reports data as statistics that can be retrieved using statistics commands. They can be fetched using the commands @@ -202,25 +202,25 @@ Alarms ~~~~~~ Alarms may be defined to watch specific durations. Each alarm defines a high-water mark, -``high-water-ms``, and a low-water mark, ``low-water-ms``. If the reported average value +``high-water-ms``, and a low-water mark, ``low-water-ms``. If the reported mean value for the duration exceeds the high-water mark a WARN level alarm log is emitted, at which point the alarm is considered "triggered." Once triggered, the WARN level log is repeated at the alarm report interval specified by ``alarm-report-secs``, as long as the reported -average for the duration remains above the low-water mark. Once the average falls below the +mean for the duration remains above the low-water mark. Once the mean falls below the low-water mark the alarm is cleared and an INFO level log is emitted. The alarm-triggered WARN log looks similar to the following: :: - 2024-03-20 10:22:14.030 WARN [kea-dhcp6.leases/47195.139913679886272] PERFMON_ALARM_TRIGGERED Alarm for DHCPDISCOVER.DHCPOFFER.composite-total_response.0 has been triggered since 2024-03-20 10:18:20.070000, reported average duration 00:00:00.700000 exceeds high-water-ms: 500 + 2024-03-20 10:22:14.030 WARN [kea-dhcp6.leases/47195.139913679886272] PERFMON_ALARM_TRIGGERED Alarm for DHCPDISCOVER.DHCPOFFER.composite-total_response.0 has been triggered since 2024-03-20 10:18:20.070000, reported mean duration 00:00:00.700000 exceeds high-water-ms: 500 The alarm-cleared INFO log looks like this: :: - 2024-03-20 10:30:14.030 INFO [kea-dhcp6.leases/47195.139913679886272] PERFMON_ALARM_CLEARED Alarm for DHCPDISCOVER.DHCPOFFER.composite-total_response.0 has been cleared, reported average duration 00:00:00.010000 is now below low-water-ms: 25 + 2024-03-20 10:30:14.030 INFO [kea-dhcp6.leases/47195.139913679886272] PERFMON_ALARM_CLEARED Alarm for DHCPDISCOVER.DHCPOFFER.composite-total_response.0 has been cleared, reported mean duration 00:00:00.010000 is now below low-water-ms: 25 API Commands ~~~~~~~~~~~~ @@ -301,7 +301,7 @@ of durations will be returned as a list of individual elements as shown below: "occurrences": 501, "start-time": "2024-06-12 17:52:06.814884", "total-duration-usecs": 23951, - "ave-duration-usecs": 47 + "mean-duration-usecs": 47 }, ... ], @@ -328,10 +328,11 @@ a format similar to an SQL result set as follows: "end-event", "subnet-id", "interval-start", - "occurences", + "occurrence", "min-duration-usecs", "max-duration-usecs", - "total-duration-usecsave-duration-usecs" + "total-duration-usecs", + "mean-duration-usecs" ], "rows": [ [ "DHCPDISCOVER", diff --git a/src/hooks/dhcp/perfmon/alarm.h b/src/hooks/dhcp/perfmon/alarm.h index 883431d91a..d89f18897e 100644 --- a/src/hooks/dhcp/perfmon/alarm.h +++ b/src/hooks/dhcp/perfmon/alarm.h @@ -34,8 +34,8 @@ public: /// @param start_event_label label of the start event /// @param stop_event_label label of the end event /// @param subnet_id SubnetID of the selected subnet - /// @param low_water threshold below which the average duration must fall to clear the alarm - /// @param high_water threshold above which the average duration must rise to trigger the alarm + /// @param low_water threshold below which the mean duration must fall to clear the alarm + /// @param high_water threshold above which the mean duration must rise to trigger the alarm /// @param enabled true sets state to CLEAR, otherwise DISABLED, defaults to true Alarm(uint16_t family, uint8_t query_type, uint8_t response_type, const std::string& start_event_label, const std::string& stop_event_label, @@ -45,8 +45,8 @@ public: /// @brief Constructor /// /// @param key composite key that identifies the alarm - /// @param low_water threshold below which the average duration must fall to clear the alarm - /// @param high_water threshold above which the average duration must rise to trigger the alarm + /// @param low_water threshold below which the mean duration must fall to clear the alarm + /// @param high_water threshold above which the mean duration must rise to trigger the alarm /// @param enabled true sets state to CLEAR, otherwise DISABLED, defaults to true Alarm(const DurationKey& key, const Duration& low_water, const Duration& high_water, bool enabled = true); @@ -148,10 +148,10 @@ public: bool checkSample(const Duration& sample, const Duration& report_interval); private: - /// @brief Threshold below which the average duration must fall to clear the alarm. + /// @brief Threshold below which the mean duration must fall to clear the alarm. Duration low_water_; - /// @brief Threshold above which the average duration must rise to trigger the alarm. + /// @brief Threshold above which the mean duration must rise to trigger the alarm. Duration high_water_; /// @brief Current alarm state. diff --git a/src/hooks/dhcp/perfmon/alarm_store.h b/src/hooks/dhcp/perfmon/alarm_store.h index dfaacce5f6..22f4462345 100644 --- a/src/hooks/dhcp/perfmon/alarm_store.h +++ b/src/hooks/dhcp/perfmon/alarm_store.h @@ -105,8 +105,8 @@ public: /// @brief Creates a new alarm and adds it to the store /// /// @param key key value of the alarm to create. - /// @param low_water threshold below which the average duration must fall to clear the alarm - /// @param high_water threshold above which the average duration must rise to trigger the alarm. + /// @param low_water threshold below which the mean duration must fall to clear the alarm + /// @param high_water threshold above which the mean duration must rise to trigger the alarm. /// @param enabled true sets state to CLEAR, otherwise DISABLED, defaults to true. /// /// @return pointer to the newly created alarm. diff --git a/src/hooks/dhcp/perfmon/monitored_duration.cc b/src/hooks/dhcp/perfmon/monitored_duration.cc index b9508711c2..a2c8831393 100644 --- a/src/hooks/dhcp/perfmon/monitored_duration.cc +++ b/src/hooks/dhcp/perfmon/monitored_duration.cc @@ -44,7 +44,7 @@ DurationDataInterval::addDuration(const Duration& duration) { } Duration -DurationDataInterval::getAverageDuration() const { +DurationDataInterval::getMeanDuration() const { if (!occurrences_) { return (ZERO_DURATION()); } @@ -333,14 +333,14 @@ MonitoredDuration::toElement() const { element->set("min-duration-usecs", Element::create(previous_interval_->getMinDuration().total_microseconds())); element->set("max-duration-usecs", Element::create(previous_interval_->getMaxDuration().total_microseconds())); element->set("total-duration-usecs", Element::create(previous_interval_->getTotalDuration().total_microseconds())); - element->set("ave-duration-usecs", Element::create(previous_interval_->getAverageDuration().total_microseconds())); + element->set("mean-duration-usecs", Element::create(previous_interval_->getMeanDuration().total_microseconds())); } else { element->set("start-time", Element::create("")); element->set("occurrences", Element::create(0)); element->set("min-duration-usecs", Element::create(0)); element->set("max-duration-usecs", Element::create(0)); element->set("total-duration-usecs", Element::create(0)); - element->set("ave-duration-usecs", Element::create(0)); + element->set("mean-duration-usecs", Element::create(0)); } return (element); @@ -359,7 +359,7 @@ MonitoredDuration::valueRowColumns() { "min-duration-usecs", "max-duration-usecs", "total-duration-usecs" - "ave-duration-usecs" + "mean-duration-usecs" }; static ElementPtr cols; @@ -393,7 +393,7 @@ MonitoredDuration::toValueRow() const { row->add(Element::create(previous_interval_->getMinDuration().total_microseconds())); row->add(Element::create(previous_interval_->getMaxDuration().total_microseconds())); row->add(Element::create(previous_interval_->getTotalDuration().total_microseconds())); - row->add(Element::create(previous_interval_->getAverageDuration().total_microseconds())); + row->add(Element::create(previous_interval_->getMeanDuration().total_microseconds())); } else { row->add(Element::create("")); row->add(Element::create(0)); diff --git a/src/hooks/dhcp/perfmon/monitored_duration.h b/src/hooks/dhcp/perfmon/monitored_duration.h index 258301c86b..6cdb3b0f4f 100644 --- a/src/hooks/dhcp/perfmon/monitored_duration.h +++ b/src/hooks/dhcp/perfmon/monitored_duration.h @@ -8,6 +8,7 @@ #define _MONITORED_DURATION_H #include +#include #include #include @@ -90,10 +91,10 @@ public: return (total_duration_); } - /// @brief Get the average duration for the interval. + /// @brief Get the mean duration for the interval. /// - /// @return Duration containing the average. - Duration getAverageDuration() const; + /// @return Duration containing the mean. + Duration getMeanDuration() const; /// @brief Equality operator. /// @@ -130,7 +131,7 @@ typedef boost::shared_ptr DurationDataIntervalPtr; /// -# Start Event /// -# Stop Event /// -# Subnet ID can be GLOBAL_SUBNET_ID for aggregate durations -class DurationKey { +class DurationKey : public data::CfgToElement { public: /// @brief Constructor /// @@ -227,7 +228,7 @@ public: /// @brief Get the StatsMgr formatted compatible name. /// - /// @param value_name name of the specific value (e.g. "average-usecs", "min-duration-usecs"). + /// @param value_name name of the specific value (e.g. "mean-usecs", "min-duration-usecs"). /// The format of the string: /// /// @code @@ -236,9 +237,9 @@ public: /// /// Examples: /// - /// perfmon.discover-offer.socket_received-buffer_read.average-usecs + /// perfmon.discover-offer.socket_received-buffer_read.mean-usecs /// - /// subnet[9].perfmon.discover-offer.socket_received-buffer_read.average-usecs + /// subnet[9].perfmon.discover-offer.socket_received-buffer_read.mean-usecs /// /// @endcode /// @@ -415,8 +416,8 @@ public: /// "min-duration-usecs": 5300, /// "max-duration-usecs": 9000, /// "total-duration-usecs": 786500, - /// "ave-duration-usecs": 7490 - /// } + /// "mean-duration-usecs": 7490 + /// } /// @endcode /// /// If there is no previous interval, it will appears as follows: @@ -435,8 +436,8 @@ public: /// "min-duration-usecs": 0, /// "max-duration-usecs": 0, /// "total-duration-usecs": 0, - /// "ave-duration-usecs": 0 - /// } + /// "mean-duration-usecs": 0 + /// } /// @endcode /// /// @return Element::map containing the duration key values. @@ -459,7 +460,7 @@ public: /// -# "min-duration-usecs" /// -# "max-duration-usecs" /// -# "total-duration-usecs" - /// -# "ave-duration-usecs" + /// -# "mean-duration-usecs" /// /// @return Element::map containing the duration key values. static data::ConstElementPtr valueRowColumns(); @@ -483,7 +484,7 @@ public: /// -# min-duration-usecs Element::int /// -# max-duration-usecs Element::int /// -# total-duration-usecs Element::int - /// -# ave-duration-usecs Element::int + /// -# mean-duration-usecs Element::int /// /// @return Element::map containing the duration key values. data::ElementPtr toValueRow() const; diff --git a/src/hooks/dhcp/perfmon/perfmon_messages.cc b/src/hooks/dhcp/perfmon/perfmon_messages.cc index 5fee39676e..5875d30afe 100644 --- a/src/hooks/dhcp/perfmon/perfmon_messages.cc +++ b/src/hooks/dhcp/perfmon/perfmon_messages.cc @@ -24,8 +24,8 @@ extern const isc::log::MessageID PERFMON_INIT_OK = "PERFMON_INIT_OK"; namespace { const char* values[] = { - "PERFMON_ALARM_CLEARED", "Alarm for %1 has been cleared, reported average duration %2 is now below low-water-ms: %3", - "PERFMON_ALARM_TRIGGERED", "Alarm for %1 has been triggered since %2, reported average duration %3 exceeds high-water-ms: %4", + "PERFMON_ALARM_CLEARED", "Alarm for %1 has been cleared, reported mean duration %2 is now below low-water-ms: %3", + "PERFMON_ALARM_TRIGGERED", "Alarm for %1 has been triggered since %2, reported mean duration %3 exceeds high-water-ms: %4", "PERFMON_CMDS_CONTROL_ERROR", "perfmon-control command processing failed: %1", "PERFMON_CMDS_CONTROL_OK", "perfmon-control command success: active monitoring: %1, stats-mgr-reporting: %2", "PERFMON_CMDS_GET_ALL_DURATIONS_ERROR", "perfmon-get-all-durations command processing failed: %1", diff --git a/src/hooks/dhcp/perfmon/perfmon_messages.mes b/src/hooks/dhcp/perfmon/perfmon_messages.mes index f747033b11..67f3610b86 100644 --- a/src/hooks/dhcp/perfmon/perfmon_messages.mes +++ b/src/hooks/dhcp/perfmon/perfmon_messages.mes @@ -1,18 +1,18 @@ # Copyright (C) 2024 Internet Systems Consortium, Inc. ("ISC") -% PERFMON_ALARM_CLEARED Alarm for %1 has been cleared, reported average duration %2 is now below low-water-ms: %3 -This info message is emitted when the reported average duration for +% PERFMON_ALARM_CLEARED Alarm for %1 has been cleared, reported mean duration %2 is now below low-water-ms: %3 +This info message is emitted when the reported mean duration for an alarm that has been triggered has fallen below the value of its low-water-ms parameter. The arguments detail the alarm's key and -the most recently reported average. +the most recently reported mean. -% PERFMON_ALARM_TRIGGERED Alarm for %1 has been triggered since %2, reported average duration %3 exceeds high-water-ms: %4 -This warning message is emitted when the reported average duration for +% PERFMON_ALARM_TRIGGERED Alarm for %1 has been triggered since %2, reported mean duration %3 exceeds high-water-ms: %4 +This warning message is emitted when the reported mean duration for an alarm exceeds its high-water-ms value. As long as the reported averges remain above the low-water-ms value, the alarm will remain triggered and this message will be repeated every alarm-report-secs. Arguments detail the alarm's key, the time the alarm was first -triggered, the most recent reported average, and the high-water-ms +triggered, the most recent reported mean, and the high-water-ms value. % PERFMON_DEINIT_FAILED unloading PerfMon hooks library failed: %1 diff --git a/src/hooks/dhcp/perfmon/perfmon_mgr.cc b/src/hooks/dhcp/perfmon/perfmon_mgr.cc index 1ff537d145..cc3c0238db 100644 --- a/src/hooks/dhcp/perfmon/perfmon_mgr.cc +++ b/src/hooks/dhcp/perfmon/perfmon_mgr.cc @@ -150,15 +150,15 @@ PerfMonMgr::addDurationSample(DurationKeyPtr key, const Duration& sample) { // Update duration - duration is only returned if its time to report. MonitoredDurationPtr duration = duration_store_->addDurationSample(key, sample); if (duration) { - // Report to stat mgr, returns average duration. - Duration average = reportToStatsMgr(duration); + // Report to stat mgr, returns mean duration. + Duration mean = reportToStatsMgr(duration); - // Check the average against an alarm, if one exists. - AlarmPtr alarm = alarm_store_->checkDurationSample(duration, average, alarm_report_interval_); + // Check the mean against an alarm, if one exists. + AlarmPtr alarm = alarm_store_->checkDurationSample(duration, mean, alarm_report_interval_); // If an alarm had a reportable outcome, report it. if (alarm) { - reportAlarm(alarm, average); + reportAlarm(alarm, mean); } } } @@ -174,25 +174,25 @@ PerfMonMgr::reportToStatsMgr(MonitoredDurationPtr duration) { isc_throw(BadValue, "reportToStatsMgr - duration previous interval is empty!"); } - auto average = previous_interval->getAverageDuration(); + auto mean = previous_interval->getMeanDuration(); if (getStatsMgrReporting()) { - StatsMgr::instance().setValue(duration->getStatName("average-usecs"), - static_cast(average.total_microseconds())); + StatsMgr::instance().setValue(duration->getStatName("mean-usecs"), + static_cast(mean.total_microseconds())); } /// @todo - decide if we want to report min and max values too. - return (average); + return (mean); } void -PerfMonMgr::reportAlarm(AlarmPtr alarm, const Duration& average) { +PerfMonMgr::reportAlarm(AlarmPtr alarm, const Duration& mean) { std::string label = alarm->getLabel(); switch(alarm->getState()) { case Alarm::CLEAR: LOG_INFO(perfmon_logger, PERFMON_ALARM_CLEARED) .arg(alarm->getLabel()) - .arg(average) + .arg(mean) .arg(alarm->getLowWater().total_milliseconds()); break; @@ -200,7 +200,7 @@ PerfMonMgr::reportAlarm(AlarmPtr alarm, const Duration& average) { LOG_WARN(perfmon_logger, PERFMON_ALARM_TRIGGERED) .arg(alarm->getLabel()) .arg(ptimeToText(alarm->getStosTime(), 3)) - .arg(average) + .arg(mean) .arg(alarm->getHighWater().total_milliseconds()); alarm->setLastHighWaterReport(); alarm_store_->updateAlarm(alarm); @@ -240,6 +240,8 @@ PerfMonMgr::perfmonControlHandler(hooks::CalloutHandle& handle) { txt = cmd_args_->str(); } + + // Both arguments are optional. if (cmd_args_) { SimpleParser::checkKeywords(keywords, cmd_args_); @@ -258,6 +260,7 @@ PerfMonMgr::perfmonControlHandler(hooks::CalloutHandle& handle) { .arg(enable_monitoring_ ? "enabled" : "disabled") .arg(stats_mgr_reporting_ ? "enabled" : "disabled"); + // Always return the new/current values for both settings. result->set("enable-monitoring", Element::create(enable_monitoring_)); result->set("stats-mgr-reporting", Element::create(stats_mgr_reporting_)); response = createAnswer(CONTROL_RESULT_SUCCESS, "perfmon-control success", result); @@ -314,7 +317,8 @@ PerfMonMgr::perfmonGetAllDurationsHandler(hooks::CalloutHandle& handle) { std::ostringstream oss; oss << "perfmon-get-all-durations: " << rows << " found"; - response = createAnswer(CONTROL_RESULT_SUCCESS, oss.str(), result); + response = createAnswer((rows > 0 ? CONTROL_RESULT_SUCCESS : CONTROL_RESULT_EMPTY), + oss.str(), result); LOG_INFO(perfmon_logger, PERFMON_CMDS_GET_ALL_DURATIONS_OK) .arg(rows); } catch (const std::exception& ex) { diff --git a/src/hooks/dhcp/perfmon/perfmon_mgr.h b/src/hooks/dhcp/perfmon/perfmon_mgr.h index eb4e2768ce..e9b59ad14e 100644 --- a/src/hooks/dhcp/perfmon/perfmon_mgr.h +++ b/src/hooks/dhcp/perfmon/perfmon_mgr.h @@ -25,7 +25,7 @@ namespace perfmon { /// @brief Singleton which provides overall configuration, control, and state of /// the PerfMon hook library. It owns the MonitoredDurationStore and AlarmStore /// instances and supplies callout and command API handlers. It derives from -/// PerfMonConfig. +/// PerfMonConfiga and CmdsImpl. class PerfMonMgr : public PerfMonConfig, private config::CmdsImpl { public: /// @brief Constructor. @@ -71,7 +71,7 @@ public: /// The MonitoredDuration identified by the given key is fetched from /// the store and updated with the sample. If the update returns the /// duration this means it is time to report the duration via StatsMgr. - /// The reported average is then checked against an alarm, if one exists. + /// The reported mean is then checked against an alarm, if one exists. /// If the check returns the alarm, then the alarm has undergone a /// reportable event and is passed to reporting. /// @@ -82,12 +82,12 @@ public: /// @brief Emits an entry to StatsMgr for a given duration. /// - /// Calculates the average duration for the reportable interval and + /// Calculates the mean duration for the reportable interval and /// reports the value to StatsMgr if stat-mgr-reporting is true. /// /// @param duration duration to report. /// - /// @return Always returns the average duration for reportable interval. + /// @return Always returns the mean duration for reportable interval. Duration reportToStatsMgr(MonitoredDurationPtr duration); /// @brief Emits a report for a given alarm. @@ -97,8 +97,8 @@ public: /// accommodate additional reporting mechanisms. /// /// @param alarm Alarm to report. - /// @param average Duration average which caused the state transition. - void reportAlarm(AlarmPtr alarm, const Duration& average); + /// @param mean Duration mean which caused the state transition. + void reportAlarm(AlarmPtr alarm, const Duration& mean); /// @brief Handler invoked when the report timer expires. /// @@ -132,14 +132,14 @@ public: /// /// It extracts the command name and arguments from the given CalloutHandle, /// attempts to process them, and then set's the handle's "response" - /// arguments accordingly. Regardless of which parameters were specified - /// in the command arguments (if any), it returns the values for both - /// parameters: + /// arguments accordingly. Regardless of which arguments, if any, were + /// specified the command will always return the new/current values + /// for both settings. /// /// @code /// "arguments": { - /// "enable-monitoring": false, - /// "stats-mgr-reporting": false + /// "enable-monitoring": true, + /// "stats-mgr-reporting": true /// }, /// "result": 0, /// "text": "perfmon-control success" @@ -153,12 +153,12 @@ public: /// @brief perfmon-get-all-durations handler /// - /// This command fetches all of the monitored durations and their preivous + /// This command fetches all of the monitored durations and their previous /// intervals (if one). /// /// @code /// { - /// "command": "perfmon-get-all-duations", + /// "command": "perfmon-get-all-durations", /// "arguments": { /// "result-set-format": true /// } @@ -212,7 +212,7 @@ public: /// "durations-result-set": { /// "columns": [ /// "subnet-id", "query-type", "response-type", "start-event", "end-event", - /// "interval start", "occurences", "min-duration-usecs", "max-duration-usecs", + /// "interval start", "occurrences", "min-duration-usecs", "max-duration-usecs", /// "total-duration-usecs" /// ], /// "rows": [ @@ -245,7 +245,7 @@ public: /// "durations-result-set": { /// "columns": [ /// "subnet-id", "query-type", "response-type", "start-event", "end-event", - /// "interval start", "occurences", "min-duration-usecs", "max-duration-usecs", + /// "interval start", "occurrences", "min-duration-usecs", "max-duration-usecs", /// "total-duration-usecs" /// ], /// "rows": [ diff --git a/src/hooks/dhcp/perfmon/tests/monitored_duration_unittests.cc b/src/hooks/dhcp/perfmon/tests/monitored_duration_unittests.cc index b64d857c80..90311aa6ea 100644 --- a/src/hooks/dhcp/perfmon/tests/monitored_duration_unittests.cc +++ b/src/hooks/dhcp/perfmon/tests/monitored_duration_unittests.cc @@ -10,6 +10,7 @@ #include #include #include +#include #include #include @@ -20,6 +21,7 @@ using namespace isc::data; using namespace isc::dhcp; using namespace isc::perfmon; using namespace isc::util; +using namespace isc::test; using namespace boost::posix_time; namespace { @@ -41,7 +43,7 @@ TEST(DurationDataInterval, basics) { EXPECT_EQ(interval->getMinDuration(), pos_infin); EXPECT_EQ(interval->getMaxDuration(), neg_infin); EXPECT_EQ(interval->getTotalDuration(), DurationDataInterval::ZERO_DURATION()); - EXPECT_EQ(interval->getAverageDuration(), DurationDataInterval::ZERO_DURATION()); + EXPECT_EQ(interval->getMeanDuration(), DurationDataInterval::ZERO_DURATION()); // Verify that start time can be specified. interval.reset(new DurationDataInterval(start_time + milliseconds(5000))); @@ -55,7 +57,7 @@ TEST(DurationDataInterval, basics) { EXPECT_EQ(interval->getMinDuration(), d100); EXPECT_EQ(interval->getMaxDuration(), d100); EXPECT_EQ(interval->getTotalDuration(), d100); - EXPECT_EQ(interval->getAverageDuration(), d100); + EXPECT_EQ(interval->getMeanDuration(), d100); // Add 300ms duration and check contents. Duration d300(milliseconds(300)); @@ -64,7 +66,7 @@ TEST(DurationDataInterval, basics) { EXPECT_EQ(interval->getMinDuration(), d100); EXPECT_EQ(interval->getMaxDuration(), d300); EXPECT_EQ(interval->getTotalDuration(), d100 + d300); - EXPECT_EQ(interval->getAverageDuration(), Duration(milliseconds(200))); + EXPECT_EQ(interval->getMeanDuration(), Duration(milliseconds(200))); // Add 50ms duration and check contents. Duration d50(milliseconds(50)); @@ -73,7 +75,7 @@ TEST(DurationDataInterval, basics) { EXPECT_EQ(interval->getMinDuration(), d50); EXPECT_EQ(interval->getMaxDuration(), d300); EXPECT_EQ(interval->getTotalDuration(), d100 + d300 + d50); - EXPECT_EQ(interval->getAverageDuration(), Duration(milliseconds(150))); + EXPECT_EQ(interval->getMeanDuration(), Duration(milliseconds(150))); // Add a zero duration and check contents. interval->addDuration(DurationDataInterval::ZERO_DURATION()); @@ -81,7 +83,7 @@ TEST(DurationDataInterval, basics) { EXPECT_EQ(interval->getMinDuration(), DurationDataInterval::ZERO_DURATION()); EXPECT_EQ(interval->getMaxDuration(), d300); EXPECT_EQ(interval->getTotalDuration(), d100 + d300 + d50); - EXPECT_EQ(interval->getAverageDuration(), Duration(microseconds(112500))); + EXPECT_EQ(interval->getMeanDuration(), Duration(microseconds(112500))); } // Exercises the basic functions of DurationDataInterval. @@ -101,8 +103,8 @@ TEST(DurationKey, basics) { EXPECT_EQ(key->getSubnetId(), SUBNET_ID_GLOBAL); EXPECT_EQ("DHCPDISCOVER-DHCPOFFER.process_started-process_completed.0", key->getLabel()); - EXPECT_EQ("perfmon.DHCPDISCOVER-DHCPOFFER.process_started-process_completed.average-ms", - key->getStatName("average-ms")); + EXPECT_EQ("perfmon.DHCPDISCOVER-DHCPOFFER.process_started-process_completed.mean-usecs", + key->getStatName("mean-usecs")); // Create valid v6 key, verify contents and label. ASSERT_NO_THROW_LOG(key.reset(new DurationKey(AF_INET6, DHCPV6_SOLICIT, DHCPV6_ADVERTISE, @@ -116,8 +118,8 @@ TEST(DurationKey, basics) { EXPECT_EQ(key->getSubnetId(), 77); EXPECT_EQ("SOLICIT-ADVERTISE.mt_queued-process_started.77", key->getLabel()); - EXPECT_EQ("subnet-id[77].perfmon.SOLICIT-ADVERTISE.mt_queued-process_started.average-ms", - key->getStatName("average-ms")); + EXPECT_EQ("subnet-id[77].perfmon.SOLICIT-ADVERTISE.mt_queued-process_started.mean-usecs", + key->getStatName("mean-usecs")); // Make sure constructor catches an insane message pairing. ASSERT_THROW_MSG(key.reset(new DurationKey(AF_INET6, DHCPV6_ADVERTISE, DHCPV6_SOLICIT, @@ -269,30 +271,32 @@ TEST(DurationKey, toElement) { SUBNET_ID_GLOBAL))); ASSERT_TRUE(key); - ElementPtr ref_key_elem = Element::createMap(); - ref_key_elem->set("query-type", Element::create("DHCPDISCOVER")); - ref_key_elem->set("response-type", Element::create("DHCPOFFER")); - ref_key_elem->set("start-event", Element::create("process_started")); - ref_key_elem->set("stop-event", Element::create("process_completed")); - ref_key_elem->set("subnet-id", Element::create(SUBNET_ID_GLOBAL)); + std::string expected_json = + R"({ + "query-type": "DHCPDISCOVER", + "response-type": "DHCPOFFER", + "start-event": "process_started", + "stop-event": "process_completed", + "subnet-id": 0 + })"; - auto key_elem = key->toElement(); - EXPECT_EQ(*ref_key_elem, *key_elem); + runToElementTest(expected_json, *key); // Create valid v6 key, verify contents and label. ASSERT_NO_THROW_LOG(key.reset(new DurationKey(AF_INET6, DHCPV6_SOLICIT, DHCPV6_ADVERTISE, "mt_queued", "process_started", 77))); ASSERT_TRUE(key); - ref_key_elem = Element::createMap(); - ref_key_elem->set("query-type", Element::create("SOLICIT")); - ref_key_elem->set("response-type", Element::create("ADVERTISE")); - ref_key_elem->set("start-event", Element::create("mt_queued")); - ref_key_elem->set("stop-event", Element::create("process_started")); - ref_key_elem->set("subnet-id", Element::create(77)); + expected_json = + R"({ + "query-type": "SOLICIT", + "response-type": "ADVERTISE", + "start-event": "mt_queued", + "stop-event": "process_started", + "subnet-id": 77 + })"; - key_elem = key->toElement(); - EXPECT_EQ(*ref_key_elem, *key_elem); + runToElementTest(expected_json, *key); } // Verifies MonitoredDuration valid construction. @@ -592,36 +596,56 @@ TEST(MonitoredDuration, toElement) { ref_duration_elem->set("duration-key", ref_key_elem); // Add the data. Should have empty values as we do not have a previous interval. - ref_duration_elem->set("ave-duration-usecs", Element::create(0)); + ref_duration_elem->set("mean-duration-usecs", Element::create(0)); ref_duration_elem->set("max-duration-usecs", Element::create(0)); ref_duration_elem->set("min-duration-usecs", Element::create(0)); ref_duration_elem->set("occurrences", Element::create(0)); ref_duration_elem->set("start-time", Element::create("")); ref_duration_elem->set("total-duration-usecs", Element::create(0)); - // Generate the valueRow Element and compare it to the reference. - auto duration_elem = duration->toElement(); - ASSERT_TRUE(duration_elem); - EXPECT_EQ(*ref_duration_elem, *duration_elem); + std::string expected_json = + R"({ + "mean-duration-usecs": 0, + "duration-key": { + "query-type": "DHCPDISCOVER", + "response-type": "DHCPOFFER", + "start-event": "process_started", + "stop-event": "process_completed", + "subnet-id": 0 }, + "max-duration-usecs": 0, + "min-duration-usecs": 0, + "occurrences": 0, + "start-time": "", + "total-duration-usecs": 0 + })"; + + // Check toElement() against expected JSON. + runToElementTest(expected_json, *duration); // Now expire the current interval so we'll have a previous interval. duration->expireCurrentInterval(); auto previous_interval = duration->getPreviousInterval(); ASSERT_TRUE(previous_interval); - // Replace the data values with those from the new previous interval. - ref_duration_elem->set("ave-duration-usecs", Element::create(4)); - ref_duration_elem->set("max-duration-usecs", Element::create(7)); - ref_duration_elem->set("min-duration-usecs", Element::create(2)); - ref_duration_elem->set("occurrences", Element::create(3)); - ref_duration_elem->set("start-time", - Element::create(ptimeToText(previous_interval->getStartTime()))); - ref_duration_elem->set("total-duration-usecs", Element::create(14)); - - // Generate the valueRow Element and compare it to the reference. - duration_elem = duration->toElement(); - ASSERT_TRUE(duration_elem); - EXPECT_EQ(*ref_duration_elem, *duration_elem); + std::ostringstream oss; + oss << + R"({ + "mean-duration-usecs": 4, + "duration-key": { + "query-type": "DHCPDISCOVER", + "response-type": "DHCPOFFER", + "start-event": "process_started", + "stop-event": "process_completed", + "subnet-id": 0 }, + "max-duration-usecs": 7, + "min-duration-usecs": 2, + "occurrences": 3, + "start-time": ")" + << ptimeToText(previous_interval->getStartTime()) + << R"(", "total-duration-usecs": 14 })"; + + // Check toElement() against expected JSON. + runToElementTest(oss.str(), *duration); } // Verifies the MonitoredDuration::toElement(). We do not bother with @@ -630,7 +654,6 @@ TEST(MonitoredDuration, toElement) { TEST(MonitoredDuration, toValueRow) { MonitoredDurationPtr duration; Duration interval_duration(milliseconds(50)); - auto ten_ms = milliseconds(10); // Create valid v4 duration. ASSERT_NO_THROW_LOG(duration.reset(new MonitoredDuration(AF_INET6, DHCPV6_SOLICIT, DHCPV6_ADVERTISE, @@ -658,12 +681,13 @@ TEST(MonitoredDuration, toValueRow) { ref_row_elem->add(Element::create(0)); // min-duration-usecs ref_row_elem->add(Element::create(0)); // max-duration-usecs ref_row_elem->add(Element::create(0)); // total-duration-usecs - ref_row_elem->add(Element::create(0)); // ave-duration-usecs + ref_row_elem->add(Element::create(0)); // mean-duration-usecs // Generate the valueRow Element and compare it to the reference. auto row_elem = duration->toValueRow(); + ASSERT_TRUE(row_elem); - EXPECT_EQ(*ref_row_elem, *row_elem); + EXPECT_EQ(prettyPrint(ref_row_elem), prettyPrint(row_elem)); // Now expire the current interval so we'll have a previous interval. duration->expireCurrentInterval(); @@ -681,12 +705,12 @@ TEST(MonitoredDuration, toValueRow) { ref_row_elem->add(Element::create(2)); // min-duration-usecs ref_row_elem->add(Element::create(7)); // max-duration-usecs ref_row_elem->add(Element::create(14)); // total-duration-usecs - ref_row_elem->add(Element::create(4)); // ave-duration-usecs + ref_row_elem->add(Element::create(4)); // mean-duration-usecs // Generate the valueRow Element and compare it to the reference. row_elem = duration->toValueRow(); ASSERT_TRUE(row_elem); - EXPECT_EQ(*ref_row_elem, *row_elem); + EXPECT_EQ(prettyPrint(ref_row_elem), prettyPrint(row_elem)); } } // end of anonymous namespace diff --git a/src/hooks/dhcp/perfmon/tests/perfmon_cmds_unittests.cc b/src/hooks/dhcp/perfmon/tests/perfmon_cmds_unittests.cc index ee0c538a74..61a0fc52c0 100644 --- a/src/hooks/dhcp/perfmon/tests/perfmon_cmds_unittests.cc +++ b/src/hooks/dhcp/perfmon/tests/perfmon_cmds_unittests.cc @@ -47,8 +47,8 @@ public: StatsMgr::instance().removeAll(); StatsMgr::instance().setMaxSampleCountAll(1); if (family_ == AF_INET) { - subnet22_.reset(new Subnet4(IOAddress("192.0.22.0"), 8, 100, 200, 300, 22)); - subnet33_.reset(new Subnet4(IOAddress("192.0.33.0"), 8, 100, 200, 300, 33)); + subnet22_.reset(new Subnet4(IOAddress("192.0.22.0"), 24, 100, 200, 300, 22)); + subnet33_.reset(new Subnet4(IOAddress("192.0.33.0"), 24, 100, 200, 300, 33)); } else { subnet22_.reset(new Subnet6(IOAddress("3001:22::"), 64, 100, 200, 300, 300, 22)); subnet33_.reset(new Subnet6(IOAddress("3002:33::"), 64, 100, 200, 300, 300, 33)); @@ -56,25 +56,25 @@ public: } void SetUp() { - std::string valid_config = - R"({ - "enable-monitoring": false, - "interval-width-secs": 5000, - "stats-mgr-reporting": false, - "alarm-report-secs": 600000, - "alarms": [{ - "duration-key": { - "query-type": "", - "response-type": "", - "start-event": "process-started", - "stop-event": "process-completed", - "subnet-id": 70 - }, - "enable-alarm": true, - "high-water-ms": 500, - "low-water-ms": 25 - }] - })"; + std::string valid_config = R"( + { + "enable-monitoring": false, + "interval-width-secs": 5000, + "stats-mgr-reporting": false, + "alarm-report-secs": 600000, + "alarms": [{ + "duration-key": { + "query-type": "", + "response-type": "", + "start-event": "process-started", + "stop-event": "process-completed", + "subnet-id": 70 + }, + "enable-alarm": true, + "high-water-ms": 500, + "low-water-ms": 25 + }] + })"; ASSERT_NO_THROW_LOG(createMgr(valid_config)); } @@ -429,7 +429,7 @@ public: } } - /// @brief Veriies that a valid perfmon-get-all-durations command with + /// @brief Verifies that a valid perfmon-get-all-durations command with /// result-set-format set false, returns all durations correctly. void testPerfMonGetAllDurationsResultSetFalse() { std::string now_str = ptimeToText(PktEvent::now()); @@ -452,7 +452,7 @@ public: checkAnswerAgainstDurations(ref_durations, answer, ref_time, false); } - /// @brief Veriies that a valid perfmon-get-all-durations with result-set-format + /// @brief Verifies that a valid perfmon-get-all-durations with result-set-format /// set true, returns all durations correctly. void testPerfMonGetAllDurationsResultSetTrue() { std::string now_str = ptimeToText(PktEvent::now()); @@ -481,8 +481,8 @@ public: /// /// @param ref_durations list of expected MonitoredDurations in the order they /// should appear in the results. - /// @param anwswer complete command answer to check - /// @param ref_time timestamp used to compare againt the "timestamp" in the answer. + /// @param answer complete command answer to check + /// @param ref_time timestamp used to compare against the "timestamp" in the answer. /// @param result_set_format expected format style of the answer void checkAnswerAgainstDurations(const MonitoredDurationCollectionPtr ref_durations, ConstElementPtr answer, diff --git a/src/hooks/dhcp/perfmon/tests/perfmon_mgr_unittests.cc b/src/hooks/dhcp/perfmon/tests/perfmon_mgr_unittests.cc index cd1ad3477a..1d24cf2218 100644 --- a/src/hooks/dhcp/perfmon/tests/perfmon_mgr_unittests.cc +++ b/src/hooks/dhcp/perfmon/tests/perfmon_mgr_unittests.cc @@ -328,20 +328,20 @@ public: mond->addSample(milliseconds(250)); mond->expireCurrentInterval(); - Duration average; - ASSERT_NO_THROW_LOG(average = mgr_->reportToStatsMgr(mond)); - EXPECT_EQ(milliseconds(175), average); + Duration mean; + ASSERT_NO_THROW_LOG(mean = mgr_->reportToStatsMgr(mond)); + EXPECT_EQ(milliseconds(175), mean); - auto obs = StatsMgr::instance().getObservation(mond->getStatName("average-usecs")); + auto obs = StatsMgr::instance().getObservation(mond->getStatName("mean-usecs")); ASSERT_TRUE(obs); EXPECT_EQ(175000, obs->getInteger().first); StatsMgr::instance().removeAll(); mgr_->setStatsMgrReporting(false); - ASSERT_NO_THROW_LOG(average = mgr_->reportToStatsMgr(mond)); - EXPECT_EQ(milliseconds(175), average); - obs = StatsMgr::instance().getObservation(mond->getStatName("average-usecs")); + ASSERT_NO_THROW_LOG(mean = mgr_->reportToStatsMgr(mond)); + EXPECT_EQ(milliseconds(175), mean); + obs = StatsMgr::instance().getObservation(mond->getStatName("mean-usecs")); ASSERT_FALSE(obs); } @@ -409,15 +409,15 @@ public: // Duration should have a current total of 95 ms, and a previous total of 160. checkDuration(__LINE__, key, 95, true, 160); - // Should have one stat reported with a average value of 80. + // Should have one stat reported with a mean value of 80. EXPECT_EQ(1, StatsMgr::instance().count()); - auto obs = StatsMgr::instance().getObservation(key->getStatName("average-usecs")); + auto obs = StatsMgr::instance().getObservation(key->getStatName("mean-usecs")); ASSERT_TRUE(obs); EXPECT_EQ(80000, obs->getInteger().first); // The alarm should have triggered and reported. beforeAndAfterAlarm(__LINE__, before_alarm, Alarm::TRIGGERED, true); - addString("reported average duration 00:00:00.080000 exceeds high-water-ms: 50"); + addString("reported mean duration 00:00:00.080000 exceeds high-water-ms: 50"); // Sleep 100ms second to make sure the current interval duration elapses. usleep(100 * 1000); @@ -446,11 +446,11 @@ public: // above high water. The alarm should report again because the reporting // interval has elapsed. beforeAndAfterAlarm(__LINE__, before_alarm, Alarm::TRIGGERED, true); - addString("reported average duration 00:00:00.100000 exceeds high-water-ms: 50"); + addString("reported mean duration 00:00:00.100000 exceeds high-water-ms: 50"); // Should have one stat reported with a value of 100. EXPECT_EQ(1, StatsMgr::instance().count()); - obs = StatsMgr::instance().getObservation(key->getStatName("average-usecs")); + obs = StatsMgr::instance().getObservation(key->getStatName("mean-usecs")); ASSERT_TRUE(obs); EXPECT_EQ(100000, obs->getInteger().first); @@ -466,11 +466,11 @@ public: // The Alarm should now be CLEAR since the newly completed interval is // below high water. The alarm should low-water report. beforeAndAfterAlarm(__LINE__, before_alarm, Alarm::CLEAR, false); - addString("reported average duration 00:00:00.010000 is now below low-water-ms: 25"); + addString("reported mean duration 00:00:00.010000 is now below low-water-ms: 25"); // Should have one stat reported with a value of 10. EXPECT_EQ(1, StatsMgr::instance().count()); - obs = StatsMgr::instance().getObservation(key->getStatName("average-usecs")); + obs = StatsMgr::instance().getObservation(key->getStatName("mean-usecs")); ASSERT_TRUE(obs); EXPECT_EQ(10000, obs->getInteger().first); diff --git a/src/share/api/perfmon-get-all-durations.json b/src/share/api/perfmon-get-all-durations.json index 7dd8c9ab93..ee99f8ddb4 100644 --- a/src/share/api/perfmon-get-all-durations.json +++ b/src/share/api/perfmon-get-all-durations.json @@ -25,7 +25,6 @@ "{", " \"arguments\": {", " \"durations\": [{", - " \"ave-duration-usecs\": 47,", " \"duration-key\": {", " \"query-type\": \"DHCPDISCOVER\",", " \"response-type\": \"DHCPOFFER\",", @@ -34,6 +33,7 @@ " \"subnet-id\": 0", " },", " \"max-duration-usecs\": 118,", + " \"mean-duration-usecs\": 47,", " \"min-duration-usecs\": 31,", " \"occurrences\": 501,", " \"start-time\": \"2024-06-12 17:52:06.814884\",", @@ -62,7 +62,8 @@ " \"occurences\",", " \"min-duration-usecs\",", " \"max-duration-usecs\",", - " \"total-duration-usecsave-duration-usecs\"", + " \"total-duration-usecs\"", + " \"mean-duration-usecs\"", " ],", " \"rows\": [", " [",