bitbake: toaster: measure task duration with server-side timestamps

The buildstats and toaster use separate time markers to measure the
duration of task execution. This causes a mismatch in the time
measured by buildstats class and the time measured in toaster.

The solution implemented here is to timestamp the creation of
every TaskBase event on the bitbake server side and calculate
the execution duration as the difference between creation time
of TaskSucceeded and TaskStarted events.

Based on an original patch by Marius Avram.

[YOCTO #5485]

(Bitbake rev: 7a08282c074c264f414cf7665dc873f51245072c)

Signed-off-by: Marius Avram <marius.avram@intel.com>
Signed-off-by: Alexandru DAMIAN <alexandru.damian@intel.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>

2 files changed, 9 insertions, 4 deletions

diff --git a/bitbake/lib/bb/build.py b/bitbake/lib/bb/build.py
index 52e41493c1..5cb4c06a88 100644
--- a/bitbake/lib/bb/build.py
+++ b/bitbake/lib/bb/build.py
@@ -30,6 +30,7 @@ import sys
 import logging
 import shlex
 import glob
+import time
 import bb
 import bb.msg
 import bb.process
@@ -75,6 +76,7 @@ class TaskBase(event.Event):
         self.taskfile = d.getVar("FILE", True)
         self.taskname = self._task
         self.logfile = logfile
+        self.time = time.time()
         event.Event.__init__(self)
         self._message = "recipe %s: task %s: %s" % (d.getVar("PF", True), t, self.getDisplayName())
 
diff --git a/bitbake/lib/bb/ui/buildinfohelper.py b/bitbake/lib/bb/ui/buildinfohelper.py
index 15bc069b8f..2084aab96c 100644
--- a/bitbake/lib/bb/ui/buildinfohelper.py
+++ b/bitbake/lib/bb/ui/buildinfohelper.py
@@ -133,10 +133,10 @@ class ORMWrapper(object):
             elif outcome_task_setscene == Task.OUTCOME_FAILED:
                 task_object.sstate_result = Task.SSTATE_FAILED
 
-        # mark down duration if we have a start time
-        if 'start_time' in task_information.keys():
-            duration = datetime.datetime.now() - task_information['start_time']
-            task_object.elapsed_time = duration.total_seconds()
+        # mark down duration if we have a start time and a current time
+        if 'start_time' in task_information.keys() and 'time' in vars(event):
+            duration = event.time - task_information['start_time']
+            task_object.elapsed_time = duration
 
         task_object.save()
         return task_object
@@ -717,6 +717,9 @@ class BuildInfoHelper(object):
         recipe = self.orm_wrapper.get_update_recipe_object(recipe_information, True)
         task_information = self._get_task_information(event,recipe)
 
+        if 'time' in vars(event) and isinstance(event, bb.build.TaskStarted):
+            self.internal_state['taskdata'][identifier]['start_time'] = event.time
+
         task_information['start_time'] = self.internal_state['taskdata'][identifier]['start_time']
         task_information['outcome'] = self.internal_state['taskdata'][identifier]['outcome']