From aa0d8cb1b95705a09c0d0318a7e5f2a13e300883 Mon Sep 17 00:00:00 2001 From: Guilherme Costa Date: Fri, 23 Oct 2026 16:30:08 +0100 Subject: [PATCH 1/4] fix(network): stop scan and unchanged-state lines flooding the INFO log --- BlocksScreen/lib/network/worker.py | 15 ++++++++++++--- tests/network/test_worker_unit.py | 22 ++++++++++++++++++++++ 2 files changed, 34 insertions(+), 3 deletions(-) diff --git a/BlocksScreen/lib/network/worker.py b/BlocksScreen/lib/network/worker.py index 351e4ba0..07ca0347 100644 --- a/BlocksScreen/lib/network/worker.py +++ b/BlocksScreen/lib/network/worker.py @@ -133,6 +133,8 @@ def __init__(self) -> None: self._stale_logged_gen = -1 # Wi-Fi FAILED count, latched by the StateChanged listener. self._wifi_failures = 0 + # Last logged state minus signal: an unchanged snapshot logs at DEBUG only. + self._last_state_key: tuple | None = None self._asyncio_loop: asyncio.AbstractEventLoop = asyncio.new_event_loop() self._asyncio_thread = threading.Thread( @@ -1021,14 +1023,20 @@ async def _build_current_state(self) -> NetworkState: carrier, vlans = await asyncio.gather( self._has_ethernet_carrier(), self._get_active_vlans() ) - logger.info( - "state: conn=%s ssid='%s' ip=%s wifi=%s eth=%s hotspot=%s sig=%d", + state_key = ( connectivity.name, current_ssid, current_ip or "-", wifi_enabled, eth_connected, hotspot_enabled, + ) + changed = state_key != self._last_state_key + self._last_state_key = state_key + logger.log( + logging.INFO if changed else logging.DEBUG, + "state: conn=%s ssid='%s' ip=%s wifi=%s eth=%s hotspot=%s sig=%d", + *state_key, signal, ) return NetworkState( @@ -1294,7 +1302,8 @@ async def _scan_networks_once(self) -> None: seen_ssids.add(info.ssid) networks.sort(key=lambda n: (-n.network_status, -n.signal_strength)) - logger.info("scan: %d visible of %d AP(s)", len(networks), len(ap_paths)) + # Counts drift on every periodic scan: INFO here flooded the field logs. + logger.debug("scan: %d visible of %d AP(s)", len(networks), len(ap_paths)) self.networks_scanned.emit(networks) async def _request_scan_if_allowed(self) -> None: diff --git a/tests/network/test_worker_unit.py b/tests/network/test_worker_unit.py index f87f2e9d..00a10801 100644 --- a/tests/network/test_worker_unit.py +++ b/tests/network/test_worker_unit.py @@ -74,6 +74,7 @@ def _make_worker(qapp, *, running=True, with_wifi=True, with_wired=False): w._rediscover_gen = 0 w._stale_logged_gen = -1 w._wifi_failures = 0 + w._last_state_key = None w._system_bus = MagicMock(name="mock_system_bus") w._primary_wifi_path = ( "/org/freedesktop/NetworkManager/Devices/2" if with_wifi else "" @@ -120,6 +121,7 @@ def _bare_worker(qapp): w._rediscover_gen = 0 w._stale_logged_gen = -1 w._wifi_failures = 0 + w._last_state_key = None w._system_bus = None w._primary_wifi_path = "" w._primary_wifi_iface = "" @@ -157,6 +159,7 @@ def _make(qapp, *, running=True, wifi=True, wired=True): w._rediscover_gen = 0 w._stale_logged_gen = -1 w._wifi_failures = 0 + w._last_state_key = None w._system_bus = MagicMock(name="mock_bus") w._primary_wifi_path = "/org/freedesktop/NetworkManager/Devices/2" if wifi else "" w._primary_wifi_iface = "wlan0" if wifi else "" @@ -947,6 +950,25 @@ async def test_connected_state(self, qapp): assert state.wifi_enabled is True assert state.current_ssid == "" + @pytest.mark.asyncio + async def test_unchanged_state_logs_at_debug(self, qapp, caplog): + w = _make_worker(qapp) + w._nm = _ProxyFactory(AsyncProxyMock(connectivity=4, wireless_enabled=True)) + w._get_current_ssid = AsyncMock(return_value="BLOCKS") + w._get_current_ip = AsyncMock(return_value="192.168.1.151") + w._is_ethernet_connected = AsyncMock(return_value=False) + w._has_ethernet_carrier = AsyncMock(return_value=False) + w._get_active_vlans = AsyncMock(return_value=[]) + signals = iter([(67, "wpa-psk"), (68, "wpa-psk"), (68, "wpa-psk")]) + w._wifi_signal_and_security = AsyncMock(side_effect=lambda _: next(signals)) + with caplog.at_level(logging.DEBUG, logger=_worker_mod.logger.name): + await w._build_current_state() + await w._build_current_state() # only the signal moved + w._get_current_ip = AsyncMock(return_value="192.168.1.152") + await w._build_current_state() + levels = [r.levelno for r in caplog.records if r.msg.startswith("state:")] + assert levels == [logging.INFO, logging.DEBUG, logging.INFO] + @pytest.mark.asyncio async def test_connected_with_ssid_gets_signal_and_security(self, qapp): w = _make_worker(qapp) From 93197a46a7f4356740b00c0ce587b5b9e4fec5f1 Mon Sep 17 00:00:00 2001 From: Guilherme Costa Date: Mon, 26 Oct 2026 16:38:14 +0000 Subject: [PATCH 2/4] fix(network): reset state key on failures and keep signal-band and empty-scan lines at INFO --- BlocksScreen/lib/network/worker.py | 20 +++++++-- tests/network/test_worker_unit.py | 69 ++++++++++++++++++++++++++++-- 2 files changed, 82 insertions(+), 7 deletions(-) diff --git a/BlocksScreen/lib/network/worker.py b/BlocksScreen/lib/network/worker.py index 07ca0347..f97dacdc 100644 --- a/BlocksScreen/lib/network/worker.py +++ b/BlocksScreen/lib/network/worker.py @@ -32,6 +32,7 @@ VlanInfo, is_connectable_security, is_hidden_ssid, + signal_to_bars, ) logger = logging.getLogger(__name__) @@ -133,8 +134,9 @@ def __init__(self) -> None: self._stale_logged_gen = -1 # Wi-Fi FAILED count, latched by the StateChanged listener. self._wifi_failures = 0 - # Last logged state minus signal: an unchanged snapshot logs at DEBUG only. + # Last logged state, signal as bars: an unchanged snapshot logs at DEBUG only. self._last_state_key: tuple | None = None + self._last_scan_visible = -1 self._asyncio_loop: asyncio.AbstractEventLoop = asyncio.new_event_loop() self._asyncio_thread = threading.Thread( @@ -984,6 +986,7 @@ def _get_ip_os_fallback(iface: str) -> str: async def _build_current_state(self) -> NetworkState: """Read all relevant NM properties and assemble a NetworkState snapshot.""" if not self._system_bus: + self._last_state_key = None return NetworkState() try: wifi_iface = self._get_wifi_iface_name() @@ -1030,13 +1033,14 @@ async def _build_current_state(self) -> NetworkState: wifi_enabled, eth_connected, hotspot_enabled, + signal_to_bars(signal), ) changed = state_key != self._last_state_key self._last_state_key = state_key logger.log( logging.INFO if changed else logging.DEBUG, "state: conn=%s ssid='%s' ip=%s wifi=%s eth=%s hotspot=%s sig=%d", - *state_key, + *state_key[:-1], signal, ) return NetworkState( @@ -1053,6 +1057,7 @@ async def _build_current_state(self) -> NetworkState: ) except Exception as exc: logger.error("Error building current state: %s", exc) + self._last_state_key = None return NetworkState() async def _resolve_current_ip( @@ -1302,8 +1307,15 @@ async def _scan_networks_once(self) -> None: seen_ssids.add(info.ssid) networks.sort(key=lambda n: (-n.network_status, -n.signal_strength)) - # Counts drift on every periodic scan: INFO here flooded the field logs. - logger.debug("scan: %d visible of %d AP(s)", len(networks), len(ap_paths)) + # Counts drift on every periodic scan: only going to or from none is INFO. + emptied = (len(networks) == 0) != (self._last_scan_visible == 0) + self._last_scan_visible = len(networks) + logger.log( + logging.INFO if emptied else logging.DEBUG, + "scan: %d visible of %d AP(s)", + len(networks), + len(ap_paths), + ) self.networks_scanned.emit(networks) async def _request_scan_if_allowed(self) -> None: diff --git a/tests/network/test_worker_unit.py b/tests/network/test_worker_unit.py index 00a10801..1d4a0448 100644 --- a/tests/network/test_worker_unit.py +++ b/tests/network/test_worker_unit.py @@ -75,6 +75,7 @@ def _make_worker(qapp, *, running=True, with_wifi=True, with_wired=False): w._stale_logged_gen = -1 w._wifi_failures = 0 w._last_state_key = None + w._last_scan_visible = -1 w._system_bus = MagicMock(name="mock_system_bus") w._primary_wifi_path = ( "/org/freedesktop/NetworkManager/Devices/2" if with_wifi else "" @@ -122,6 +123,7 @@ def _bare_worker(qapp): w._stale_logged_gen = -1 w._wifi_failures = 0 w._last_state_key = None + w._last_scan_visible = -1 w._system_bus = None w._primary_wifi_path = "" w._primary_wifi_iface = "" @@ -160,6 +162,7 @@ def _make(qapp, *, running=True, wifi=True, wired=True): w._stale_logged_gen = -1 w._wifi_failures = 0 w._last_state_key = None + w._last_scan_visible = -1 w._system_bus = MagicMock(name="mock_bus") w._primary_wifi_path = "/org/freedesktop/NetworkManager/Devices/2" if wifi else "" w._primary_wifi_iface = "wlan0" if wifi else "" @@ -959,15 +962,45 @@ async def test_unchanged_state_logs_at_debug(self, qapp, caplog): w._is_ethernet_connected = AsyncMock(return_value=False) w._has_ethernet_carrier = AsyncMock(return_value=False) w._get_active_vlans = AsyncMock(return_value=[]) - signals = iter([(67, "wpa-psk"), (68, "wpa-psk"), (68, "wpa-psk")]) + signals = iter( + [(67, "wpa-psk"), (68, "wpa-psk"), (40, "wpa-psk"), (40, "wpa-psk")] + ) w._wifi_signal_and_security = AsyncMock(side_effect=lambda _: next(signals)) with caplog.at_level(logging.DEBUG, logger=_worker_mod.logger.name): await w._build_current_state() - await w._build_current_state() # only the signal moved + await w._build_current_state() # same signal band + await w._build_current_state() # band dropped w._get_current_ip = AsyncMock(return_value="192.168.1.152") await w._build_current_state() levels = [r.levelno for r in caplog.records if r.msg.startswith("state:")] - assert levels == [logging.INFO, logging.DEBUG, logging.INFO] + assert levels == [logging.INFO, logging.DEBUG, logging.INFO, logging.INFO] + + @pytest.mark.parametrize("failure", ["no_bus", "raises"]) + @pytest.mark.asyncio + async def test_recovery_to_same_state_logs_at_info(self, qapp, caplog, failure): + w = _make_worker(qapp) + w._nm = _ProxyFactory(AsyncProxyMock(connectivity=4, wireless_enabled=True)) + w._get_current_ssid = AsyncMock(return_value="BLOCKS") + w._get_current_ip = AsyncMock(return_value="192.168.1.151") + w._is_ethernet_connected = AsyncMock(return_value=False) + w._has_ethernet_carrier = AsyncMock(return_value=False) + w._get_active_vlans = AsyncMock(return_value=[]) + w._wifi_signal_and_security = AsyncMock(return_value=(67, "wpa-psk")) + with caplog.at_level(logging.DEBUG, logger=_worker_mod.logger.name): + await w._build_current_state() + if failure == "no_bus": + bus, w._system_bus = w._system_bus, None + await w._build_current_state() + w._system_bus = bus + else: + ssid, w._get_current_ssid = w._get_current_ssid, AsyncMock( + side_effect=RuntimeError("NM restarted") + ) + await w._build_current_state() + w._get_current_ssid = ssid + await w._build_current_state() + levels = [r.levelno for r in caplog.records if r.msg.startswith("state:")] + assert levels == [logging.INFO, logging.INFO] @pytest.mark.asyncio async def test_connected_with_ssid_gets_signal_and_security(self, qapp): @@ -1098,6 +1131,36 @@ async def test_exception_returns_default(self, qapp, caplog): class TestScanNetworks: + @pytest.mark.asyncio + async def test_scan_count_to_or_from_zero_logs_at_info(self, qapp, caplog): + w = _make_worker(qapp) + w._ensure_dbus_connection = AsyncMock(return_value=True) + w._nm = _ProxyFactory(AsyncProxyMock(wireless_enabled=True)) + wifi_proxy = AsyncProxyMock(request_scan=AsyncMock(), last_scan=100) + w._wifi = _ProxyFactory(wifi_proxy) + w._get_current_ssid = AsyncMock(return_value="") + w._get_saved_ssid_names_cached = AsyncMock(return_value=[]) + w._parse_ap = AsyncMock( + side_effect=lambda p, *_: NetworkInfo( + ssid=p, + signal_strength=75, + network_status=NetworkStatus.DISCOVERED, + security_type=SecurityType.WPA2_PSK, + ) + ) + with caplog.at_level(logging.DEBUG, logger=_worker_mod.logger.name): + for aps in (["a"], ["a", "b"], [], [], ["a"]): + wifi_proxy.get_all_access_points = AsyncMock(return_value=aps) + await w._scan_networks_once() + levels = [r.levelno for r in caplog.records if r.msg.startswith("scan: %d")] + assert levels == [ + logging.DEBUG, + logging.DEBUG, + logging.INFO, + logging.DEBUG, + logging.INFO, + ] + @pytest.mark.asyncio async def test_scan_no_wifi_path_emits_empty(self, qapp): w = _make_worker(qapp, with_wifi=False) From 2ed582d278bc400ef75510fe9785cc76476d7aaf Mon Sep 17 00:00:00 2001 From: Guilherme Costa Date: Mon, 26 Oct 2026 17:35:33 +0000 Subject: [PATCH 3/4] fix(updater): drop misleading UI-restart suffix from batch-complete log --- updater/service.py | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/updater/service.py b/updater/service.py index 2c1abba8..11b3112b 100644 --- a/updater/service.py +++ b/updater/service.py @@ -913,7 +913,7 @@ async def _finalize_git_batch( # Shrink the marker before any restart: survivors stand from here on. await self._settle_inflight(pending_revert) self._log.info( - "git batch complete: %d/%d component(s) updated; queueing UI restart(s)", + "git batch complete: %d/%d component(s) updated", len(alive), len(batch), ) From b3d2e39083b177a7714b295dcb0086ba87985fd4 Mon Sep 17 00:00:00 2001 From: Guilherme Costa Date: Mon, 26 Oct 2026 17:35:35 +0000 Subject: [PATCH 4/4] test(updater): stub restart_service in batch revert tests --- tests/updater/test_service_unit.py | 2 ++ 1 file changed, 2 insertions(+) diff --git a/tests/updater/test_service_unit.py b/tests/updater/test_service_unit.py index 1e9d6b36..fb536ff2 100644 --- a/tests/updater/test_service_unit.py +++ b/tests/updater/test_service_unit.py @@ -987,6 +987,7 @@ async def test_inflight_marker_kept_when_abort_revert_fails(self, tmp_path): return_value=(True, ""), ), patch("updater.service.git_reset_to_hash", return_value=(False, "boom")), + patch("updater.service.restart_service", return_value=(False, "failed")), ): await svc._run_git_batch(comps) assert svc._inflight_path.exists() @@ -1008,6 +1009,7 @@ async def test_abort_completes_when_revert_raises(self, tmp_path): return_value=(True, ""), ), patch("updater.service.git_reset_to_hash", side_effect=OSError("disk")), + patch("updater.service.restart_service", return_value=(False, "failed")), ): await svc._run_git_batch(comps) assert svc._inflight_path.exists()