From: "Bob Feng" <bob.c.feng@intel.com>
To: devel@edk2.groups.io
Cc: Liming Gao <liming.gao@intel.com>, Bob Feng <bob.c.feng@intel.com>
Subject: [Patch 7/9] BaseTools: Add LogAgent to support multiple process Autogen
Date: Thu, 18 Jul 2019 14:14:21 +0800 [thread overview]
Message-ID: <20190718061423.30612-8-bob.c.feng@intel.com> (raw)
In-Reply-To: <20190718061423.30612-1-bob.c.feng@intel.com>
BZ: https://bugzilla.tianocore.org/show_bug.cgi?id=1875
AutoGen processes race the logfile. To resolve this issue,
this patch create a LogAgent thread in main process to write
the log content to console or file, Other process will send
the log content to the LogAgent.
Cc: Liming Gao <liming.gao@intel.com>
Signed-off-by: Bob Feng <bob.c.feng@intel.com>
---
.../Source/Python/AutoGen/AutoGenWorker.py | 86 +++++++++++++++----
BaseTools/Source/Python/AutoGen/DataPipe.py | 2 +-
BaseTools/Source/Python/Common/EdkLogger.py | 33 ++++++-
BaseTools/Source/Python/build/build.py | 27 ++++--
4 files changed, 120 insertions(+), 28 deletions(-)
diff --git a/BaseTools/Source/Python/AutoGen/AutoGenWorker.py b/BaseTools/Source/Python/AutoGen/AutoGenWorker.py
index 150de0891c6e..19d1cfac39fd 100644
--- a/BaseTools/Source/Python/AutoGen/AutoGenWorker.py
+++ b/BaseTools/Source/Python/AutoGen/AutoGenWorker.py
@@ -19,52 +19,111 @@ from Workspace.WorkspaceDatabase import BuildDB
import time
from queue import Empty
import traceback
import sys
from AutoGen.DataPipe import MemoryDataPipe
+import logging
+
+class LogAgent(threading.Thread):
+ def __init__(self,log_q,log_level,log_file=None):
+ super(LogAgent,self).__init__()
+ self.log_q = log_q
+ self.log_level = log_level
+ self.log_file = log_file
+ def InitLogger(self):
+ # For DEBUG level (All DEBUG_0~9 are applicable)
+ self._DebugLogger_agent = logging.getLogger("tool_debug_agent")
+ _DebugFormatter = logging.Formatter("[%(asctime)s.%(msecs)d]: %(message)s", datefmt="%H:%M:%S")
+ self._DebugLogger_agent.setLevel(self.log_level)
+ _DebugChannel = logging.StreamHandler(sys.stdout)
+ _DebugChannel.setFormatter(_DebugFormatter)
+ self._DebugLogger_agent.addHandler(_DebugChannel)
+
+ # For VERBOSE, INFO, WARN level
+ self._InfoLogger_agent = logging.getLogger("tool_info_agent")
+ _InfoFormatter = logging.Formatter("%(message)s")
+ self._InfoLogger_agent.setLevel(self.log_level)
+ _InfoChannel = logging.StreamHandler(sys.stdout)
+ _InfoChannel.setFormatter(_InfoFormatter)
+ self._InfoLogger_agent.addHandler(_InfoChannel)
+
+ # For ERROR level
+ self._ErrorLogger_agent = logging.getLogger("tool_error_agent")
+ _ErrorFormatter = logging.Formatter("%(message)s")
+ self._ErrorLogger_agent.setLevel(self.log_level)
+ _ErrorCh = logging.StreamHandler(sys.stderr)
+ _ErrorCh.setFormatter(_ErrorFormatter)
+ self._ErrorLogger_agent.addHandler(_ErrorCh)
+
+ if self.log_file:
+ if os.path.exists(self.log_file):
+ os.remove(self.log_file)
+ _Ch = logging.FileHandler(self.log_file)
+ _Ch.setFormatter(_DebugFormatter)
+ self._DebugLogger_agent.addHandler(_Ch)
+
+ _Ch= logging.FileHandler(self.log_file)
+ _Ch.setFormatter(_InfoFormatter)
+ self._InfoLogger_agent.addHandler(_Ch)
+
+ _Ch = logging.FileHandler(self.log_file)
+ _Ch.setFormatter(_ErrorFormatter)
+ self._ErrorLogger_agent.addHandler(_Ch)
+
+ def run(self):
+ self.InitLogger()
+ while True:
+ log_message = self.log_q.get()
+ if log_message is None:
+ break
+ if log_message.name == "tool_error":
+ self._ErrorLogger_agent.log(log_message.levelno,log_message.getMessage())
+ elif log_message.name == "tool_info":
+ self._InfoLogger_agent.log(log_message.levelno,log_message.getMessage())
+ elif log_message.name == "tool_debug":
+ self._DebugLogger_agent.log(log_message.levelno,log_message.getMessage())
+ else:
+ self._InfoLogger_agent.log(log_message.levelno,log_message.getMessage())
+
+ def kill(self):
+ self.log_q.put(None)
class AutoGenManager(threading.Thread):
def __init__(self,autogen_workers, feedback_q):
super(AutoGenManager,self).__init__()
self.autogen_workers = autogen_workers
self.feedback_q = feedback_q
- self.terminate = False
self.Status = True
def run(self):
try:
while True:
- if self.terminate:
- break
- if self.feedback_q.empty():
- time.sleep(1)
- continue
- badnews = self.feedback_q.get(False)
- if badnews:
- print(badnews)
+ badnews = self.feedback_q.get()
+ if badnews is None:
self.Status = False
self.TerminateWorkers()
break
except Exception:
return
def kill(self):
- self.terminate = True
+ self.feedback_q.put(None)
def TerminateWorkers(self):
for w in self.autogen_workers:
if w.is_alive():
w.terminate()
class AutoGenWorkerInProcess(mp.Process):
- def __init__(self,module_queue,data_pipe_file_path,feedback_q,file_lock, share_data):
+ def __init__(self,module_queue,data_pipe_file_path,feedback_q,file_lock, share_data,log_q):
mp.Process.__init__(self)
self.module_queue = module_queue
self.data_pipe_file_path =data_pipe_file_path
self.data_pipe = None
self.feedback_q = feedback_q
self.PlatformMetaFileSet = {}
self.file_lock = file_lock
self.share_data = share_data
+ self.log_q = log_q
def GetPlatformMetaFile(self,filepath,root):
try:
return self.PlatformMetaFileSet[(filepath,root)]
except:
self.PlatformMetaFileSet[(filepath,root)] = filepath
@@ -75,18 +134,15 @@ class AutoGenWorkerInProcess(mp.Process):
with self.file_lock:
if not os.path.exists(self.data_pipe_file_path):
self.feedback_q.put(taskname + ":" + "load data pipe %s failed." % self.data_pipe_file_path)
self.data_pipe = MemoryDataPipe()
self.data_pipe.load(self.data_pipe_file_path)
- EdkLogger.Initialize()
+ EdkLogger.LogClientInitialize(self.log_q)
loglevel = self.data_pipe.Get("LogLevel")
if not loglevel:
loglevel = EdkLogger.INFO
EdkLogger.SetLevel(loglevel)
- logfile = self.data_pipe.Get("LogFile")
- if logfile:
- EdkLogger.SetLogFile(logfile)
target = self.data_pipe.Get("P_Info").get("Target")
toolchain = self.data_pipe.Get("P_Info").get("ToolChain")
archlist = self.data_pipe.Get("P_Info").get("ArchList")
active_p = self.data_pipe.Get("P_Info").get("ActivePlatform")
diff --git a/BaseTools/Source/Python/AutoGen/DataPipe.py b/BaseTools/Source/Python/AutoGen/DataPipe.py
index 9478f41d481b..33d2b14c9add 100644
--- a/BaseTools/Source/Python/AutoGen/DataPipe.py
+++ b/BaseTools/Source/Python/AutoGen/DataPipe.py
@@ -145,9 +145,9 @@ class MemoryDataPipe(DataPipe):
self.DataContainer = {"PackageList": [(dec.MetaFile,dec.Arch) for dec in PlatformInfo.PackageList]}
self.DataContainer = {"GuidDict": PlatformInfo.Platform._GuidDict}
self.DataContainer = {"DatabasePath":GlobalData.gDatabasePath}
+
self.DataContainer = {"FdfParser": True if GlobalData.gFdfParser else False}
self.DataContainer = {"LogLevel": EdkLogger.GetLevel()}
- self.DataContainer = {"LogFile": GlobalData.gOptions.LogFile if GlobalData.gOptions.LogFile is not None else ""}
diff --git a/BaseTools/Source/Python/Common/EdkLogger.py b/BaseTools/Source/Python/Common/EdkLogger.py
index ae2070bebba3..f6a5e3b4daf9 100644
--- a/BaseTools/Source/Python/Common/EdkLogger.py
+++ b/BaseTools/Source/Python/Common/EdkLogger.py
@@ -8,10 +8,11 @@
## Import modules
from __future__ import absolute_import
import Common.LongFilePathOs as os, sys, logging
import traceback
from .BuildToolError import *
+import logging.handlers
## Log level constants
DEBUG_0 = 1
DEBUG_1 = 2
DEBUG_2 = 3
@@ -198,30 +199,30 @@ def error(ToolName, ErrorCode, Message=None, File=None, Line=None, ExtraData=Non
# Log information which should be always put out
quiet = _ErrorLogger.error
## Initialize log system
-def Initialize():
+def LogClientInitialize(log_q):
#
# Since we use different format to log different levels of message into different
# place (stdout or stderr), we have to use different "Logger" objects to do this.
#
# For DEBUG level (All DEBUG_0~9 are applicable)
_DebugLogger.setLevel(INFO)
- _DebugChannel = logging.StreamHandler(sys.stdout)
+ _DebugChannel = logging.handlers.QueueHandler(log_q)
_DebugChannel.setFormatter(_DebugFormatter)
_DebugLogger.addHandler(_DebugChannel)
# For VERBOSE, INFO, WARN level
_InfoLogger.setLevel(INFO)
- _InfoChannel = logging.StreamHandler(sys.stdout)
+ _InfoChannel = logging.handlers.QueueHandler(log_q)
_InfoChannel.setFormatter(_InfoFormatter)
_InfoLogger.addHandler(_InfoChannel)
# For ERROR level
_ErrorLogger.setLevel(INFO)
- _ErrorCh = logging.StreamHandler(sys.stderr)
+ _ErrorCh = logging.handlers.QueueHandler(log_q)
_ErrorCh.setFormatter(_ErrorFormatter)
_ErrorLogger.addHandler(_ErrorCh)
## Set log level
#
@@ -232,10 +233,34 @@ def SetLevel(Level):
Level = INFO
_DebugLogger.setLevel(Level)
_InfoLogger.setLevel(Level)
_ErrorLogger.setLevel(Level)
+## Initialize log system
+def Initialize():
+ #
+ # Since we use different format to log different levels of message into different
+ # place (stdout or stderr), we have to use different "Logger" objects to do this.
+ #
+ # For DEBUG level (All DEBUG_0~9 are applicable)
+ _DebugLogger.setLevel(INFO)
+ _DebugChannel = logging.StreamHandler(sys.stdout)
+ _DebugChannel.setFormatter(_DebugFormatter)
+ _DebugLogger.addHandler(_DebugChannel)
+
+ # For VERBOSE, INFO, WARN level
+ _InfoLogger.setLevel(INFO)
+ _InfoChannel = logging.StreamHandler(sys.stdout)
+ _InfoChannel.setFormatter(_InfoFormatter)
+ _InfoLogger.addHandler(_InfoChannel)
+
+ # For ERROR level
+ _ErrorLogger.setLevel(INFO)
+ _ErrorCh = logging.StreamHandler(sys.stderr)
+ _ErrorCh.setFormatter(_ErrorFormatter)
+ _ErrorLogger.addHandler(_ErrorCh)
+
def InitializeForUnitTest():
Initialize()
SetLevel(SILENT)
## Get current log level
diff --git a/BaseTools/Source/Python/build/build.py b/BaseTools/Source/Python/build/build.py
index 46aed15bd9d1..6ecb80e45ed2 100644
--- a/BaseTools/Source/Python/build/build.py
+++ b/BaseTools/Source/Python/build/build.py
@@ -28,11 +28,12 @@ from subprocess import Popen,PIPE
from collections import OrderedDict, defaultdict
from optparse import OptionParser
from AutoGen.PlatformAutoGen import PlatformAutoGen
from AutoGen.ModuleAutoGen import ModuleAutoGen
from AutoGen.WorkspaceAutoGen import WorkspaceAutoGen
-from AutoGen.AutoGenWorker import AutoGenWorkerInProcess,AutoGenManager
+from AutoGen.AutoGenWorker import AutoGenWorkerInProcess,AutoGenManager,\
+ LogAgent
from AutoGen import GenMake
from Common import Misc as Utils
from Common.TargetTxtClassObject import TargetTxt
from Common.ToolDefClassObject import ToolDef
@@ -697,11 +698,11 @@ class Build():
#
# @param Target The build command target, one of gSupportedTarget
# @param WorkspaceDir The directory of workspace
# @param BuildOptions Build options passed from command line
#
- def __init__(self, Target, WorkspaceDir, BuildOptions):
+ def __init__(self, Target, WorkspaceDir, BuildOptions,log_q):
self.WorkspaceDir = WorkspaceDir
self.Target = Target
self.PlatformFile = BuildOptions.PlatformFile
self.ModuleFile = BuildOptions.ModuleFile
self.ArchList = BuildOptions.TargetArch
@@ -827,16 +828,17 @@ class Build():
self.AutoGenMgr = None
EdkLogger.info("")
os.chdir(self.WorkspaceDir)
self.share_data = Manager().dict()
+ self.log_q = log_q
def StartAutoGen(self,mqueue, DataPipe,SkipAutoGen,PcdMaList,share_data):
if SkipAutoGen:
return
feedback_q = mp.Queue()
file_lock = mp.Lock()
- auto_workers = [AutoGenWorkerInProcess(mqueue,DataPipe.dump_file,feedback_q,file_lock,share_data) for _ in range(mp.cpu_count()//2)]
+ auto_workers = [AutoGenWorkerInProcess(mqueue,DataPipe.dump_file,feedback_q,file_lock,share_data,self.log_q) for _ in range(mp.cpu_count()//2)]
self.AutoGenMgr = AutoGenManager(auto_workers,feedback_q)
self.AutoGenMgr.start()
for w in auto_workers:
w.start()
if PcdMaList is not None:
@@ -2393,35 +2395,42 @@ def MyOptionParser():
# @retval 1 Tool failed
#
def Main():
StartTime = time.time()
+ #
+ # Create a log Queue
+ #
+ LogQ = mp.Queue()
# Initialize log system
- EdkLogger.Initialize()
+ EdkLogger.LogClientInitialize(LogQ)
GlobalData.gCommand = sys.argv[1:]
#
# Parse the options and args
#
(Option, Target) = MyOptionParser()
GlobalData.gOptions = Option
GlobalData.gCaseInsensitive = Option.CaseInsensitive
# Set log level
+ LogLevel = EdkLogger.INFO
if Option.verbose is not None:
EdkLogger.SetLevel(EdkLogger.VERBOSE)
+ LogLevel = EdkLogger.VERBOSE
elif Option.quiet is not None:
EdkLogger.SetLevel(EdkLogger.QUIET)
+ LogLevel = EdkLogger.QUIET
elif Option.debug is not None:
EdkLogger.SetLevel(Option.debug + 1)
+ LogLevel = Option.debug + 1
else:
EdkLogger.SetLevel(EdkLogger.INFO)
- if Option.LogFile is not None:
- EdkLogger.SetLogFile(Option.LogFile)
-
if Option.WarningAsError == True:
EdkLogger.SetWarningAsError()
+ Log_Agent = LogAgent(LogQ,LogLevel,Option.LogFile)
+ Log_Agent.start()
if platform.platform().find("Windows") >= 0:
GlobalData.gIsWindows = True
else:
GlobalData.gIsWindows = False
@@ -2491,11 +2500,11 @@ def Main():
EdkLogger.error("build", ErrorCode, ExtraData=ErrorInfo)
if Option.Flag is not None and Option.Flag not in ['-c', '-s']:
EdkLogger.error("build", OPTION_VALUE_INVALID, "UNI flag must be one of -c or -s")
- MyBuild = Build(Target, Workspace, Option)
+ MyBuild = Build(Target, Workspace, Option,LogQ)
GlobalData.gCommandLineDefines['ARCH'] = ' '.join(MyBuild.ArchList)
if not (MyBuild.LaunchPrebuildFlag and os.path.exists(MyBuild.PlatformBuildPath)):
MyBuild.Launch()
#
@@ -2577,10 +2586,12 @@ def Main():
EdkLogger.SetLevel(EdkLogger.QUIET)
EdkLogger.quiet("\n- %s -" % Conclusion)
EdkLogger.quiet(time.strftime("Build end time: %H:%M:%S, %b.%d %Y", time.localtime()))
EdkLogger.quiet("Build total time: %s\n" % BuildDurationStr)
+ Log_Agent.kill()
+ Log_Agent.join()
return ReturnCode
if __name__ == '__main__':
r = Main()
## 0-127 is a safe return range, and 1 is a standard default error
--
2.20.1.windows.1
next prev parent reply other threads:[~2019-07-18 6:14 UTC|newest]
Thread overview: 14+ messages / expand[flat|nested] mbox.gz Atom feed top
2019-07-18 6:14 [Patch 0/9] Enable multiple process AutoGen Bob Feng
2019-07-18 6:14 ` [Patch 1/9] BaseTools: Singleton the object to handle build conf file Bob Feng
2019-07-18 6:14 ` [Patch 2/9] BaseTools: Split WorkspaceAutoGen._InitWorker into multiple functions Bob Feng
2019-07-18 6:14 ` [Patch 3/9] BaseTools: Add functions to get platform scope build options Bob Feng
2019-07-18 6:14 ` [Patch 4/9] BaseTools: Decouple AutoGen Objects Bob Feng
2019-07-18 6:14 ` [Patch 5/9] BaseTools: Enable Multiple Process AutoGen Bob Feng
2019-07-18 6:14 ` [Patch 6/9] BaseTools: Add shared data for processes Bob Feng
2019-07-18 6:14 ` Bob Feng [this message]
2019-07-18 6:14 ` [Patch 8/9] BaseTools: Move BuildOption parser out of build.py Bob Feng
2019-07-18 6:14 ` [Patch 9/9] BaseTools: Add the support for python 2 Bob Feng
2019-07-21 12:26 ` [edk2-devel] [Patch 0/9] Enable multiple process AutoGen Laszlo Ersek
2019-07-21 15:55 ` Steven Shi
2019-07-22 9:11 ` Bob Feng
2019-07-22 19:50 ` Laszlo Ersek
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-list from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=20190718061423.30612-8-bob.c.feng@intel.com \
--to=devel@edk2.groups.io \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox