diff --git a/src/component.py b/src/component.py index 01c1d06..f3ee188 100644 --- a/src/component.py +++ b/src/component.py @@ -423,7 +423,14 @@ class Component(QtCore.QObject, metaclass=ComponentMetaclass): for attr, widget in self._trackedWidgets.items(): key = attr if attr not in self._presetNames \ else self._presetNames[attr] - val = presetDict[key] + try: + val = presetDict[key] + except KeyError as e: + log.info( + '%s missing value %s. Outdated preset?', + self.currentPreset, str(e) + ) + val = getattr(self, key) if attr in self._colorWidgets: widget.setText('%s,%s,%s' % val) @@ -580,7 +587,7 @@ class Component(QtCore.QObject, metaclass=ComponentMetaclass): 'colorWidgets', 'relativeWidgets', ): - setattr(self, '_%s' % kwarg, kwargs[kwarg]) + setattr(self, '_{}'.format(kwarg), kwargs[kwarg]) else: raise ComponentError( self, 'Nonsensical keywords to trackWidgets.') @@ -613,6 +620,10 @@ class Component(QtCore.QObject, metaclass=ComponentMetaclass): self._relativeMaximums[attr] = \ self._trackedWidgets[attr].maximum() self.updateRelativeWidgetMaximum(attr) + setattr( + self, attr, getWidgetValue(self._trackedWidgets[attr]) + ) + self._preUpdate() self._autoUpdate() @@ -732,13 +743,12 @@ class Component(QtCore.QObject, metaclass=ComponentMetaclass): can make determining the 'previous' value tricky. ''' if self.oldAttrs is not None: - log.verbose('Using nonstandard oldAttr for %s', attr) return self.oldAttrs[attr] else: try: return getattr(self, attr) except AttributeError: - log.info('Using visible values instead of attrs') + log.error('Using visible values instead of oldAttrs') return self._trackedWidgets[attr].value() def updateRelativeWidget(self, attr): @@ -893,7 +903,7 @@ class ComponentUpdate(QtWidgets.QUndoCommand): def redo(self): if self.undone: - log.debug('Redoing component update') + log.info('Redoing component update') self.parent.oldAttrs = self.relativeWidgetValsAfterUndo self.setWidgetValues(self.modifiedVals) self.parent.update(auto=True) @@ -906,7 +916,7 @@ class ComponentUpdate(QtWidgets.QUndoCommand): self.parent._sendUpdateSignal() def undo(self): - log.debug('Undoing component update') + log.info('Undoing component update') self.undone = True self.parent.oldAttrs = self.relativeWidgetValsAfterRedo self.setWidgetValues(self.oldWidgetVals) diff --git a/src/components/spectrum.py b/src/components/spectrum.py index 2b98dc2..77cb086 100644 --- a/src/components/spectrum.py +++ b/src/components/spectrum.py @@ -148,15 +148,22 @@ class Component(Component): '-codec:v', 'rawvideo', '-', '-frames:v', '1', ]) - logFilename = os.path.join( - self.core.logDir, 'preview_%s.log' % str(self.compPos)) - log.debug('Creating ffmpeg process (log at %s)' % logFilename) - with open(logFilename, 'w') as logf: - logf.write(" ".join(command) + '\n\n') - with open(logFilename, 'a') as logf: + + if self.core.logEnabled: + logFilename = os.path.join( + self.core.logDir, 'preview_%s.log' % str(self.compPos)) + log.debug('Creating ffmpeg process (log at %s)' % logFilename) + with open(logFilename, 'w') as logf: + logf.write(" ".join(command) + '\n\n') + with open(logFilename, 'a') as logf: + self.previewPipe = openPipe( + command, stdin=subprocess.DEVNULL, stdout=subprocess.PIPE, + stderr=logf, bufsize=10**8 + ) + else: self.previewPipe = openPipe( command, stdin=subprocess.DEVNULL, stdout=subprocess.PIPE, - stderr=logf, bufsize=10**8 + stderr=subprocess.DEVNULL, bufsize=10**8 ) byteFrame = self.previewPipe.stdout.read(self.chunkSize) closePipe(self.previewPipe) diff --git a/src/components/video.py b/src/components/video.py index e6486ea..8ad21b5 100644 --- a/src/components/video.py +++ b/src/components/video.py @@ -139,16 +139,23 @@ class Component(Component): '-frames:v', '1', ]) - logFilename = os.path.join( - self.core.logDir, 'preview_%s.log' % str(self.compPos)) - log.debug('Creating ffmpeg process (log at %s)' % logFilename) - with open(logFilename, 'w') as logf: - logf.write(" ".join(command) + '\n\n') - with open(logFilename, 'a') as logf: + if self.core.logEnabled: + logFilename = os.path.join( + self.core.logDir, 'preview_%s.log' % str(self.compPos)) + log.debug('Creating ffmpeg process (log at %s)' % logFilename) + with open(logFilename, 'w') as logf: + logf.write(" ".join(command) + '\n\n') + with open(logFilename, 'a') as logf: + pipe = openPipe( + command, stdin=subprocess.DEVNULL, stdout=subprocess.PIPE, + stderr=logf, bufsize=10**8 + ) + else: pipe = openPipe( command, stdin=subprocess.DEVNULL, stdout=subprocess.PIPE, - stderr=logf, bufsize=10**8 + stderr=subprocess.DEVNULL, bufsize=10**8 ) + byteFrame = pipe.stdout.read(self.chunkSize) closePipe(pipe) diff --git a/src/components/waveform.py b/src/components/waveform.py index 5c02bbf..cbfc47f 100644 --- a/src/components/waveform.py +++ b/src/components/waveform.py @@ -110,15 +110,21 @@ class Component(Component): '-codec:v', 'rawvideo', '-', '-frames:v', '1', ]) - logFilename = os.path.join( - self.core.logDir, 'preview_%s.log' % str(self.compPos)) - log.debug('Creating ffmpeg process (log at %s)' % logFilename) - with open(logFilename, 'w') as logf: - logf.write(" ".join(command) + '\n\n') - with open(logFilename, 'a') as logf: + if self.core.logEnabled: + logFilename = os.path.join( + self.core.logDir, 'preview_%s.log' % str(self.compPos)) + log.debug('Creating ffmpeg log at %s', logFilename) + with open(logFilename, 'w') as logf: + logf.write(" ".join(command) + '\n\n') + with open(logFilename, 'a') as logf: + pipe = openPipe( + command, stdin=subprocess.DEVNULL, stdout=subprocess.PIPE, + stderr=logf, bufsize=10**8 + ) + else: pipe = openPipe( command, stdin=subprocess.DEVNULL, stdout=subprocess.PIPE, - stderr=logf, bufsize=10**8 + stderr=subprocess.DEVNULL, bufsize=10**8 ) byteFrame = pipe.stdout.read(self.chunkSize) closePipe(pipe) diff --git a/src/core.py b/src/core.py index b9e2335..1a90296 100644 --- a/src/core.py +++ b/src/core.py @@ -13,8 +13,8 @@ import toolkit log = logging.getLogger('AVP.Core') -STDOUT_LOGLVL = logging.VERBOSE -FILE_LOGLVL = logging.DEBUG +STDOUT_LOGLVL = logging.INFO +FILE_LOGLVL = logging.VERBOSE class Core: @@ -145,17 +145,11 @@ class Core: saveValueStore = self.getPreset(filepath) if not saveValueStore: return False - try: - comp = self.selectedComponents[compIndex] - comp.loadPreset( - saveValueStore, - presetName - ) - except KeyError as e: - log.warning( - '%s #%s\'s preset is missing value: %s', - comp.name, str(compIndex), str(e) - ) + comp = self.selectedComponents[compIndex] + comp.loadPreset( + saveValueStore, + presetName + ) self.savedPresets[presetName] = dict(saveValueStore) return True @@ -472,11 +466,12 @@ class Core: encoderOptions = json.load(json_file) settings = { + 'canceled': False, + 'FFMPEG_BIN': findFfmpeg(), 'dataDir': dataDir, 'settings': QtCore.QSettings( os.path.join(dataDir, 'settings.ini'), QtCore.QSettings.IniFormat), - 'logDir': os.path.join(dataDir, 'log'), 'presetDir': os.path.join(dataDir, 'presets'), 'componentsPath': os.path.join(wd, 'components'), 'junkStream': os.path.join(wd, 'gui', 'background.png'), @@ -486,8 +481,8 @@ class Core: '1280x720', '854x480', ], - 'FFMPEG_BIN': findFfmpeg(), - 'canceled': False, + 'logDir': os.path.join(dataDir, 'log'), + 'logEnabled': False, } settings['videoFormats'] = toolkit.appendUppercase([ @@ -572,42 +567,42 @@ class Core: @staticmethod def makeLogger(): - logFilename = os.path.join(Core.logDir, 'avp_debug.log') - libLogFilename = os.path.join(Core.logDir, 'global_debug.log') - # delete old logs - for log in (logFilename, libLogFilename): - if os.path.exists(log): - os.remove(log) - - # create file handlers to capture every log message somewhere - logFile = logging.FileHandler(logFilename) - logFile.setLevel(FILE_LOGLVL) - libLogFile = logging.FileHandler(libLogFilename) - libLogFile.setLevel(FILE_LOGLVL) - - # send some critical log messages to stdout as well + # send critical log messages to stdout logStream = logging.StreamHandler() logStream.setLevel(STDOUT_LOGLVL) - - # create formatters for each stream - fileFormatter = logging.Formatter( - '[%(asctime)s] %(threadName)-10.10s %(name)-23.23s %(levelname)s: ' - '%(message)s' - ) streamFormatter = logging.Formatter( - '<%(name)s> %(message)s' + '<%(name)s> %(levelname)s: %(message)s' ) - logFile.setFormatter(fileFormatter) - libLogFile.setFormatter(fileFormatter) logStream.setFormatter(streamFormatter) - log = logging.getLogger('AVP') - log.addHandler(logFile) log.addHandler(logStream) - libLog = logging.getLogger() - libLog.addHandler(libLogFile) - # lowest level must be explicitly set on the root Logger - libLog.setLevel(0) + + if FILE_LOGLVL is not None: + # write log files as well! + Core.logEnabled = True + logFilename = os.path.join(Core.logDir, 'avp_debug.log') + libLogFilename = os.path.join(Core.logDir, 'global_debug.log') + # delete old logs + for log_ in (logFilename, libLogFilename): + if os.path.exists(log_): + os.remove(log_) + + logFile = logging.FileHandler(logFilename) + logFile.setLevel(FILE_LOGLVL) + libLogFile = logging.FileHandler(libLogFilename) + libLogFile.setLevel(FILE_LOGLVL) + fileFormatter = logging.Formatter( + '[%(asctime)s] %(threadName)-10.10s %(name)-23.23s %(levelname)s: ' + '%(message)s' + ) + logFile.setFormatter(fileFormatter) + libLogFile.setFormatter(fileFormatter) + + libLog = logging.getLogger() + log.addHandler(logFile) + libLog.addHandler(libLogFile) + # lowest level must be explicitly set on the root Logger + libLog.setLevel(0) # always store settings in class variables even if a Core object is not created Core.storeSettings() diff --git a/src/gui/mainwindow.py b/src/gui/mainwindow.py index d7fde5c..81c5d7c 100644 --- a/src/gui/mainwindow.py +++ b/src/gui/mainwindow.py @@ -92,6 +92,10 @@ class MainWindow(QtWidgets.QMainWindow): self.previewWorker.moveToThread(self.previewThread) self.previewWorker.imageCreated.connect(self.showPreviewImage) self.previewThread.start() + self.previewThread.finished.connect( + lambda: + log.critical('PREVIEW THREAD DIED! This should never happen.') + ) timeout = 500 log.debug( @@ -442,7 +446,7 @@ class MainWindow(QtWidgets.QMainWindow): appName += '*' except AttributeError: pass - log.debug('Setting window title to %s' % appName) + log.verbose('Setting window title to %s' % appName) self.window.setWindowTitle(appName) @QtCore.pyqtSlot(int, dict) @@ -459,16 +463,8 @@ class MainWindow(QtWidgets.QMainWindow): modified = False else: modified = (presetStore != self.core.savedPresets[name]) - if modified: - log.verbose( - 'Differing values between presets: %s', - ", ".join([ - '%s: %s' % item for item in presetStore.items() - if val != self.core.savedPresets[name][key] - ]) - ) - else: - modified = bool(presetStore) + + modified = bool(presetStore) if pos < 0: pos = len(self.core.selectedComponents)-1 name = self.core.selectedComponents[pos].name diff --git a/src/toolkit/ffmpeg.py b/src/toolkit/ffmpeg.py index a77831e..d78d803 100644 --- a/src/toolkit/ffmpeg.py +++ b/src/toolkit/ffmpeg.py @@ -91,16 +91,24 @@ class FfmpegVideo: def fillBuffer(self): from component import ComponentError - logFilename = os.path.join( - core.Core.logDir, 'render_%s.log' % str(self.component.compPos)) - log.debug('Creating ffmpeg process (log at %s)', logFilename) - with open(logFilename, 'w') as logf: - logf.write(" ".join(self.command) + '\n\n') - with open(logFilename, 'a') as logf: + if core.Core.logEnabled: + logFilename = os.path.join( + core.Core.logDir, 'render_%s.log' % str(self.component.compPos) + ) + log.debug('Creating ffmpeg process (log at %s)', logFilename) + with open(logFilename, 'w') as logf: + logf.write(" ".join(self.command) + '\n\n') + with open(logFilename, 'a') as logf: + self.pipe = openPipe( + self.command, stdin=subprocess.DEVNULL, + stdout=subprocess.PIPE, stderr=logf, bufsize=10**8 + ) + else: self.pipe = openPipe( self.command, stdin=subprocess.DEVNULL, stdout=subprocess.PIPE, - stderr=logf, bufsize=10**8 + stderr=subprocess.DEVNULL, bufsize=10**8 ) + while True: if self.parent.canceled: break