Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
27 changes: 24 additions & 3 deletions BlocksScreen/lib/network/worker.py
Original file line number Diff line number Diff line change
Expand Up @@ -32,6 +32,7 @@
VlanInfo,
is_connectable_security,
is_hidden_ssid,
signal_to_bars,
)

logger = logging.getLogger(__name__)
Expand Down Expand Up @@ -133,6 +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, 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(
Expand Down Expand Up @@ -982,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()
Expand Down Expand Up @@ -1021,14 +1026,21 @@ 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,
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[:-1],
signal,
)
return NetworkState(
Expand All @@ -1045,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(
Expand Down Expand Up @@ -1294,7 +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))
logger.info("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:
Expand Down
85 changes: 85 additions & 0 deletions tests/network/test_worker_unit.py
Original file line number Diff line number Diff line change
Expand Up @@ -74,6 +74,8 @@ 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._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 ""
Expand Down Expand Up @@ -120,6 +122,8 @@ def _bare_worker(qapp):
w._rediscover_gen = 0
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 = ""
Expand Down Expand Up @@ -157,6 +161,8 @@ 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._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 ""
Expand Down Expand Up @@ -947,6 +953,55 @@ 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"), (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() # 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, 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):
w = _make_worker(qapp)
Expand Down Expand Up @@ -1076,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)
Expand Down
2 changes: 2 additions & 0 deletions tests/updater/test_service_unit.py
Original file line number Diff line number Diff line change
Expand Up @@ -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()
Expand All @@ -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()
Expand Down
2 changes: 1 addition & 1 deletion updater/service.py
Original file line number Diff line number Diff line change
Expand Up @@ -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),
)
Expand Down