From: Marcin Siodelski <marcin@isc.org>
Date: Mon, 20 Apr 2015 14:43:04 +0000 (+0200)
Subject: [3804] Measure total execution time for all callouts for the hook.
X-Git-Tag: trac3791_base~2^2~3
X-Git-Url: http://git.ipfire.org/gitweb.cgi?a=commitdiff_plain;h=04b76159d4c280c10d41e39d8e014db0c35c3697;p=thirdparty%2Fkea.git

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

diff --git a/src/lib/hooks/callout_manager.cc b/src/lib/hooks/callout_manager.cc
index dabdb12308..2582941bd2 100644
--- a/src/lib/hooks/callout_manager.cc
+++ b/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;
diff --git a/src/lib/hooks/hooks_messages.mes b/src/lib/hooks/hooks_messages.mes
index d0c40e603a..35a396df68 100644
--- a/src/lib/hooks/hooks_messages.mes
+++ b/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