Browse Source

server/process: Ensure logging is flushed

The cookerlog output goes to a file and its misleading to look at it and
not have it up to date with what the cooker is actually doing. Ensure
written data is flushed.

Ultimately this should be using python's logging but that is for another
day, we need simple fixes right now.

Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Richard Purdie 3 years ago
parent
commit
d95c3dd2b8
1 changed files with 23 additions and 21 deletions
  1. 23 21
      lib/bb/server/process.py

+ 23 - 21
lib/bb/server/process.py

@@ -35,6 +35,10 @@ logger = logging.getLogger('BitBake')
 class ProcessTimeout(SystemExit):
 class ProcessTimeout(SystemExit):
     pass
     pass
 
 
+def serverlog(msg):
+    print(msg)
+    sys.stdout.flush()
+
 class ProcessServer():
 class ProcessServer():
     profile_filename = "profile.log"
     profile_filename = "profile.log"
     profile_processed_filename = "profile.log.processed"
     profile_processed_filename = "profile.log.processed"
@@ -73,7 +77,7 @@ class ProcessServer():
         if self.xmlrpcinterface[0]:
         if self.xmlrpcinterface[0]:
             self.xmlrpc = bb.server.xmlrpcserver.BitBakeXMLRPCServer(self.xmlrpcinterface, self.cooker, self)
             self.xmlrpc = bb.server.xmlrpcserver.BitBakeXMLRPCServer(self.xmlrpcinterface, self.cooker, self)
 
 
-            print("Bitbake XMLRPC server address: %s, server port: %s" % (self.xmlrpc.host, self.xmlrpc.port))
+            serverlog("Bitbake XMLRPC server address: %s, server port: %s" % (self.xmlrpc.host, self.xmlrpc.port))
 
 
         try:
         try:
             self.bitbake_lock.seek(0)
             self.bitbake_lock.seek(0)
@@ -84,7 +88,7 @@ class ProcessServer():
                 self.bitbake_lock.write("%s\n" % (os.getpid()))
                 self.bitbake_lock.write("%s\n" % (os.getpid()))
             self.bitbake_lock.flush()
             self.bitbake_lock.flush()
         except Exception as e:
         except Exception as e:
-            print("Error writing to lock file: %s" % str(e))
+            serverlog("Error writing to lock file: %s" % str(e))
             pass
             pass
 
 
         if self.cooker.configuration.profile:
         if self.cooker.configuration.profile:
@@ -98,7 +102,7 @@ class ProcessServer():
 
 
             prof.dump_stats("profile.log")
             prof.dump_stats("profile.log")
             bb.utils.process_profilelog("profile.log")
             bb.utils.process_profilelog("profile.log")
-            print("Raw profiling information saved to profile.log and processed statistics to profile.log.processed")
+            serverlog("Raw profiling information saved to profile.log and processed statistics to profile.log.processed")
 
 
         else:
         else:
             ret = self.main()
             ret = self.main()
@@ -118,10 +122,10 @@ class ProcessServer():
         if self.xmlrpc:
         if self.xmlrpc:
             fds.append(self.xmlrpc)
             fds.append(self.xmlrpc)
         seendata = False
         seendata = False
-        print("Entering server connection loop")
+        serverlog("Entering server connection loop")
 
 
         def disconnect_client(self, fds):
         def disconnect_client(self, fds):
-            print("Disconnecting Client")
+            serverlog("Disconnecting Client")
             if self.controllersock:
             if self.controllersock:
                 fds.remove(self.controllersock)
                 fds.remove(self.controllersock)
                 self.controllersock.close()
                 self.controllersock.close()
@@ -139,12 +143,12 @@ class ProcessServer():
                 self.haveui = False
                 self.haveui = False
             ready = select.select(fds,[],[],0)[0]
             ready = select.select(fds,[],[],0)[0]
             if newconnections:
             if newconnections:
-                print("Starting new client")
+                serverlog("Starting new client")
                 conn = newconnections.pop(-1)
                 conn = newconnections.pop(-1)
                 fds.append(conn)
                 fds.append(conn)
                 self.controllersock = conn
                 self.controllersock = conn
             elif self.timeout is None and not ready:
             elif self.timeout is None and not ready:
-                print("No timeout, exiting.")
+                serverlog("No timeout, exiting.")
                 self.quit = True
                 self.quit = True
 
 
         self.lastui = time.time()
         self.lastui = time.time()
@@ -153,17 +157,17 @@ class ProcessServer():
                 while select.select([self.sock],[],[],0)[0]:
                 while select.select([self.sock],[],[],0)[0]:
                     controllersock, address = self.sock.accept()
                     controllersock, address = self.sock.accept()
                     if self.controllersock:
                     if self.controllersock:
-                        print("Queuing %s (%s)" % (str(ready), str(newconnections)))
+                        serverlog("Queuing %s (%s)" % (str(ready), str(newconnections)))
                         newconnections.append(controllersock)
                         newconnections.append(controllersock)
                     else:
                     else:
