diff --git a/CHANGELOG b/CHANGELOG index e1dc8e7..df16579 100644 --- a/CHANGELOG +++ b/CHANGELOG @@ -1,3 +1,7 @@ +2.4.0 +- added INI switch "force_Restart" and implemented camera restart (solves crashes for IMX290 and IMX519) +- forwarding log messages to client + 2.3.0 - update FITS header formatting and timestamps - use lxml for construction of indi_pylibcamera.xml diff --git a/README.md b/README.md index e7384d7..f67af4d 100644 --- a/README.md +++ b/README.md @@ -12,6 +12,19 @@ The "indi_pylibcamera" may support all cameras supported by "libcamera". But not in the required formats (raw Bayer or at least RGB). So it is not guaranteed that the driver will work with all cameras you can connect to a Raspberry Pi. +The 'indi_pylibcamera' is one layer in a stack of software: +``` + INDI client (for instance KStars, PHD2, CCDciel, ...) + --> INDI server + --> indi_pylibcamera + --> picamera2 + --> libcamera library + --> kernel driver +``` +It can not work when the versions of `libcamera` and `picamera2` are too old (both are in a dynamic development). +And it can not work when the libcamera-tools (like `libcamera-hello` and `libcamera-still`) have issues with your +camera. + ## Requirements and installation Some packages need to be installed with apt-get: - `libcamera` (if not already installed). You can test libcamera and the support @@ -94,6 +107,14 @@ at the beginning of the driver initialization. This can be done here in the INI indi_pylibcamera driver uses this feature to get observer location, telescope information and telescope direction from the mount driver. It writes these information as metadata in the FITS images. This function got newly implemented and may make trouble in some setups. With the `DoSnooping` you can disable this function. +- `force_Restart` (`yes`, `no`, `auto`): Some cameras crash after the first exposure. Restarting the camera before +every frame exposure can solve this issue. Valid values of this switch are: + * `no`: Do not restart if not needed to reconfigure camera. + * `yes`: Always restart. Can lead to longer time between frames. + * `auto`: Automatically choose based on list of known critical cameras. + + Default (if not otherwise set in INI file) is `auto`. + There are more settings, mostly to support debugging. @@ -287,9 +308,10 @@ exposure time was successful. and has therefore well-defined restrictions. It is not clear if the reported higher maximum analogue gain is correct. ## Credits -Many thanks to all who helped o improve this software. Contributions came from: +Many thanks to all who helped to improve this software. Contributions came from: - Simon Ε ander - Aaron W Morris - Caden Gobat +- anjok I hope I did not forget someone. If so please do not be angry and tell me. diff --git a/src/indi_pylibcamera/CameraControl.py b/src/indi_pylibcamera/CameraControl.py index 50497ca..f753f5a 100755 --- a/src/indi_pylibcamera/CameraControl.py +++ b/src/indi_pylibcamera/CameraControl.py @@ -1,7 +1,6 @@ """ indi_pylibcamera: CameraControl class """ -import logging import os.path import numpy as np import io @@ -164,8 +163,8 @@ def is_ReconfigurationNeeded(self, NewCameraSettings): return is_ReconfigurationNeeded def __str__(self): - return f'CameraSettings: FastExposure={self.DoFastExposure}, DoRaw={self.DoRaw}, ProcSize={self.ProcSize}, ` +\ - `RawMode={self.RawMode}, CameraControls={self.camera_controls}' + return f'CameraSettings: FastExposure={self.DoFastExposure}, DoRaw={self.DoRaw}, ProcSize={self.ProcSize}, ' \ + f'RawMode={self.RawMode}, CameraControls={self.camera_controls}' def __repr__(self): return str(self) @@ -226,6 +225,7 @@ def __init__(self, parent, config): self.min_AnalogueGain = None self.max_AnalogueGain = None self.camera_controls = dict() + self.needs_Restarts = False # exposure loop control self.ExposureTime = 0.0 self.Sig_Do = threading.Event() # do an action @@ -244,7 +244,7 @@ def __init__(self, parent, config): def closeCamera(self): """close camera """ - logging.info('closing camera') + logger.info('closing camera') # stop exposure loop if self.ExposureThread is not None: if self.ExposureThread.is_alive(): @@ -283,11 +283,11 @@ def getRawCameraModes(self): sensor_format = sensor_mode["unpacked"] # packed data formats are not supported if sensor_format.endswith("_CSI2P"): - logging.warning(f'raw mode not supported: {sensor_mode}') + logger.warning(f'raw mode not supported: {sensor_mode}') continue # only Bayer pattern formats are supported if not re.match("S[RGB]{4}[0-9]+", sensor_format): - logging.warning(f'raw mode not supported: {sensor_mode}') + logger.warning(f'raw mode not supported: {sensor_mode}') continue # size = sensor_mode["size"] @@ -310,7 +310,7 @@ def getRawCameraModes(self): elif size == (4056, 3040): true_size = (4056, 3040) else: - logging.warning(f'Unsupported frame size {size} for imx477!') + logger.warning(f'Unsupported frame size {size} for imx477!') elif self.CamProps["Model"] == 'ov5647': if size == (640, 480): binning = (4, 4) @@ -321,7 +321,7 @@ def getRawCameraModes(self): elif size == (2592, 1944): pass else: - logging.warning(f'Unsupported frame size {size} for ov5647!') + logger.warning(f'Unsupported frame size {size} for ov5647!') elif self.CamProps["Model"].startswith("imx708"): if size == (1536, 864): binning = (2, 2) @@ -330,7 +330,7 @@ def getRawCameraModes(self): elif size == (4608, 2592): pass else: - logging.warning(f'Unsupported frame size {size} for imx708!') + logger.warning(f'Unsupported frame size {size} for imx708!') # add to list of raw formats raw_mode = { "label": f'{size[0]}x{size[1]} {sensor_format[1:5]} {sensor_mode["bit_depth"]}bit', @@ -348,15 +348,14 @@ def getRawCameraModes(self): def openCamera(self, idx: int): """open camera with given index idx """ - self.closeCamera() - logging.info("opening camera") + logger.info("opening camera") self.picam2 = Picamera2(idx) # read camera properties self.CamProps = self.picam2.camera_properties - logging.info(f'camera properties: {self.CamProps}') + logger.info(f'camera properties: {self.CamProps}') # force properties with values from config file if "UnitCellSize" not in self.CamProps: - logging.warning("Camera properties do not have UnitCellSize value. Need to force from config file!") + logger.warning("Camera properties do not have UnitCellSize value. Need to force from config file!") self.CamProps["UnitCellSize"] = ( self.config.getint( "driver", "force_UnitCellSize_X", @@ -380,6 +379,18 @@ def openCamera(self, idx: int): # exposure time range self.min_ExposureTime, self.max_ExposureTime, default_exp = self.camera_controls["ExposureTime"] self.min_AnalogueGain, self.max_AnalogueGain, default_again = self.camera_controls["AnalogueGain"] + # TODO + force_Restart = self.config.get("driver", "force_Restart", fallback="auto").lower() + if force_Restart == "yes": + logger.info("INI setting forces camera restart") + self.needs_Restarts = True + elif force_Restart == "no": + logger.info("INI setting for camera restarts as needed") + self.needs_Restarts = False + else: + if force_Restart != "auto": + logger.warning(f'unknown INI value for camera restart: force_Restart={force_Restart}') + self.needs_Restarts = self.CamProps["Model"] in ["imx290", "imx519"] # start exposure loop self.Sig_ActionExit.clear() self.Sig_ActionExpose.clear() @@ -481,7 +492,7 @@ def snooped_FitsHeader(self): "EQUINOX": (2000, "[yr] Equinox"), "DATE-END": (datetime.datetime.utcnow().isoformat(timespec="milliseconds"), "UTC time at end of observation"), }) - logging.info("Finished collecting snooped data.") + logger.debug("Finished collecting snooped data.") #### return FitsHeader @@ -673,15 +684,15 @@ def __ExposureLoop(self): advertised_camera_controls=self.camera_controls, has_RawModes=has_RawModes, ) - logging.info(f'exposure settings: {NewCameraSettings}') + logger.info(f'exposure settings: {NewCameraSettings}') # need a camera stop/start when something has changed on exposure controls - IsRestartNeeded = self.present_CameraSettings.is_RestartNeeded(NewCameraSettings) + IsRestartNeeded = self.present_CameraSettings.is_RestartNeeded(NewCameraSettings) or self.needs_Restarts if self.picam2.started and IsRestartNeeded: - logging.info(f'stopping camera for deeper reconfiguration') + logger.info(f'stopping camera for deeper reconfiguration') self.picam2.stop_() # change of DoFastExposure needs a configuration change - if self.present_CameraSettings.is_ReconfigurationNeeded(NewCameraSettings): - logging.info(f'reconfiguring camera') + if self.present_CameraSettings.is_ReconfigurationNeeded(NewCameraSettings) or self.needs_Restarts: + logger.info(f'reconfiguring camera') # need a new camera configuration config = self.picam2.create_still_configuration( queue=NewCameraSettings.DoFastExposure, @@ -713,7 +724,7 @@ def __ExposureLoop(self): # start camera if not already running in Fast Exposure mode if not self.picam2.started: self.picam2.start() - logging.info(f'camera started') + logger.debug(f'camera started') # camera runs now with new parameter self.present_CameraSettings = NewCameraSettings # last chance to exit or abort before doing exposure @@ -759,7 +770,7 @@ def __ExposureLoop(self): # get frame and its metadata if not Abort: (array, ), metadata = self.picam2.wait(job) - logging.info("got exposed frame") + logger.info("got exposed frame") # at least HQ camera reports CCD temperature in meta data self.parent.setVector("CCD_TEMPERATURE", "CCD_TEMPERATURE_VALUE", value=metadata.get('SensorTemperature', 0)) @@ -802,18 +813,18 @@ def __ExposureLoop(self): # requested to save locally local_filename = getLocalFileName(dir=upload_dir, prefix=upload_prefix, suffix=".fits") bstream.seek(0) - logging.info(f"saving image to file {local_filename}") + logger.info(f"saving image to file {local_filename}") with open(local_filename, 'wb') as fh: fh.write(bstream.getbuffer()) if upload_mode[0] in ["UPLOAD_CLIENT", "UPLOAD_BOTH"]: # send blob to client bstream.seek(0) # make BLOB - logging.info(f"preparing frame as BLOB: {size} bytes") + logger.info(f"preparing frame as BLOB: {size} bytes") bv = self.parent.knownVectors["CCD1"] compress = self.parent.knownVectors["CCD_COMPRESSION"]["CCD_COMPRESS"].value == ISwitchState.ON bv["CCD1"].set_data(data=bstream.getbuffer(), format=".fits", compress=compress) - logging.info(f"sending BLOB") + logger.info(f"sending BLOB") bv.send_setVector() # tell client that we finished exposure if DoFastExposure: diff --git a/src/indi_pylibcamera/SnoopingManager.py b/src/indi_pylibcamera/SnoopingManager.py index 25b87e7..2cbc486 100644 --- a/src/indi_pylibcamera/SnoopingManager.py +++ b/src/indi_pylibcamera/SnoopingManager.py @@ -1,11 +1,11 @@ """ Snooping manager """ -import logging class SnoopingManager: - def __init__(self, parent, to_server_func): + def __init__(self, parent, to_server_func, logger): + self.logger = logger self.to_server = to_server_func self.parent = parent # snooped values: dict(device->dict(name->dict(elements))) @@ -54,7 +54,7 @@ def catching(self, device: str, name: str, values: dict): if device in self.snoopedValues: if name in self.snoopedValues[device]: self.snoopedValues[device][name] = values - logging.debug(f'snooped "{device}" - "{name}": {values}') + self.logger.debug(f'snooped "{device}" - "{name}": {values}') if ("DO_SNOOPING" in self.parent.knownVectors) and ("SNOOP" in self.parent.knownVectors["DO_SNOOPING"].get_OnSwitches()): if name in self.parent.knownVectors: self.parent.knownVectors[name].set_byClient(values) diff --git a/src/indi_pylibcamera/__init__.py b/src/indi_pylibcamera/__init__.py index 158e5e6..371a9ef 100644 --- a/src/indi_pylibcamera/__init__.py +++ b/src/indi_pylibcamera/__init__.py @@ -2,4 +2,4 @@ INDI driver for libcamera supported cameras """ -__version__ = "2.3.0" +__version__ = "2.4.0" diff --git a/src/indi_pylibcamera/indi_pylibcamera.ini b/src/indi_pylibcamera/indi_pylibcamera.ini index a1742e7..1472e6d 100644 --- a/src/indi_pylibcamera/indi_pylibcamera.ini +++ b/src/indi_pylibcamera/indi_pylibcamera.ini @@ -26,6 +26,16 @@ LoggingLevel=Info # This feature requires the system time on your Raspberry Pi to be correct! DoSnooping=yes +# Some cameras crash after the first exposure. Restarting the camera before every frame exposure can solve this issue. +# Valid values are: +# no - Do not restart if not needed to reconfigure camera. +# yes - Always restart. Can lead to longer time between frames. +# auto - automatically choose based on list of critical cameras +# Default if not otherwise set in INI file is "auto". +#force_Restart=auto +#force_Restart=no +#force_Restart=yes + ##################################### # The following settings are to help debugging. Don't change them unasked! # diff --git a/src/indi_pylibcamera/indi_pylibcamera.py b/src/indi_pylibcamera/indi_pylibcamera.py index e395298..b5ecdd9 100755 --- a/src/indi_pylibcamera/indi_pylibcamera.py +++ b/src/indi_pylibcamera/indi_pylibcamera.py @@ -1,5 +1,4 @@ #!/usr/bin/env python3 -import logging import sys import os import os.path @@ -19,11 +18,10 @@ from .CameraControl import CameraControl -logging.basicConfig(filename=None, level=logging.INFO, format='%(name)s-%(levelname)s- %(message)s') - IniPath = Path(Path.home(), ".indi_pylibcamera") IniPath.mkdir(parents=True, exist_ok=True) + def read_config(): # iterative list of INI files to load configfiles = [Path(__file__, "indi_pylibcamera.ini")] @@ -34,7 +32,7 @@ def read_config(): # create config parser instance config = ConfigParser() config.read(configfiles) - logging.debug(f"ConfigParser: {config}") + logger.debug(f"ConfigParser: {config}") return config @@ -50,7 +48,7 @@ def __init__(self, parent): self.parent = parent LoggingLevel = self.parent.config.get("driver", "LoggingLevel", fallback="Info") if LoggingLevel not in ["Debug", "Info", "Warning", "Error"]: - logging.error('Parameter "LoggingLevel" in INI file has an unsupported value!') + logger.error('Parameter "LoggingLevel" in INI file has an unsupported value!') LoggingLevel = "Info" super().__init__( device=self.parent.device, timestamp=self.parent.timestamp, name="LOGGING_LEVEL", @@ -65,19 +63,17 @@ def __init__(self, parent): ) self.configure_logger() - def configure_logger(self): selectedLogLevel = self.get_OnSwitches()[0] - logging.info(f'selected logging level: {selectedLogLevel}') + logger.info(f'selected logging level: {selectedLogLevel}') if selectedLogLevel == "LOGGING_DEBUG": - logging.getLogger().setLevel(logging.DEBUG) + logger.setLevel(logging.DEBUG) elif selectedLogLevel == "LOGGING_INFO": - logging.getLogger().setLevel(logging.INFO) + logger.setLevel(logging.INFO) elif selectedLogLevel == "LOGGING_WARN": - logging.getLogger().setLevel(logging.WARN) + logger.setLevel(logging.WARN) else: - logging.getLogger().setLevel(logging.ERROR) - + logger.setLevel(logging.ERROR) def set_byClient(self, values: dict): """called when vector gets set by client @@ -86,7 +82,7 @@ def set_byClient(self, values: dict): Args: values: dict(propertyName: value) of values to set """ - logging.debug(f"logging level action: {values}") + logger.debug(f"logging level action: {values}") super().set_byClient(values = values) self.configure_logger() @@ -116,7 +112,7 @@ def set_byClient(self, values: dict): Args: values: dict(propertyName: value) of values to set """ - logging.debug(f"connect/disconnect action: {values}") + logger.debug(f"connect/disconnect action: {values}") self.message = self.update_SwitchStates(values=values) # send updated property values if len(self.message) > 0: @@ -455,8 +451,7 @@ def set_byClient(self, values: dict): Args: values: dict(propertyName: value) of values to set """ - logging.debug(f"logging level action: {values}") - logging.info(f'Snooped values: {str(self.parent.SnoopingManager)}') + logger.info(f'Snooped values: {str(self.parent.SnoopingManager)}') self.state = IVectorState.OK self.send_setVector() @@ -493,18 +488,18 @@ def set_byClient(self, values: dict): action = actions[0] if action == "CONFIG_LOAD": if config_filename.exists(): - logging.info(f'loading configuration from {config_filename}') + logger.info(f'loading configuration from {config_filename}') with open(config_filename, "r") as fh: states = json.load(fh) for vector in states: if vector["name"] in self.parent.knownVectors: self.parent.knownVectors[vector["name"]].set_byClient(vector["values"]) else: - logging.warning(f'Ignoring unknown vector {vector["name"]}!') + logger.warning(f'Ignoring unknown vector {vector["name"]}!') else: - logging.info(f'configuration {config_filename} does not exist') + logger.info(f'configuration {config_filename} does not exist') elif action == "CONFIG_SAVE": - logging.info(f'saving configuration in {config_filename}') + logger.info(f'saving configuration in {config_filename}') states = list() for vector in self.parent.knownVectors: state = vector.save() @@ -513,11 +508,11 @@ def set_byClient(self, values: dict): with open(config_filename, "w") as fh: json.dump(states, fh, indent=4) elif action == "CONFIG_DEFAULT": - logging.info(f'restoring driver defaults') + logger.info(f'restoring driver defaults') for vector in self.parent.knownVectors: vector.restore_DriverDefault() else: # action == "CONFIG_PURGE" - logging.info(f'deleting configuration {config_filename}') + logger.info(f'deleting configuration {config_filename}') config_filename.unlink(missing_ok=True) # set all buttons Off again super().set_byClient(values={element.name: ISwitchState.OFF for element in self.elements}) @@ -531,9 +526,9 @@ def kill_oldDriver(): Alternative would be 3rd party library psutil which may need to be installed. """ my_PID = os.getpid() - logging.info(f'my PID: {my_PID}') + logger.info(f'my PID: {my_PID}') my_fileName = os.path.basename(__file__)[:-3] - logging.info(f'my file name: {my_fileName}') + logger.info(f'my file name: {my_fileName}') ps_ax = subprocess.check_output(["ps", "ax"]).decode(sys.stdout.encoding) ps_ax = ps_ax.split("\n") pids_oldDriver = [] @@ -541,7 +536,7 @@ def kill_oldDriver(): if ("python3" in processInfo) and (my_fileName in processInfo): PID = int(processInfo.strip().split(" ", maxsplit=1)[0]) if PID != my_PID: - logging.info(f'found old driver with PID {PID} ({processInfo})') + logger.info(f'found old driver with PID {PID} ({processInfo})') pids_oldDriver.append(PID) for pid_oldDriver in pids_oldDriver: try: @@ -551,7 +546,7 @@ def kill_oldDriver(): pass except PermissionError: # not allowed to kill - logging.error(f'Do not have permission to kill old driver with PID {pid_oldDriver}.') + logger.error(f'Do not have permission to kill old driver with PID {pid_oldDriver}.') # the device driver @@ -570,6 +565,8 @@ def __init__(self, config=None): super().__init__(device=config.get("driver", "DeviceName", fallback="indi_pylibcamera")) self.config = config self.timestamp = self.config.getboolean("driver", "SendTimeStamps", fallback=False) + # send logging messages to client + enable_Logging(device=self.device, timestamp=self.timestamp) # camera self.CameraThread = CameraControl( parent=self, @@ -580,7 +577,7 @@ def __init__(self, config=None): signal.signal(signal.SIGTERM, self.exit_gracefully) # get connected cameras cameras = Picamera2.global_camera_info() - logging.info(f'found cameras: {cameras}') + logger.info(f'found cameras: {cameras}') # use Id as unique camera identifier self.Cameras = [c["Id"] for c in cameras] # INDI vector names only available with connected camera @@ -717,7 +714,7 @@ def __init__(self, config=None): def exit_gracefully(self, sig, frame): """exit driver on system signals """ - logging.info("Exit triggered by SIGINT or SIGTERM") + logger.info("Exit triggered by SIGINT or SIGTERM") self.CameraThread.closeCamera() traceback.print_stack(frame) sys.exit(0) @@ -738,7 +735,7 @@ def openCamera(self): if len(CameraSel) < 1: return False CameraIdx = CameraSel[0] - logging.info(f'connecting to camera {self.Cameras[CameraIdx]}') + logger.info(f'connecting to camera {self.Cameras[CameraIdx]}') self.closeCamera() self.CameraThread.openCamera(CameraIdx) # update INDI properties diff --git a/src/indi_pylibcamera/indi_pylibcamera.xml b/src/indi_pylibcamera/indi_pylibcamera.xml index a8fc684..1e596ed 100644 --- a/src/indi_pylibcamera/indi_pylibcamera.xml +++ b/src/indi_pylibcamera/indi_pylibcamera.xml @@ -2,7 +2,7 @@ indi_pylibcamera - 2.3.0 + 2.4.0 diff --git a/src/indi_pylibcamera/indidevice.py b/src/indi_pylibcamera/indidevice.py index 1b88295..7072f4b 100755 --- a/src/indi_pylibcamera/indidevice.py +++ b/src/indi_pylibcamera/indidevice.py @@ -20,6 +20,7 @@ from . import SnoopingManager +logger = logging.getLogger(__name__) # helping functions @@ -137,7 +138,7 @@ def set_byClient(self, value: str) -> str: error message if failed or empty string if okay """ errmsg = f'setting property {self.name} not implemented' - logging.error(errmsg) + logger.error(errmsg) return errmsg @@ -266,7 +267,7 @@ def send_defVector(self, device: str = None): device: device name """ if (device is None) or (device == self.device): - logging.debug(f'send_defVector: {self.get_defVector()}') + logger.debug(f'send_defVector: {self.get_defVector()}') to_server(self.get_defVector()) def get_delVector(self, msg: str = None) -> str: @@ -284,7 +285,7 @@ def get_delVector(self, msg: str = None) -> str: def send_delVector(self): """tell client to remove this vector """ - logging.debug(f'send_delVector: {self.get_delVector()}') + logger.debug(f'send_delVector: {self.get_delVector()}') to_server(self.get_delVector()) def get_setVector(self) -> str: @@ -307,7 +308,7 @@ def get_setVector(self) -> str: def send_setVector(self): """tell client about vector data """ - logging.debug(f'send_setVector: {self.get_setVector()[:100]}') + logger.debug(f'send_setVector: {self.get_setVector()[:100]}') to_server(self.get_setVector()) def set_byClient(self, values: dict): @@ -639,7 +640,7 @@ def __init__( def send_setVector(self): """tell client about vector data, special version for IBlobVector to avoid double calculation of setVector """ - # logging.debug(f'send_setVector: {self.get_setVector()[:100]}') + # logger.debug(f'send_setVector: {self.get_setVector()[:100]}') # this takes too long! to_server(self.get_setVector()) @@ -716,6 +717,56 @@ def checkout(self, name: str): self.pop(name).send_delVector() +class indiMessageHandler(logging.StreamHandler): + """logging message handler for INDI + + allows sending of log messages to client + """ + def __init__(self, device, timestamp=False): + super().__init__() + self.device = device + self.timestamp = timestamp + + def emit(self, record): + msg = self.format(record) + # use etree here to get correct encoding of special characters in msg + attribs = {"device": self.device, "message": msg} + if self.timestamp: + attribs['timestamp'] = get_TimeStamp() + et = etree.ElementTree(etree.Element("message", attribs)) + to_server(etree.tostring(et, xml_declaration=True).decode("latin")) + #print(f'DBG MessageHandler: {etree.tostring(et, xml_declaration=True).decode("latin")}', file=sys.stderr) + + +def handle_exception(exc_type, exc_value, exc_traceback): + """logging of uncaught exceptions + """ + if issubclass(exc_type, KeyboardInterrupt): + sys.__excepthook__(exc_type, exc_value, exc_traceback) + return + logger.error("Uncaught exception!", exc_info=(exc_type, exc_value, exc_traceback)) + + +def enable_Logging(device, timestamp=False): + """enable logging to client + """ + global logger + logger.setLevel(logging.INFO) + # console handler + ch = logging.StreamHandler() + #ch.setLevel(logging.INFO) + formatter = logging.Formatter('%(name)s-%(levelname)s- %(message)s') + ch.setFormatter(formatter) + # INDI message handler + ih = indiMessageHandler(device=device, timestamp=timestamp) + ih.setFormatter(logging.Formatter('[%(levelname)s] %(message)s')) + # add the handlers to logger + logger.addHandler(ch) + logger.addHandler(ih) + # log uncought exceptions and forward them to client + sys.excepthook = handle_exception + + class indidevice: """general INDI device """ @@ -732,7 +783,7 @@ def __init__(self, device: str): # lock for device parameter self.knownVectorsLock = threading.Lock() # snooping - self.SnoopingManager = SnoopingManager.SnoopingManager(parent=self, to_server_func=to_server) + self.SnoopingManager = SnoopingManager.SnoopingManager(parent=self, to_server_func=to_server, logger=logger) def send_Message(self, message: str, severity: str = "INFO", timestamp: bool = False): """send message to client @@ -746,7 +797,6 @@ def send_Message(self, message: str, severity: str = "INFO", timestamp: bool = F if timestamp: xml += f' timestamp="{get_TimeStamp()}"' xml += f'/>' - logging.debug(f'send_Message: {xml}') to_server(xml) def on_getProperties(self, device=None): @@ -771,11 +821,11 @@ def message_loop(self): xml = etree.fromstring(inp) inp = "" except etree.XMLSyntaxError as error: - logging.debug(f"XML not complete ({error}): {inp}") + #logger.debug(f"XML not complete ({error}): {inp}") # creates too many log messages! continue - logging.debug(f'Parsed data from client:\n{etree.tostring(xml, pretty_print=True).decode()}') - logging.debug("End client data") + logger.debug(f'Parsed data from client:\n{etree.tostring(xml, pretty_print=True).decode()}') + logger.debug("End client data") device = xml.attrib.get('device', None) if xml.tag == "getProperties": @@ -787,13 +837,13 @@ def message_loop(self): try: vector = self.knownVectors[vectorName] except ValueError as e: - logging.error(f'unknown vector name {vectorName}') + logger.error(f'unknown vector name {vectorName}') else: - logging.debug(f"calling {vector} set_byClient") + logger.debug(f"calling {vector} set_byClient") with self.knownVectorsLock: vector.set_byClient(values) else: - logging.error( + logger.error( f'could not interpret client request: {etree.tostring(xml, pretty_print=True).decode()}') else: # can be a snooped device @@ -807,7 +857,7 @@ def message_loop(self): # snooped device got closed pass else: - logging.error( + logger.error( f'could not interpret client request: {etree.tostring(xml, pretty_print=True).decode()}') def checkin(self, vector: IVector, send_defVector: bool = False):