diff --git a/CHANGELOG.md b/CHANGELOG.md index 745fb3b..735d3b9 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,4 +1,5 @@ **unreleased** +- SDR device log messages are now available in the web configuration to simplify troubleshooting **1.2.1** - FifiSDR support fixed (pipeline formats now line up correctly) diff --git a/debian/changelog b/debian/changelog index 92ffe46..6a9bd9d 100644 --- a/debian/changelog +++ b/debian/changelog @@ -1,4 +1,6 @@ openwebrx (1.3.0) UNRELEASED; urgency=low + * SDR device log messages are now available in the web configuration to + simplify troubleshooting -- Jakob Ketterl Fri, 30 Sep 2022 16:47:00 +0000 diff --git a/htdocs/css/admin.css b/htdocs/css/admin.css index b956e9e..742fe32 100644 --- a/htdocs/css/admin.css +++ b/htdocs/css/admin.css @@ -159,4 +159,8 @@ h1 { .imageupload.is-invalid ~ .invalid-feedback { display: block; +} + +.device-log-messages { + max-height: 500px; } \ No newline at end of file diff --git a/htdocs/lib/settings/LogMessages.js b/htdocs/lib/settings/LogMessages.js new file mode 100644 index 0000000..ea2683e --- /dev/null +++ b/htdocs/lib/settings/LogMessages.js @@ -0,0 +1,5 @@ +$.fn.logMessages = function() { + $.each(this, function(){ + $(this).scrollTop(this.scrollHeight); + }); +}; \ No newline at end of file diff --git a/htdocs/settings.js b/htdocs/settings.js index 3a071b5..b1bc736 100644 --- a/htdocs/settings.js +++ b/htdocs/settings.js @@ -8,4 +8,5 @@ $(function(){ $('.optional-section').optionalSection(); $('#scheduler').schedulerInput(); $('.exponential-input').exponentialInput(); + $('.device-log-messages').logMessages(); }); \ No newline at end of file diff --git a/owrx/controllers/assets.py b/owrx/controllers/assets.py index ca3e7f9..2ae1ab1 100644 --- a/owrx/controllers/assets.py +++ b/owrx/controllers/assets.py @@ -158,6 +158,7 @@ class CompiledAssetsController(GzipMixin, ModificationAwareController): "lib/settings/OptionalSection.js", "lib/settings/SchedulerInput.js", "lib/settings/ExponentialInput.js", + "lib/settings/LogMessages.js", "settings.js", ], } diff --git a/owrx/controllers/settings/sdr.py b/owrx/controllers/settings/sdr.py index 40c6185..1f17b46 100644 --- a/owrx/controllers/settings/sdr.py +++ b/owrx/controllers/settings/sdr.py @@ -12,6 +12,7 @@ from owrx.form.input import TextInput, DropdownInput, Option from owrx.form.input.validator import RequiredValidator from owrx.property import PropertyLayer from owrx.breadcrumb import BreadcrumbMixin, Breadcrumb, BreadcrumbItem +from owrx.log import HistoryHandler from abc import ABCMeta, abstractmethod from uuid import uuid4 @@ -279,6 +280,21 @@ class SdrDeviceController(SdrFormControllerWithModal): config.store() return self.send_redirect("{}settings/sdr".format(self.get_document_root())) + def render_sections(self): + handler = HistoryHandler.getHandler("owrx.source.{id}".format(id=self.device_id)) + return """ + {sections} +
+
Recent device log messages
+
+
{messages}
+
+
+ """.format( + sections=super().render_sections(), + messages=handler.getFormattedHistory(), + ) + class NewSdrDeviceController(SettingsFormController): def __init__(self, handler, request, options): diff --git a/owrx/log/__init__.py b/owrx/log/__init__.py new file mode 100644 index 0000000..745a079 --- /dev/null +++ b/owrx/log/__init__.py @@ -0,0 +1,52 @@ +import threading +import os +from logging import Logger, Handler, LogRecord, Formatter + + +class LogPipe(threading.Thread): + + def __init__(self, level: int, logger: Logger, prefix: str = ""): + threading.Thread.__init__(self) + self.daemon = False + self.level = level + self.logger = logger + self.prefix = prefix + self.fdRead, self.fdWrite = os.pipe() + self.pipeReader = os.fdopen(self.fdRead) + self.start() + + def fileno(self): + return self.fdWrite + + def run(self): + for line in iter(self.pipeReader.readline, ''): + self.logger.log(self.level, "{}: {}".format(self.prefix, line.strip('\n'))) + + self.pipeReader.close() + + def close(self): + os.close(self.fdWrite) + + +class HistoryHandler(Handler): + handlers = {} + + @staticmethod + def getHandler(name: str): + if name not in HistoryHandler.handlers: + HistoryHandler.handlers[name] = HistoryHandler() + return HistoryHandler.handlers[name] + + def __init__(self, maxRecords: int = 200): + super().__init__() + self.history = [] + self.maxRecords = maxRecords + self.setFormatter(Formatter(fmt="%(asctime)s - %(name)s - %(levelname)s - %(message)s")) + + def emit(self, record: LogRecord) -> None: + self.history.append(record) + # truncate + self.history = self.history[-self.maxRecords:] + + def getFormattedHistory(self) -> str: + return "\n".join([self.format(r) for r in self.history]) diff --git a/owrx/source/__init__.py b/owrx/source/__init__.py index 618d773..9d4c7bb 100644 --- a/owrx/source/__init__.py +++ b/owrx/source/__init__.py @@ -18,6 +18,7 @@ from owrx.form.input.device import GainInput, SchedulerInput, WaterfallLevelsInp from owrx.form.input.validator import RequiredValidator from owrx.form.section import OptionalSection from owrx.feature import FeatureDetector +from owrx.log import LogPipe, HistoryHandler from typing import List from enum import Enum @@ -114,6 +115,10 @@ class SdrSource(ABC): self.commandMapper = None self.tcpSource = None self.buffer = None + self.logger = logger.getChild(id) if id is not None else logger + self.logger.addHandler(HistoryHandler.getHandler(self.logger.name)) + self.stdoutPipe = None + self.stderrPipe = None self.props = PropertyStack() @@ -185,17 +190,17 @@ class SdrSource(ABC): for id, p in self.props["profiles"].items(): props.replaceLayer(0, p) if "center_freq" not in props: - logger.warning('Profile "%s" does not specify a center_freq', id) + self.logger.warning('Profile "%s" does not specify a center_freq', id) continue if "samp_rate" not in props: - logger.warning('Profile "%s" does not specify a samp_rate', id) + self.logger.warning('Profile "%s" does not specify a samp_rate', id) continue if "start_freq" in props: start_freq = props["start_freq"] srh = props["samp_rate"] / 2 center_freq = props["center_freq"] if start_freq < center_freq - srh or start_freq > center_freq + srh: - logger.warning('start_freq for profile "%s" is out of range', id) + self.logger.warning('start_freq for profile "%s" is out of range', id) def isAlwaysOn(self): return "always-on" in self.props and self.props["always-on"] @@ -225,11 +230,11 @@ class SdrSource(ABC): return [self.getCommandMapper().map(self.getCommandValues())] def activateProfile(self, profile_id): - logger.debug("activating profile {0} for {1}".format(profile_id, self.getId())) + self.logger.debug("activating profile {0} for {1}".format(profile_id, self.getId())) try: self.profileCarousel.switch(profile_id) except KeyError: - logger.warning("invalid profile %s for sdr %s. ignoring", profile_id, self.getId()) + self.logger.warning("invalid profile %s for sdr %s. ignoring", profile_id, self.getId()) def getId(self): return self.id @@ -283,23 +288,37 @@ class SdrSource(ABC): try: self.preStart() except Exception: - logger.exception("Exception during preStart()") + self.logger.exception("Exception during preStart()") cmd = self.getCommand() cmd = [c for c in cmd if c is not None] + self.stdoutPipe = LogPipe(logging.INFO, self.logger, "STDOUT") + self.stderrPipe = LogPipe(logging.WARNING, self.logger, "STDERR") + # don't use shell mode for commands without piping if len(cmd) > 1: # multiple commands with pipes cmd = "|".join(cmd) - self.process = subprocess.Popen(cmd, shell=True, start_new_session=True) + self.process = subprocess.Popen( + cmd, + shell=True, + start_new_session=True, + stdout=self.stdoutPipe, + stderr=self.stderrPipe + ) else: # single command cmd = cmd[0] # start_new_session can go as soon as there's no piped commands left # the os.killpg call must be replaced with something more reasonable at the same time - self.process = subprocess.Popen(shlex.split(cmd), start_new_session=True) - logger.info("Started sdr source: " + cmd) + self.process = subprocess.Popen( + shlex.split(cmd), + start_new_session=True, + stdout=self.stdoutPipe, + stderr=self.stderrPipe + ) + self.logger.info("Started sdr source: " + cmd) available = False failed = False @@ -307,9 +326,13 @@ class SdrSource(ABC): def wait_for_process_to_end(): nonlocal failed rc = self.process.wait() - logger.debug("shut down with RC={0}".format(rc)) + self.logger.debug("shut down with RC={0}".format(rc)) self.process = None self.monitor = None + self.stdoutPipe.close() + self.stdoutPipe = None + self.stderrPipe.close() + self.stderrPipe = None if self.getState() is SdrSourceState.RUNNING: self.fail() else: @@ -340,7 +363,7 @@ class SdrSource(ABC): try: self.postStart() except Exception: - logger.exception("Exception during postStart()") + self.logger.exception("Exception during postStart()") failed = True if failed: @@ -374,7 +397,7 @@ class SdrSource(ABC): self.monitor.join(10) # if the monitor is still running, the process still hasn't ended, so kill it if self.monitor: - logger.warning("source has not shut down normally within 10 seconds, sending SIGKILL") + self.logger.warning("source has not shut down normally within 10 seconds, sending SIGKILL") os.killpg(os.getpgid(self.process.pid), signal.SIGKILL) except ProcessLookupError: # been killed by something else, ignore diff --git a/owrx/source/connector.py b/owrx/source/connector.py index 58c535d..7175d9b 100644 --- a/owrx/source/connector.py +++ b/owrx/source/connector.py @@ -6,10 +6,6 @@ from owrx.command import Flag, Option from typing import List from owrx.form.input import Input, NumberInput, CheckboxInput -import logging - -logger = logging.getLogger(__name__) - class ConnectorSource(SdrSource): def __init__(self, id, props): @@ -40,7 +36,7 @@ class ConnectorSource(SdrSource): for prop, value in changes.items(): if value is PropertyDeleted: value = None - logger.debug("sending property change over control socket: {0} changed to {1}".format(prop, value)) + self.logger.debug("sending property change over control socket: {0} changed to {1}".format(prop, value)) self.controlSocket.sendall("{prop}:{value}\n".format(prop=prop, value=value).encode()) def onPropertyChange(self, changes): @@ -56,7 +52,7 @@ class ConnectorSource(SdrSource): self.sendControlMessage(changes) def postStart(self): - logger.debug("opening control socket...") + self.logger.debug("opening control socket...") self.controlSocket = socket.socket(socket.AF_INET, socket.SOCK_STREAM) self.controlSocket.connect(("localhost", self.controlPort)) diff --git a/owrx/source/direct.py b/owrx/source/direct.py index e8c2025..4860dd1 100644 --- a/owrx/source/direct.py +++ b/owrx/source/direct.py @@ -5,10 +5,6 @@ from typing import Optional from pycsdr.modules import Buffer from pycsdr.types import Format -import logging - -logger = logging.getLogger(__name__) - class DirectSource(SdrSource, metaclass=ABCMeta): def __init__(self, id, props): @@ -16,7 +12,7 @@ class DirectSource(SdrSource, metaclass=ABCMeta): super().__init__(id, props) def onPropertyChange(self, changes): - logger.debug("restarting sdr source due to property changes: {0}".format(changes)) + self.logger.debug("restarting sdr source due to property changes: {0}".format(changes)) self.stop() self.sleepOnRestart() self.start() diff --git a/owrx/source/fifi_sdr.py b/owrx/source/fifi_sdr.py index e3999b3..24dbc45 100644 --- a/owrx/source/fifi_sdr.py +++ b/owrx/source/fifi_sdr.py @@ -1,16 +1,14 @@ from owrx.command import Option from owrx.source.direct import DirectSource, DirectSourceDeviceDescription +from owrx.log import LogPipe from subprocess import Popen from csdr.chain import Chain from pycsdr.modules import Convert, Gain from pycsdr.types import Format from typing import List from owrx.form.input import Input, TextInput - import logging -logger = logging.getLogger(__name__) - class FifiSdrSource(DirectSource): def getCommandMapper(self): @@ -29,11 +27,19 @@ class FifiSdrSource(DirectSource): return Chain([Convert(Format.COMPLEX_SHORT, Format.COMPLEX_FLOAT), Gain(Format.COMPLEX_FLOAT, 5.0)]) def sendRockProgFrequency(self, frequency): - process = Popen(["rockprog", "--vco", "-w", "--freq={}".format(frequency / 1e6)]) + stdoutPipe = LogPipe(logging.DEBUG, self.logger, "STDOUT") + stderrPipe = LogPipe(logging.DEBUG, self.logger, "STDERR") + process = Popen( + ["rockprog", "--vco", "-w", "--freq={}".format(frequency / 1e6)], + stdout=stdoutPipe, + stderr=stderrPipe + ) process.communicate() rc = process.wait() if rc != 0: - logger.warning("rockprog failed to set frequency; rc=%i", rc) + self.logger.warning("rockprog failed to set frequency; rc=%i", rc) + stdoutPipe.close() + stderrPipe.close() def preStart(self): values = self.getCommandValues() diff --git a/owrx/source/resampler.py b/owrx/source/resampler.py index 7d45c2e..fb1c2d0 100644 --- a/owrx/source/resampler.py +++ b/owrx/source/resampler.py @@ -3,14 +3,10 @@ from pycsdr.modules import Buffer, FirDecimate, Shift from pycsdr.types import Format from csdr.chain import Chain -import logging - -logger = logging.getLogger(__name__) - class Resampler(SdrSource): def onPropertyChange(self, changes): - logger.warning("Resampler is unable to handle property changes: {0}".format(changes)) + self.logger.warning("Resampler is unable to handle property changes: {0}".format(changes)) def __init__(self, props, sdr): sdrProps = sdr.getProps() @@ -41,7 +37,7 @@ class Resampler(SdrSource): super().stop() def activateProfile(self, profile_id=None): - logger.warning("Resampler does not support setting profiles") + self.logger.warning("Resampler does not support setting profiles") pass def validateProfiles(self):