[3804] Measure total execution time for all callouts for the hook.

src/lib/hooks/callout_manager.cc

@@ -135,8 +135,14 @@ CalloutManager::callCallouts(int hook_index, CalloutHandle& callout_handle) {
         // change and potentially affect the iteration through that vector.
         CalloutVector callouts(hook_vector_[hook_index]);
 
+        // This object will be used to measure execution time of each callout
+        // and the total time spent in callouts for this hook point.
         util::Stopwatch stopwatch;
 
+        // Mark that the callouts begin for the hook.
+        LOG_DEBUG(hooks_logger, HOOKS_DBG_CALLS, HOOKS_CALLOUTS_BEGIN)
+            .arg(server_hooks_.getName(current_hook_));
+
         // Call all the callouts.
         for (CalloutVector::const_iterator i = callouts.begin();
              i != callouts.end(); ++i) {
@@ -175,6 +181,12 @@ CalloutManager::callCallouts(int hook_index, CalloutHandle& callout_handle) {
 
         }
 
+        // Mark end of callout execution. Include the total execution
+        // time for callouts.
+        LOG_DEBUG(hooks_logger, HOOKS_DBG_CALLS, HOOKS_CALLOUTS_COMPLETE)
+            .arg(server_hooks_.getName(current_hook_))
+            .arg(stopwatch.logFormatTotalDuration());
+
         // Reset the current hook and library indexs to an invalid value to
         // catch any programming errors.
         current_hook_ = -1;

src/lib/hooks/hooks_messages.mes

@@ -20,6 +20,15 @@ by the library with the given index were removed.  This is similar to
 the HOOKS_CALLOUTS_REMOVED message (and the two are likely to be seen
 together), but is issued at a lower-level in the hook framework.
 
+% HOOKS_CALLOUTS_BEGIN begin all callouts for hook %1
+This debug message is issued when callout manager begins to invoke callouts
+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.
+
 % HOOKS_CALLOUTS_REMOVED callouts removed from hook %1 for library %2
 This is a debug message issued during library unloading.  It notes that
 one of more callouts registered by that library have been removed from