[core] Logging : fix several issues on the log files

meshroom/core/desc/node.py

@@ -158,7 +158,7 @@ def processChunk(self, chunk):
 
     def executeChunkCommandLine(self, chunk, cmd, env=None):
         try:
-            with open(chunk.logFile, 'w') as logF:
+            with open(chunk.logFile, 'a') as logF:
                 chunk.status.commandLine = cmd
                 chunk.saveStatusFile()
                 cmdList = shlex.split(cmd)
@@ -190,6 +190,7 @@ def executeChunkCommandLine(self, chunk, cmd, env=None):
                     stderr=logF,
                     cwd=chunk.node.internalFolder,
                     env=env,
+                    text=True,
                     **platformArgs,
                 )
 

meshroom/core/node.py

@@ -243,9 +243,13 @@ def restorePreviousLogger(self):
             self.logger.addHandler(h)
         self.logger.setLevel(self._previousLevel)
 
-    def start(self, level):
-        # Clear log file
+    def clearLogFile(self):
         open(self.logFile, 'w').close()
+
+    def start(self, level):
+        # Make sure the log file exists
+        if not os.path.exists(self.logFile):
+            self.clearLogFile()
         self.configureLogger()
         self.logger.propagate = False
         self.logger.setLevel(self.textToLevel(level))
@@ -400,26 +404,18 @@ def updateStatusFromCache(self):
 
     @property
     def statusFile(self):
-        if self.range.blockSize == 0:
-            return os.path.join(self.node.internalFolder, "status")
-        else:
-            return os.path.join(self.node.internalFolder,
-                                str(self.index) + ".status")
+        chunkIndex = self.index if self.range.blockSize else 0
+        return os.path.join(self.node.internalFolder, str(chunkIndex) + ".status")
 
     @property
     def statisticsFile(self):
-        if self.range.blockSize == 0:
-            return os.path.join(self.node.internalFolder, "statistics")
-        else:
-            return os.path.join(self.node.internalFolder, str(self.index) + ".statistics")
+        chunkIndex = self.index if self.range.blockSize else 0
+        return os.path.join(self.node.internalFolder, str(chunkIndex) + ".statistics")
 
     @property
     def logFile(self):
-        if self.range.blockSize == 0:
-            return os.path.join(self.node.internalFolder, "log")
-        else:
-            return os.path.join(self.node.internalFolder,
-                                str(self.index) + ".log")
+        chunkIndex = self.index if self.range.blockSize else 0
+        return os.path.join(self.node.internalFolder, str(chunkIndex) + ".log")
 
     def saveStatusFile(self):
         """
@@ -514,11 +510,14 @@ def process(self, forceCompute=False, inCurrentEnv=False):
         self.statThread.start()
 
         try:
+            logging.info(f"[Process chunk] Start processing...")
             self.node.nodeDesc.processChunk(self)
             # NOTE: this assumes saving the output attributes for each chunk
             self.node.saveOutputAttr()
             executionStatus = Status.SUCCESS
         except Exception:
+            # with open(self.logFile, "r") as fo:
+            #     print(f"logfile:<<<{fo.read()}>>>")
             self.updateStatusFromCache()  # check if the status has been updated by another process
             if self._status.status != Status.STOPPED:
                 executionStatus = Status.ERROR
@@ -533,7 +532,7 @@ def process(self, forceCompute=False, inCurrentEnv=False):
 
             if executionStatus:
                 self.upgradeStatusTo(executionStatus)
-            logging.info(f" - elapsed time: {self._status.elapsedTimeStr}")
+            logging.info(f"[Process chunk] elapsed time: {self._status.elapsedTimeStr}")
             # Ask and wait for the stats thread to stop
             self.statThread.stopRequest()
             self.statThread.join()
@@ -1378,14 +1377,13 @@ def getLogHandlers(self):
 
     def prepareLogger(self, iteration=-1):
         # Get file handler path
-        logFileName = "log"
-        if iteration != -1:
-            chunk = self.chunks[iteration]
-            logFileName = str(chunk.index) + ".log"
+        chunkIndex = self.chunks[iteration].index if iteration != -1 else 0
+        logFileName = f"{chunkIndex}.log"
         logFile = os.path.join(self.internalFolder, logFileName)
         # Setup logger
         rootLogger = logging.getLogger()
         self._logManager = LogManager(rootLogger, logFile)
+        self._logManager.clearLogFile()
         self._logManager.start(self.getNodeLogLevel())
 
     def restoreLogger(self):

meshroom/core/taskManager.py

@@ -67,7 +67,7 @@ def run(self):
                         stopAndRestart = True
                         break
                     else:
-                        logging.error(f"Error on node computation: {exc}.")
+                        logging.error(f"Error on node computation: {exc}")
                         nodesToRemove, _ = self._manager._graph.dfsOnDiscover(startNodes=[node], reverse=True)
                         # remove following nodes from the task queue
                         for n in nodesToRemove[1:]:  # exclude current node

tests/test_compute.py

@@ -23,9 +23,7 @@ def executeChunks(node, size):
     logFiles = {}
     for chunkIndex in range(size):
         iteration = chunkIndex if size > 1 else -1
-        logFileName = "log"
-        if size > 1:
-            logFileName = f"{chunkIndex}.log"
+        logFileName = f"{chunkIndex}.log"
         logFile = Path(node.internalFolder) / logFileName
         logFiles[chunkIndex] = logFile
         logFile.touch()