Log manager for Python based nodes

meshroom/core/node.py

@@ -127,6 +127,101 @@ def fromDict(self, d):
         self.sessionUid = d.get('sessionUid', '')
 
 
+class LogManager:
+    dateTimeFormatting = '%H:%M:%S'
+
+    def __init__(self, chunk):
+        self.chunk = chunk
+        self.chunk.statusChanged.connect(self.clear)
+        self.progressBar = False
+        self.cleared = False
+        self.logger = logging.getLogger(chunk.node.getName())
+
+    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):
+        for handler in self.logger.handlers[:]:
+            self.logger.removeHandler(handler)
+        handler = logging.FileHandler(self.chunk.logFile)
+        formatter = self.Formatter('[%(asctime)s.%(msecs)03d][%(levelname)s] %(message)s', self.dateTimeFormatting)
+        handler.setFormatter(formatter)
+        self.logger.addHandler(handler)
+
+    def clear(self): 
+        if self.chunk.statusName == 'RUNNING' and not self.cleared:
+            open(self.chunk.logFile, 'w').close()
+            self.configureLogger()
+            self.cleared = True
+        # When the node gets ran again the log needs to be cleared
+        elif self.chunk.statusName in ['ERROR', 'SUCCESS']:
+            for handler in self.logger.handlers[:]:
+                # Stops the file being locked
+                handler.close()
+            self.cleared = False
+            self.progressBar = False
+
+    def waitUntilCleared(self):
+        while not self.cleared:
+            time.sleep(0.01)
+
+    def makeProgressBar(self, end, message=''):
+        assert end > 0
+        assert not self.progressBar
+        self.waitUntilCleared()
+
+        self.progressEnd = end
+        self.currentProgressTics = 0
+        self.progressBar = True
+
+        with open(self.chunk.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, 'r') as f:
+            content = f.read()
+            self.progressBarPosition = content.rfind('\n')
+
+            f.close()
+
+    def updateProgressBar(self, value):
+        assert self.progressBar
+        assert value <= self.progressEnd
+        self.waitUntilCleared()
+
+        tics = round((value/self.progressEnd)*51)
+
+        with open(self.chunk.logFile, 'r+') as f:
+            text = f.read()
+            for i in range(tics-self.currentProgressTics):
+                text = text[:self.progressBarPosition]+'*'+text[self.progressBarPosition:]
+            f.seek(0)
+            f.write(text)
+            f.close()
+
+        self.currentProgressTics = tics
+
+    def completeProgressBar(self):
+        assert self.progressBar
+
+        self.progressBar = False
+
+    def textToLevel(self, text):
+        if text == 'critical': return logging.CRITICAL
+        elif text == 'error': return logging.ERROR
+        elif text == 'warning': return logging.WARNING
+        elif text == 'info': return logging.INFO
+        elif text == 'debug': return logging.DEBUG
+        else: return logging.NOTSET
+
+
 runningProcesses = {}
 
 
@@ -142,6 +237,7 @@ def __init__(self, node, range, parent=None):
         super(NodeChunk, self).__init__(parent)
         self.node = node
         self.range = range
+        self.logManager = LogManager(self)
         self.status = StatusData(node.name, node.nodeType, node.packageName, node.packageVersion)
         self.statistics = stats.Statistics()
         self.statusFileLastModTime = -1
@@ -164,6 +260,10 @@ def name(self):
     def statusName(self):
         return self.status.status.name
 
+    @property
+    def logger(self):
+        return self.logManager.logger
+
     @property
     def execModeName(self):
         return self.status.execMode.name

meshroom/nodes/aliceVision/Publish.py

@@ -1,6 +1,6 @@
 from __future__ import print_function
 
-__version__ = "1.1"
+__version__ = "1.2"
 
 from meshroom.core import desc
 import shutil
@@ -30,6 +30,15 @@ class Publish(desc.Node):
             description="",
             value="",
             uid=[0],
+        ),
+        desc.ChoiceParam(
+            name='verboseLevel',
+            label='Verbose Level',
+            description='''verbosity level (critical, error, warning, info, debug).''',
+            value='info',
+            values=['critical', 'error', 'warning', 'info', 'debug'],
+            exclusive=True,
+            uid=[],
             ),
         ]
 
@@ -41,23 +50,27 @@ def resolvedPaths(self, inputFiles, outDir):
         return paths
 
     def processChunk(self, chunk):
-        print("Publish")
+        chunk.logManager.waitUntilCleared()
+        chunk.logger.setLevel(chunk.logManager.textToLevel(chunk.node.verboseLevel.value))
+
         if not chunk.node.inputFiles:
-            print("Nothing to publish")
+            chunk.logger.warning('Nothing to publish')
             return
         if not chunk.node.output.value:
             return
 
         outFiles = self.resolvedPaths(chunk.node.inputFiles.value, chunk.node.output.value)
 
         if not outFiles:
-            raise RuntimeError("Publish: input files listed, but nothing to publish. "
-                               "Listed input files: {}".format(chunk.node.inputFiles.value))
+            error = 'Publish: input files listed, but nothing to publish'
+            chunk.logger.error(error)
+            chunk.logger.info('Listed input files: {}'.format([i.value for i in chunk.node.inputFiles.value]))
+            raise RuntimeError(error)
 
         if not os.path.exists(chunk.node.output.value):
             os.mkdir(chunk.node.output.value)
 
         for iFile, oFile in outFiles.items():
-            print('Publish file', iFile, 'into', oFile)
+            chunk.logger.info('Publish file {} into {}'.format(iFile, oFile))
             shutil.copyfile(iFile, oFile)
-        print('Publish end')
+        chunk.logger.info('Publish end')