Skip to content

Commit 011fb6b

Browse files
authored
fix: log a missing MQTT client at debug when the tree is transport-free by design (#20)
A tree built with mqtt_cfg=None has no client because that is what was asked for, so every traversal reports one: a 31-device tree emitted 1,593 WARNING lines saying only that the caller got what they requested. _transport_free() is true when the root holds no client and was given no config to build one from. The twelve NoMqttClient sites log at debug when it holds and keep their previous severity otherwise, so "you forgot to start the root" stays as loud as it was. Bring-your-own-transport is not transport-free: the client is present, so its absence would still be an anomaly. Property and Node resolve the predicate through node -> device -> root, mirroring the walk already in Property.start_mqtt_client. An incomplete chain falls through as not transport-free, so a half-built tree stays loud rather than going quiet. Closes #11.
1 parent 7518c7a commit 011fb6b

2 files changed

Lines changed: 169 additions & 12 deletions

File tree

src/ebus_sdk/homie.py

Lines changed: 75 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -74,6 +74,21 @@ class StrEnum(str, Enum):
7474

7575
logger = logging.getLogger("homie")
7676

77+
78+
def _log_missing_client(message: str, *, by_design: bool, level: int = logging.WARNING) -> None:
79+
"""Log a missing MQTT client at the severity its cause deserves.
80+
81+
A tree built without transport has no client because that is what was asked for, so
82+
every entity in it reports one on each traversal — thousands of lines saying only that
83+
the caller got what they requested. That case is DEBUG.
84+
85+
Everywhere else a client was expected: the root was given a config, or handed one, and
86+
its absence means something went wrong. That case keeps the severity it had, so the
87+
"you forgot to start the root" warning stays as loud as it was.
88+
"""
89+
logger.log(logging.DEBUG if by_design else level, message)
90+
91+
7792
# One-time warning when a `$format` JSONSchema is present but jsonschema is not.
7893
_jsonschema_warned = False
7994

@@ -532,6 +547,14 @@ def node(self) -> Node:
532547
"""
533548
return self._node
534549

550+
def _transport_free(self) -> bool:
551+
"""See ``Device._transport_free``. Resolved node -> device, mirroring the walk in
552+
``start_mqtt_client``; an incomplete chain falls through as *not* transport-free so
553+
a half-built tree stays loud rather than going quiet."""
554+
node = self.node()
555+
device = node.device() if node is not None else None
556+
return device._transport_free() if device is not None else False
557+
535558
def get_node_id(self) -> str:
536559
"""
537560
Why is this needed?
@@ -677,7 +700,9 @@ def get_mqtt_client(self) -> Optional[MqttDeviceTransport]:
677700
return None
678701
mqttc = node.get_mqtt_client()
679702
if not mqttc:
680-
logger.warning(f"reason=propertyGetMqttClientNoMqttClient,propertyID={self._id}")
703+
_log_missing_client(
704+
f"reason=propertyGetMqttClientNoMqttClient,propertyID={self._id}", by_design=self._transport_free()
705+
)
681706
return mqttc
682707

683708
def start_mqtt_client(self) -> None:
@@ -686,7 +711,9 @@ def start_mqtt_client(self) -> None:
686711
"""
687712
mqttc = self.get_mqtt_client()
688713
if not mqttc:
689-
logger.warning(f"reason=propertyStartMqttClientNoMqttClient,propertyID={self._id}")
714+
_log_missing_client(
715+
f"reason=propertyStartMqttClientNoMqttClient,propertyID={self._id}", by_design=self._transport_free()
716+
)
690717
return
691718
# Never start a caller-owned client (bring-your-own-transport): mirror the
692719
# ownership guard on Device.start_mqtt_client(), and start via the concrete
@@ -758,7 +785,9 @@ def publish_value(self) -> bool:
758785
# is_running covers the owned path (True after start()); for an owned client
759786
# connected implies running, so this does not change owned behavior.
760787
if not mqttc or not (mqttc.is_running or mqttc.is_connected()):
761-
logger.warning(f"reason=propertyPublishValueNoMqttClient,id={self._id}")
788+
_log_missing_client(
789+
f"reason=propertyPublishValueNoMqttClient,id={self._id}", by_design=self._transport_free()
790+
)
762791
return False
763792
node_id = self.get_node_id()
764793
device_id = self.get_device_id()
@@ -837,7 +866,9 @@ def clear_value(self) -> bool:
837866
# See publish_value: gate on connectivity so an injected (caller-driven)
838867
# client can retract a retained value even without the SDK's is_running.
839868
if not mqttc or not (mqttc.is_running or mqttc.is_connected()):
840-
logger.warning(f"reason=propertyClearValueNoMqttClient,propertyID={self._id}")
869+
_log_missing_client(
870+
f"reason=propertyClearValueNoMqttClient,propertyID={self._id}", by_design=self._transport_free()
871+
)
841872
return False
842873
node_id = self.get_node_id()
843874
device_id = self.get_device_id()
@@ -957,7 +988,7 @@ def set_subscribe(self) -> None:
957988
logger.debug(f"reason=propertySetSubscribe,id={self._id}")
958989
mqttc = self.get_mqtt_client()
959990
if not mqttc:
960-
logger.warning("reason=propertySetSubscribeNoMqttClient")
991+
_log_missing_client("reason=propertySetSubscribeNoMqttClient", by_design=self._transport_free())
961992
return
962993
if not self.settable():
963994
logger.debug(f"reason=propertySetSubscribePropertyNotSettable,id={self._id}")
@@ -1054,6 +1085,12 @@ def get_device_id(self) -> str:
10541085
def device(self) -> Device:
10551086
return self._device
10561087

1088+
def _transport_free(self) -> bool:
1089+
"""See ``Device._transport_free``. An incomplete chain falls through as *not*
1090+
transport-free so a half-built tree stays loud rather than going quiet."""
1091+
device = self.device()
1092+
return device._transport_free() if device is not None else False
1093+
10571094
def set_device(self, device: Device) -> None:
10581095
self._device = device
10591096

@@ -1064,7 +1101,9 @@ def get_mqtt_client(self) -> Optional[MqttDeviceTransport]:
10641101
return None
10651102
mqttc = device.get_mqtt_client()
10661103
if not mqttc:
1067-
logger.warning(f"reason=nodeGetMqttClientNoMqttClient,nodeID={self._id}")
1104+
_log_missing_client(
1105+
f"reason=nodeGetMqttClientNoMqttClient,nodeID={self._id}", by_design=self._transport_free()
1106+
)
10681107
return mqttc
10691108

10701109
def add_property(self, property: Property) -> Property:
@@ -1415,6 +1454,18 @@ def root(self) -> "Device":
14151454
"""
14161455
return self if self._parent is None else self._parent.root()
14171456

1457+
def _transport_free(self) -> bool:
1458+
"""True when this tree was deliberately built without transport.
1459+
1460+
The root holds no client and was given no config to build one from, so "no client"
1461+
is the requested state rather than a fault: the tree is serving as a naming and
1462+
structure model for topic derivation, ``$description``, or tests. A root that was
1463+
handed a client or given a config is the opposite case — there a missing client is
1464+
an anomaly and stays a warning.
1465+
"""
1466+
root = self.root()
1467+
return root.mqttc is None and root._mqtt_cfg is None
1468+
14181469
@staticmethod
14191470
def now_ems() -> int:
14201471
"""
@@ -1500,7 +1551,9 @@ def get_mqtt_client(self) -> Optional[MqttDeviceTransport]:
15001551
"""
15011552
mqttc = self.root().mqttc
15021553
if not mqttc:
1503-
logger.warning(f"reason=deviceGetMqttClientNoMqttClient,id={self._id}")
1554+
_log_missing_client(
1555+
f"reason=deviceGetMqttClientNoMqttClient,id={self._id}", by_design=self._transport_free()
1556+
)
15041557
return mqttc
15051558

15061559
def start_mqtt_client(self) -> None:
@@ -1510,7 +1563,9 @@ def start_mqtt_client(self) -> None:
15101563
"""
15111564
root = self.root()
15121565
if root.mqttc is None:
1513-
logger.warning(f"reason=deviceStartMqttClientNoMqttClient,id={self._id}")
1566+
_log_missing_client(
1567+
f"reason=deviceStartMqttClientNoMqttClient,id={self._id}", by_design=self._transport_free()
1568+
)
15141569
return
15151570
if not root._owns_client:
15161571
# Bring-your-own-transport: the caller owns the client's lifecycle, so
@@ -1566,7 +1621,7 @@ def stop(self, *, flush_timeout: float = 1.0, stop_timeout: float = 2.0) -> None
15661621
root = self.root()
15671622
mqttc = root.mqttc
15681623
if mqttc is None:
1569-
logger.warning(f"reason=deviceStopNoMqttClient,id={self._id}")
1624+
_log_missing_client(f"reason=deviceStopNoMqttClient,id={self._id}", by_design=self._transport_free())
15701625
return
15711626
# Best-effort graceful $state=disconnected. publish_and_flush is bounded
15721627
# and returns False (never blocks/raises) when the broker is unreachable,
@@ -1718,7 +1773,9 @@ def delete_all_from_mqtt(self) -> None:
17181773

17191774
mqttc = self.get_mqtt_client()
17201775
if not mqttc:
1721-
logger.warning(f"reason=deviceDeleteAllFromMqttNoMqttClient,deviceId={self._id}")
1776+
_log_missing_client(
1777+
f"reason=deviceDeleteAllFromMqttNoMqttClient,deviceId={self._id}", by_design=self._transport_free()
1778+
)
17221779
return
17231780

17241781
base_topic = f"{EBUS_HOMIE_DOMAIN}/{EBUS_HOMIE_VERSION_MAJOR}/{self._id}"
@@ -1808,7 +1865,9 @@ def clear_retained_topic(self, topic_path: str) -> bool:
18081865
"""
18091866
mqttc = self.get_mqtt_client()
18101867
if not mqttc:
1811-
logger.warning(f"reason=deviceClearTopicNoMqttClient,topic={topic_path}")
1868+
_log_missing_client(
1869+
f"reason=deviceClearTopicNoMqttClient,topic={topic_path}", by_design=self._transport_free()
1870+
)
18121871
return False
18131872
try:
18141873
mqttc.publish(topic_path, "", retain=True, qos=self._qos)
@@ -1930,7 +1989,11 @@ def publish(self, attribute: str = "", value: Optional[Any] = None) -> None:
19301989
"""
19311990
mqttc = self.get_mqtt_client()
19321991
if not mqttc:
1933-
logger.info(f"reason=devicePublishNoMqttClient,attribute={attribute}")
1992+
_log_missing_client(
1993+
f"reason=devicePublishNoMqttClient,attribute={attribute}",
1994+
by_design=self._transport_free(),
1995+
level=logging.INFO,
1996+
)
19341997
return
19351998
if not self._id:
19361999
logger.info("reason=devicePublishNoDeviceID")

tests/test_homie_device.py

Lines changed: 94 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
"""Tests for ebus_sdk.homie device-role classes: Property, Node, Device, and helpers."""
22

33
import json
4+
import logging
45
from enum import Enum
56
from unittest.mock import MagicMock, patch
67

@@ -2106,3 +2107,96 @@ def test_guard_still_fires_when_a_configured_root_has_no_client(self):
21062107

21072108
with pytest.raises(RuntimeError, match="has no MQTT client"):
21082109
Device(id="child", type="dev.child", parent=root)
2110+
2111+
2112+
class TestTransportFreeLogSeverity:
2113+
"""A tree built without transport reports "no client" at DEBUG, not WARNING (#11).
2114+
2115+
The message is right either way; only the cause differs. Transport-free means the caller
2116+
asked for no client, so every traversal announcing one is noise — a 31-device tree emitted
2117+
1,593 WARNING lines saying only that it got what it requested. A root that was given a
2118+
config, or handed a client, is the case where a missing client is a real fault, and that
2119+
one stays exactly as loud as it was.
2120+
"""
2121+
2122+
@staticmethod
2123+
def _tree(**root_kwargs):
2124+
root = Device(id="root", name="Root", type="dev.root", **root_kwargs)
2125+
node = root.add_node_from_dict({"id": "meter", "name": "meter", "type": "cap.meter"})
2126+
prop = node.add_property_from_dict({"id": "power", "name": "power", "datatype": "float", "settable": True})
2127+
return root, node, prop
2128+
2129+
@staticmethod
2130+
def _no_client_records(caplog, level):
2131+
return [r for r in caplog.records if r.levelno == level and "NoMqttClient" in r.getMessage()]
2132+
2133+
def test_transport_free_tree_reports_missing_client_at_debug(self, caplog):
2134+
"""The whole point: no WARNING anywhere in a tree that asked for no transport."""
2135+
root, _node, prop = self._tree()
2136+
2137+
with caplog.at_level(logging.DEBUG, logger="homie"):
2138+
prop.get_mqtt_client() # property -> node -> device, three sites in one call
2139+
prop.publish_value()
2140+
prop.set_subscribe()
2141+
prop.start_mqtt_client()
2142+
root.start_mqtt_client()
2143+
root.stop()
2144+
2145+
assert self._no_client_records(caplog, logging.WARNING) == []
2146+
assert self._no_client_records(caplog, logging.DEBUG)
2147+
2148+
def test_a_root_given_a_config_still_warns(self, caplog):
2149+
"""The "you forgot to start the root" case, which the issue is careful to preserve.
2150+
2151+
`_mqtt_cfg` is what separates it: a root that was told how to build a client and has
2152+
none is broken, where a root told nothing is simply passive.
2153+
"""
2154+
with patch("ebus_sdk.homie.MqttClient.from_config") as mock_from_config:
2155+
mock_from_config.return_value = _mock_mqtt_client()
2156+
root, _node, prop = self._tree(mqtt_cfg={"host": "broker.invalid"})
2157+
root.mqttc = None # client expected, absent — the genuine fault
2158+
2159+
with caplog.at_level(logging.DEBUG, logger="homie"):
2160+
prop.get_mqtt_client()
2161+
2162+
assert root._transport_free() is False
2163+
assert self._no_client_records(caplog, logging.WARNING)
2164+
2165+
def test_an_injected_client_is_not_transport_free(self):
2166+
"""Bring-your-own-transport is the opposite of transport-free, even though both
2167+
leave `_mqtt_cfg` unset — the client is present, so its absence would be an anomaly."""
2168+
root = Device(id="root", type="dev.root", mqttc=_mock_mqtt_client())
2169+
2170+
assert root._transport_free() is False
2171+
2172+
def test_the_predicate_resolves_from_every_level(self):
2173+
"""Property and Node answer for their tree, not for themselves."""
2174+
root, node, prop = self._tree()
2175+
child = Device(id="child", type="dev.child", parent=root)
2176+
2177+
assert root._transport_free() is True
2178+
assert child._transport_free() is True
2179+
assert node._transport_free() is True
2180+
assert prop._transport_free() is True
2181+
2182+
def test_a_detached_entity_stays_loud(self, caplog):
2183+
"""An incomplete chain cannot prove the tree is transport-free, so it does not go
2184+
quiet: a property with no node is a bug, and silencing it would hide one."""
2185+
orphan = Property(id="power", name="power", datatype=PropertyDatatype.FLOAT)
2186+
2187+
assert orphan._transport_free() is False
2188+
2189+
def test_device_publish_keeps_its_own_severity_when_a_client_was_expected(self, caplog):
2190+
"""`devicePublishNoMqttClient` was already INFO on main. Transport-free drops it to
2191+
DEBUG; the expected-a-client case keeps INFO rather than being escalated."""
2192+
with patch("ebus_sdk.homie.MqttClient.from_config") as mock_from_config:
2193+
mock_from_config.return_value = _mock_mqtt_client()
2194+
root, _node, _prop = self._tree(mqtt_cfg={"host": "broker.invalid"})
2195+
root.mqttc = None
2196+
2197+
with caplog.at_level(logging.DEBUG, logger="homie"):
2198+
root.publish(attribute="$state", value="ready")
2199+
2200+
assert [
2201+
r for r in caplog.records if r.levelno == logging.INFO and "devicePublishNoMqttClient" in r.getMessage()
2202+
]

0 commit comments

Comments
 (0)