From bb93b6d1fbe2565d54ca202d840e877fa3563943 Mon Sep 17 00:00:00 2001 From: Richard Purdie Date: Fri, 24 May 2024 11:45:36 +0100 Subject: bitbake: runqueue: Add timing warnings around slow loops With hashserve enabled, there are two slow paths/loops, one at initial runqueue generation and also during the rehash process when new outhashes are found. Add timing information at the hashserve log level for when these loops take longer than 30s or 60s overall. This will leave evidence in the logs when things are running particularly slowly. (Bitbake rev: 9ee503c79936b13f1d45f9e43211f77a528cdbfa) Signed-off-by: Richard Purdie Signed-off-by: Steve Sakoman --- bitbake/lib/bb/runqueue.py | 22 ++++++++++++++++++++++ 1 file changed, 22 insertions(+) (limited to 'bitbake/lib') diff --git a/bitbake/lib/bb/runqueue.py b/bitbake/lib/bb/runqueue.py index bc7e18175d..beec1e0465 100644 --- a/bitbake/lib/bb/runqueue.py +++ b/bitbake/lib/bb/runqueue.py @@ -1273,6 +1273,9 @@ class RunQueueData: bb.parse.siggen.set_setscene_tasks(self.runq_setscene_tids) + starttime = time.time() + lasttime = starttime + # Iterate over the task list and call into the siggen code dealtwith = set() todeal = set(self.runtaskentries) @@ -1284,6 +1287,14 @@ class RunQueueData: self.prepare_task_hash(tid) bb.event.check_for_interrupts(self.cooker.data) + if time.time() > (lasttime + 30): + lasttime = time.time() + hashequiv_logger.verbose("Initial setup loop progress: %s of %s in %s" % (len(todeal), len(self.runtaskentries), lasttime - starttime)) + + endtime = time.time() + if (endtime-starttime > 60): + hashequiv_logger.verbose("Initial setup loop took: %s" % (endtime-starttime)) + bb.parse.siggen.writeout_file_checksum_cache() #self.dump_data() @@ -2556,6 +2567,9 @@ class RunQueueExecute: elif self.rqdata.runtaskentries[p].depends.isdisjoint(total): next.add(p) + starttime = time.time() + lasttime = starttime + # When an item doesn't have dependencies in total, we can process it. Drop items from total when handled while next: current = next.copy() @@ -2588,6 +2602,14 @@ class RunQueueExecute: total.remove(tid) next.intersection_update(total) + if time.time() > (lasttime + 30): + lasttime = time.time() + hashequiv_logger.verbose("Rehash loop slow progress: %s in %s" % (len(total), lasttime - starttime)) + + endtime = time.time() + if (endtime-starttime > 60): + hashequiv_logger.verbose("Rehash loop took more than 60s: %s" % (endtime-starttime)) + if changed: for mc in self.rq.worker: RunQueue.send_pickled_data(self.rq.worker[mc].process, bb.parse.siggen.get_taskhashes(), "newtaskhashes") -- cgit v1.2.3-54-g00ecf