Merge branch 'main' into jm/glitch

gw_spaceheat/actors/config.py

@@ -1,3 +1,5 @@
+import logging
+
 from gwproactor.config.mqtt import TLSInfo
 from pydantic import model_validator, BaseModel
 from data_classes.house_0_names import H0N
@@ -20,6 +22,7 @@ class ScadaSettings(ProactorSettings):
     """Settings for the GridWorks scada."""
     #logging related (temporary)
     pico_cycler_state_logging: bool = False
+    power_meter_logging_level: int = logging.WARNING
     local_mqtt: MQTTClient = MQTTClient()
     gridworks_mqtt: MQTTClient = MQTTClient()
     seconds_per_report: int = 300

gw_spaceheat/actors/power_meter.py

@@ -1,12 +1,15 @@
 """Implements PowerMeter via SyncThreadActor and PowerMeterDriverThread. A helper class, DriverThreadSetupHelper,
 isolates code used only in PowerMeterDriverThread constructor. """
-
+import logging
 import time
 import typing
 from typing import Dict
 from typing import List
 from typing import Optional
+
+from gwproactor.logger import LoggerOrAdapter
 from gwproto import Message
+from gwproto.enums import TelemetryName
 
 from actors.message import PowerWattsMessage
 from actors.message import SyncedReadingsMessage
@@ -74,12 +77,14 @@ class DriverThreadSetupHelper:
     settings: ScadaSettings
     hardware_layout: HardwareLayout
     component: ElectricMeterComponent
