[PATCH][RFC] bitbake: add task tracking

[PATCH][RFC] bitbake: add task tracking

[Qing He]

Add a new option to record start and end time of every task

Signed-off-by: Qing He <qing.he@intel.com>

---
diff --git a/bitbake/bin/bitbake b/bitbake/bin/bitbake
index 797b5a8..e43568b 100755
--- a/bitbake/bin/bitbake
+++ b/bitbake/bin/bitbake
@@ -147,6 +147,9 @@ Default BBFILES are the .bb files in the current directory.""")
     parser.add_option("-P", "--profile", help = "profile the command and print a report",
                action = "store_true", dest = "profile", default = False)
 
+    parser.add_option("-t", "--track", help = "record start and end time of all tasks",
+               action = "store_true", dest = "track_tasks", default = False)
+
     parser.add_option("-u", "--ui", help = "userinterface to use",
                action = "store", dest = "ui")
 
diff --git a/bitbake/lib/bb/runqueue.py b/bitbake/lib/bb/runqueue.py
index 85ecafc..fa0b0b3 100644
--- a/bitbake/lib/bb/runqueue.py
+++ b/bitbake/lib/bb/runqueue.py
@@ -29,6 +29,7 @@ import signal
 import stat
 import fcntl
 import copy
+import time
 
 try:
     import cPickle as pickle
@@ -997,6 +998,7 @@ class RunQueueExecute:
         self.cooker = rq.cooker
         self.cfgData = rq.cfgData
         self.rqdata = rq.rqdata
+        self.track = rq.cooker.configuration.track_tasks
 
         self.number_tasks = int(bb.data.getVar("BB_NUMBER_THREADS", self.cfgData, 1) or 1)
         self.scheduler = bb.data.getVar("BB_SCHEDULER", self.cfgData, 1) or "speed"
@@ -1009,6 +1011,9 @@ class RunQueueExecute:
         self.build_procs = {}
         self.failed_fnids = []
 
+        if self.track:
+            self.tout = open("task-track.log", "w")
+
     def runqueue_process_waitpid(self):
         """
         Return none is there are no processes awaiting result collection, otherwise
@@ -1039,6 +1044,10 @@ class RunQueueExecute:
         for pipe in self.build_pipes:
             self.build_pipes[pipe].read()
 
+        if self.track and self.tout:
+            self.tout.flush()
+            self.tout.close()
+
     def finish(self):
         self.rq.state = runQueueCleanUp
 
@@ -1054,6 +1063,10 @@ class RunQueueExecute:
             self.rq.state = runQueueFailed
             return
 
+        if self.track and self.tout:
+            self.tout.flush()
+            self.tout.close()
+
         self.rq.state = runQueueComplete
         return
 
@@ -1170,6 +1183,8 @@ class RunQueueExecuteTasks(RunQueueExecute):
         self.stats.taskCompleted()
         bb.event.fire(runQueueTaskCompleted(task, self.stats, self.rq), self.cfgData)
         self.task_completeoutright(task)
+        if self.track:
+            self.tout.write("complete: %f (%s)\n" % (time.time(), self.rqdata.get_user_idstring(task)))
 
     def task_fail(self, task, exitcode):
         """
@@ -1183,6 +1198,8 @@ class RunQueueExecuteTasks(RunQueueExecute):
         bb.event.fire(runQueueTaskFailed(task, self.stats, self.rq), self.cfgData)
         if self.rqdata.taskData.abort:
             self.rq.state = runQueueCleanUp
+        if self.track:
+            self.tout.write("fail: %f (%s)\n" % (time.time(), self.rqdata.get_user_idstring(task)))
 
     def task_skip(self, task):
         self.runq_running[task] = 1
@@ -1221,6 +1238,8 @@ class RunQueueExecuteTasks(RunQueueExecute):
                                                                 self.stats.total,
                                                                 task,
                                                                 self.rqdata.get_user_idstring(task)))
+                if self.track:
+                    self.tout.write("noexec: %f (%s)\n" % (time.time(), self.rqdata.get_user_idstring(task)))
                 self.runq_running[task] = 1
                 self.stats.taskActive()
                 bb.build.make_stamp(task, self.rqdata.dataCache, fn)
@@ -1233,6 +1252,8 @@ class RunQueueExecuteTasks(RunQueueExecute):
                                                                 task,
                                                                 self.rqdata.get_user_idstring(task)))
 
+            if self.track:
+                self.tout.write("start: %f (%s)\n" % (time.time(), self.rqdata.get_user_idstring(task)))
             proc = self.fork_off_task(fn, task, taskname)
 
             self.build_pids[proc.pid] = task

Re: [PATCH][RFC] bitbake: add task tracking

[Chris Larson]

[-- Attachment #1: Type: text/plain, Size: 866 bytes --]

On Thu, Nov 18, 2010 at 8:51 PM, Qing He <qing.he@intel.com> wrote:

> Add a new option to record start and end time of every task
>
> Signed-off-by: Qing He <qing.he@intel.com>
>

This is useful conceptually, and I'm glad to see others touching the bitbake
code, so kudos on that, but implementation wise, I have concerns.  For one,
this doesn't need to be in bitbake at all, it's quite easily implemented in
the metadata using an event handler and the task events.  For two,
hardcoding the log file and format seems unwise.
 --
Christopher Larson
clarson at kergoth dot com
Founder - BitBake, OpenEmbedded, OpenZaurus
Maintainer - Tslib
Senior Software Engineer, Mentor Graphics



-- 
Christopher Larson
clarson at kergoth dot com
Founder - BitBake, OpenEmbedded, OpenZaurus
Maintainer - Tslib
Senior Software Engineer, Mentor Graphics

[-- Attachment #2: Type: text/html, Size: 1320 bytes --]

Re: [PATCH][RFC] bitbake: add task tracking

[Richard Purdie]

On Thu, 2010-11-18 at 21:13 -0700, Chris Larson wrote:
> On Thu, Nov 18, 2010 at 8:51 PM, Qing He <qing.he@intel.com> wrote:
>         Add a new option to record start and end time of every task
>         
>         Signed-off-by: Qing He <qing.he@intel.com>
> 
> 
> This is useful conceptually, and I'm glad to see others touching the
> bitbake code, so kudos on that, but implementation wise, I have
> concerns.  For one, this doesn't need to be in bitbake at all, it's
> quite easily implemented in the metadata using an event handler and
> the task events.  For two, hardcoding the log file and format seems
> unwise.

I agree, implementing this as an event handler would be a better
approach and allow more flexibility. 

Qing: I thought we'd already discussed that?

Cheers,

Richard