diff --git a/rest_log/components/service.py b/rest_log/components/service.py
index 41065dd0b..eeec82832 100644
--- a/rest_log/components/service.py
+++ b/rest_log/components/service.py
@@ -5,6 +5,7 @@
import json
import logging
+import time
import traceback
from psycopg2.errors import OperationalError
@@ -44,6 +45,7 @@ def dispatch(self, method_name, *args, params=None):
return self._dispatch_with_db_logging(method_name, *args, params=params)
def _dispatch_with_db_logging(self, method_name, *args, params=None):
+ start_time = time.time()
try:
with self.env.cr.savepoint():
result = super().dispatch(method_name, *args, params=params)
@@ -54,6 +56,7 @@ def _dispatch_with_db_logging(self, method_name, *args, params=None):
orig_exception,
*args,
params=params,
+ exec_time=time.time() - start_time,
)
except exceptions.ValidationError as orig_exception:
self._dispatch_exception(
@@ -62,6 +65,7 @@ def _dispatch_with_db_logging(self, method_name, *args, params=None):
orig_exception,
*args,
params=params,
+ exec_time=time.time() - start_time,
)
except exceptions.UserError as orig_exception:
self._dispatch_exception(
@@ -70,6 +74,7 @@ def _dispatch_with_db_logging(self, method_name, *args, params=None):
orig_exception,
*args,
params=params,
+ exec_time=time.time() - start_time,
)
except Exception as orig_exception:
self._dispatch_exception(
@@ -78,15 +83,26 @@ def _dispatch_with_db_logging(self, method_name, *args, params=None):
orig_exception,
*args,
params=params,
+ exec_time=time.time() - start_time,
)
- self._log_dispatch_success(method_name, result, *args, params)
+ self._log_dispatch_success(
+ method_name, result, *args, params, exec_time=time.time() - start_time
+ )
return result
- def _log_dispatch_success(self, method_name, result, *args, params=None):
+ def _log_dispatch_success(
+ self, method_name, result, *args, params=None, exec_time=None
+ ):
try:
with self.env.cr.savepoint():
log_entry = self._log_call_in_db(
- self.env, request, method_name, *args, params, result=result
+ self.env,
+ request,
+ method_name,
+ *args,
+ params,
+ result=result,
+ exec_time=exec_time,
)
if log_entry and not isinstance(result, Response):
log_entry_url = self._get_log_entry_url(log_entry)
@@ -95,7 +111,13 @@ def _log_dispatch_success(self, method_name, result, *args, params=None):
_logger.exception("Rest Log Error Creation: %s", e)
def _dispatch_exception(
- self, method_name, exception_klass, orig_exception, *args, params=None
+ self,
+ method_name,
+ exception_klass,
+ orig_exception,
+ *args,
+ params=None,
+ exec_time=None,
):
exc_msg, log_entry_url = None, None # in case it fails below
try:
@@ -110,6 +132,7 @@ def _dispatch_exception(
params=params,
traceback=tb,
orig_exception=orig_exception,
+ exec_time=exec_time,
)
log_entry_url = self._get_log_entry_url(log_entry)
except Exception as e:
@@ -165,6 +188,7 @@ def _log_call_in_db_values(self, _request, *args, params=None, **kw):
"exception_name": exception_name,
"exception_message": exception_message,
"state": state,
+ "exec_time": kw.get("exec_time"),
}
def _log_call_prepare_result(self, result):
diff --git a/rest_log/models/rest_log.py b/rest_log/models/rest_log.py
index 50665c521..3a2c45d64 100644
--- a/rest_log/models/rest_log.py
+++ b/rest_log/models/rest_log.py
@@ -39,6 +39,12 @@ class RESTLog(models.Model):
state = fields.Selection(
selection=[("success", "Success"), ("failed", "Failed")], readonly=True
)
+ exec_time = fields.Float(
+ readonly=True,
+ string="Exec time (s)",
+ help="Time spent (in seconds) to dispatch the request.",
+ aggregator="avg",
+ )
severity = fields.Selection(
selection=[
("functional", "Functional"),
diff --git a/rest_log/tests/test_db_logging.py b/rest_log/tests/test_db_logging.py
index b7b3ebf85..0fcec1974 100644
--- a/rest_log/tests/test_db_logging.py
+++ b/rest_log/tests/test_db_logging.py
@@ -2,6 +2,7 @@
# License LGPL-3.0 or later (http://www.gnu.org/licenses/lgpl.html).
# from urllib.parse import urlparse
import json
+import time
from unittest import mock
from odoo import exceptions
@@ -88,6 +89,39 @@ def test_log_entry(self):
self.assertIn("log_entry_url", resp)
self.assertTrue(self.log_model.search_count([]) > log_entry_count)
+ def test_log_entry_exec_time_success(self):
+ delay = 0.2
+ original_get = self.service.get
+
+ def _delayed_get(*args, **kwargs):
+ time.sleep(delay)
+ return original_get(*args, **kwargs)
+
+ with (
+ self._get_mocked_request(),
+ mock.patch.object(self.service, "get", side_effect=_delayed_get),
+ ):
+ self.service.dispatch("get", 100)
+ entry = self.log_model.search([], order="id desc", limit=1)
+ self.assertGreaterEqual(entry.exec_time, delay)
+
+ def test_log_entry_exec_time_failed(self):
+ delay = 0.2
+ original_fail = self.service.fail
+
+ def _delayed_fail(*args, **kwargs):
+ time.sleep(delay)
+ return original_fail(*args, **kwargs)
+
+ with (
+ self._get_mocked_request(),
+ mock.patch.object(self.service, "fail", side_effect=_delayed_fail),
+ self.assertRaises(Exception),
+ ):
+ self.service.dispatch("fail", "value")
+ entry = self.log_model.search([], order="id desc", limit=1)
+ self.assertGreaterEqual(entry.exec_time, delay)
+
def test_log_entry_values_success(self):
params = {"some": "value"}
kw = {"result": {"data": "worked!"}}
diff --git a/rest_log/views/rest_log_views.xml b/rest_log/views/rest_log_views.xml
index a37a94993..ca41cf392 100644
--- a/rest_log/views/rest_log_views.xml
+++ b/rest_log/views/rest_log_views.xml
@@ -12,6 +12,7 @@
+
@@ -50,6 +51,7 @@
+