logging, threading and file watchers, finally it's going well.

gui/deploy.py

@@ -1,6 +1,7 @@
+from multiprocessing.util import get_logger
+
 import jinja2 as j2
 import yaml
-import subprocess
 import shutil
 import requests
 import os
@@ -15,8 +16,7 @@ from PIL import Image
 from mutagen.oggvorbis import OggVorbis
 from distutils.dir_util import copy_tree
 from pathlib import Path
-from widgets import create_logger
+from subprocess import PIPE, STDOUT, CalledProcessError, CompletedProcess, Popen
-
 
 def rmfulldir(dirpath):
     try:
@@ -43,9 +43,23 @@ def get_ffmpeg_version():
     return ffmpeg_version
 
 
+def stream_command(args, *, stdout_handler=logging.info, check=True, text=True,
+                   stdout=PIPE, stderr=STDOUT, **kwargs):
+    """Mimic subprocess.run, while processing the command output in real time."""
+    with Popen(args, text=text, stdout=stdout, stderr=stderr, **kwargs) as process:
+        for line in process.stdout:
+            stdout_handler(line[:-1])
+    return_code = process.poll()
+    if check and return_code:
+        raise CalledProcessError(return_code, process.args)
+    return CompletedProcess(process.args, return_code)
+
+
 class Deployer:
     def __init__(self, logging_handler: logging.Handler = None):
-        logging.basicConfig(stream=sys.stdout, level=logging.INFO)
+        logging.basicConfig(stream=sys.stdout, level=logging.INFO,
+                            format='[%(asctime)s| %(levelname)s| %(processName)s] %(message)s')
+
         self.logger = logging.getLogger()
 
         if logging_handler is not None:
@@ -57,8 +71,6 @@ class Deployer:
         self.source_dir = "./source"
         self.install_dir = self.find_install_dir()
 
-    def write_something(self):
-        self.logger.info("lalala")
 
     def find_install_dir(self):
         self.logger.info("Trying to find Barotraumma install folder")
@@ -94,15 +106,16 @@ class Deployer:
         self.download_and_extract(url_git_source, out_git_archive, subdir="/git")
 
     def download_and_extract(self, url_source, out_archive, subdir=""):
-        self.logger.info(f"Downloading {url_source}, this may take a while.")
+        self.logger.info(f"Downloading {url_source}. This may take a while.")
 
         download_via_requests(url_source, out_archive)
         time.sleep(0.7)
         self.logger.info("Download complete.")
 
-        self.logger.info(f"Extracting {out_archive}")
+        self.logger.info(f"Extracting {out_archive} with 7z")
         extract = [f"{self.utils_dir}/7z/7za.exe", "x", out_archive, "-o" f"{self.utils_dir}{subdir}"]
-        subprocess.call(extract)
+
+        stream_command(extract, stdout_handler=self.logger.info)
 
         time.sleep(0.7)
         self.logger.info("Removing " + out_archive)
@@ -111,7 +124,7 @@ class Deployer:
     def update(self):
         self.logger.info(f"checking for updates via git pull.")
         pull = [f"{self.utils_dir}/git/bin/git.exe", "pull"]
-        subprocess.call(pull)
+        stream_command(pull, stdout_handler=self.logger.info)
 
     def fetch_and_cut_song(self, tape, ffmpeg_version):
         python_executable = f"{self.utils_dir}/python-3.9.7-embed-amd64/python.exe"
@@ -126,7 +139,7 @@ class Deployer:
             # this is done in a separate python script because subprocess.call makes sure that the
             # download process is finished before trying to cut the song
 
-            subprocess.call(fetch)
+            stream_command(fetch, stdout_handler=self.logger.info)
 
             time.sleep(0.1)
 
@@ -140,7 +153,7 @@ class Deployer:
                 cut = cut[:-7] + ["-to", f"{tape['source']['end']}"] + cut[-7:]
 
             try:
-                subprocess.call(cut)
+                stream_command(cut, stdout_handler=self.logger.info)
             except FileNotFoundError:
                 print("ffmpeg not in utils directory. Run python install_dependencies.py "
                       "or download the latest release version manually.")
@@ -152,7 +165,7 @@ class Deployer:
                    f"{self.music_dir}/{tape['identifier']}-walkman.ogg"]
 
         try:
-            subprocess.call(walkman)
+            stream_command(walkman, stdout_handler=self.logger.info)
         except FileNotFoundError:
             self.logger.error("ffmpeg not in utils directory. Run python install_dependencies.py "
                               "or download the latest release version manually.")

gui/installer.py

@@ -3,6 +3,7 @@ import os
 import getpass
 import logging
 import time
+from threading import Thread
 
 from tape_editor_widgets import *
 from widgets import LabelWebLink
@@ -92,7 +93,7 @@ class OptionsWidget(QWidget):
         self.options_gbox.setLayout(self.options_hbox)
 
         # Update widget
-        self.update_widget = UpdateWidget(self)
+        self.update_widget = UpdateWidget(self, self.deployer)
         # Install widget
         self.install_widget = InstallWidget(self, self.deployer)
         # Console widget
@@ -128,12 +129,6 @@ class OptionsWidget(QWidget):
                 "durability": self.cbox_durability.isChecked(),
                 "repair": self.cbox_repair.isChecked()}
 
