Jack Nagy
36acf3a209
Four failure modes observed in-house since the polling-first refactor
(709fdf4):
1. Half-open DTLS sessions where the socket stays writable but the peer
has gone silent. Ping sends succeed against a wedged peer because
RT-OCF doesn't reliably emit a RST; only successful polls prove the
session is live.
- PollScheduler exposes last_success_ts (bumped on every 2.05).
- KeepaliveTask takes liveness_fn(); ticks fail if no 2.05 in the
last 60s, even when the ping send succeeded.
- Bridge force-closes the session after 120s unreachable so
run_forever() breaks out of sess.join() and reconnects.
2. RT-OCF cascade under load. One wedged path can eat 8s of timeout,
the next tier tick fires immediately and stacks another attempt,
and the device wedges harder.
- PollTier.timeout_s per-tier override (hot=2s, warm=4s, sweep=15s).
- On TimeoutError, the href goes into a 5-60s cooldown via the
existing _defer_until mechanism.
- take_window_stats() now reports successful-poll RTT separately
from a timeout count, exposed as the "Poll Timeouts (window)"
diagnostic entity in HA.
- Active-window throttle: if the previous health window saw >=3
timeouts and is_active=True, drop back to idle cadence -- stops
stacking polls on a stalled responder.
3. OBSERVE table aging across cloud-auth blips. The device stays
DTLS-reachable but the on-device stack clears its observer table
during the blip, so push delivery stays dead even after upstream
recovers.
- New ObserveRefreshTask per bridge; every 6h derregs all current
observer tokens and re-subscribes on the existing session.
4. Oven lamp/door coupling. Oven hardware auto-drives the lamp from
door state but /mode/vs/0 is warm-tier (30s) so HA showed stale lamp
during a cook.
- Track door + lamp value-change timestamps in descriptor_state.
When the door transition is newer, derive lamp from door_open.
When an HA optimistic write is newer, the cache value wins.
Also: ANSI-coloured WARNING/ERROR lines (NO_COLOR=1 opt-out), jittered
reconnect backoff so dryer + oven don't sync up after a router blip.
In-house verification: running on dryer + oven since 2026-06-03.
71 lines
2.4 KiB
Python
71 lines
2.4 KiB
Python
"""Stdout logging — works correctly under Docker's PYTHONUNBUFFERED=1.
|
|
|
|
Two logger families share the root handler:
|
|
* `samsung_appliance` (and its children) for module-level lines —
|
|
DTLS warnings, generic startup chatter, MQTT plumbing.
|
|
* `<class>.<serial>` for per-appliance bridge lines — e.g.
|
|
`dryer.<serial>`. Each PushBridge gets its own such logger
|
|
via bridge_logger() once the seed reveals the appliance's serial.
|
|
|
|
Both trees propagate to the root logger, which is the one with the
|
|
StreamHandler, so the same format applies everywhere.
|
|
|
|
WARNING lines render yellow, ERROR red, when colour is enabled. Set
|
|
`NO_COLOR=1` in the environment to fall back to plain text (e.g. when
|
|
writing logs to a file)."""
|
|
import logging
|
|
import os
|
|
import sys
|
|
|
|
|
|
_LEVEL_COLOURS = {
|
|
logging.WARNING: '\033[33m', # yellow
|
|
logging.ERROR: '\033[31m', # red
|
|
logging.CRITICAL: '\033[1;31m', # bold red
|
|
}
|
|
_RESET = '\033[0m'
|
|
|
|
|
|
def _colour_enabled() -> bool:
|
|
return 'NO_COLOR' not in os.environ
|
|
|
|
|
|
class _LevelColourFormatter(logging.Formatter):
|
|
"""Wraps the rendered line in an ANSI colour for WARNING+ levels.
|
|
INFO/DEBUG pass through unchanged so the bulk of the log stays
|
|
readable and a yellow line draws the eye."""
|
|
|
|
def __init__(self, fmt: str, datefmt: str, use_colour: bool):
|
|
super().__init__(fmt=fmt, datefmt=datefmt)
|
|
self.use_colour = use_colour
|
|
|
|
def format(self, record: logging.LogRecord) -> str:
|
|
line = super().format(record)
|
|
if not self.use_colour:
|
|
return line
|
|
colour = _LEVEL_COLOURS.get(record.levelno)
|
|
if colour is None:
|
|
return line
|
|
return f"{colour}{line}{_RESET}"
|
|
|
|
|
|
_handler = logging.StreamHandler(sys.stdout)
|
|
_handler.setFormatter(_LevelColourFormatter(
|
|
fmt='%(asctime)s %(levelname)-5s %(name)-26s %(message)s',
|
|
datefmt='%H:%M:%S',
|
|
use_colour=_colour_enabled(),
|
|
))
|
|
|
|
logging.basicConfig(level=logging.INFO, handlers=[_handler], force=True)
|
|
|
|
logger = logging.getLogger("samsung_appliance")
|
|
|
|
|
|
def bridge_logger(klass: str, serial: str | None = None) -> logging.Logger:
|
|
"""Return a top-level logger tagged with the appliance class and,
|
|
once known, the serial. Pre-seed callers pass serial=None and get
|
|
e.g. `dryer`; post-seed callers pass the serial and get e.g.
|
|
`dryer.<serial>`."""
|
|
name = f"{klass}.{serial}" if serial else klass
|
|
return logging.getLogger(name)
|