Feat (Logging) - Add optional rotating file logging

.gitignore

@@ -10,3 +10,7 @@ warnposeidon_main.txt
 xref-poseidon_main.html
 poseidon_controller_gui.cpython-36.pyc
 .txt
+
+# poseidon logging output
+logs/
+*.log

README.MD

@@ -144,6 +144,14 @@ python3.5 poseidon_main.py
 If the sleds are not moving in the right direction simply rotate the relevant stepper motor plug (that connects to the CNC shield) 180 degrees and plug it back in.
 
 
+## Logging
+The controller mirrors everything it normally prints to the terminal into a rotating log file, so you have a record to look at when troubleshooting pump or serial-connection problems, even on a Raspberry Pi or with the packaged executable where no terminal is visible. The terminal output itself is unchanged.
+
+The log is written to `logs/poseidon.log` in the folder you launch from (rotated, capped at a few MB). Logging is **on by default**; to turn it off, set the environment variable `POSEIDON_LOG=0` before launching.
+
+To run the logging tests, from the `SOFTWARE/` folder run `python -m unittest test_poseidon_logging`.
+
+
 ## How does it work, and how to modify it. (Very easy!)
 The poseidon system was designed to be customizable. It uses the [Raspberry Pi](https://www.raspberrypi.org/)  and [Arduino](https://www.arduino.cc/) electronics boards, which are supported by a strong ecosystem of open source hardware and software, facilitating the implementation of new functionalities.
 

SOFTWARE/poseidon_logging.py

@@ -0,0 +1,182 @@
+#!/usr/bin/env python
+# -*- coding: utf-8 -*-
+
+# ##############################################################################
+# POSEIDON LOGGING
+# ##############################################################################
+# Additive logging for the poseidon controller.
+#
+# This module mirrors everything written to stdout/stderr (all the existing
+# print() calls and any tracebacks) into a rotating log file, while leaving the
+# terminal output exactly as it was.
+# Call setup_logging() once at startup.
+#
+# It is ON by default. To turn it off set the environment variable:
+#     POSEIDON_LOG=0
+# ##############################################################################
+
+import io
+import os
+import sys
+import logging
+import threading
+from logging.handlers import RotatingFileHandler
+
+# Master switch. Logging to file is on unless POSEIDON_LOG is set to "0".
+ENABLED = os.environ.get("POSEIDON_LOG", "1") != "0"
+
+# Where the log lives. Mirrors the ./images pattern used by save_image().
+LOG_DIR = "logs"
+LOG_FILE = os.path.join(LOG_DIR, "poseidon.log")
+
+# 1 MB per file
+MAX_BYTES = 1 * 1024 * 1024
+
+# keep poseidon.log + 3 rotated copies
+BACKUP_COUNT = 3
+
+
+class StreamToLogger:
+    """
+    Captures print() (stdout) and tracebacks (stderr) into a logger
+    without touching any of the existing print() calls.
+
+    Each thread keeps its own line buffer (threading.local), so concurrent
+    prints from worker threads never interleave and no lock is needed.
+
+    fallback is the original stream, used by write()'s re-entrancy guard to
+    avoid recursion when a logging handler itself errors.
+    """
+
+    def __init__(self, logger, level, fallback=None):
+        self.logger = logger
+        self.level = level
+        self.fallback = fallback
+        self._local = threading.local()
+
+    def write(self, message):
+        # Re-entrancy guard: a nested write() (logging reporting its own error)
+        # goes straight to the real stream, not back into the logger.
+        if getattr(self._local, "in_write", False):
+            if self.fallback is not None:
+                self.fallback.write(message)
+            return len(message)
+        self._local.in_write = True
+        try:
+            # print() emits text and \n separately; buffer until newline. Blank lines (poseidon's \n\n spacers) kept.
+            buffer = getattr(self._local, "buffer", "") + message
+            while "\n" in buffer:
+                line, buffer = buffer.split("\n", 1)
+                self.logger.log(self.level, line)
+            self._local.buffer = buffer
+        finally:
+            self._local.in_write = False
+        return len(message)
+
+    def writelines(self, lines):
+        for line in lines:
+            self.write(line)
+
+    def flush(self):
+        buffer = getattr(self._local, "buffer", "")
+        if buffer:
+            self.logger.log(self.level, buffer)
+            self._local.buffer = ""
+
+    # --- file-like interface: delegate to the real stream, honest defaults ---
+    # Code and libraries (colorama, click, subprocess, ...) introspect the
+    # stream they're handed; a bare write/flush object would crash them.
+
+    def isatty(self):
+        if self.fallback is not None and hasattr(self.fallback, "isatty"):
+            return self.fallback.isatty()
+        return False
+
+    def fileno(self):
+        if self.fallback is not None and hasattr(self.fallback, "fileno"):
+            return self.fallback.fileno()
+        raise io.UnsupportedOperation("fileno")
+
+    def writable(self):
+        return True
+
+    def readable(self):
+        return False
+
+    def seekable(self):
+        return False
+
+    @property
+    def encoding(self):
+        return getattr(self.fallback, "encoding", None) or "utf-8"
+
+    @property
+    def errors(self):
+        return getattr(self.fallback, "errors", None) or "strict"
+
+
+class _BelowLevel(logging.Filter):
+    """Passes only records strictly below `level` (keeps ERROR off the stdout console)."""
+
+    def __init__(self, level):
+        super().__init__()
+        self.level = level
+
+    def filter(self, record):
+        return record.levelno < self.level
+
+
+def setup_logging():
+    """
+    Send stdout and stderr to logs/poseidon.log keeping console output as-is.
+    Off when POSEIDON_LOG=0.
+    Does nothing if the log file can't be created.
+    """
+    if not ENABLED:
+        return
+
+    logger = logging.getLogger("poseidon")
+    if logger.handlers:
+        return
+
+    # handlers must write here, not to the replaced sys.stdout
+    orig_stdout = sys.stdout
+    orig_stderr = sys.stderr
+
+    try:
+        os.makedirs(LOG_DIR, exist_ok=True)
+        file_handler = RotatingFileHandler(
+            LOG_FILE, maxBytes=MAX_BYTES, backupCount=BACKUP_COUNT,
+            encoding="utf-8",
+        )
+    except OSError as e:
+        # Can't write the log file: warn on the real console (if any) and
+        # leave stdout/stderr untouched so the app behaves exactly as before.
+        if orig_stderr is not None:
+            orig_stderr.write("poseidon_logging: file logging disabled (%s)\n" % e)
+        return
+
+    file_handler.setFormatter(logging.Formatter(
+        "%(asctime)s %(levelname)s [%(threadName)s] %(message)s"
+    ))
+
+    logger.setLevel(logging.DEBUG)
+    logger.propagate = False
+    logger.addHandler(file_handler)
+
+    # Echo to the console with no prefix: INFO -> stdout, ERROR -> stderr (a None stream is skipped).
+    def add_console(stream, level, max_level=None):
+        if stream is None:
+            return
+        handler = logging.StreamHandler(stream)
+        handler.setFormatter(logging.Formatter("%(message)s"))
+        handler.setLevel(level)
+        if max_level is not None:
+            handler.addFilter(_BelowLevel(max_level))
+        logger.addHandler(handler)
+
+    add_console(orig_stdout, logging.INFO, max_level=logging.ERROR)
+    add_console(orig_stderr, logging.ERROR)
+
+    sys.stdout = StreamToLogger(logger, logging.INFO, orig_stdout)
+    sys.stderr = StreamToLogger(logger, logging.ERROR, orig_stderr)

SOFTWARE/poseidon_main.py

@@ -21,6 +21,7 @@
 from decimal import Decimal
 # This is our window from QtCreator
 import poseidon_controller_gui
+import poseidon_logging
 import pdb
 import traceback, sys
 
@@ -1476,6 +1477,9 @@ def closeEvent(self, event):
 
 # I feel better having one of these
 def main():
+	# Mirror stdout/stderr to a rotating log file (see poseidon_logging).
+	# Additive: terminal output is unchanged. Disable with POSEIDON_LOG=0.
+	poseidon_logging.setup_logging()
 	# a new app instance
 	app = QtWidgets.QApplication(sys.argv)
 	window = MainWindow()