Replay pre-init config warnings into the night log (follow-up to #924)

RMS/ConfigReader.py

@@ -21,6 +21,7 @@
 import os
 import sys
 from RMS.CompileArgs import getCompileArgs
+from RMS.Logger import installEarlyLogBuffer
 from RMS.Misc import getRmsRootDir
 from Utils.GenerateTimelapse import isFfmpegWorking
 import matplotlib.colors as mcolors
@@ -737,6 +738,12 @@ def parse(path, strict=True):
 
     """
 
+    # Buffer any warnings raised while parsing (clamped FPS, bad binning, upload disabled on the
+    # default station code, ...) so initLogging can replay them into the night log. Config parsing
+    # runs before logging is initialized in every entry point, and every config load funnels
+    # through here. Idempotent and a no-op once logging is up (see installEarlyLogBuffer).
+    installEarlyLogBuffer()
+
     delimiter = ";"
 
     try:

RMS/Logger.py

@@ -148,6 +148,109 @@ def filter(self, record):
         return any(_inside(p, root) for root in self.allowed_dirs)
 
 
+class EarlyRecordBuffer(logging.Handler):
+    """
+    Keep log records emitted before initLogging so they can be replayed into the night log.
+
+    Every entry point loads the config before it initializes logging, so warnings raised while
+    parsing (clamped FPS, bad binning factor, upload disabled on the default station code) would
+    otherwise only ever reach the console and never the uploaded night log.
+    """
+
+    def __init__(self, capacity=200):
+        logging.Handler.__init__(self)
+
+        self.capacity = capacity
+        self.records = []
+        self.dropped = 0
+
+
+    def emit(self, record):
+
+        # A full buffer just stops collecting - a handler must never raise
+        if len(self.records) < self.capacity:
+            self.records.append(record)
+
+        else:
+            self.dropped += 1
+
+
+class _SuppressReplayedOnConsole(logging.Filter):
+    """
+    Drop records replayed from the early buffer so the console does not show a config warning
+    twice. Such a record was already printed to stderr by _default_handler before logging was
+    initialized; the replay exists only to get it into the night-log FILE. Applied to the console
+    handler only - the file handler still receives the replayed record.
+    """
+
+    def filter(self, record):
+        return not getattr(record, "replayed_from_early_buffer", False)
+
+
+def installEarlyLogBuffer(level=logging.WARNING):
+    """
+    Attach a record buffer to the root logger so records emitted before initLogging can be
+    replayed into the night log. Meant to be called at the start of config parsing (see
+    ConfigReader.parse) - the one path every entry point hits before it initializes logging.
+
+    Idempotent and self-managing:
+      - a second call while still pre-init returns the existing buffer,
+      - once real logging is up (a QueueHandler on the root logger, installed by initLogging or
+        initChildProcess) it is a no-op, since records already reach the night log directly and a
+        buffer installed now would never be drained.
+
+    The console side is already covered by _default_handler, installed on the root logger when
+    this module is imported. Only warnings and above are kept by default, so the buffer cannot
+    fill up with third-party chatter before the interesting records arrive.
+
+    Return:
+        [EarlyRecordBuffer or None] The buffer on the root logger, or None if real logging is
+            already initialized.
+    """
+
+    root = logging.getLogger()
+
+    # Real logging already up: records reach the night log directly, so a buffer installed now
+    # would only accumulate undrained. No-op.
+    for handler in root.handlers:
+        if isinstance(handler, logging.handlers.QueueHandler):
+            return None
+
+    # Pre-init: reuse a buffer if one is already attached
+    for handler in root.handlers:
+        if isinstance(handler, EarlyRecordBuffer):
+            return handler
+
+    buffer_handler = EarlyRecordBuffer()
+    buffer_handler.setLevel(level)
+    root.addHandler(buffer_handler)
+
+    return buffer_handler
+
+
+def _drainEarlyLogBuffer():
+    """
+    Take the records off any early buffer on the root logger.
+
+    Return:
+        [tuple] (records, dropped) - the buffered records and the number that did not fit.
+    """
+
+    root = logging.getLogger()
+
+    records = []
+    dropped = 0
+
+    for handler in root.handlers:
+        if isinstance(handler, EarlyRecordBuffer):
+            records.extend(handler.records)
+            dropped += handler.dropped
+            handler.records = []
+            handler.dropped = 0
+
+    return records, dropped
+
+
 # Reproduced from RMS.Misc due to circular import issue
 def getRmsRootDir():
     """
@@ -485,6 +588,11 @@ def get_log_level(level_str, default=logging.INFO):
             if self.is_initialized:
                 return
 
+            # Take anything logged before this point off the early buffer, so it can be replayed
+            # into the night log once the queue handler is up. Config parsing happens before
+            # initLogging in every entry point, so this is where its warnings come from.
+            early_records, early_dropped = _drainEarlyLogBuffer()
+
             # Remove any default handlers from the root logger
             main_logger = logging.getLogger()
             for handler in main_logger.handlers[:]:
@@ -504,6 +612,21 @@ def get_log_level(level_str, default=logging.INFO):
             main_logger.setLevel(min(console_level, file_level)) # Keep root logger permissive
             main_logger.propagate = False
 
+            # Replay the pre-init records into the night log. handle() skips the logger level
+            # check but still runs the handler filters, so InRmsFilter drops non-RMS records as
+            # usual, and each record keeps its original timestamp. Mark them so the listener's
+            # console handler can skip them: _default_handler already printed them to stderr
+            # before logging came up, so replaying to the console too would double them - the
+            # replay exists only to get them into the night-log file.
+            for record in early_records:
+                record.replayed_from_early_buffer = True
+                main_logger.handle(record)
+
+            if early_dropped:
+                main_logger.warning(
+                    "{:d} log record(s) emitted before logging was initialized were dropped".format(
+                        early_dropped))
+
             # Redirect standard streams
             sys.stderr = LoggerWriter(main_logger, logging.WARNING, stdout_captured=config.log_stdout)
             if config.log_stdout:
@@ -821,6 +944,10 @@ def _listener_configurer(config, log_file_prefix, safedir, console_level=logging
     handler.addFilter(InRmsFilter(config))
     console.addFilter(InRmsFilter(config))
 
+    # Config warnings replayed from the early buffer were already shown on the console before
+    # logging was initialized; keep them in the file but skip them on the console (no double print)
+    console.addFilter(_SuppressReplayedOnConsole())
+
     # Set common formatter for both handlers
     formatter = logging.Formatter(
         fmt='%(asctime)s-%(levelname)s-%(module)s-line:%(lineno)d - %(message)s',

RMS/Reprocess.py

@@ -5,11 +5,9 @@
 
 
 import os
-import sys
 import glob
 import json
 import collections
-import traceback
 import argparse
 import random
 import shutil
@@ -291,9 +289,8 @@ def processNight(night_data_dir, config, detection_results=None, nodetect=False)
             try:
                 generateCalibrationReport(config, night_data_dir, platepar=platepar)
 
-            except Exception as e:
-                log.warning('Generating calibration report failed with the message:\n' + repr(e))
-                log.warning(repr(traceback.format_exception(*sys.exc_info())))
+            except Exception:
+                log.warning('Generating calibration report failed', exc_info=True)
 
 
 
@@ -304,9 +301,8 @@ def processNight(night_data_dir, config, detection_results=None, nodetect=False)
                     save_plot=True, plot_activity=True, color_map=config.shower_color_map, 
                     sporadic_color=config.sporadic_color)
 
-            except Exception as e:
-                log.warning('Shower association failed with the message:\n' + repr(e))
-                log.warning(repr(traceback.format_exception(*sys.exc_info())))
+            except Exception:
+                log.warning('Shower association failed', exc_info=True)
 
 
 
@@ -353,9 +349,8 @@ def processNight(night_data_dir, config, detection_results=None, nodetect=False)
 
 
 
-            except Exception as e:
-                log.warning("Generating a FOV KML file failed with the message:\n" + repr(e))
-                log.warning(repr(traceback.format_exception(*sys.exc_info())))
+            except Exception:
+                log.warning("Generating a FOV KML file failed", exc_info=True)
 
 
 
@@ -365,9 +360,8 @@ def processNight(night_data_dir, config, detection_results=None, nodetect=False)
                 prepareFluxFiles(config, night_data_dir, os.path.join(night_data_dir, ftpdetectinfo_name),
                                  mask=mask, platepar=platepar)
 
-            except Exception as e:
-                log.warning("Preparing flux files failed with the message:\n" + repr(e))
-                log.warning(repr(traceback.format_exception(*sys.exc_info())))
+            except Exception:
+                log.warning("Preparing flux files failed", exc_info=True)
 
 
     else:
@@ -383,9 +377,8 @@ def processNight(night_data_dir, config, detection_results=None, nodetect=False)
     try:
         plotFieldsums(night_data_dir, config)
 
-    except Exception as e:
-        log.warning('Plotting field sums failed with message:\n' + repr(e))
-        log.warning(repr(traceback.format_exception(*sys.exc_info())))
+    except Exception:
+        log.warning('Plotting field sums failed', exc_info=True)
 
 
 
@@ -426,7 +419,7 @@ def processNight(night_data_dir, config, detection_results=None, nodetect=False)
                         tar_path = os.path.join(year_dir, '{}_{}_FT.tar.bz2'.format(config.stationID, day))
 
                         # Use the tarWithProgress function with removal of source
-                        print("Creating archive for {} FT files...".format(day))
+                        log.info("Creating archive for {} FT files...".format(day))
                         archive_success = tarWithProgress(
                             source_dir=day_dir,
                             tar_path=tar_path,
@@ -435,17 +428,17 @@ def processNight(night_data_dir, config, detection_results=None, nodetect=False)
                         )
 
                         if archive_success:
-                            print("Successfully created tar archive at: {}".format(tar_path))
+                            log.info("Successfully created tar archive at: {}".format(tar_path))
                             # Add to extra files for upload
                             extra_files.append(tar_path)
                         else:
-                            print("Archive creation failed, keeping original directory: {}".format(day_dir))
-
-                    except Exception as e:
-                        print("Error in archiving process: {}".format(e))
-        except Exception as e:
-            log.warning('Archiving FT files failed with message:\n' + repr(e))
-            log.warning(repr(traceback.format_exception(*sys.exc_info())))
+                            log.warning("Archive creation failed, keeping original directory: {}".format(
+                                day_dir))
+
+                    except Exception:
+                        log.warning("Error in archiving process for {}".format(day), exc_info=True)
+        except Exception:
+            log.warning('Archiving FT files failed', exc_info=True)
 
 
     log.info('Making a flat...')
@@ -454,9 +447,8 @@ def processNight(night_data_dir, config, detection_results=None, nodetect=False)
     try:
         flat_img = makeFlat(night_data_dir, config)
 
-    except Exception as e:
-        log.warning('Making a flat failed with message:\n' + repr(e))
-        log.warning(repr(traceback.format_exception(*sys.exc_info())))
+    except Exception:
+        log.warning('Making a flat failed', exc_info=True)
         flat_img = None
 
 
@@ -493,9 +485,8 @@ def processNight(night_data_dir, config, detection_results=None, nodetect=False)
             # Add the timelapse to the extra files
             extra_files.append(timelapse_path)
 
-        except Exception as e:
-            log.warning('Generating a timelapse failed with message:\n' + repr(e))
-            log.warning(repr(traceback.format_exception(*sys.exc_info())))
+        except Exception:
+            log.warning('Generating a timelapse failed', exc_info=True)
 
     log.info('Plotting timestamp intervals...')
 
@@ -518,9 +509,8 @@ def processNight(night_data_dir, config, detection_results=None, nodetect=False)
         addObsParam(obs_dict,"dropped_frame_rate",dropped_frame_rate)
 
 
-    except Exception as e:
-        log.warning('Plotting timestamp interval failed with message:\n' + repr(e))
-        log.warning(repr(traceback.format_exception(*sys.exc_info())))
+    except Exception:
+        log.warning('Plotting timestamp interval failed', exc_info=True)
 
     # Generate a config audit report
     log.info('Generate config audit report')
@@ -542,9 +532,8 @@ def processNight(night_data_dir, config, detection_results=None, nodetect=False)
 
         extra_files.append(audit_file_path)
 
-    except Exception as e:
-        log.warning('Generating config audit failed with message:\n' + repr(e))
-        log.warning(repr(traceback.format_exception(*sys.exc_info())))
+    except Exception:
+        log.warning('Generating config audit failed', exc_info=True)
 
 
     ### Add extra files to archive
@@ -669,9 +658,8 @@ def processNight(night_data_dir, config, detection_results=None, nodetect=False)
         extra_files.append(observation_summary_json_path_file_name)
 
 
-    except Exception as e:
-        log.warning('Finalizing Observation Summary failed with message:\n' + repr(e))
-        log.warning(repr(traceback.format_exception(*sys.exc_info())))
+    except Exception:
+        log.warning('Finalizing Observation Summary failed', exc_info=True)
 
     obs_summary_to_log = serialize(config, night_directory=night_data_dir, final=True)
     log.info("\n\nObservation Summary\n===================\n\n" + obs_summary_to_log + "\n\n")

Utils/FRbinViewer.py

@@ -260,9 +260,11 @@ def destroyWindow(self):
             self._mpl_ready = False
 
 
-# On-screen key legend, toggled with the 'h' key while viewing
+# On-screen key legend, toggled with the 'h' key while viewing. Off by default so it never covers
+# the image unless it was asked for - KEY_BANNER is printed to the console when a file is opened.
 KEY_LEGEND = "Keys: SPACE pause | 1 prev file | 2 next line | q quit | h hide keys"
-show_key_legend = True
+KEY_BANNER = "Keys: SPACE pause | 1 prev file | 2 next line | q quit | h show/hide the on-screen legend"
+show_key_legend = False
 
 
 def view(dir_path, ff_path, fr_path, config, save_frames=False, extract_format=None, hide=False,
@@ -300,6 +302,9 @@ def view(dir_path, ff_path, fr_path, config, save_frames=False, extract_format=N
     print('------------------------')
     print('Showing file:', fr_path)
 
+    if not hide:
+        print(KEY_BANNER)
+
 
     if ff_path is None:
         #background = np.zeros((config.height, config.width), np.uint8)

Utils/README.md

@@ -95,7 +95,6 @@ The main pipeline modules live in the `RMS/` package and are run the same way, u
 - **`RMS.CaptureDuration`**: Prints the capture start time and duration for the night (given the station coordinates).
 - **`RMS.DeleteOldObservations`**: Frees up disk space by deleting old observation data.
 - **`RMS.MLFilter`**: Filters detections using the machine-learning meteor classifier.
-- **`RMS.ClearSkyDetector`**: Estimates which parts of the night had clear skies.
 
 Other pipeline modules (e.g. `RMS.ArchiveDetections`, `RMS.UploadManager`, `RMS.DownloadPlatepar`, `RMS.CaptureModeSwitcher`) are internal - their `__main__` blocks are hardcoded test stubs, not user CLIs. They run as part of `RMS.StartCapture`/`RMS.Reprocess`.