diff --git a/README.md b/README.md index febc2b3..fb06a92 100644 --- a/README.md +++ b/README.md @@ -228,6 +228,14 @@ Two things about how it is put together: instead of leaping 30% the moment unpacking starts — and likewise for AUR with nothing pending, or a machine with no Flatpaks. The weights only ever have to be right about the steps that actually run. +- **Expanding *Details* shows the run log's last five lines, live.** The + percentage says the update is alive; these say what it is alive doing. It + matters most where there is nothing to count — an AUR package compiling for + a quarter of an hour talks constantly, and all of it used to go into a file + nobody was looking at. The job model behind this interface carries exactly + two description fields (`descriptionValue1` and `2` — there is no third), so + one holds the current package and the other the tail; newlines inside a value + do render, which is what makes five lines fit in one field. - pacman's output is line-buffered through `stdbuf`. Writing to a log rather than a terminal, libc would hand it over in 4 KB blocks instead, and 4 KB of `upgrading foo...` is on the order of a hundred and sixty packages arriving diff --git a/doc/cachy-auto-update.1.scd b/doc/cachy-auto-update.1.scd index a210bfd..ff7ac14 100644 --- a/doc/cachy-auto-update.1.scd +++ b/doc/cachy-auto-update.1.scd @@ -131,6 +131,13 @@ stuck update. On a domestic line the download is then the longest of the three, and a bar that called the whole thing "installing" would sit near its beginning for minutes at a time looking stuck. +Expanding "Details" shows the last five lines of the run log as they are +written, alongside the package currently being worked on. The percentage says +the update is alive; these lines say what it is alive doing, which matters most +during the stretches that have nothing countable to report - an AUR package +being compiled, above all. The job interface carries exactly two description +fields, so those are the two things shown. + A step that turns out to have no work is dropped from the bar instead of being handed its share for nothing. Packages already in the cache are never announced, so a run with everything already fetched skips the download step diff --git a/po/cachy-auto-update.pot b/po/cachy-auto-update.pot index 4931b69..279608b 100644 --- a/po/cachy-auto-update.pot +++ b/po/cachy-auto-update.pot @@ -258,6 +258,9 @@ msgstr "" msgid "Cleaning up after the update" msgstr "" +msgid "Log" +msgstr "" + msgid "Package" msgstr "" diff --git a/po/de.po b/po/de.po index 7ee7fc8..4580876 100644 --- a/po/de.po +++ b/po/de.po @@ -259,6 +259,9 @@ msgstr "AppImages werden aktualisiert" msgid "Cleaning up after the update" msgstr "Aufräumen nach dem Update" +msgid "Log" +msgstr "Protokoll" + msgid "Package" msgstr "Paket" diff --git a/src/cachy-auto-update-progress b/src/cachy-auto-update-progress index 0597c45..ead8cb9 100644 --- a/src/cachy-auto-update-progress +++ b/src/cachy-auto-update-progress @@ -8,6 +8,7 @@ # # infotext headline, already translated by the caller # detailnamevalue a labelled line under "Details" +# lognamelineline... the run log's last lines, one per field # totaln how many items this step has # donen how many of them are finished # percentn overall progress, 0-100 @@ -113,6 +114,16 @@ def main(): elif cmd == "detail" and len(fields) > 2: job.call("setDescriptionField", GLib.Variant("(uss)", (0, arg, fields[2]))) + elif cmd == "log" and len(fields) > 2: + # Field 1, and there is no field 2: the job model behind this + # interface carries exactly two, and anything further is + # discarded without complaint at the other end. + # + # The tail arrives one line per field, because the protocol + # itself is one instruction per line. Joined back up with the + # newlines the job view does render. + job.call("setDescriptionField", + GLib.Variant("(uss)", (1, arg, "\n".join(fields[2:])))) elif cmd == "total": job.call("setTotalAmount", GLib.Variant("(ts)", (int(arg), unit))) elif cmd == "done": diff --git a/src/cachy-auto-update-run b/src/cachy-auto-update-run index 3bb2eb4..439f9d4 100644 --- a/src/cachy-auto-update-run +++ b/src/cachy-auto-update-run @@ -192,6 +192,11 @@ progress_steps=(resolve download repo) progress_steps+=(cleanup) cau_progress_begin "${progress_steps[@]}" +# And carry the run log's last lines along with it, so "Details" shows what the +# update is doing during the stretches that have nothing to count - an AUR +# package building for a quarter of an hour, most of all. +cau_progress_tail_start "$CAU_RUNLOG" + if ! cau_pacman_update; then failed=1 fi diff --git a/src/lib/progress.sh b/src/lib/progress.sh index 477e836..7dcf64a 100644 --- a/src/lib/progress.sh +++ b/src/lib/progress.sh @@ -367,6 +367,83 @@ cau_progress_detail() { done } +# How many lines of the run log the job entry carries, and how wide each one +# is allowed to be. Both are display limits rather than arbitrary ones: five +# lines is about what fits under a notification popup before it starts pushing +# the buttons off the bottom, and a line long enough to be elided anyway is +# only costing room in the pipe. Together they also keep one instruction well +# inside PIPE_BUF, which is what makes the write atomic against the runner +# writing its own progress down the same pipe. +CAU_PROGRESS_TAIL_LINES=5 +CAU_PROGRESS_TAIL_COLS=120 +CAU_PROGRESS_TAIL_PID=0 + +# cau_progress_log +# The second description field, holding the last few lines of the run log. +# +# The protocol is one instruction per line, so the tail travels tab separated +# and is put back together on the other side. Tabs inside a log line would +# split it in two on the way, so they become spaces first - the job view +# renders either as whitespace, and a line broken in half renders as nonsense. +cau_progress_log() { + local label="$1" text="$2" i fd + + (( ${#CAU_PROGRESS_FDS[@]} )) || return 0 + + text="${text//$'\t'/ }" + text="${text//$'\n'/$'\t'}" + + for i in "${!CAU_PROGRESS_FDS[@]}"; do + fd="${CAU_PROGRESS_FDS[$i]}" + [[ -n $fd ]] || continue + cau_msg_into "${CAU_PROGRESS_LOCALES[$i]}" "$label" + printf 'log\t%s\t%s\n' "$CAU_MSG_RESULT" "$text" >&"$fd" 2>/dev/null || true + done +} + +# cau_progress_tail_start / cau_progress_tail_stop +# Follows the run log for as long as the update lasts, so expanding "Details" +# shows what the update is actually doing right now. +# +# This is the answer to the part of a run that has no counter and never will: +# an AUR helper compiling for a quarter of an hour says plenty about what it is +# up to, none of it countable, and all of it going into a log file nobody is +# looking at. The percentage says the update is alive; these lines say what it +# is alive doing. +# +# Polled rather than followed with tail -F, for the same reason the pacman +# watcher polls: only the last few lines are ever displayed, so every line in +# between is work nobody would see. Re-read whole and compared, which also +# makes truncation and rotation of the log a non-event. +cau_progress_tail_start() { + local file="$1" + + cau_progress_tail_stop + (( ${#CAU_PROGRESS_FDS[@]} )) || return 0 + cau_have tail || return 0 + + { + local nap last='' now + exec {nap}<> <(:) + while :; do + read -r -t 2 -u "$nap" _ || true + now="$(tail -n "$CAU_PROGRESS_TAIL_LINES" "$file" 2>/dev/null \ + | cut -c "1-${CAU_PROGRESS_TAIL_COLS}")" + [[ -n $now && $now != "$last" ]] || continue + last="$now" + cau_progress_log "Log" "$now" + done + } & + CAU_PROGRESS_TAIL_PID=$! +} + +cau_progress_tail_stop() { + (( CAU_PROGRESS_TAIL_PID )) || return 0 + kill "$CAU_PROGRESS_TAIL_PID" 2>/dev/null + wait "$CAU_PROGRESS_TAIL_PID" 2>/dev/null + CAU_PROGRESS_TAIL_PID=0 +} + # cau_progress_end [outcome: ok|failed] [failure-msgid] # Closes the entry. Must run on every exit path, including a killed run: an # entry whose owner merely vanishes is reported by the desktop as "the @@ -386,9 +463,11 @@ cau_progress_end() { local outcome="${1:-ok}" msgid="${2:-}" local i fd - # Before the descriptors go: a ticker still running would be writing into - # a pipe whose reader is about to be waited on. + # Before the descriptors go: anything still running in the background holds + # its own copy of them, so the helper would not see the end of its input + # until it exited - and it is about to be waited on. cau_progress_creep_stop + cau_progress_tail_stop # The last step never consumes its own share - nothing reports items for # the cleanup - so the bar would stop a few percent short of the end and