[3804] Addressed review comments.

- Renamed getMilliseconds to getLastMilliseconds
- Renamed getMicroseconds to getLastMicroseconds
- Added time units to hooks messages descriptions
- Fixed some typos

diff --git a/src/lib/hooks/callout_manager.cc b/src/lib/hooks/callout_manager.cc
index 2582941bd2809584aea9ceb3ecd42c36c1e6b5d2..0bc95fd73ccdb8ac9d2328c03049e797d52b0eaf 100644 (file)
--- a/src/lib/hooks/callout_manager.cc
+++ b/src/lib/hooks/callout_manager.cc
@@ -170,6 +170,9 @@ CalloutManager::callCallouts(int hook_index, CalloutHandle& callout_handle) {
                         .arg(stopwatch.logFormatLastDuration());
                 }
             } catch (const std::exception& e) {
+                // If an exception occurred, the stopwatch.stop() hasn't been
+                // called, so we have to call it here.
+                stopwatch.stop();
                 // Any exception, not just ones based on isc::Exception
                 LOG_ERROR(hooks_logger, HOOKS_CALLOUT_EXCEPTION)
                     .arg(current_library_)

diff --git a/src/lib/hooks/hooks_messages.mes b/src/lib/hooks/hooks_messages.mes
index 35a396df6883e91eba44333802b4ffa11755b2ed..ea36e660b249fafef07f672617747a0ebfeb65f8 100644 (file)
--- a/src/lib/hooks/hooks_messages.mes
+++ b/src/lib/hooks/hooks_messages.mes
@@ -27,7 +27,7 @@ for the hook. The argument specifies the hook name.
 % HOOKS_CALLOUTS_COMPLETE completed callouts for hook %1 (total callouts duration: %2)
 This debug message is issued when callout manager has completed execution
 of all callouts for the particular hook. The arguments specify the hook
-name and total execution time for all callouts.
+name and total execution time for all callouts in milliseconds.
 
 % HOOKS_CALLOUTS_REMOVED callouts removed from hook %1 for library %2
 This is a debug message issued during library unloading.  It notes that
@@ -40,7 +40,8 @@ higher-level in the hook framework.
 Only output at a high debugging level, this message indicates that
 a callout on the named hook registered by the library with the given
 index (in the list of loaded libraries) has been called and returned a
-success state.  The address of the callout is given in the message
+success state.  The address of the callout is given in the message.
+The message includes the callout execution time in milliseconds.
 
 % HOOKS_CALLOUT_DEREGISTERED hook library at index %1 deregistered a callout on hook %2
 A debug message issued when all instances of a particular callouts on
@@ -52,12 +53,14 @@ If a callout returns an error status when called, this error message
 is issued.  It identifies the hook to which the callout is attached, the
 index of the library (in the list of loaded libraries) that registered
 it and the address of the callout.  The error is otherwise ignored.
+The error message includes the callout execution time in milliseconds.
 
 % HOOKS_CALLOUT_EXCEPTION exception thrown by callout on hook %1 registered by library with index %2 (callout address %3): %4 (callout duration: $5)
 If a callout throws an exception when called, this error message is
 issued.  It identifies the hook to which the callout is attached, the
 index of the library (in the list of loaded libraries) that registered
 it and the address of the callout.  The error is otherwise ignored.
+The error message includes the callout execution time in milliseconds.
 
 % HOOKS_CALLOUT_REGISTRATION hooks library with index %1 registering callout for hook '%2'
 This is a debug message, output when a library (whose index in the list

diff --git a/src/lib/util/stopwatch.cc b/src/lib/util/stopwatch.cc
index 59b3f6c516f82c64a4ddae87f54298e37919502a..54f3bf11c39be12e204bc840e5ef219c4805838a 100644 (file)
--- a/src/lib/util/stopwatch.cc
+++ b/src/lib/util/stopwatch.cc
@@ -58,7 +58,7 @@ Stopwatch::getTotalDuration() const {
 }
 
 long
-Stopwatch::getMilliseconds() const {
+Stopwatch::getLastMilliseconds() const {
     return (getLastDuration().total_milliseconds());
 }
 
@@ -68,7 +68,7 @@ Stopwatch::getTotalMilliseconds() const {
 }
 
 long
-Stopwatch::getMicroseconds() const {
+Stopwatch::getLastMicroseconds() const {
     return (getLastDuration().total_microseconds());
 }
 

diff --git a/src/lib/util/stopwatch.h b/src/lib/util/stopwatch.h
index c683d737c726f272ddff753f56c0617d0b3bb831..2d57a173251fc63a3a706e3722096b1469f9316b 100644 (file)
--- a/src/lib/util/stopwatch.h
+++ b/src/lib/util/stopwatch.h
@@ -61,7 +61,7 @@ public:
     /// Sets the stopwatch to the "started" state. In this state the stopwatch
     /// is measuring the duration since @c Stopwatch::start has been invoked.
     ///
-    //// This method is no-op if the stopwatch is already in the "stopped"
+    //// This method is no-op if the stopwatch is already in the "started"
     /// state.
     void start();
 
@@ -103,13 +103,13 @@ public:
     boost::posix_time::time_duration getTotalDuration() const;
 
     /// @brief Retrieves the last measured duration in milliseconds.
-    long getMilliseconds() const;
+    long getLastMilliseconds() const;
 
     /// @brief Retrieves the total measured duration in milliseconds.
     long getTotalMilliseconds() const;
 
     /// @brief Retrieves the last measured duration in microseconds.
-    long getMicroseconds() const;
+    long getLastMicroseconds() const;
 
     /// @brief Retrieves the total measured duration in microseconds.
     long getTotalMicroseconds() const;

diff --git a/src/lib/util/tests/stopwatch_unittest.cc b/src/lib/util/tests/stopwatch_unittest.cc
index 973b71fe7d6f4642ddb37c1018f22831247977b6..02c14e563735daf33da038115f28375a70d3b10f 100644 (file)
--- a/src/lib/util/tests/stopwatch_unittest.cc
+++ b/src/lib/util/tests/stopwatch_unittest.cc
@@ -224,7 +224,7 @@ TEST_F(StopwatchTest, multipleMeasurements) {
 TEST_F(StopwatchTest, realTime) {
     // Initially, the measured time should be 0.
     Stopwatch stopwatch;
-    EXPECT_EQ(0, stopwatch.getMilliseconds());
+    EXPECT_EQ(0, stopwatch.getLastMilliseconds());
     EXPECT_EQ(0, stopwatch.getTotalMilliseconds());
 
     // Start the stopwatch.
@@ -236,7 +236,7 @@ TEST_F(StopwatchTest, realTime) {
     stopwatch.stop();
 
     // The measured duration should be greater or equal 1 ms.
-    long current_duration = stopwatch.getMilliseconds();
+    long current_duration = stopwatch.getLastMilliseconds();
     EXPECT_GE(current_duration, 1);
     EXPECT_EQ(current_duration, stopwatch.getTotalMilliseconds());
 
@@ -244,7 +244,7 @@ TEST_F(StopwatchTest, realTime) {
     usleep(2000);
 
     // In the stopped state, we should still have old durations measured.
-    EXPECT_EQ(current_duration, stopwatch.getMilliseconds());
+    EXPECT_EQ(current_duration, stopwatch.getLastMilliseconds());
     EXPECT_EQ(current_duration, stopwatch.getTotalMilliseconds());
 
     // Start it again.
@@ -254,13 +254,13 @@ TEST_F(StopwatchTest, realTime) {
     usleep(1000);
 
     // The durations should get updated as appropriate.
-    current_duration = stopwatch.getMilliseconds();
-    EXPECT_GE(stopwatch.getMilliseconds(), 1);
+    current_duration = stopwatch.getLastMilliseconds();
+    EXPECT_GE(stopwatch.getLastMilliseconds(), 1);
     EXPECT_GE(stopwatch.getTotalMilliseconds(), 2);
 }
 
 // Make sure that we can obtain the durations as microseconds.
-TEST_F(StopwatchTest, getMicroseconds) {
+TEST_F(StopwatchTest, getLastMicroseconds) {
     Stopwatch stopwatch;
     stopwatch.start();
 
@@ -268,7 +268,7 @@ TEST_F(StopwatchTest, getMicroseconds) {
 
     stopwatch.stop();
 
-    long current_duration = stopwatch.getMicroseconds();
+    long current_duration = stopwatch.getLastMicroseconds();
     EXPECT_GE(current_duration, 1000);
     EXPECT_EQ(current_duration, stopwatch.getTotalMicroseconds());
 }
@@ -281,8 +281,8 @@ TEST_F(StopwatchTest, autostart) {
 
     stopwatch.stop();
 
-    EXPECT_GE(stopwatch.getMilliseconds(), 1);
-    EXPECT_EQ(stopwatch.getMilliseconds(), stopwatch.getTotalMilliseconds());
+    EXPECT_GE(stopwatch.getLastMilliseconds(), 1);
+    EXPECT_EQ(stopwatch.getLastMilliseconds(), stopwatch.getTotalMilliseconds());
 }
 
 // Make sure that the conversion to the loggable string works as expected.