Skip to content

Commit 4fc3317

Browse files
accesswatchJeff Bishopclaude
authored
feat(radio): configure file logging + settable log location (quill-radio #5) (#1130)
The standalone app never configured file logging, so everything radio debug mode raised to DEBUG had nowhere to land. Fix and make it settable: - apps/radio.main() now calls configure_logging (to RadioHistory.log_dir or the default <data_dir>/logs) before the app comes up, keeps the QueueListener, hands it to the frame, and stops it on exit. - RadioHistory.log_dir persists the choice; Preferences (Ctrl+,) gains a "Log folder" field that relocates the live log via the new logging_config.relocate_log() and persists -- a bad path is a no-op that leaves logging working. Closes the observable-radio work (quill-radio #5): verbose debug mode, ffmpeg stderr capture, discovery/engine/finalization logging, and settable temp/log locations all now land in one readable quill.log. Tests: relocate moves new records + tolerates a bad path; configure writes the log; log_dir round-trips. apps/radio.py rebaselined 1081 -> 1115 with reason. Co-authored-by: Jeff Bishop <jeff@community-access.org> Co-authored-by: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
1 parent 1016e97 commit 4fc3317

8 files changed

Lines changed: 417 additions & 269 deletions

File tree

CHANGELOG.md

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,8 @@
88

99
### Improved
1010

11+
- **Quill Radio now writes a log, and you can choose where (quill-radio #5).** The standalone app never configured file logging, so debug mode had nowhere to write; it now writes `quill.log` from launch (to `<data>/logs` by default), and **Preferences (Ctrl+,)** gains a **Log folder** field to point it wherever you like -- changing it moves the live log immediately, and a bad path is ignored rather than breaking logging. This completes the observable-radio work: verbose debug mode, ffmpeg stderr capture, discovery/engine/finalization logging, and settable temp/log locations all now land in one readable log.
12+
1113
- **More radio debug logging: playback-engine selection and recording finalization (quill-radio #5).** With radio debug mode on, `quill.log` now also records which playback backend was chosen for a station and why (preference + whether mpv is present), and how each recording ended and where its finished file landed. Internal cleanup rode along: the pure ffmpeg/ffprobe command and filename builders moved out of `recording.py` into a new `recording_commands` module (no behavior change; the recorder module dropped back under its size budget).
1214

1315
- **Radio stream discovery now leaves a debug trail (quill-radio #5).** With radio debug mode on, Find Streams from a Website logs each scanned page and the candidate links it kept (with the reason for each, including the iHeart/TuneIn portal-page follow), and the Triton/StreamTheWorld resolver logs which callsign resolved to how many playable streams -- so a "why didn't this station's stream show up?" question has an answer in `quill.log`. Every logged URL is redacted first. (More per-module coverage -- engine selection, reconnects, recording finalization -- follows with the recording-module decomposition.)

quill/apps/radio.py

Lines changed: 34 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -839,6 +839,12 @@ def _open_preferences(self) -> None:
839839
_NOW_PLAYING_HELP,
840840
history.now_playing_template,
841841
),
842+
PreferenceText(
843+
"&Log folder:",
844+
"Where quill.log is written; leave blank for the default. "
845+
"Changing it moves the log immediately.",
846+
history.log_dir,
847+
),
842848
],
843849
actions=[
844850
PreferenceAction(
@@ -880,6 +886,19 @@ def _open_preferences(self) -> None:
880886
self._radio_controller.set_output_device(chosen_device)
881887
new_template = text_values[0].strip()
882888
history.now_playing_template = new_template or _DEFAULT_NOW_PLAYING_TEMPLATE
889+
new_log_dir = text_values[1].strip()
890+
if new_log_dir != history.log_dir:
891+
history.log_dir = new_log_dir
892+
# Relocate the live log so new records land in the chosen folder now
893+
# (quill-radio #5), not just next launch.
894+
listener = getattr(self, "_log_listener", None)
895+
if listener is not None:
896+
from pathlib import Path
897+
898+
from quill.stability.logging_config import relocate_log
899+
900+
target = Path(new_log_dir) if new_log_dir else app_data_dir() / "logs"
901+
relocate_log(listener, target)
883902
radio_history.save_history(app_data_dir(), history)
884903
menu_bar = self.frame.GetMenuBar()
885904
if menu_bar is not None:
@@ -1070,10 +1089,25 @@ def _on_radio_app_close(self, event: wx.CloseEvent) -> None:
10701089

10711090
def main() -> int:
10721091
safe_mode = bool(os.environ.get("QUILL_SAFE_MODE"))
1092+
# Configure file logging before the app comes up so startup records -- and
1093+
# everything radio debug mode raises to DEBUG -- land in quill.log
1094+
# (quill-radio #5). The folder is the log-location preference, or the
1095+
# default <data_dir>/logs.
1096+
from pathlib import Path
1097+
1098+
from quill.core.paths import app_data_dir
1099+
from quill.core.radio import history as radio_history
1100+
from quill.stability.logging_config import configure_logging
1101+
1102+
history = radio_history.load_history(app_data_dir())
1103+
log_dir = Path(history.log_dir) if history.log_dir else app_data_dir() / "logs"
1104+
log_listener = configure_logging(log_dir)
10731105
app = wx.App()
10741106
frame = RadioAppFrame(safe_mode=safe_mode)
1107+
frame._log_listener = log_listener
10751108
frame.frame.Show()
10761109
app.MainLoop()
1110+
log_listener.stop()
10771111
return 0
10781112

10791113

quill/core/radio/history.py

Lines changed: 229 additions & 223 deletions
Large diffs are not rendered by default.

quill/stability/logging_config.py

Lines changed: 81 additions & 45 deletions
Original file line numberDiff line numberDiff line change
@@ -1,45 +1,81 @@
1-
"""Queue-backed logging configuration used during early startup.
2-
3-
Implements: ROADMAP STAB-1 (the rotating-file ``quill.log`` and the
4-
queue listener that drains log records off the UI thread so a
5-
flooded log channel never blocks the wx main thread). The handler
6-
list installed here is what :mod:`quill.stability.crash_report` reads
7-
when the user saves a diagnostic bundle.
8-
"""
9-
10-
from __future__ import annotations
11-
12-
import logging
13-
import logging.handlers
14-
import queue
15-
from pathlib import Path
16-
17-
18-
def configure_logging(log_dir: Path) -> logging.handlers.QueueListener:
19-
log_dir.mkdir(parents=True, exist_ok=True)
20-
21-
log_queue: queue.Queue[logging.LogRecord] = queue.Queue(maxsize=10_000)
22-
queue_handler = logging.handlers.QueueHandler(log_queue)
23-
24-
root = logging.getLogger()
25-
root.setLevel(logging.INFO)
26-
root.handlers.clear()
27-
root.addHandler(queue_handler)
28-
29-
file_handler = logging.handlers.RotatingFileHandler(
30-
log_dir / "quill.log",
31-
maxBytes=5_000_000,
32-
backupCount=5,
33-
encoding="utf-8",
34-
)
35-
file_handler.setFormatter(
36-
logging.Formatter("%(asctime)s %(levelname)s %(threadName)s %(name)s: %(message)s")
37-
)
38-
39-
listener = logging.handlers.QueueListener(
40-
log_queue,
41-
file_handler,
42-
respect_handler_level=True,
43-
)
44-
listener.start()
45-
return listener
1+
"""Queue-backed logging configuration used during early startup.
2+
3+
Implements: ROADMAP STAB-1 (the rotating-file ``quill.log`` and the
4+
queue listener that drains log records off the UI thread so a
5+
flooded log channel never blocks the wx main thread). The handler
6+
list installed here is what :mod:`quill.stability.crash_report` reads
7+
when the user saves a diagnostic bundle.
8+
"""
9+
10+
from __future__ import annotations
11+
12+
import logging
13+
import logging.handlers
14+
import queue
15+
from pathlib import Path
16+
17+
18+
def configure_logging(log_dir: Path) -> logging.handlers.QueueListener:
19+
log_dir.mkdir(parents=True, exist_ok=True)
20+
21+
log_queue: queue.Queue[logging.LogRecord] = queue.Queue(maxsize=10_000)
22+
queue_handler = logging.handlers.QueueHandler(log_queue)
23+
24+
root = logging.getLogger()
25+
root.setLevel(logging.INFO)
26+
root.handlers.clear()
27+
root.addHandler(queue_handler)
28+
29+
file_handler = logging.handlers.RotatingFileHandler(
30+
log_dir / "quill.log",
31+
maxBytes=5_000_000,
32+
backupCount=5,
33+
encoding="utf-8",
34+
)
35+
file_handler.setFormatter(
36+
logging.Formatter("%(asctime)s %(levelname)s %(threadName)s %(name)s: %(message)s")
37+
)
38+
39+
listener = logging.handlers.QueueListener(
40+
log_queue,
41+
file_handler,
42+
respect_handler_level=True,
43+
)
44+
listener.start()
45+
return listener
46+
47+
48+
def relocate_log(listener: logging.handlers.QueueListener, log_dir: Path) -> None:
49+
"""Move the active ``quill.log`` to *log_dir* at runtime (quill-radio #5).
50+
51+
Swaps the listener's rotating-file handler for one writing into *log_dir*,
52+
so a user who changes the log-folder preference sees new records land there
53+
without a restart. The old handler is closed. A no-op (leaving the current
54+
handler in place) if the new directory can't be created, so a bad path
55+
never leaves logging broken.
56+
"""
57+
try:
58+
log_dir.mkdir(parents=True, exist_ok=True)
59+
new_handler = logging.handlers.RotatingFileHandler(
60+
log_dir / "quill.log",
61+
maxBytes=5_000_000,
62+
backupCount=5,
63+
encoding="utf-8",
64+
)
65+
except OSError:
66+
logging.getLogger(__name__).warning(
67+
"Could not relocate the log to %s; keeping the current location.", log_dir
68+
)
69+
return
70+
new_handler.setFormatter(
71+
logging.Formatter("%(asctime)s %(levelname)s %(threadName)s %(name)s: %(message)s")
72+
)
73+
old_handlers = list(listener.handlers)
74+
listener.stop()
75+
listener.handlers = (new_handler,)
76+
listener.start()
77+
for handler in old_handlers:
78+
try:
79+
handler.close()
80+
except OSError:
81+
pass

quill/tools/module_size_budgets.json

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -350,7 +350,8 @@
350350
"_rebaseline_2026_06_27_prompt_store_consolidation": "quill/__main__.py 638->640 and quill/core/prompt_library.py 364->393 (+29) for the one-prompt-store-truth migration (AI Library Phase 2/3, docs/planning/ai-menu-redesign-plan.md). __main__.py: the two-line guarded startup call (import + consolidate_prompts_quietly()) alongside the existing consolidate_provider_keys_quietly() hook; the migration logic itself lives in the new wx-free quill/core/prompt_migration.py so it adds no growth to either store. prompt_library.py: the new upsert_external() method, which inserts/replaces a user prompt by explicit id (refusing built-ins) so import and the store migration are idempotent and reversible. Same accepted startup-hook / additive-method rebaseline pattern. Budgets re-baselined to current size.",
351351
"_rebaseline_2026_06_27_main_resync_merge": "Merge of origin/main (0.8.0 line: Python 3.13 runtime, upgrade hardening, legacy-import + startup-maintenance, winrt OCR, bundled Kokoro) into 2.0-dev. Seven modules touched independently on both branches now hold the union of both sides' additions, so the max-of-both budget no longer fits: __main__.py 640->651 (both startup hooks: apply_pending_legacy_import + run_pending_startup_maintenance from main, consolidate_provider_keys/prompts from 2.0-dev), keymap.py 682->683, settings.py 1226->1231, ai_hub_dialog.py 924->927, assistant_panel.py 943->947, main_frame.py 26172->26218, main_frame_statusbar.py 956->967. These are merge combinations of pre-approved per-branch growth, not new feature work; CQ-1 decomposition remains the path down for the large UI modules. Budgets re-baselined to current size.",
352352
"budgets": {
353-
"quill/apps/radio.py": 1081,
353+
"quill/apps/radio.py": 1115,
354+
"_rebaseline_2026_07_18_radio_log_location": "apps/radio.py 1081 -> 1115 (+34): quill-radio #5, the settable log location -- the standalone previously configured no file logging at all, so debug mode had nowhere to write. main() now calls configure_logging (to RadioHistory.log_dir or the default <data_dir>/logs) before the app comes up, keeps the QueueListener, hands it to the frame, and stops it on exit; Preferences (Ctrl+,) gains a 'Log folder' text field that relocates the live log via the new logging_config.relocate_log and persists. log_dir lives in core/radio/history.py; relocate_log in stability/logging_config.py (both under cap).",
354355
"_rebaseline_2026_07_17_radio_missed_recording_report": "apps/radio.py 1051 -> 1081 (+30): quill-radio #4, the startup missed-recording report. _report_missed_recordings (scheduled via wx.CallAfter at launch) reads RadioHistory.last_seen, asks the wx-free recording_schedule.missed_occurrences/describe_missed which enabled schedules fired while the app was closed, announces a one-line summary, and re-stamps last_seen; the exit path also stamps last_seen=now so the next launch's window is the closed gap. The occurrence math + the spoken-summary formatter live in core/radio/recording_schedule.py (under cap); last_seen lives in core/radio/history.py.",
355356
"_rebaseline_2026_07_17_radio_debug_mode_pref": "apps/radio.py 1038 -> 1051 (+13): quill-radio #5, the Preferences (Ctrl+,) 'Verbose logging (debug mode)' checkbox -- one PreferenceCheckbox spec, its addition to the checkbox-values unpack, and the immediate set_radio_debug(history.debug_mode) apply-on-change block so it takes effect this session. The debug_mode field lives in core/radio/history.py and the logging switch itself is the under-cap core/radio/radio_logging.set_radio_debug.",
356357
"_rebaseline_2026_07_17_low_vision_tree_contrast": "apps/radio.py 1033 -> 1038 (+5): quill-radio #3, low-vision legibility. The main-page favorites TreeCtrl now calls the shared apply_readable_tree_colours() (in favorites_manager_dialog.py) to pin it to the theme-resolved system window/text colours so it is never near-invisible on a mismatched default. Not dark mode -- no hard-coded colours, no toggle.",

tests/unit/core/test_radio_history.py

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -58,6 +58,13 @@ def test_check_updates_on_startup_round_trips(tmp_path: Path) -> None:
5858
assert loaded.last_update_check == "2026-07-16T00:00:00"
5959

6060

61+
def test_log_dir_round_trips_and_defaults_empty(tmp_path: Path) -> None:
62+
# quill-radio #5: the settable log-folder preference.
63+
assert load_history(tmp_path).log_dir == ""
64+
save_history(tmp_path, RadioHistory(log_dir="D:/radio-logs"))
65+
assert load_history(tmp_path).log_dir == "D:/radio-logs"
66+
67+
6168
def test_last_seen_round_trips_and_defaults_empty(tmp_path: Path) -> None:
6269
# quill-radio #4: the "last running" stamp for the missed-recording report.
6370
assert load_history(tmp_path).last_seen == ""
Lines changed: 61 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,61 @@
1+
"""Tests for the queue-backed logging configuration (STAB-1) and the
2+
runtime log relocation used by Quill Radio's log-folder preference (#5)."""
3+
4+
from __future__ import annotations
5+
6+
import logging
7+
from pathlib import Path
8+
9+
from quill.stability.logging_config import configure_logging, relocate_log
10+
11+
12+
def _drain_and_close(listener: logging.handlers.QueueListener) -> None:
13+
"""Stop the listener and close its handlers so the file is released."""
14+
listener.stop()
15+
for handler in listener.handlers:
16+
handler.close()
17+
logging.getLogger().handlers.clear()
18+
19+
20+
def test_configure_logging_writes_quill_log(tmp_path: Path) -> None:
21+
listener = configure_logging(tmp_path)
22+
try:
23+
logging.getLogger("quill.core.radio.test").warning("hello-configure")
24+
listener.stop() # flush the queue to the file
25+
listener.start()
26+
assert (tmp_path / "quill.log").exists()
27+
assert "hello-configure" in (tmp_path / "quill.log").read_text(encoding="utf-8")
28+
finally:
29+
_drain_and_close(listener)
30+
31+
32+
def test_relocate_log_moves_new_records_to_the_new_dir(tmp_path: Path) -> None:
33+
first = tmp_path / "first"
34+
second = tmp_path / "second"
35+
listener = configure_logging(first)
36+
try:
37+
logging.getLogger("quill.core.radio.test").warning("in-first")
38+
relocate_log(listener, second)
39+
logging.getLogger("quill.core.radio.test").warning("in-second")
40+
listener.stop()
41+
listener.start()
42+
assert (second / "quill.log").exists()
43+
assert "in-second" in (second / "quill.log").read_text(encoding="utf-8")
44+
finally:
45+
_drain_and_close(listener)
46+
47+
48+
def test_relocate_log_bad_path_keeps_current_handler(tmp_path: Path) -> None:
49+
listener = configure_logging(tmp_path)
50+
try:
51+
# A path whose parent is a file cannot be made a directory; relocation
52+
# must be a no-op that leaves logging working, not raise.
53+
blocker = tmp_path / "blocker"
54+
blocker.write_text("x", encoding="utf-8")
55+
relocate_log(listener, blocker / "sub")
56+
logging.getLogger("quill.core.radio.test").warning("still-logging")
57+
listener.stop()
58+
listener.start()
59+
assert "still-logging" in (tmp_path / "quill.log").read_text(encoding="utf-8")
60+
finally:
61+
_drain_and_close(listener)

tests/unit/ui/test_radio_reset_all_sound_enhancements.py

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -38,6 +38,7 @@ def _frame(*, playing: RadioStation | None = None) -> Any:
3838
compressor_enabled=True,
3939
now_playing_template="{title}[ by {artist}]",
4040
debug_mode=False,
41+
log_dir="",
4142
)
4243
frame._radio_favorites = RadioFavoritesStore()
4344
frame._radio_controller = SimpleNamespace(

0 commit comments

Comments
 (0)