diff --git a/src/component.py b/src/component.py index 5b6f9a7..a1e24db 100644 --- a/src/component.py +++ b/src/component.py @@ -8,6 +8,7 @@ import os import sys import math import time +import logging from toolkit.frame import BlankFrame from toolkit import ( @@ -15,6 +16,9 @@ from toolkit import ( ) +log = logging.getLogger('AVP.ComponentHandler') + + class ComponentMetaclass(type(QtCore.QObject)): ''' Checks the validity of each Component class and mutates some attrs. @@ -135,17 +139,17 @@ class ComponentMetaclass(type(QtCore.QObject)): # Turn version string into a number try: if 'version' not in attrs: - print( + log.error( 'No version attribute in %s. Defaulting to 1' % attrs['name']) attrs['version'] = 1 else: attrs['version'] = int(attrs['version'].split('.')[0]) except ValueError: - print('%s component has an invalid version string:\n%s' % ( + log.critical('%s component has an invalid version string:\n%s' % ( attrs['name'], str(attrs['version']))) except KeyError: - print('%s component has no version string.' % attrs['name']) + log.critical('%s component has no version string.' % attrs['name']) else: return super().__new__(cls, name, parents, attrs) quit(1) @@ -546,6 +550,8 @@ class Component(QtCore.QObject, metaclass=ComponentMetaclass): and oldRelativeVal != newRelativeVal: # Float changed without pixel value changing, which # means the pixel value needs to be updated + log.debug('Updating %s #%s\'s relative widget: %s' % ( + self.name, self.compPos, attr)) self._trackedWidgets[attr].blockSignals(True) self.updateRelativeWidgetMaximum(attr) pixelVal = self.pixelValForAttr(attr, oldRelativeVal) @@ -576,7 +582,7 @@ class ComponentError(RuntimeError): msg = str(sys.exc_info()[1]) else: msg = 'Unknown error.' - print("##### ComponentError by %s's %s: %s" % ( + log.error("ComponentError by %s's %s: %s" % ( caller.name, name, msg)) # Don't create multiple windows for quickly repeated messages diff --git a/src/components/spectrum.py b/src/components/spectrum.py index 666e20a..32763c0 100644 --- a/src/components/spectrum.py +++ b/src/components/spectrum.py @@ -4,6 +4,7 @@ import os import math import subprocess import time +import logging from component import Component from toolkit.frame import BlankFrame, scale @@ -13,6 +14,9 @@ from toolkit.ffmpeg import ( ) +log = logging.getLogger('AVP.Components.Spectrum') + + class Component(Component): name = 'Spectrum' version = '1.0.0' @@ -68,6 +72,7 @@ class Component(Component): if not changedSize \ and not self.changedOptions \ and self.previewFrame is not None: + log.debug('Comp #%s is reusing old preview frame' % self.compPos) return self.previewFrame frame = self.getPreviewFrame() @@ -131,13 +136,14 @@ class Component(Component): '-frames:v', '1', ]) logFilename = os.path.join( - self.core.dataDir, 'preview_%s.log' % str(self.compPos)) - with open(logFilename, 'w') as log: - log.write(" ".join(command) + '\n\n') - with open(logFilename, 'a') as log: + 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=log, bufsize=10**8 + stderr=logf, bufsize=10**8 ) byteFrame = pipe.stdout.read(self.chunkSize) closePipe(pipe) diff --git a/src/components/video.py b/src/components/video.py index b6bdd52..a189f60 100644 --- a/src/components/video.py +++ b/src/components/video.py @@ -3,6 +3,7 @@ from PyQt5 import QtGui, QtCore, QtWidgets import os import math import subprocess +import logging from component import Component from toolkit.frame import BlankFrame, scale @@ -10,6 +11,9 @@ from toolkit.ffmpeg import openPipe, closePipe, testAudioStream, FfmpegVideo from toolkit import checkOutput +log = logging.getLogger('AVP.Components.Video') + + class Component(Component): name = 'Video' version = '1.0.0' @@ -134,10 +138,17 @@ class Component(Component): '-ss', '90', '-frames:v', '1', ]) - pipe = openPipe( - command, stdin=subprocess.DEVNULL, stdout=subprocess.PIPE, - stderr=subprocess.DEVNULL, bufsize=10**8 - ) + + 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 + ) byteFrame = pipe.stdout.read(self.chunkSize) closePipe(pipe) diff --git a/src/components/waveform.py b/src/components/waveform.py index 71cbcac..1517be2 100644 --- a/src/components/waveform.py +++ b/src/components/waveform.py @@ -4,6 +4,7 @@ from PyQt5.QtGui import QColor import os import math import subprocess +import logging from component import Component from toolkit.frame import BlankFrame, scale @@ -13,6 +14,9 @@ from toolkit.ffmpeg import ( ) +log = logging.getLogger('AVP.Components.Waveform') + + class Component(Component): name = 'Waveform' version = '1.0.0' @@ -106,10 +110,16 @@ class Component(Component): '-codec:v', 'rawvideo', '-', '-frames:v', '1', ]) - pipe = openPipe( - command, stdin=subprocess.DEVNULL, stdout=subprocess.PIPE, - stderr=subprocess.DEVNULL, bufsize=10**8 - ) + 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 + ) byteFrame = pipe.stdout.read(self.chunkSize) closePipe(pipe) diff --git a/src/core.py b/src/core.py index 61905eb..4023542 100644 --- a/src/core.py +++ b/src/core.py @@ -7,11 +7,17 @@ import sys import os import json from importlib import import_module +import logging import toolkit import video_thread +log = logging.getLogger('AVP.Core') +STDOUT_LOGLVL = logging.WARNING +FILE_LOGLVL = logging.DEBUG + + class Core: ''' MainWindow and Command module both use an instance of this class @@ -35,6 +41,7 @@ class Core: continue elif ext == '.py': yield name + log.debug('Importing component modules') self.modules = [ import_module('components.%s' % name) for name in findComponents() @@ -67,7 +74,7 @@ class Core: compPos = len(self.selectedComponents) if len(self.selectedComponents) > 50: return None - + log.debug('Inserting Component from module #%s' % moduleIndex) component = self.modules[moduleIndex].Component( moduleIndex, compPos, self ) @@ -104,7 +111,7 @@ class Core: self.componentListChanged() def updateComponent(self, i): - # print('updating %s' % self.selectedComponents[i]) + log.debug('Updating %s #%s' % (self.selectedComponents[i], str(i))) self.selectedComponents[i].update() def moduleIndexFor(self, compName): @@ -125,12 +132,17 @@ class Core: if not saveValueStore: return False try: - self.selectedComponents[compIndex].loadPreset( + comp = self.selectedComponents[compIndex] + comp.loadPreset( saveValueStore, presetName ) except KeyError as e: - print('preset missing value: %s' % e) + log.warning( + '%s #%s\'s preset is missing value: %s' % ( + comp.name, str(compIndex), str(e) + ) + ) self.savedPresets[presetName] = dict(saveValueStore) return True @@ -206,7 +218,7 @@ class Core: preset['preset'] ) except KeyError as e: - print('%s missing value: %s' % ( + log.warning('%s missing value: %s' % ( self.selectedComponents[i], e) ) @@ -224,7 +236,7 @@ class Core: typ, value, tb = data if typ.__name__ == 'KeyError': # probably just an old version, still loadable - print('file missing value: %s' % value) + log.warning('Project file missing value: %s' % value) return if hasattr(loader, 'createNewProject'): loader.createNewProject(prompt=False) @@ -244,6 +256,7 @@ class Core: Returns dictionary with section names as the keys, each one contains a list of tuples: (compName, version, compPresetDict) ''' + log.debug('Parsing av file: %s' % filepath) validSections = ( 'Components', 'Settings', @@ -362,6 +375,7 @@ class Core: def createProjectFile(self, filepath, window=None): '''Create a project file (.avp) using the current program state''' + log.info('Creating %s' % filepath) settingsKeys = [ 'componentDir', 'inputDir', @@ -374,9 +388,8 @@ class Core: filepath += '.avp' if os.path.exists(filepath): os.remove(filepath) - with open(filepath, 'w') as f: - print('creating %s' % filepath) + with open(filepath, 'w') as f: f.write('[Components]\n') for comp in self.selectedComponents: saveValueStore = comp.savePreset() @@ -443,6 +456,7 @@ class Core: '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'), 'encoderOptions': encoderOptions, @@ -489,6 +503,13 @@ class Core: setattr(cls, classvar, val) cls.loadDefaultSettings() + if not os.path.exists(cls.dataDir): + os.makedirs(cls.dataDir) + for neededDirectory in ( + cls.presetDir, cls.logDir, cls.settings.value("projectDir")): + if not os.path.exists(neededDirectory): + os.mkdir(neededDirectory) + cls.makeLogger() @classmethod def loadDefaultSettings(cls): @@ -522,6 +543,42 @@ class Core: if val in ('true', 'false'): cls.settings.setValue(key, True if val == 'true' else False) + @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 + logStream = logging.StreamHandler() + logStream.setLevel(STDOUT_LOGLVL) + + # create formatters and put everything together + fileFormatter = logging.Formatter( + '[%(asctime)s] <%(name)s> %(levelname)s: %(message)s' + ) + streamFormatter = logging.Formatter( + '<%(name)s> %(message)s' + ) + logFile.setFormatter(fileFormatter) + libLogFile.setFormatter(fileFormatter) + logStream.setFormatter(streamFormatter) + log = logging.getLogger('AVP') + log.setLevel(FILE_LOGLVL) + log.addHandler(logFile) + log.addHandler(logStream) + libLog = logging.getLogger() + libLog.setLevel(FILE_LOGLVL) + libLog.addHandler(libLogFile) # always store settings in class variables even if a Core object is not created Core.storeSettings() diff --git a/src/main.py b/src/main.py index 421a09f..3a6fbe7 100644 --- a/src/main.py +++ b/src/main.py @@ -1,10 +1,14 @@ from PyQt5 import uic, QtWidgets import sys import os +import logging from __init__ import wd +log = logging.getLogger('AVP.Entrypoint') + + def main(): app = QtWidgets.QApplication(sys.argv) app.setApplicationName("audio-visualizer") @@ -28,6 +32,7 @@ def main(): from command import Command main = Command() + log.debug("Finished creating command object") elif mode == 'GUI': from mainwindow import MainWindow @@ -48,6 +53,7 @@ def main(): # window.verticalLayout_2.setContentsMargins(0, topMargin, 0, 0) main = MainWindow(window, proj) + log.debug("Finished creating main window") window.raise_() signal.signal(signal.SIGINT, main.cleanUp) diff --git a/src/mainwindow.py b/src/mainwindow.py index 789a6e7..114015c 100644 --- a/src/mainwindow.py +++ b/src/mainwindow.py @@ -13,6 +13,7 @@ import os import signal import filecmp import time +import logging from core import Core import preview_thread @@ -20,11 +21,15 @@ from presetmanager import PresetManager from toolkit import disableWhenEncoding, disableWhenOpeningProject, checkOutput +log = logging.getLogger('AVP.MainWindow') + + class PreviewWindow(QtWidgets.QLabel): ''' Paints the preview QLabel and maintains the aspect ratio when the window is resized. ''' + log = logging.getLogger('AVP.MainWindow.Preview') def __init__(self, parent, img): super(PreviewWindow, self).__init__() @@ -58,11 +63,15 @@ class PreviewWindow(QtWidgets.QLabel): if i >= 0: component = self.parent.core.selectedComponents[i] if not hasattr(component, 'previewClickEvent'): + self.log.info('Ignored click event') return pos = (event.x(), event.y()) size = (self.width(), self.height()) + butt = event.button() + self.log.info('Click event for #%s: %s button %s' % ( + i, pos, butt)) component.previewClickEvent( - pos, size, event.button() + pos, size, butt ) self.parent.core.updateComponent(i) @@ -91,9 +100,10 @@ class MainWindow(QtWidgets.QMainWindow): def __init__(self, window, project): QtWidgets.QMainWindow.__init__(self) - # print('main thread id: {}'.format(QtCore.QThread.currentThreadId())) self.window = window self.core = Core() + log.debug( + 'Main thread id: {}'.format(QtCore.QThread.currentThreadId())) # widgets of component settings self.pages = [] @@ -103,27 +113,23 @@ class MainWindow(QtWidgets.QMainWindow): self.autosaveCooldown = 0.2 self.encoding = False - # Create data directory, load/create settings + # Find settings created by Core object self.dataDir = Core.dataDir self.presetDir = Core.presetDir self.autosavePath = os.path.join(self.dataDir, 'autosave.avp') self.settings = Core.settings + self.presetManager = PresetManager( uic.loadUi( os.path.join(Core.wd, 'presetmanager.ui')), self) - if not os.path.exists(self.dataDir): - os.makedirs(self.dataDir) - for neededDirectory in ( - self.presetDir, self.settings.value("projectDir")): - if not os.path.exists(neededDirectory): - os.mkdir(neededDirectory) - # Create the preview window and its thread, queues, and timers + log.debug('Creating preview window') self.previewWindow = PreviewWindow(self, os.path.join( Core.wd, "background.png")) window.verticalLayout_previewWrapper.addWidget(self.previewWindow) + log.debug('Starting preview thread') self.previewQueue = Queue() self.previewThread = QtCore.QThread(self) self.previewWorker = preview_thread.Worker(self, self.previewQueue) @@ -132,6 +138,7 @@ class MainWindow(QtWidgets.QMainWindow): self.previewWorker.imageCreated.connect(self.showPreviewImage) self.previewThread.start() + log.debug('Starting preview timer') self.timer = QtCore.QTimer(self) self.timer.timeout.connect(self.processTask.emit) self.timer.start(500) @@ -141,6 +148,8 @@ class MainWindow(QtWidgets.QMainWindow): componentList = self.window.listWidget_componentList if sys.platform == 'darwin': + log.debug( + 'Darwin detected: showing progress label below progress bar') window.progressBar_createVideo.setTextVisible(False) else: window.progressLabel.setHidden(True) @@ -276,6 +285,7 @@ class MainWindow(QtWidgets.QMainWindow): ) self.updateWindowTitle() + log.debug('Showing main window') window.show() if project and project != self.autosavePath: @@ -398,6 +408,7 @@ class MainWindow(QtWidgets.QMainWindow): @QtCore.pyqtSlot() def cleanUp(self, *args): + log.info('Ending the preview thread') self.timer.stop() self.previewThread.quit() self.previewThread.wait() @@ -414,11 +425,12 @@ class MainWindow(QtWidgets.QMainWindow): appName += '*' except AttributeError: pass + log.debug('Setting window title to %s' % appName) self.window.setWindowTitle(appName) @QtCore.pyqtSlot(int, dict) def updateComponentTitle(self, pos, presetStore=False): - if type(presetStore) == dict: + if type(presetStore) is dict: name = presetStore['preset'] if name is None or name not in self.core.savedPresets: modified = False @@ -428,11 +440,20 @@ class MainWindow(QtWidgets.QMainWindow): modified = bool(presetStore) if pos < 0: pos = len(self.core.selectedComponents)-1 - title = str(self.core.selectedComponents[pos]) + name = str(self.core.selectedComponents[pos]) + title = str(name) if self.core.selectedComponents[pos].currentPreset: title += ' - %s' % self.core.selectedComponents[pos].currentPreset if modified: title += '*' + if type(presetStore) is bool: + log.debug('Forcing %s #%s\'s modified status to %s: %s' % ( + name, pos, modified, title + )) + else: + log.debug('Setting %s #%s\'s title: %s' % ( + name, pos, title + )) self.window.listWidget_componentList.item(pos).setText(title) def updateCodecs(self): @@ -493,6 +514,8 @@ class MainWindow(QtWidgets.QMainWindow): elif force or timeDiff >= self.autosaveCooldown * 5: self.autosaveCooldown = 0.2 self.autosaveTimes.insert(0, self.lastAutosave) + else: + log.debug('Autosave rejected by cooldown') def autosaveExists(self, identical=True): '''Determines if creating the autosave should be blocked.''' @@ -500,9 +523,14 @@ class MainWindow(QtWidgets.QMainWindow): if self.currentProject and os.path.exists(self.autosavePath) \ and filecmp.cmp( self.autosavePath, self.currentProject) == identical: + log.debug( + 'Autosave found %s to be identical' % \ + 'not' if not identical else '' + ) return True except FileNotFoundError: - print('project file couldn\'t be located:', self.currentProject) + log.error( + 'Project file couldn\'t be located:', self.currentProject) return identical return False @@ -543,7 +571,7 @@ class MainWindow(QtWidgets.QMainWindow): self.window.lineEdit_outputFile.setText(fileName) def stopVideo(self): - print('stop') + log.info('Export cancelled') self.videoWorker.cancel() self.canceled = True @@ -773,6 +801,7 @@ class MainWindow(QtWidgets.QMainWindow): mousePos = -1 else: mousePos = mousePos.index(True) + log.debug('Click component list row %s' % mousePos) return mousePos @disableWhenEncoding diff --git a/src/preview_thread.py b/src/preview_thread.py index bb22f0c..9615884 100644 --- a/src/preview_thread.py +++ b/src/preview_thread.py @@ -8,11 +8,15 @@ from PIL import Image from PIL.ImageQt import ImageQt from queue import Queue, Empty import os +import logging from toolkit.frame import Checkerboard from toolkit import disableWhenOpeningProject +log = logging.getLogger("AVP.PreviewThread") + + class Worker(QtCore.QObject): imageCreated = pyqtSignal(QtGui.QImage) @@ -55,7 +59,7 @@ class Worker(QtCore.QObject): self.background = Checkerboard(width, height) frame = self.background.copy() - + log.debug('Creating new preview frame') components = nextPreviewInformation["components"] for component in reversed(components): try: @@ -73,10 +77,11 @@ class Worker(QtCore.QObject): newFrame.width, newFrame.height, width, height ) + log.critical(errMsg) self.error.emit(errMsg) break except RuntimeError as e: - print(e) + log.error(str(e)) else: self.frame = ImageQt(frame) self.imageCreated.emit(QtGui.QImage(self.frame)) diff --git a/src/toolkit/ffmpeg.py b/src/toolkit/ffmpeg.py index 3421049..6ab445c 100644 --- a/src/toolkit/ffmpeg.py +++ b/src/toolkit/ffmpeg.py @@ -8,12 +8,16 @@ import subprocess import threading import signal from queue import PriorityQueue +import logging import core from toolkit.common import checkOutput, pipeWrapper from component import ComponentError +log = logging.getLogger('AVP.Toolkit.Ffmpeg') + + class FfmpegVideo: '''Opens a pipe to ffmpeg and stores a buffer of raw video frames.''' @@ -88,13 +92,14 @@ class FfmpegVideo: def fillBuffer(self): logFilename = os.path.join( - core.Core.dataDir, 'extra_%s.log' % str(self.component.compPos)) - with open(logFilename, 'w') as log: - log.write(" ".join(self.command) + '\n\n') - with open(logFilename, 'a') as log: + 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=log, bufsize=10**8 + stderr=logf, bufsize=10**8 ) while True: if self.parent.canceled: @@ -375,7 +380,7 @@ def getAudioDuration(filename): try: info = fileInfo.decode("utf-8").split('\n') except UnicodeDecodeError as e: - print('Unicode error:', str(e)) + log.error('Unicode error:', str(e)) return False for line in info: @@ -398,7 +403,7 @@ def readAudioFile(filename, videoWorker): ''' duration = getAudioDuration(filename) if not duration: - print('Audio file doesn\'t exist or unreadable.') + log.error('Audio file doesn\'t exist or unreadable.') return command = [ diff --git a/src/toolkit/frame.py b/src/toolkit/frame.py index 7e83d58..02f9229 100644 --- a/src/toolkit/frame.py +++ b/src/toolkit/frame.py @@ -7,10 +7,14 @@ from PIL.ImageQt import ImageQt import sys import os import math +import logging import core +log = logging.getLogger('AVP.Toolkit.Frame') + + class FramePainter(QtGui.QPainter): ''' A QPainter for a blank frame, which can be converted into a @@ -79,6 +83,7 @@ def FloodFrame(width, height, RgbaTuple): @defaultSize def BlankFrame(width, height): '''The base frame used by each component to start drawing.''' + log.debug('Creating new %s*%s blank frame' % (width, height)) return FloodFrame(width, height, (0, 0, 0, 0)) @@ -88,6 +93,7 @@ def Checkerboard(width, height): A checkerboard to represent transparency to the user. TODO: Would be cool to generate this image with numpy instead. ''' + log.debug('Creating new %s*%s checkerboard' % (width, height)) image = FloodFrame(1920, 1080, (0, 0, 0, 0)) image.paste(Image.open( os.path.join(core.Core.wd, "background.png")), diff --git a/src/video_thread.py b/src/video_thread.py index 5963def..e7e4136 100644 --- a/src/video_thread.py +++ b/src/video_thread.py @@ -17,6 +17,7 @@ from queue import Queue, PriorityQueue from threading import Thread, Event import time import signal +import logging from component import ComponentError from toolkit.frame import Checkerboard @@ -26,6 +27,9 @@ from toolkit.ffmpeg import ( ) +log = logging.getLogger("AVP.VideoThread") + + class Worker(QtCore.QObject): imageCreated = pyqtSignal(['QImage']) @@ -92,7 +96,7 @@ class Worker(QtCore.QObject): by a renderNode later. All indices are multiples of self.sampleSize sampleSize * frameNo = audioI, AKA audio data starting at frameNo ''' - print('Dispatching Frames for Compositing...') + log.debug('Dispatching Frames for Compositing...') for audioI in range(0, len(self.completeAudioArray), self.sampleSize): self.compositeQueue.put(audioI) @@ -156,10 +160,12 @@ class Worker(QtCore.QObject): self.progressBarUpdate.emit(0) self.progressBarSetText.emit("Starting components...") canceledByComponent = False - print('Loaded Components:', ", ".join([ + initText = ", ".join([ "%s) %s" % (num, str(component)) for num, component in enumerate(reversed(self.components)) - ])) + ]) + print('Loaded Components:', initText) + log.info('Calling preFrameRender for %s' % initText) self.staticComponents = {} for compNo, comp in enumerate(reversed(self.components)): try: @@ -191,6 +197,7 @@ class Worker(QtCore.QObject): compError[0] ) ) + log.critical(errMsg) comp._error.emit(errMsg, compError[1]) break if 'static' in compProps: @@ -199,7 +206,7 @@ class Worker(QtCore.QObject): if self.canceled: if canceledByComponent: - print('Export cancelled by component #%s (%s): %s' % ( + log.critical('Export cancelled by component #%s (%s): %s' % ( compNo, comp.name, 'No message.' if comp.error() is None else ( @@ -224,8 +231,11 @@ class Worker(QtCore.QObject): ffmpegCommand = createFfmpegCommand( self.inputFile, self.outputFile, self.components, duration ) - print('###### FFMPEG COMMAND ######\n%s' % " ".join(ffmpegCommand)) + cmd = " ".join(ffmpegCommand) + print('###### FFMPEG COMMAND ######\n%s' % cmd) print('############################') + log.info('Opening pipe to ffmpeg') + log.info(cmd) self.out_pipe = openPipe( ffmpegCommand, stdin=sp.PIPE, stdout=sys.stdout, stderr=sys.stdout ) @@ -298,9 +308,9 @@ class Worker(QtCore.QObject): try: self.out_pipe.stdin.close() except BrokenPipeError: - print('Broken pipe to ffmpeg!') + log.error('Broken pipe to ffmpeg!') if self.out_pipe.stderr is not None: - print(self.out_pipe.stderr.read()) + log.error(self.out_pipe.stderr.read()) self.out_pipe.stderr.close() self.error = True self.out_pipe.wait()