[PATCH][RFC] bitbake: add task tracking

[Qing He <qing.he@intel.com>]

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