-    def run_process(self, function, arguments):
-        logger = create_logger()
-        logger.info('Starting pooling')
-        p = multiprocessing.Pool()
-        p.apply_async(function, arguments)
-
 
 # TODO: implement random local mod name
 
@@ -388,10 +383,11 @@ class ValidationWidget(QWidget):
 
 
 class UpdateWidget(QGroupBox):
-    def __init__(self, parent: QWidget):
+    def __init__(self, parent: QWidget, deployer: Deployer):
         super().__init__("Update")
 
         self.parent = parent
+        self.deployer = deployer
 
         hr_html_string = "<hr style=\"background-color:gray;\">"
         self.grid = QGridLayout(self)
@@ -416,16 +412,21 @@ class UpdateWidget(QGroupBox):
         self.git_update_label = QLabel("Download update from git")
         self.git_update_label_link = LabelWebLink("https://git.kompot.si/jaka/barotrauma-sunken-tapes")
         self.git_update_pushbutton = QPushButton("Update")
+        self.git_update_pushbutton.clicked.connect(self.update_action)
         self.grid.addWidget(self.git_update_checkbox, 10, 0)
         self.grid.addWidget(self.git_update_label, 10, 1)
         self.grid.addWidget(self.git_update_label_link, 11, 1)
         self.grid.addWidget(self.git_update_pushbutton, 10, 2)
         self.grid.addWidget(QLabel(hr_html_string), 12, 0, 1, 3)
 
+        self.git_dir_watcher = QFileSystemWatcher()
+        self.git_dir_watcher.addPath(Path(self.git_dir.directory).as_posix())
+        self.git_dir_watcher.directoryChanged.connect(self.does_git_exist)
+
         self.does_git_exist()
 
     def download_git_action(self):
-        self.parent.deployer.download_git()
+        Thread(target=self.deployer.download_git).start()
 
     def does_git_exist(self):
         executable_path = Path("git/bin/git.exe")
@@ -436,8 +437,12 @@ class UpdateWidget(QGroupBox):
 
         self.git_pushbutton.setEnabled(not exists)
         self.git_checkbox.setChecked(exists)
+        self.git_update_pushbutton.setEnabled(exists)
         return exists
 
+    def update_action(self):
+        Thread(target=self.deployer.update).start()        
+
 
 class ConsoleWidget(QGroupBox):
     def __init__(self, parent: QWidget):
@@ -445,6 +450,9 @@ class ConsoleWidget(QGroupBox):
         self.parent = parent
 
         self.console = QPlainTextEdit(self)
+        self.console.setReadOnly(True)
+        self.console.setFont("Consolas")
+        self.console.setMinimumHeight(100)
 
         layout = QVBoxLayout(self)
         layout.addWidget(self.console)
@@ -510,6 +518,10 @@ class InstallWidget(QGroupBox):
 
         self.grid.setRowStretch(50, 20)
 
+        self.utils_dir_watcher = QFileSystemWatcher()
+        self.utils_dir_watcher.addPath(Path(self.ffmpeg_dir.directory).as_posix())
+        self.utils_dir_watcher.directoryChanged.connect(self.does_ffmpeg_exist)
+
         self.does_ffmpeg_exist()
 
     def does_ffmpeg_exist(self):
@@ -525,12 +537,7 @@ class InstallWidget(QGroupBox):
         return exists
 
     def download_ffmpeg_action(self):
-
+        Thread(target=self.deployer.download_ffmpeg).start()
-        self.deployer.write_something()
-
-        #self.parent.run_process(self.deployer.download_ffmpeg, ())
-        #download_ffmpeg(self.ffmpeg_dir.directory)
-        self.does_ffmpeg_exist()
 
     def are_songs_ready(self):
         tapes = self.parent.parent.validation_widget.tapes
@@ -584,9 +591,8 @@ class SignalHandler(logging.Handler):
         super(SignalHandler, self).__init__(*args, **kwargs)
         self.emitter = QSignaler()
 
-    def emit(self, logRecord):
+    def emit(self, log_record: logging.LogRecord):
-        msg = "{0}".format(logRecord.getMessage())
+        self.emitter.log_message.emit(f"{log_record.message}")
-        self.emitter.log_message.emit(msg)
         # When the line below is enabled, logging is immediate/otherwise events
         # on the queue will be processed when the slot has finished.
         # QtGui.qApp.processEvents()

gui/widgets.py

@@ -18,20 +18,6 @@ from pathlib import Path
 from typing import Optional
 
 
-def create_logger():
-    logger = multiprocessing.get_logger()
-    logger.setLevel(logging.INFO)
-    formatter = logging.Formatter('[%(asctime)s| %(levelname)s| %(processName)s] %(message)s')
-    handler = logging.StreamHandler()
-    handler.setFormatter(formatter)
-
-    # this bit will make sure you won't have
-    # duplicated messages in the output
-    if not len(logger.handlers):
-        logger.addHandler(handler)
-    return logger
-
-
 class LabelWebLink(QLabel):
     def __init__(self, text):
         text = f"<a href=\"{text}\">{text.replace('https://', '')}</a>"