Improve GUI action logging
This commit is contained in:
2
PKGBUILD
2
PKGBUILD
@@ -1,5 +1,5 @@
|
||||
pkgname=whipper-git
|
||||
pkgver=0.10.0.r66.g992923b
|
||||
pkgver=0.10.2.r0.g9564c7c
|
||||
pkgrel=1
|
||||
pkgdesc='CD-DA ripper prioritising accuracy over speed'
|
||||
arch=('x86_64')
|
||||
|
||||
123
whipper/gui.py
123
whipper/gui.py
@@ -434,6 +434,14 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
end_iter = self.log_buffer.get_end_iter()
|
||||
self.log_buffer.insert(end_iter, text)
|
||||
|
||||
def _log_action(self, message, *args, level=logging.INFO):
|
||||
if args:
|
||||
message = message % args
|
||||
logger.log(level, message)
|
||||
if not message.endswith("\n"):
|
||||
message += "\n"
|
||||
self._append_log(message)
|
||||
|
||||
def _clear_log(self):
|
||||
self.log_buffer.set_text("")
|
||||
|
||||
@@ -563,6 +571,7 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
current = self.device_combo.get_active_text()
|
||||
self.device_combo.remove_all()
|
||||
devices = drive.getAllDevicePaths()
|
||||
logger.info("refreshing optical drives")
|
||||
for path in devices:
|
||||
self.device_combo.append_text(path)
|
||||
if not devices:
|
||||
@@ -570,12 +579,15 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
self.device_combo.set_active(0)
|
||||
self.read_button.set_sensitive(False)
|
||||
self.rip_button.set_sensitive(False)
|
||||
logger.warning("no optical drives detected")
|
||||
else:
|
||||
self.read_button.set_sensitive(True)
|
||||
if current in devices:
|
||||
self.device_combo.set_active(devices.index(current))
|
||||
else:
|
||||
self.device_combo.set_active(0)
|
||||
logger.info("detected %d optical drive(s); active device: %s",
|
||||
len(devices), self.device_combo.get_active_text())
|
||||
self._apply_configured_offset()
|
||||
|
||||
def _selected_device(self):
|
||||
@@ -646,31 +658,36 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
return
|
||||
info = drive.getDeviceInfo(device)
|
||||
if not info:
|
||||
logger.info("no configured offset information for %s", device)
|
||||
return
|
||||
try:
|
||||
offset = config.Config().getReadOffset(*info)
|
||||
except KeyError:
|
||||
logger.info("configured read offset not found for %s", device)
|
||||
return
|
||||
if offset is not None:
|
||||
self.offset_spin.set_value(int(offset))
|
||||
logger.info("loaded configured read offset %d for %s", offset, device)
|
||||
|
||||
def _read_disc_worker(self, device, country):
|
||||
try:
|
||||
self.scan_cancel_requested = False
|
||||
GLib.idle_add(self._clear_log)
|
||||
GLib.idle_add(self._reset_progress)
|
||||
GLib.idle_add(self._append_log, "Reading disc from %s\n\n" % device)
|
||||
GLib.idle_add(self._log_action, "Reading disc from %s", device)
|
||||
GLib.idle_add(self._set_running_state, True, "Reading disc")
|
||||
GLib.idle_add(self.progress_label.set_text, "Scanning disc and looking up MusicBrainz")
|
||||
|
||||
runner = CancellableSyncRunner()
|
||||
self.scan_runner = runner
|
||||
|
||||
GLib.idle_add(self._log_action, "Preparing drive %s", device)
|
||||
utils.load_device(device)
|
||||
utils.unmount_device(device)
|
||||
if drive.get_cdrom_drive_status(device) == 1:
|
||||
raise OSError("No CD detected, please insert one and retry")
|
||||
|
||||
GLib.idle_add(self._log_action, "Reading disc TOC")
|
||||
toc_task = cdrdao.ReadTOCTask(device, fast_toc=True)
|
||||
runner.run(toc_task, verbose=False)
|
||||
ittoc = toc_task.toc.table
|
||||
@@ -681,6 +698,12 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
if self.scan_cancel_requested:
|
||||
raise RuntimeError("Disc scan cancelled")
|
||||
|
||||
GLib.idle_add(
|
||||
self._log_action,
|
||||
"Querying MusicBrainz for %s%s",
|
||||
mbid,
|
||||
" (country=%s)" % country if country else "",
|
||||
)
|
||||
try:
|
||||
releases = mbngs.musicbrainz(mbid, country=country or None, record=False)
|
||||
except mbngs.NotFoundException:
|
||||
@@ -707,12 +730,12 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
self._append_log("CDDB disc id: %s\n" % cddb)
|
||||
self._append_log("MusicBrainz disc id: %s\n" % mbid)
|
||||
self._append_log("Disc duration: %s, %s audio tracks\n" % (duration, track_count))
|
||||
self._append_log("\nFound %d matching release(s)\n" % len(releases))
|
||||
self._log_action("Found %d matching release(s)", len(releases))
|
||||
self._update_release_store(releases)
|
||||
self._set_running_state(False, "Disc ready")
|
||||
self.progress_label.set_text("Disc metadata loaded")
|
||||
if not releases:
|
||||
self._append_log("No MusicBrainz matches found\n")
|
||||
self._log_action("No MusicBrainz matches found", level=logging.WARNING)
|
||||
return False
|
||||
|
||||
GLib.idle_add(apply_results)
|
||||
@@ -726,12 +749,12 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
self._set_label("device", device)
|
||||
if self.scan_cancel_requested:
|
||||
self._set_label("disc_status", "Cancelled")
|
||||
self._append_log("Disc scan cancelled\n")
|
||||
self._log_action("Disc scan cancelled", level=logging.WARNING)
|
||||
self._set_running_state(False, "Cancelled")
|
||||
self.progress_label.set_text("Disc scan cancelled")
|
||||
else:
|
||||
self._set_label("disc_status", "Error")
|
||||
self._append_log("%s\n" % exc)
|
||||
self._log_action("%s", exc, level=logging.ERROR)
|
||||
self._set_running_state(False, "Failed")
|
||||
self.progress_label.set_text("Disc scan failed")
|
||||
return False
|
||||
@@ -974,21 +997,40 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
GLib.idle_add(self._reset_progress)
|
||||
GLib.idle_add(self._set_running_state, True, "Ripping disc")
|
||||
GLib.idle_add(self.progress_label.set_text, "Preparing rip")
|
||||
GLib.idle_add(self._append_log, "Starting native whipper rip\n\n")
|
||||
GLib.idle_add(self._log_action, "Starting native whipper rip")
|
||||
|
||||
runner = CancellableSyncRunner()
|
||||
self.rip_runner = runner
|
||||
conf = config.Config()
|
||||
program = Program(conf, record=False)
|
||||
|
||||
GLib.idle_add(
|
||||
self._log_action,
|
||||
"Rip settings: device=%s output=%s working_dir=%s logger=%s offset=%d overread=%s cover_art=%s retries=%s keep_going=%s cdr=%s unknown=%s",
|
||||
settings["device"],
|
||||
settings["output_directory"],
|
||||
settings["working_directory"] or "-",
|
||||
settings["logger"],
|
||||
settings["offset"],
|
||||
settings["overread"],
|
||||
settings["cover_art"] or "disabled",
|
||||
settings["max_retries"],
|
||||
settings["keep_going"],
|
||||
settings["cdr"],
|
||||
settings["unknown"],
|
||||
)
|
||||
|
||||
if settings["working_directory"]:
|
||||
GLib.idle_add(self._log_action, "Changing working directory to %s", settings["working_directory"])
|
||||
os.chdir(os.path.expanduser(settings["working_directory"]))
|
||||
|
||||
GLib.idle_add(self._log_action, "Preparing drive %s", settings["device"])
|
||||
utils.load_device(settings["device"])
|
||||
utils.unmount_device(settings["device"])
|
||||
if drive.get_cdrom_drive_status(settings["device"]) == 1:
|
||||
raise OSError("No CD detected, please insert one and retry")
|
||||
|
||||
GLib.idle_add(self._log_action, "Reading fast TOC")
|
||||
ittoc = program.getFastToc(runner, settings["device"])
|
||||
program.getRipResult()
|
||||
cddb = ittoc.getCDDBDiscId()
|
||||
@@ -996,22 +1038,27 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
GLib.idle_add(self._append_log, "CDDB disc id: %s\n" % cddb)
|
||||
GLib.idle_add(self._append_log, "MusicBrainz disc id: %s\n" % mbdiscid)
|
||||
|
||||
GLib.idle_add(self._log_action, "Resolving release metadata")
|
||||
program.metadata = self._resolve_release_metadata(mbdiscid, settings)
|
||||
if program.metadata is None and not settings["unknown"]:
|
||||
raise RuntimeError("Unable to resolve disc metadata. Select a release or enable ripping without metadata.")
|
||||
if program.metadata is not None:
|
||||
program.metadata.discid = mbdiscid
|
||||
GLib.idle_add(
|
||||
self._append_log,
|
||||
self._log_action,
|
||||
"Using release: %s - %s\n" % (
|
||||
program.metadata.artist or "Unknown Artist",
|
||||
program.metadata.releaseTitle or program.metadata.title or "Unknown Title",
|
||||
),
|
||||
)
|
||||
else:
|
||||
GLib.idle_add(self._log_action, "Continuing without release metadata", level=logging.WARNING)
|
||||
|
||||
program.result.isCdr = cdrdao.DetectCdr(settings["device"])
|
||||
if program.result.isCdr and not settings["cdr"]:
|
||||
raise RuntimeError("Inserted disc appears to be a CD-R. Enable 'Allow CD-R' to continue.")
|
||||
if program.result.isCdr:
|
||||
GLib.idle_add(self._log_action, "Detected CD-R media", level=logging.WARNING)
|
||||
|
||||
out_fpath = program.getPath(
|
||||
settings["output_directory"],
|
||||
@@ -1019,6 +1066,7 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
mbdiscid,
|
||||
program.metadata,
|
||||
)
|
||||
GLib.idle_add(self._log_action, "Reading full disc table")
|
||||
itable = program.getTable(
|
||||
runner,
|
||||
ittoc.getCDDBDiscId(),
|
||||
@@ -1045,6 +1093,15 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
program.result.overread = settings["overread"]
|
||||
program.result.logger = settings["logger"]
|
||||
program.outdir = settings["output_directory"]
|
||||
GLib.idle_add(
|
||||
self._log_action,
|
||||
"Drive info: vendor=%s model=%s release=%s offset=%s overread=%s",
|
||||
program.result.vendor,
|
||||
program.result.model,
|
||||
program.result.release,
|
||||
program.result.offset,
|
||||
program.result.overread,
|
||||
)
|
||||
|
||||
disc_name = program.getPath(program.outdir, settings["disc_template"], mbdiscid, program.metadata)
|
||||
dirname = os.path.dirname(disc_name)
|
||||
@@ -1052,17 +1109,22 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
log_file = disc_name + ".log"
|
||||
if os.path.exists(log_file):
|
||||
raise RuntimeError("output directory %s is a finished rip" % dirname)
|
||||
GLib.idle_add(self._log_action, "Using existing output directory %s", dirname)
|
||||
else:
|
||||
os.makedirs(dirname)
|
||||
GLib.idle_add(self._log_action, "Created output directory %s", dirname)
|
||||
|
||||
cover_art_path = None
|
||||
if settings["cover_art"] in {"embed", "complete"} and importlib.util.find_spec("PIL") is None:
|
||||
GLib.idle_add(self._append_log, "Cover art embedding requires Pillow; continuing without embedded art\n")
|
||||
GLib.idle_add(self._log_action, "Cover art embedding requires Pillow; continuing without embedded art", level=logging.WARNING)
|
||||
elif settings["cover_art"] in {"file", "embed", "complete"}:
|
||||
if getattr(program.metadata, "mbid", None):
|
||||
GLib.idle_add(self._log_action, "Fetching cover art with mode %s", settings["cover_art"])
|
||||
cover_art_path = program.getCoverArt(dirname, program.metadata.mbid)
|
||||
if cover_art_path is not None:
|
||||
GLib.idle_add(self._log_action, "Cover art saved to %s", cover_art_path)
|
||||
else:
|
||||
GLib.idle_add(self._append_log, "Cover art requested but disc metadata is unavailable\n")
|
||||
GLib.idle_add(self._log_action, "Cover art requested but disc metadata is unavailable", level=logging.WARNING)
|
||||
if settings["cover_art"] == "file":
|
||||
embed_cover_art_path = None
|
||||
else:
|
||||
@@ -1071,14 +1133,16 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
skipped_tracks = []
|
||||
rip_numbers = []
|
||||
if program.getHTOA():
|
||||
GLib.idle_add(self._log_action, "Hidden Track One Audio detected")
|
||||
rip_numbers.append(0)
|
||||
for index, track in enumerate(itable.tracks, start=1):
|
||||
if track.audio:
|
||||
rip_numbers.append(index)
|
||||
else:
|
||||
GLib.idle_add(self._append_log, "Skipping data track %d, not implemented\n" % index)
|
||||
GLib.idle_add(self._log_action, "Skipping data track %d, not implemented", index, level=logging.WARNING)
|
||||
track.indexes[1].relative = 0
|
||||
|
||||
GLib.idle_add(self._log_action, "Planned rip items: %d", len(rip_numbers))
|
||||
total_items = len(rip_numbers)
|
||||
for item_index, track_number in enumerate(rip_numbers, start=1):
|
||||
if self.rip_cancel_requested:
|
||||
@@ -1098,15 +1162,19 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
|
||||
if settings["cover_art"] == "embed" and cover_art_path is not None:
|
||||
os.remove(cover_art_path)
|
||||
GLib.idle_add(self._log_action, "Removed temporary cover art file %s", cover_art_path)
|
||||
|
||||
if self.rip_cancel_requested:
|
||||
raise RipCancelledError("Rip cancelled")
|
||||
|
||||
program.skipped_tracks = skipped_tracks or None
|
||||
GLib.idle_add(self._log_action, "Writing CUE sheet")
|
||||
program.writeCue(disc_name)
|
||||
GLib.idle_add(self._log_action, "Writing M3U playlist")
|
||||
program.write_m3u(disc_name)
|
||||
|
||||
try:
|
||||
GLib.idle_add(self._log_action, "Running AccurateRip image verification")
|
||||
with contextlib.redirect_stdout(io.StringIO()) as stdout_buffer:
|
||||
program.verifyImage(runner, itable)
|
||||
accurip.print_report(program.result)
|
||||
@@ -1114,19 +1182,20 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
if report_output:
|
||||
GLib.idle_add(self._append_log, "\n" + report_output + "\n")
|
||||
except accurip.EntryNotFound:
|
||||
GLib.idle_add(self._append_log, "AccurateRip entry not found\n")
|
||||
GLib.idle_add(self._log_action, "AccurateRip entry not found", level=logging.WARNING)
|
||||
|
||||
txt_logger = result.getLoggers()[settings["logger"]]()
|
||||
GLib.idle_add(self._log_action, "Writing rip log with logger '%s'", settings["logger"])
|
||||
program.writeLog(disc_name, txt_logger)
|
||||
if skipped_tracks:
|
||||
GLib.idle_add(self._append_log, "%d track(s) were skipped during this rip\n" % len(skipped_tracks))
|
||||
GLib.idle_add(self._log_action, "%d track(s) were skipped during this rip", len(skipped_tracks), level=logging.WARNING)
|
||||
GLib.idle_add(self._finish_rip, 5, "Done with skipped tracks")
|
||||
else:
|
||||
GLib.idle_add(self._append_log, "Rip finished successfully\n")
|
||||
GLib.idle_add(self._log_action, "Rip finished successfully")
|
||||
GLib.idle_add(self._finish_rip, 0, "Done")
|
||||
except Exception as exc:
|
||||
if not isinstance(exc, RipCancelledError):
|
||||
GLib.idle_add(self._append_log, "%s\n" % exc)
|
||||
GLib.idle_add(self._log_action, "%s", exc, level=logging.ERROR)
|
||||
GLib.idle_add(self._finish_rip, 1, "Cancelled" if self.rip_cancel_requested else "Failed")
|
||||
finally:
|
||||
self.rip_runner = None
|
||||
@@ -1146,6 +1215,7 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
self.rip_button.set_sensitive(self._can_rip())
|
||||
|
||||
def _on_refresh_clicked(self, _button):
|
||||
self._log_action("Refreshing drive list")
|
||||
self._refresh_devices()
|
||||
|
||||
def _on_unknown_toggled(self, _button):
|
||||
@@ -1167,12 +1237,21 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
def _on_device_changed(self, _combo):
|
||||
self._apply_configured_offset()
|
||||
self._save_gui_settings()
|
||||
device = self._selected_device()
|
||||
if device:
|
||||
self._log_action("Selected device %s", device)
|
||||
|
||||
def _on_read_clicked(self, _button):
|
||||
device = self._selected_device()
|
||||
if not device:
|
||||
self._log_action("Read requested without an active device", level=logging.WARNING)
|
||||
return
|
||||
country = self.country_entry.get_text().strip()
|
||||
self._log_action(
|
||||
"Read requested for %s%s",
|
||||
device,
|
||||
" with country filter %s" % country if country else "",
|
||||
)
|
||||
self.worker = threading.Thread(
|
||||
target=self._read_disc_worker,
|
||||
args=(device, country),
|
||||
@@ -1182,16 +1261,24 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
|
||||
def _on_rip_clicked(self, _button):
|
||||
if not self._can_rip():
|
||||
self._append_log("Select a release or enable ripping without metadata.\n")
|
||||
self._log_action("Rip requested without a selected release", level=logging.WARNING)
|
||||
self.status_label.set_text("Missing release")
|
||||
return
|
||||
settings = self._collect_rip_settings()
|
||||
try:
|
||||
self._validate_rip_settings(settings)
|
||||
except Exception as exc:
|
||||
self._append_log("%s\n" % exc)
|
||||
self._log_action("%s", exc, level=logging.ERROR)
|
||||
self.status_label.set_text("Invalid settings")
|
||||
return
|
||||
if self.current_release is not None:
|
||||
self._log_action(
|
||||
"Rip requested for release %s - %s",
|
||||
self.current_release.artist or "Unknown Artist",
|
||||
self.current_release.releaseTitle or self.current_release.title or "Unknown Title",
|
||||
)
|
||||
else:
|
||||
self._log_action("Rip requested without bound metadata release", level=logging.WARNING)
|
||||
self.worker = threading.Thread(
|
||||
target=self._rip_disc_worker,
|
||||
args=(settings,),
|
||||
@@ -1202,11 +1289,11 @@ class WhipperGui(Gtk.Application if Gtk is not None else object):
|
||||
def _on_stop_clicked(self, _button):
|
||||
if self.scan_runner is not None:
|
||||
self.scan_cancel_requested = True
|
||||
self._append_log("\nStopping scan...\n")
|
||||
self._log_action("Stopping scan", level=logging.WARNING)
|
||||
self.scan_runner.cancel()
|
||||
elif self.rip_runner is not None:
|
||||
self.rip_cancel_requested = True
|
||||
self._append_log("\nStopping rip...\n")
|
||||
self._log_action("Stopping rip", level=logging.WARNING)
|
||||
self.rip_runner.cancel()
|
||||
|
||||
|
||||
|
||||
@@ -296,6 +296,7 @@ def _make_ui_app(tmp_path):
|
||||
app._config_path = lambda: tmp_path / "gui.json"
|
||||
_bind_methods(
|
||||
app,
|
||||
"_log_action",
|
||||
"_collect_gui_settings",
|
||||
"_save_gui_settings",
|
||||
"_load_gui_settings",
|
||||
|
||||
Reference in New Issue
Block a user