Setup root logger so that we can use logging in nodes

Author: Alxiice

bin/meshroom_compute

@@ -95,13 +95,15 @@ if args.node:
         # Restore the log level
         logging.getLogger().setLevel(meshroom.logStringToPython[args.verbose])
 
+    node.prepareLogger(args.iteration)
     node.preprocess()
     if args.iteration != -1:
         chunk = node.chunks[args.iteration]
         chunk.process(args.forceCompute, args.inCurrentEnv)
     else:
         node.process(args.forceCompute, args.inCurrentEnv)
     node.postprocess()
+    node.restoreLogger()
 else:
     if args.iteration != -1:
         print('Error: "--iteration" only make sense when used with "--node".')

meshroom/core/node.py

@@ -221,30 +221,42 @@ def fromDict(self, d):
 class LogManager:
     dateTimeFormatting = '%H:%M:%S'
 
-    def __init__(self, chunk):
-        self.chunk = chunk
-        self.logger = logging.getLogger(chunk.node.getName())
-
+    def __init__(self, logger, logFile):
+        self.logger = logger
+        self.logFile = logFile
+        self._previousHandlers = []
+        self._previousLevel = 0
+    
     class Formatter(logging.Formatter):
         def format(self, record):
             # Make level name lower case
             record.levelname = record.levelname.lower()
             return logging.Formatter.format(self, record)
-
+    
     def configureLogger(self):
+        self._previousLevel = self.logger.level
+        self._previousHandlers = []
         for handler in self.logger.handlers[:]:
+            self._previousHandlers.append(handler)
             self.logger.removeHandler(handler)
-        handler = logging.FileHandler(self.chunk.logFile)
+        handler = logging.FileHandler(self.logFile)
         formatter = self.Formatter('[%(asctime)s.%(msecs)03d][%(levelname)s] %(message)s',
                                    self.dateTimeFormatting)
         handler.setFormatter(formatter)
         self.logger.addHandler(handler)
+    
+    def restorePreviousLogger(self):
+        for h in self.logger.handlers[:]:
+            self.logger.removeHandler(h)
+        for h in self._previousHandlers:
+            self.logger.addHandler(h)
+        self.logger.setLevel(self._previousLevel)
 
     def start(self, level):
         # Clear log file
-        open(self.chunk.logFile, 'w').close()
-
+        open(self.logFile, 'w').close()
         self.configureLogger()
+        self.logger.propagate = False
         self.logger.setLevel(self.textToLevel(level))
         self.progressBar = False
 
@@ -261,15 +273,15 @@ def makeProgressBar(self, end, message=''):
         self.currentProgressTics = 0
         self.progressBar = True
 
-        with open(self.chunk.logFile, 'a') as f:
+        with open(self.logFile, 'a') as f:
             if message:
                 f.write(message+'\n')
             f.write('0%   10   20   30   40   50   60   70   80   90   100%\n')
             f.write('|----|----|----|----|----|----|----|----|----|----|\n\n')
 
             f.close()
 
-        with open(self.chunk.logFile) as f:
+        with open(self.logFile) as f:
             content = f.read()
             self.progressBarPosition = content.rfind('\n')
 
@@ -281,7 +293,7 @@ def updateProgressBar(self, value):
 
         tics = round((value/self.progressEnd)*51)
 
-        with open(self.chunk.logFile, 'r+') as f:
+        with open(self.logFile, 'r+') as f:
             text = f.read()
             for i in range(tics-self.currentProgressTics):
                 text = text[:self.progressBarPosition]+'*'+text[self.progressBarPosition:]
@@ -296,7 +308,8 @@ def completeProgressBar(self):
 
         self.progressBar = False
 
-    def textToLevel(self, text):
+    @staticmethod
+    def textToLevel(text):
         if text == "critical":
             return logging.CRITICAL
         elif text == "error":
@@ -325,7 +338,7 @@ def __init__(self, node, range, parent=None):
         super().__init__(parent)
         self.node = node
         self.range = range
-        self.logManager: LogManager = LogManager(self)
+        self._logManager = None
         self._status: StatusData = StatusData(node.name, node.nodeType, node.packageName,
                                               node.packageVersion, node.getMrNodeType())
         self.statistics: stats.Statistics = stats.Statistics()
@@ -344,6 +357,13 @@ def name(self):
             return f"{self.node.name}({self.index})"
         else:
             return self.node.name
+    
+    @property
+    def logManager(self):
+        if self._logManager is None:
+            logger = logging.getLogger(self.node.getName())
+            self._logManager = LogManager(logger, self.logFile)
+        return self._logManager
 
     @property
     def statusName(self):
@@ -660,6 +680,7 @@ def __init__(self, nodeType: str, position: Position = None, parent: BaseObject
         self._uid: str = uid
         self._cmdVars: dict = {}
         self._size: int = 0
+        self._logManager: LogManager = None
         self._position: Position = position or Position()
         self._attributes = DictModel(keyAttrName='name', parent=self)
         self._internalAttributes = DictModel(keyAttrName='name', parent=self)
@@ -1312,6 +1333,25 @@ def postprocess(self):
         # node is completed
         self.nodeDesc.postprocess(self)
 
+    def getLogHandlers(self):
+        return self._handlers
+
+    def prepareLogger(self, iteration=-1):
+        # Get file handler path
+        logFileName = "log"
+        if iteration != -1:
+            chunk = self.chunks[iteration]
+            logFileName = str(chunk.index) + ".log"
+        logFile = os.path.join(self.graph.cacheDir, self.internalFolder, logFileName)
+        # Setup logger
+        rootLogger = logging.getLogger()
+        self._logManager = LogManager(rootLogger, logFile)
+        self._logManager.configureLogger()
+        rootLogger.setLevel(logging.INFO)  # Set info by default
+
+    def restoreLogger(self):
+        self._logManager.restorePreviousLogger()
+
     def updateOutputAttr(self):
         if not self.nodeDesc:
             return