Add: log message for when callback has happened

This is for making it easier to see where time is spent.

2 files changed, 8 insertions, 0 deletions

diff --git a/NEWS b/NEWS
index d2a2593..2ac7407 100644
--- a/NEWS
+++ b/NEWS
@@ -7,6 +7,7 @@ This file summarizes changes between releases of `apifw`.
 Version 0.30+git, not yet released
 ----------------------------------
 
+* Log when callbacks have happened.
 
 Version 0.30, released 2017-12-07
 ----------------------------------
diff --git a/apifw/http.py b/apifw/http.py
index 0675442..7b5a8e9 100644
--- a/apifw/http.py
+++ b/apifw/http.py
@@ -80,6 +80,12 @@ class HttpTransaction:
         }
         self._logger(self._combine_dicts(log, self.construct_response_log()))
 
+    def _log_callback(self):
+        log = {
+            'msg_type': 'http-callback',
+        }
+        self._logger(log)
+
     def _log_error(self, exc):
         log = {
             'msg_type': 'error',
@@ -99,6 +105,7 @@ class HttpTransaction:
             self._counter()
             self._log_request()
             data = callback(*args, **kwargs)
+            self._log_callback()
             self.amend_response()
             self._log_response()
             return data