bitbake: server/process: Add more timing debug

It is helpful to have timestamps on the ping failures so that they
can be matched against the bitbake logs. It is also useful to understand
how long the server takes for form a reply verses when it is sent.

(Bitbake rev: 65969a7a8f5ae22c230431d2db080eb187a27708)

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
This commit is contained in:
Richard Purdie 2023-08-30 20:39:53 +01:00
parent 7e6d7315f9
commit 733afeffd1

View File

@ -38,8 +38,11 @@ logger = logging.getLogger('BitBake')
class ProcessTimeout(SystemExit):
pass
def currenttime():
return datetime.datetime.now().strftime('%H:%M:%S.%f')
def serverlog(msg):
print(str(os.getpid()) + " " + datetime.datetime.now().strftime('%H:%M:%S.%f') + " " + msg)
print(str(os.getpid()) + " " + currenttime() + " " + msg)
sys.stdout.flush()
#
@ -289,7 +292,9 @@ class ProcessServer():
continue
try:
serverlog("Running command %s" % command)
self.command_channel_reply.send(self.cooker.command.runCommand(command, self))
reply = self.cooker.command.runCommand(command, self)
serverlog("Sending reply %s" % repr(reply))
self.command_channel_reply.send(reply)
serverlog("Command Completed (socket: %s)" % os.path.exists(self.sockname))
except Exception as e:
stack = traceback.format_exc()
@ -502,9 +507,9 @@ class ServerCommunicator():
def runCommand(self, command):
self.connection.send(command)
if not self.recv.poll(30):
logger.info("No reply from server in 30s (for command %s)" % command[0])
logger.info("No reply from server in 30s (for command %s at %s)" % (command[0], currenttime()))
if not self.recv.poll(30):
raise ProcessTimeout("Timeout while waiting for a reply from the bitbake server (60s)")
raise ProcessTimeout("Timeout while waiting for a reply from the bitbake server (60s at %s)" % currenttime())
ret, exc = self.recv.get()
# Should probably turn all exceptions in exc back into exceptions?
# For now, at least handle BBHandledException