From 95b87f5b7b374633ea5be303fdf805f7961fdf16 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 8 Jan 2021 14:25:49 +0000 Subject: [PATCH 1/5] monitor: Detect shutdown and bail in log reading loop This should mean not even generating <> Tk events once self.thread == None. --- monitor.py | 5 +++++ 1 file changed, 5 insertions(+) diff --git a/monitor.py b/monitor.py index 3ecb3a0a..b86a8590 100644 --- a/monitor.py +++ b/monitor.py @@ -327,6 +327,11 @@ class EDLogs(FileSystemEventHandler): # type: ignore # See below loghandle.seek(0, SEEK_END) # required to make macOS notice log change over SMB loghandle.seek(log_pos, SEEK_SET) # reset EOF flag # TODO: log_pos reported as possibly unbound for line in loghandle: + # Paranoia check to see if we're shutting down + if threading.current_thread() != self.thread: + logger.info("We're not meant to be running, exiting...") + return # Terminate + if b'"event":"Location"' in line: logger.trace('Found "Location" event, appending to event_queue') From 8a0a82fe43cc34853ba7e287915c86010b332c25 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 8 Jan 2021 14:28:10 +0000 Subject: [PATCH 2/5] monitor: Bail from get_entry() if self.thread is None If there's no thread to have sent the message then we shouldn't care about it as this means we're in shutdown. --- monitor.py | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/monitor.py b/monitor.py index b86a8590..792d2a77 100644 --- a/monitor.py +++ b/monitor.py @@ -828,6 +828,10 @@ class EDLogs(FileSystemEventHandler): # type: ignore # See below :return: dict representing the event """ + if self.thread is None: + logger.debug('Called whilst self.thread is None, returning') + return None + if not self.event_queue: logger.debug('Called with no event_queue') return None From be18f36e543568e1509ab78a161aeae1b9753828 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 8 Jan 2021 14:31:54 +0000 Subject: [PATCH 3/5] EDMarketConnector: Bail in AppWindow.journal_entry if monitor.thread is None monitor.thread should only be none when there's a <> to process if we're in shutdown, in which case we do *not* want to be processing journal events. --- EDMarketConnector.py | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/EDMarketConnector.py b/EDMarketConnector.py index 9a03547e..155415d3 100755 --- a/EDMarketConnector.py +++ b/EDMarketConnector.py @@ -743,6 +743,10 @@ class AppWindow(object): 'FlightCon': _('Helm'), # Multicrew role }.get(role, role) + if monitor.thread is None: + logger.debug('monitor.thread is None, assuming shutdown and returning') + return + while True: entry = monitor.get_entry() if not entry: From 81974f66ec3eb8cabc5b7484476e42a68e3bc629 Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 8 Jan 2021 14:45:08 +0000 Subject: [PATCH 4/5] monitor/dashboard: move away from `if __debug__` This includes changing one print_exc() to logger.exception() --- dashboard.py | 21 ++++++++++----------- monitor.py | 3 +-- 2 files changed, 11 insertions(+), 13 deletions(-) diff --git a/dashboard.py b/dashboard.py index 43ac67a7..4e7f9ce6 100644 --- a/dashboard.py +++ b/dashboard.py @@ -1,16 +1,13 @@ import json from calendar import timegm -from operator import itemgetter -from os import listdir from os.path import isdir, isfile, join, getsize from sys import platform import time -if __debug__: - from traceback import print_exc - from config import config +from EDMCLogging import get_main_logger +logger = get_main_logger() if platform=='darwin': from watchdog.observers import Observer @@ -67,8 +64,10 @@ class Dashboard(FileSystemEventHandler): if not self.observed and not polling: self.observed = self.observer.schedule(self, self.currentdir) - if __debug__: - print('%s Dashboard "%s"' % (polling and 'Polling' or 'Monitoring', self.currentdir)) + if polling: + logger.debug(f'Polling Dashboard "{self.currentdir}"') + else: + logger.debug(f'Monitoring Dashboard "{self.currentdir}"') # Even if we're not intending to poll, poll at least once to process pre-existing # data and to check whether the watchdog thread has crashed due to events not @@ -78,8 +77,8 @@ class Dashboard(FileSystemEventHandler): return True def stop(self): - if __debug__: - print('Stopping monitoring Dashboard') + logger.debug('Stopping monitoring Dashboard') + self.currentdir = None if self.observed: self.observed = None @@ -127,8 +126,8 @@ class Dashboard(FileSystemEventHandler): self.status != entry): self.status = entry self.root.event_generate('<>', when="tail") - except: - if __debug__: print_exc() + except Exception: + logger.exception('Reading Status.json') # singleton dashboard = Dashboard() diff --git a/monitor.py b/monitor.py index 792d2a77..9b57ef2d 100644 --- a/monitor.py +++ b/monitor.py @@ -187,8 +187,7 @@ class EDLogs(FileSystemEventHandler): # type: ignore # See below return True def stop(self): - if __debug__: - print('Stopping monitoring Journal') + logger.debug('Stopping monitoring Journal') self.currentdir = None self.version = None From 90ddd4e1e3991186f1d742d2e8892bedf1e3237b Mon Sep 17 00:00:00 2001 From: Athanasius Date: Fri, 8 Jan 2021 14:53:30 +0000 Subject: [PATCH 5/5] plugins: Log plugin names as we ask them to stop, and when we're done with them all This should point the finger at any plugin(s) that aren't stopping properly. Well, at least those that are hanging *in* their `plugin_stop()`. --- plug.py | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/plug.py b/plug.py index dd960704..07d43dfb 100644 --- a/plug.py +++ b/plug.py @@ -251,10 +251,14 @@ def notify_stop(): plugin_stop = plugin._get_func('plugin_stop') if plugin_stop: try: + logger.info(f'Asking plugin "{plugin.name}" to stop...') newerror = plugin_stop() error = error or newerror except Exception as e: logger.exception(f'Plugin "{plugin.name}" failed') + + logger.info('Done') + return error