+    logger: LoggerOrAdapter
 
     def __init__(
         self,
         node: ShNode,
         settings: ScadaSettings,
         hardware_layout: HardwareLayout,
+        logger: LoggerOrAdapter,
     ):
         if not isinstance(node.component, ElectricMeterComponent):
             raise ValueError(
@@ -90,6 +95,7 @@ def __init__(
         self.settings = settings
         self.hardware_layout = hardware_layout
         self.component = typing.cast(ElectricMeterComponent, node.component)
+        self.logger = logger
 
     def make_power_meter_driver(self) -> PowerMeterDriver:
         cac = self.component.cac
@@ -104,7 +110,11 @@ def make_power_meter_driver(self) -> PowerMeterDriver:
                 component=self.component, settings=self.settings
             )
         elif cac.MakeModel == MakeModel.EGAUGE__4030:
-            driver = EGuage4030_PowerMeterDriver(component=self.component, settings=self.settings)
+            driver = EGuage4030_PowerMeterDriver(
+                component=self.component,
+                settings=self.settings,
+                logger=self.logger,
+            )
         else:
             raise NotImplementedError(
                 f"No ElectricMeter driver yet for {cac.MakeModel}"
@@ -148,22 +158,30 @@ def __init__(
         telemetry_destination: str,
         responsive_sleep_step_seconds=0.01,
         daemon: bool = True,
+        logger: Optional[LoggerOrAdapter] = None,
     ):
         super().__init__(
             name=node.Name,
             responsive_sleep_step_seconds=responsive_sleep_step_seconds,
             daemon=daemon,
+            logger=logger,
         )
         self._hardware_layout = hardware_layout
         self._telemetry_destination = telemetry_destination
-        setup_helper = DriverThreadSetupHelper(node, settings, hardware_layout)
+        setup_helper = DriverThreadSetupHelper(
+            node,
+            settings,
+            hardware_layout,
+            logger=logger
+        )
         self.eq_reporting_config = setup_helper.make_eq_reporting_config()
         self.driver = setup_helper.make_power_meter_driver()
         self.transactive_nameplate_watts = setup_helper.get_transactive_nameplate_watts()
         self.last_reported_agg_power_w: Optional[int] = None
-        component: ElectricMeterComponent = node.component
+        component: ElectricMeterComponent = typing.cast(ElectricMeterComponent, node.component)
         my_channel_names = [cfg.ChannelName for cfg in component.gt.ConfigList]
         self.my_channels = [hardware_layout.data_channels[name] for name in my_channel_names]
+        self._validate_channels_with_component(component)
         self.last_reported_telemetry_value = {
             ch: None for ch in self.my_channels
         }
@@ -175,14 +193,30 @@ def __init__(
         }
         self.async_power_reporting_threshold = settings.async_power_reporting_threshold
 
-    def _report_problems(self, problems: Problems, tag: str):
-        self._put_to_async_queue(
-            Message(
-                Payload=problems.problem_event(
-                    summary=f"Driver problems: {tag} for {self.driver.component}",
-                )
-            )
+    def _validate_channels_with_component(self, component: ElectricMeterComponent) -> None:
+        for channel in self.my_channels:
+            if channel.TelemetryName != TelemetryName.PowerW:
+                raise ValueError(f"read_power_w got a channel with {channel.TelemetryName}")
+            channel_config = next((cfg for cfg in component.gt.ConfigList if cfg.ChannelName == channel.Name), None)
+            if channel_config is None:
+                raise Exception(f"Reading power for channel {channel.Name} but this is not in the ConfigList!")
+            self.driver.validate_config(channel_config)
+
+    def _report_problems(self, problems: Problems, tag: str, log_event: bool = False):
+        event = problems.problem_event(
+            summary=f"Driver problems: {tag} for {self.driver.component}",
         )
+        message = Message(Payload=event)
+        if log_event and self._logger.isEnabledFor(logging.DEBUG):
+            self._logger.info(
+                "PowerMeter event:\n"
+                f"{event}"
+            )
+            self._logger.info(
+                "PowerMeter message\n"
+                f"{message.model_dump_json(indent=2)}"
+            )
+        self._put_to_async_queue(message)
 
     def _preiterate(self) -> None:
         result = self.driver.start()
@@ -202,8 +236,8 @@ def _ensure_hardware_uid(self):
                 if hw_uid_read_result.value.value:
                     self._hw_uid = hw_uid_read_result.value.value.strip("\u0000")
                     if (
-                            self.driver.component.gt.HwUid
-                            and self._hw_uid != self.driver.component.gt.HwUid
+                        self.driver.component.gt.HwUid
+                        and self._hw_uid != self.driver.component.gt.HwUid
                     ):
                         self._report_problems(
                             Problems(
@@ -239,13 +273,25 @@ def _iterate(self) -> None:
         self._iterate_sleep_seconds = sleep_time_ms / 1000
 
     def update_latest_value_dicts(self):
+        logged_one = False
         for ch in self.my_channels:
             read = self.driver.read_telemetry_value(ch)
             if read.is_ok():
                 if read.value.value is not None:
                     self.latest_telemetry_value[ch] = read.value.value
                 if read.value.warnings:
-                    self._report_problems(Problems(warnings=read.value.warnings), "read warnings")
+                    log_event = False
+                    if not logged_one and self._logger.isEnabledFor(logging.DEBUG):
+                        logged_one = True
+                        log_event = True
+                        self._logger.info(f"PowerMeter: TryConnectResult:\n{read.value}")
+                        problems = Problems(warnings=read.value.warnings)
+                        self._logger.info(f"PowerMeter: Problems:\n{problems}")
+                    self._report_problems(
+                        problems=Problems(warnings=read.value.warnings),
+                        tag="read warnings",
+                        log_event=log_event
+                    )
             else:
                 raise read.value
 
@@ -351,20 +397,26 @@ def should_report_aggregated_power(self) -> bool:
 
 
 class PowerMeter(SyncThreadActor):
+    POWER_METER_LOGGER_NAME: str = "PowerMeter"
+
     def __init__(
         self,
         name: str,
         services: ScadaInterface,
         settings: Optional[ScadaSettings] = None,
     ):
-
+        settings = settings or services.settings
         super().__init__(
             name=name,
             services=services,
             sync_thread=PowerMeterDriverThread(
                 node=services.hardware_layout.node(name),
-                settings=services.settings if settings is None else settings,
+                settings=settings,
                 hardware_layout=services.hardware_layout,
                 telemetry_destination=services.name,
+                logger=services.logger.add_category_logger(
+                    self.POWER_METER_LOGGER_NAME,
+                    level=settings.power_meter_logging_level,
+                )
             ),
         )

gw_spaceheat/actors/scada.py

@@ -1,5 +1,4 @@
 """Scada implementation"""
-
 import os
 import asyncio
 import enum
@@ -19,6 +18,7 @@
 from gwproto import MQTTTopic
 from gwproto.enums import ActorClass
 
+from actors.power_meter import PowerMeter
 from data_classes.house_0_layout import House0Layout
 from gwproto.messages import FsmAtomicReport, FsmFullReport
 from gwproto.messages import EventBase
@@ -244,6 +244,10 @@ def __init__(
         self._last_sync_snap_s = int(now)
         self._dispatch_live_hack = False
         self.pending_dispatch: Optional[AnalogDispatch] = None
+        self.logger.add_category_logger(
+            PowerMeter.POWER_METER_LOGGER_NAME,
+            level=settings.power_meter_logging_level,
+        )
         if actor_nodes is not None:
             for actor_node in actor_nodes:
                 self.add_communicator(

gw_spaceheat/actors/scada_interface.py

@@ -20,3 +20,4 @@ def settings(self) -> ScadaSettings:
     @abstractmethod
     def data(self) -> ScadaData:
         ...
+

gw_spaceheat/command_line_utils.py

@@ -93,6 +93,16 @@ def parse_args(
         action="store_true",
         help="Whether to enable paho mqtt logging. Requires --verbose to be useful."
     )
+    parser.add_argument(
+        "--power-meter-logging",
+        action="store_true",
+        help="Enable extra power meter logging."
+    )
+    parser.add_argument(
+        "--power-meter-logging-verbose",
+        action="store_true",
+        help="Enable even more extra power meter logging."
+    )
     return parser.parse_args(sys.argv[1:] if argv is None else argv, namespace=args)
 
 def get_requested_names(args: argparse.Namespace) -> Optional[set[str]]:
@@ -176,11 +186,19 @@ def get_scada(
     args = parse_args(argv)
     dotenv_file = dotenv.find_dotenv(args.env_file)
     dotenv_file_debug_str = f"Env file: <{dotenv_file}>  exists:{Path(dotenv_file).exists()}"
+    # https://github.com/koxudaxi/pydantic-pycharm-plugin/issues/1013
+    # noinspection PyArgumentList
     settings = ScadaSettings(_env_file=dotenv_file)
     if args.s2:
         scada_actor_class = ActorClass.Parentless
     else:
         scada_actor_class = ActorClass.Scada
+    if args.power_meter_logging:
+        if settings.power_meter_logging_level > logging.INFO:
+            settings.power_meter_logging_level = logging.INFO
+    if args.power_meter_logging_verbose:
+        if settings.power_meter_logging_level > logging.DEBUG:
+            settings.power_meter_logging_level = logging.DEBUG
     if args.dry_run:
         rich.print(dotenv_file_debug_str)
         rich.print(settings)