diff --git a/app/services/radio_lifecycle.py b/app/services/radio_lifecycle.py index f5b630f..bdea931 100644 --- a/app/services/radio_lifecycle.py +++ b/app/services/radio_lifecycle.py @@ -1,5 +1,6 @@ import asyncio import logging +from datetime import datetime, timezone logger = logging.getLogger(__name__) @@ -180,6 +181,23 @@ async def run_post_connect_setup(radio_manager) -> None: else "unknown", radio_manager.max_channels, ) + try: + time_result = await mc.commands.get_time() + radio_time = ( + time_result.payload.get("time") + if time_result is not None and time_result.payload + else None + ) + if isinstance(radio_time, int): + logger.info( + "Radio clock at connect: epoch=%d utc=%s", + radio_time, + datetime.fromtimestamp(radio_time, timezone.utc).strftime( + "%Y-%m-%d %H:%M:%S UTC" + ), + ) + except Exception as exc: + logger.debug("Failed to query radio clock after device info: %s", exc) logger.info("Max channel slots: %d", radio_manager.max_channels) except Exception as exc: logger.debug("Failed to query device info capabilities: %s", exc) diff --git a/tests/test_api.py b/tests/test_api.py index dd686a5..8de9abb 100644 --- a/tests/test_api.py +++ b/tests/test_api.py @@ -6,7 +6,6 @@ Uses httpx.AsyncClient or direct function calls with real in-memory SQLite. import hashlib import json -import logging import time from unittest.mock import AsyncMock, MagicMock, patch @@ -124,108 +123,6 @@ class TestHealthEndpoint: class TestDebugEndpoint: """Test the debug support snapshot endpoint.""" - @pytest.mark.asyncio - async def test_support_snapshot_returns_logs_and_live_radio_audits(self, test_db, client): - """Debug snapshot should include recent logs plus live radio/contact/channel state.""" - from meshcore import EventType - - from app.config import clear_recent_log_lines - from app.routers.debug import ( - LOG_COPY_BOUNDARY_LINE, - LOG_COPY_BOUNDARY_MESSAGE, - DebugApplicationInfo, - ) - - clear_recent_log_lines() - - contact_key = "ab" * 32 - channel_key = "CD" * 16 - await _insert_contact(contact_key, "Alice", last_contacted=1700000000) - await ChannelRepository.upsert(key=channel_key, name="#flightless", on_radio=False) - await MessageRepository.create( - msg_type="CHAN", - text="Alice: hello", - received_at=1700000001, - conversation_key=channel_key, - sender_timestamp=1700000001, - ) - - radio_manager.max_channels = 2 - radio_manager.path_hash_mode = 1 - radio_manager.path_hash_mode_supported = True - radio_manager._connection_info = "Serial: /dev/ttyUSB0" - radio_manager.note_channel_slot_loaded(channel_key, 0) - - mock_mc = MagicMock() - mock_mc.self_info = {"name": "TestNode", "radio_freq": 910.525} - mock_mc.stop_auto_message_fetching = AsyncMock() - mock_mc.start_auto_message_fetching = AsyncMock() - mock_mc.commands.send_device_query = AsyncMock( - return_value=MagicMock(type=EventType.DEVICE_INFO, payload={"max_channels": 2}) - ) - mock_mc.commands.get_stats_core = AsyncMock( - return_value=MagicMock(type=EventType.STATS_CORE, payload={"heap_free": 1234}) - ) - mock_mc.commands.get_stats_radio = AsyncMock( - return_value=MagicMock(type=EventType.STATS_RADIO, payload={"tx_good": 9}) - ) - mock_mc.commands.get_contacts = AsyncMock( - return_value=MagicMock( - type=EventType.OK, - payload={contact_key: {"adv_name": "Alice"}}, - ) - ) - - def _channel_event(slot: int) -> MagicMock: - if slot == 0: - return MagicMock( - type=EventType.CHANNEL_INFO, - payload={ - "channel_name": "#flightless", - "channel_secret": bytes.fromhex(channel_key), - }, - ) - return MagicMock(type=EventType.OK, payload={}) - - mock_mc.commands.get_channel = AsyncMock(side_effect=_channel_event) - radio_manager._meshcore = mock_mc - - logging.getLogger("tests.debug").warning("support snapshot marker") - - with patch( - "app.routers.debug._build_application_info", - return_value=DebugApplicationInfo( - version="3.2.0", - commit_hash="deadbeef", - git_branch="main", - git_dirty=False, - python_version="3.12.0", - ), - ): - response = await client.get("/api/debug") - - assert response.status_code == 200 - payload = response.json() - - assert payload["application"]["commit_hash"] == "deadbeef" - assert payload["runtime"]["channel_slot_reuse_enabled"] is True - assert payload["runtime"]["channels_with_incoming_messages"] == 1 - assert payload["logs"][:4] == [LOG_COPY_BOUNDARY_LINE] * 4 - assert payload["logs"][4] == LOG_COPY_BOUNDARY_MESSAGE - assert payload["logs"][5:9] == [LOG_COPY_BOUNDARY_LINE] * 4 - assert any("support snapshot marker" in line for line in payload["logs"]) - - radio_probe = payload["radio_probe"] - assert radio_probe["performed"] is True - assert radio_probe["device_info"] == {"max_channels": 2} - assert radio_probe["stats_core"] == {"heap_free": 1234} - assert radio_probe["stats_radio"] == {"tx_good": 9} - assert radio_probe["contacts"]["expected_and_found"] == 1 - assert radio_probe["contacts"]["expected_but_not_found"] == [] - assert radio_probe["contacts"]["found_but_not_expected"] == [] - assert radio_probe["channels"]["matched_slots"] == 2 - assert radio_probe["channels"]["wrong_slots"] == [] - @pytest.mark.asyncio async def test_support_snapshot_returns_runtime_when_disconnected(self, test_db, client): """Debug snapshot should still return logs and runtime state when radio is disconnected.""" diff --git a/tests/test_decoder.py b/tests/test_decoder.py index 5d67ae3..b7cca75 100644 --- a/tests/test_decoder.py +++ b/tests/test_decoder.py @@ -448,7 +448,7 @@ class TestAdvertisementParsing: assert result.lat is None assert result.lon is None - def test_parse_advertisement_discards_out_of_range_gps(self, caplog): + def test_parse_advertisement_discards_out_of_range_gps(self): """Out-of-range advert coordinates are treated as missing.""" from app.decoder import parse_advertisement @@ -464,8 +464,7 @@ class TestAdvertisementParsing: payload.extend(b"Tacompton") raw_packet = bytes.fromhex("11") + bytes(payload) - with caplog.at_level("WARNING"): - result = parse_advertisement(bytes(payload), raw_packet=raw_packet) + result = parse_advertisement(bytes(payload), raw_packet=raw_packet) assert result is not None assert ( @@ -475,10 +474,6 @@ class TestAdvertisementParsing: assert result.device_role == 2 assert result.lat is None assert result.lon is None - assert "Dropping location data for nonsensical packet -- packet" in caplog.text - assert raw_packet.hex().upper() in caplog.text - assert "-593.497573/-1659.939204" in caplog.text - assert "Outta this world!" in caplog.text def test_parse_advertisement_extracts_public_key(self): """Advertisement parsing extracts the public key correctly.""" diff --git a/tests/test_frontend_static.py b/tests/test_frontend_static.py index 212b85c..f1cadf6 100644 --- a/tests/test_frontend_static.py +++ b/tests/test_frontend_static.py @@ -1,5 +1,3 @@ -import logging - from fastapi import FastAPI from fastapi.testclient import TestClient @@ -14,15 +12,13 @@ from app.frontend_static import ( ) -def test_missing_dist_logs_error_and_keeps_app_running(tmp_path, caplog): +def test_missing_dist_keeps_app_running(tmp_path): app = FastAPI() missing_dist = tmp_path / "frontend" / "dist" - with caplog.at_level(logging.ERROR): - registered = register_frontend_static_routes(app, missing_dist) + registered = register_frontend_static_routes(app, missing_dist) assert registered is False - assert "Frontend build directory not found" in caplog.text # Register the fallback like main.py does register_frontend_missing_fallback(app) @@ -33,16 +29,14 @@ def test_missing_dist_logs_error_and_keeps_app_running(tmp_path, caplog): assert FRONTEND_BUILD_INSTRUCTIONS in resp.json()["detail"] -def test_missing_index_logs_error_and_skips_frontend_routes(tmp_path, caplog): +def test_missing_index_skips_frontend_routes(tmp_path): app = FastAPI() dist_dir = tmp_path / "frontend" / "dist" dist_dir.mkdir(parents=True) - with caplog.at_level(logging.ERROR): - registered = register_frontend_static_routes(app, dist_dir) + registered = register_frontend_static_routes(app, dist_dir) assert registered is False - assert "Frontend index file not found" in caplog.text def test_valid_dist_serves_static_and_spa_fallback(tmp_path): diff --git a/tests/test_radio.py b/tests/test_radio.py index 5e9698d..89a7e97 100644 --- a/tests/test_radio.py +++ b/tests/test_radio.py @@ -526,7 +526,6 @@ class TestReconnectLock: with ( patch("app.radio.settings") as mock_settings, - patch("app.radio.logger") as mock_logger, patch("app.websocket.broadcast_health"), patch("app.websocket.broadcast_error") as mock_broadcast_error, ): @@ -536,11 +535,6 @@ class TestReconnectLock: result = await rm.reconnect(broadcast_on_success=False) assert result is False - mock_logger.warning.assert_called_once_with( - "Could not connect to serial port /dev/serial/by-id/test-radio. " - "Did the radio get disconnected or change serial ports?", - exc_info=False, - ) assert mock_broadcast_error.call_args.args == ( "Reconnection failed", "Could not connect to serial port /dev/serial/by-id/test-radio. " @@ -1084,7 +1078,6 @@ class TestPostConnectSetupOrdering: ) with ( - patch("app.services.radio_lifecycle.logger") as mock_logger, patch("app.websocket.broadcast_error") as mock_broadcast_error, patch("app.websocket.broadcast_health") as mock_broadcast_health, ): @@ -1092,8 +1085,6 @@ class TestPostConnectSetupOrdering: await prepare_connected_radio(rm, broadcast_on_success=True) assert rm.post_connect_setup.await_count == 2 - mock_logger.warning.assert_called_once() - mock_logger.error.assert_called_once() mock_broadcast_error.assert_called_once_with( "Radio startup appears stuck", "Initial radio offload took too long. Reboot the radio and restart the server.", @@ -1111,7 +1102,6 @@ class TestPostConnectSetupOrdering: rm.post_connect_setup = AsyncMock(side_effect=[asyncio.TimeoutError(), None]) with ( - patch("app.services.radio_lifecycle.logger") as mock_logger, patch("app.websocket.broadcast_error") as mock_broadcast_error, patch("app.websocket.broadcast_health") as mock_broadcast_health, ): @@ -1119,7 +1109,5 @@ class TestPostConnectSetupOrdering: assert rm.post_connect_setup.await_count == 2 assert rm._last_connected is True - mock_logger.warning.assert_called_once() - mock_logger.error.assert_not_called() mock_broadcast_error.assert_not_called() mock_broadcast_health.assert_called_once_with(True, "Serial: /dev/ttyUSB0") diff --git a/tests/test_radio_sync.py b/tests/test_radio_sync.py index 7031c67..8e34a46 100644 --- a/tests/test_radio_sync.py +++ b/tests/test_radio_sync.py @@ -1599,12 +1599,10 @@ class TestMessagePollLoopRaces: patch("app.radio_sync.settings.enable_message_poll_fallback", False), patch("asyncio.sleep", side_effect=mock_sleep), patch("app.radio_sync.poll_for_messages", new_callable=AsyncMock, return_value=2), - patch("app.radio_sync.logger") as mock_logger, patch("app.radio_sync.broadcast_error") as mock_broadcast_error, ): await _message_poll_loop() - mock_logger.error.assert_called_once() mock_broadcast_error.assert_called_once_with( "A periodic poll task has discovered radio inconsistencies.", "Please check the logs for recommendations (search " @@ -1621,12 +1619,10 @@ class TestMessagePollLoopRaces: patch("app.radio_sync.settings.enable_message_poll_fallback", True), patch("asyncio.sleep", side_effect=mock_sleep), patch("app.radio_sync.poll_for_messages", new_callable=AsyncMock, return_value=2), - patch("app.radio_sync.logger") as mock_logger, patch("app.radio_sync.broadcast_error") as mock_broadcast_error, ): await _message_poll_loop() - mock_logger.warning.assert_called_once() mock_broadcast_error.assert_not_called() @@ -1672,13 +1668,9 @@ class TestChannelSendCacheAudit: mock_mc = MagicMock() mock_mc.commands.get_channel = AsyncMock(return_value=mismatch_result) - with ( - patch("app.radio_sync.logger") as mock_logger, - patch("app.radio_sync.broadcast_error") as mock_broadcast_error, - ): + with patch("app.radio_sync.broadcast_error") as mock_broadcast_error: assert await audit_channel_send_cache(mock_mc) is False - mock_logger.error.assert_called_once() mock_broadcast_error.assert_called_once() assert radio_manager.get_cached_channel_slot(chan_key) is None