Add time to trace items.

https://github.com/ProjetPP/Documentation/blob/master/module-communication.md#times

ppp_libmodule/http.py

 """Handles the HTTP frontend (ie. answers to requests from a
 UI."""
 
+import time
 import json
 import logging
 
@@ -73,6 +74,26 @@ class HttpRequestHandler:
                                   'Internal server error. Sorry :/'
                                  )
 
+    def _get_times(self):
+        wall_time = time.time()
+        get_process_time = getattr(time, 'process_time', None)
+        if get_process_time: # Python ≥ 3.3 only
+            process_time = get_process_time()
+        else:
+            process_time = None
+        return (wall_time, process_time)
+
+    def _add_times_to_answers(self, answers, start_wall_time, start_process_time):
+        (end_wall_time, end_process_time) = self._get_times()
+        times_dict = {'start': start_wall_time, 'end': end_wall_time}
+        if start_wall_time and end_process_time:
+            times_dict['cpu'] = end_process_time - start_process_time
+        for answer in answers:
+            if not answer.trace:
+                continue
+            if answer.trace[0].times == {}:
+                answer.trace[0].times.update(times_dict)
+
     def process_request(self, request):
         """Processes a request."""
         try:
@@ -83,7 +104,11 @@ class HttpRequestHandler:
             raise ClientError('Missing mandatory field in request object.')
         except AttributeNotProvided as exc:
             raise ClientError('Attribute not provided: %s.' % exc.args[0])
+
+        (start_wall_time, start_process_time) = self._get_times()
         answers = self.router_class(request).answer()
+        self._add_times_to_answers(answers, start_wall_time, start_process_time)
+
         answers = [x.as_dict() for x in answers]
         return self.make_response('200 OK',
                                   'application/json',

ppp_libmodule/shortcuts.py

@@ -17,6 +17,6 @@ def traverse_until_fixpoint(predicate, tree):
 
 
 def build_answer(request, tree, measures, module_name):
-    trace = request.trace + [TraceItem(module_name, tree, measures)]
+    trace = request.trace + [TraceItem(module_name, tree, measures, {})]
     return Response(request.language, tree, measures, trace)
 

ppp_libmodule/tests.py

@@ -33,6 +33,7 @@ def PPPTestCase(app):
                 os.environ[self.config_var] = self.config_file.name
                 self.config_file.write(self.config)
                 self.config_file.seek(0)
+
         def tearDown(self):
             if self.config_var or self.config is not None:
                 assert self.config_var and self.config is not None
@@ -46,27 +47,42 @@ def PPPTestCase(app):
             j = self.app.post_json('/', obj).json
             """Make a request and return the answers."""
             return list(map(Response.from_dict, j))
+
         @arg_to_dict
-        def assertResponse(self, request, response):
-            """Makes a request and asserts the response is the expected one."""
-            self.assertEqual(self.request(request), response)
+        def assertResponses(self, request, expected_responses, *, remove_time=True):
+            """Makes a request and asserts the responses are the expected one."""
+            responses = self.request(request)
+            if remove_time:
+                for response in responses:
+                    for trace_item in response.trace:
+                        trace_item.times.clear()
+            self.assertEqual(responses, expected_responses)
+        assertResponse = assertResponses # Alias for old code
+
         @arg_to_dict
-        def assertResponsesIn(self, request, expected):
+        def assertResponsesIn(self, request, expected, *, remove_time=True):
             """Makes a request and asserts the response is among a set
             of expected ones."""
             responses = self.request(request)
+            if remove_time:
+                for response in responses:
+                    for trace_item in response.trace:
+                        trace_item.times.clear()
             self.assertTrue(all(x in expected for x in responses),
                             'Not all of:\n%r\n are in:\n%r' % (responses, expected))
+
         @arg_to_dict
         def assertResponsesCount(self, request, count):
             """Makes a request and asserts the number of responses is
             a given number."""
             self.assertEqual(len(self.request(request)), count)
+
         @arg_to_dict
         def assertStatusInt(self, obj, status):
             """Makes a request and asserts the HTTP status code is
             the one that is expected."""
             res = self.app.post_json('/', obj, status='*')
             self.assertEqual(res.status_int, status)
+
     return _PPPTestCase
 

setup.py

@@ -24,7 +24,7 @@ setup(
         'Topic :: Software Development :: Libraries',
     ],
     install_requires=[
-        'ppp_datamodel>=0.6,<0.7',
+        'ppp_datamodel>=0.6.10,<0.7',
     ],
     packages=[
         'ppp_libmodule',

tests/test_shortcuts.py

+import time
+
 from ppp_libmodule.tests import PPPTestCase
 from ppp_libmodule.http import HttpRequestHandler
 from ppp_libmodule import shortcuts
@@ -46,3 +48,19 @@ class HttpTest(PPPTestCase(app)):
         self.assertResponse(q, [Response('en', R('bar'), {},
             [TraceItem('test', R('bar'), {})])])
 
+    def testTimes(self):
+        t = T(M(), M(), M())
+        q = {'id': '1', 'language': 'en', 'tree': t.as_dict(),
+              'measures': {}, 'trace': []}
+        responses = self.request(q)
+        self.assertEqual(len(responses), 1, responses)
+        response = responses[0]
+        self.assertEqual(len(response.trace), 1, response.trace)
+        trace_item = response.trace[0]
+        self.assertEqual(set(trace_item.times), {'start', 'end', 'cpu'})
+
+        self.assertGreater(trace_item.times['cpu'], 0.)
+        # The following may fail on a very slow system.
+        self.assertLess(trace_item.times['cpu'], 1.)
+        self.assertAlmostEqual(trace_item.times['start'], time.time(), delta=1.)
+        self.assertAlmostEqual(trace_item.times['end'], time.time(), delta=1.)