[3804] Addressed review comments.

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

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_)

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

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());
 }
 

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;

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.