-                        print("Accepting %s (%s)" % (str(ready), str(newconnections)))
+                        serverlog("Accepting %s (%s)" % (str(ready), str(newconnections)))
                         self.controllersock = controllersock
                         self.controllersock = controllersock
                         fds.append(controllersock)
                         fds.append(controllersock)
             if self.controllersock in ready:
             if self.controllersock in ready:
                 try:
                 try:
-                    print("Processing Client")
+                    serverlog("Processing Client")
                     ui_fds = recvfds(self.controllersock, 3)
                     ui_fds = recvfds(self.controllersock, 3)
-                    print("Connecting Client")
+                    serverlog("Connecting Client")
 
 
                     # Where to write events to
                     # Where to write events to
                     writer = ConnectionWriter(ui_fds[0])
                     writer = ConnectionWriter(ui_fds[0])
@@ -187,14 +191,14 @@ class ProcessServer():
 
 
             if not self.timeout == -1.0 and not self.haveui and self.timeout and \
             if not self.timeout == -1.0 and not self.haveui and self.timeout and \
                     (self.lastui + self.timeout) < time.time():
                     (self.lastui + self.timeout) < time.time():
-                print("Server timeout, exiting.")
+                serverlog("Server timeout, exiting.")
                 self.quit = True
                 self.quit = True
 
 
             # If we don't see a UI connection within maxuiwait, its unlikely we're going to see
             # If we don't see a UI connection within maxuiwait, its unlikely we're going to see
             # one. We have had issue with processes hanging indefinitely so timing out UI-less
             # one. We have had issue with processes hanging indefinitely so timing out UI-less
             # servers is useful.
             # servers is useful.
             if not self.hadanyui and not self.xmlrpc and not self.timeout and (self.lastui + self.maxuiwait) < time.time():
             if not self.hadanyui and not self.xmlrpc and not self.timeout and (self.lastui + self.maxuiwait) < time.time():
-                print("No UI connection within max timeout, exiting to avoid infinite loop.")
+                serverlog("No UI connection within max timeout, exiting to avoid infinite loop.")
                 self.quit = True
                 self.quit = True
 
 
             if self.command_channel in ready:
             if self.command_channel in ready:
@@ -209,7 +213,7 @@ class ProcessServer():
                     self.quit = True
                     self.quit = True
                     continue
                     continue
                 try:
                 try:
-                    print("Running command %s" % command)
+                    serverlog("Running command %s" % command)
                     self.command_channel_reply.send(self.cooker.command.runCommand(command))
                     self.command_channel_reply.send(self.cooker.command.runCommand(command))
                 except Exception as e:
                 except Exception as e:
                    logger.exception('Exception in server main event loop running command %s (%s)' % (command, str(e)))
                    logger.exception('Exception in server main event loop running command %s (%s)' % (command, str(e)))
@@ -236,9 +240,9 @@ class ProcessServer():
             ready = self.idle_commands(.1, fds)
             ready = self.idle_commands(.1, fds)
 
 
         if len(threading.enumerate()) != 1:
         if len(threading.enumerate()) != 1:
-            print("More than one thread left?: " + str(threading.enumerate()))
+            serverlog("More than one thread left?: " + str(threading.enumerate()))
 
 
-        print("Exiting")
+        serverlog("Exiting")
         # Remove the socket file so we don't get any more connections to avoid races
         # Remove the socket file so we don't get any more connections to avoid races
         try:
         try:
             os.unlink(self.sockname)
             os.unlink(self.sockname)
@@ -296,7 +300,7 @@ class ProcessServer():
                 msg = "Delaying shutdown due to active processes which appear to be holding bitbake.lock"
                 msg = "Delaying shutdown due to active processes which appear to be holding bitbake.lock"
                 if procs:
                 if procs:
                     msg += ":\n%s" % str(procs.decode("utf-8"))
                     msg += ":\n%s" % str(procs.decode("utf-8"))
-                print(msg)
+                serverlog(msg)
 
 
     def idle_commands(self, delay, fds=None):
     def idle_commands(self, delay, fds=None):
         nextsleep = delay
         nextsleep = delay
@@ -485,8 +489,7 @@ def execServer(lockfd, readypipeinfd, lockname, sockname, server_timeout, xmlrpc
     import bb.cookerdata
     import bb.cookerdata
     import bb.cooker
     import bb.cooker
 
 
-    print(start_log_format % (os.getpid(), datetime.datetime.now().strftime(start_log_datetime_format)))
-    sys.stdout.flush()
+    serverlog(start_log_format % (os.getpid(), datetime.datetime.now().strftime(start_log_datetime_format)))
 
 
     try:
     try:
         bitbake_lock = os.fdopen(lockfd, "w")
         bitbake_lock = os.fdopen(lockfd, "w")
@@ -515,8 +518,7 @@ def execServer(lockfd, readypipeinfd, lockname, sockname, server_timeout, xmlrpc
         writer.send("r")
         writer.send("r")
         writer.close()
         writer.close()
         server.cooker = cooker
         server.cooker = cooker
-        print("Started bitbake server pid %d" % os.getpid())
-        sys.stdout.flush()
+        serverlog("Started bitbake server pid %d" % os.getpid())
 
 
         server.run()
         server.run()
     finally:
     finally: