Log the node time on startup

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)

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."""

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."""

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):

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")

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