cachy-auto-update 1.3.0

The progress bar stops freezing on a count it made up, drops the steps that
have no work, and carries the run log's last lines under Details.

Makefile

@@ -8,7 +8,7 @@
 # Overridable so a packager can pass the version it is actually building
 # (`make VERSION=$pkgver`). The literal below is the fallback for builds
 # straight from a checkout, and is what a release tag has to carry.
-VERSION      ?= 1.2.0
+VERSION      ?= 1.3.0
 
 PREFIX       ?= /usr
 DESTDIR      ?=

README.md

@@ -214,11 +214,41 @@ Two things about how it is put together:
   the length of the update, holding the connection open and taking instructions
   on stdin. It needs **python-gobject**; without it there is simply no bar and
   nothing else changes.
-- The position inside the repository step comes from pacman's own
+- Working out the upgrade, downloading it and unpacking it are three separate
-  `(120/260) upgrading foo` lines. pacman's other `(n/m)` sequences — checking
+  steps. The first is the one that used to look broken: between
-  keys, package integrity, loading files — each count to the same total, so
+  `:: Starting full system upgrade...` and the transaction it eventually
-  only the transaction verbs are followed; otherwise the bar would reach the
+  prepares, pacman prints nothing at all, and on a large backlog that silence
-  end three times before the first package was unpacked.
+  runs to minutes. A counter frozen at "0 of 161" reads as a stuck update, so
+  that stretch carries a label and deliberately no counter. On a domestic line
+  the download is then the longest of the three, and calling the whole thing
+  "installing" would leave the bar at 4% for six minutes.
+- A step that turns out to have no work is dropped from the bar rather than
+  handed its share for nothing. Packages already in the cache are never
+  announced, so a run that only has to unpack skips the download step outright
+  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
+  at once — which is how a bar comes to sit still and then jump to the end.
+- Neither counted phase gets a counter from pacman on an unattended run, so
+  both are counted a line at a time — `foo-1.2-1-x86_64 downloading...` and
+  `upgrading foo...`. The database sync just before prints the same shape
+  (` core downloading...`) with the suffix that would give it away already
+  stripped, so counting starts only after pacman's `:: Retrieving packages...`
+  header. pacman's other `(n/m)` sequences — checking keys, package integrity,
+  loading files — each count to the same total, so only the transaction verbs
+  are followed; otherwise the bar would reach the end three times before the
+  first package was unpacked.
 
 This is Plasma's job interface. On a desktop that does not implement it the
 helper exits quietly and the ordinary notifications carry on as before.

doc/cachy-auto-update.1.scd

@@ -122,10 +122,36 @@ of the update and holds that connection open. It requires _python-gobject_.
 Where that is missing, or on a desktop with no job interface, there is no
 progress entry and nothing else is affected.
 
-The position within the repository step is read from pacman's own
+Working out the upgrade, fetching it and unpacking it are three steps rather
-"(120/260) upgrading foo" output. Its other (n/m) sequences - checking keys,
+than one. Between "Starting full system upgrade" and the transaction it
-package integrity, loading package files - each count up to the same total and
+eventually prepares, pacman prints nothing at all, and on a large backlog that
-are deliberately ignored.
+silence runs to minutes; that stretch therefore carries a label of its own and
+deliberately no item count, because a counter frozen at "0 of 161" reads as a
+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
+outright rather than jumping when unpacking starts; the same applies to AUR
+with nothing pending, or a machine with no Flatpaks installed.
+
+Neither counted phase gets a counter from pacman on an unattended run, so both
+are counted here, a line at a time: "foo-1.2-1-x86_64 downloading..." for the
+first, "upgrading foo..." for the second. pacman's output is line-buffered
+through *stdbuf*(1) so those lines arrive as they happen - writing to a log
+rather than a terminal, libc would otherwise release them in 4KB blocks, around
+a hundred and sixty packages at a time. pacman's other (n/m) sequences -
+checking keys, package integrity, loading package files - each count up to the
+same total and are deliberately ignored.
 
 # HOW LONG NOTIFICATIONS STAY
 

po/cachy-auto-update.pot

@@ -174,6 +174,17 @@ msgstr ""
 msgid "cachy-update's update check has been disabled."
 msgstr ""
 
+msgid "CachyOS shows a \"Reboot recommended\" notification while an update is still running. Turn it off? [Y/n]"
+msgstr ""
+
+#, c-format
+msgid "The reboot notification has been turned off. Undo it by deleting %s."
+msgstr ""
+
+#, c-format
+msgid "Could not write %s."
+msgstr ""
+
 msgid "No log yet."
 msgstr ""
 
@@ -219,19 +230,35 @@ msgid "Without a command an interactive menu is shown."
 msgstr ""
 
 #. Progress bar
-msgid "Repository packages"
+#. The headline of the desktop's progress entry. Whoever reads it has not gone
+#. looking for it - it appears next to whatever they were doing - so each one
+#. says outright that this is an update running, rather than naming the kind of
+#. package on its own.
+msgid "Checking for updates"
 msgstr ""
 
-msgid "AUR packages"
+msgid "Preparing the update"
 msgstr ""
 
-msgid "Flatpaks"
+msgid "Downloading updates"
 msgstr ""
 
-msgid "AppImages"
+msgid "Updating system packages"
 msgstr ""
 
-msgid "Cleaning up"
+msgid "Updating AUR packages"
+msgstr ""
+
+msgid "Updating Flatpak apps"
+msgstr ""
+
+msgid "Updating AppImages"
+msgstr ""
+
+msgid "Cleaning up after the update"
+msgstr ""
+
+msgid "Log"
 msgstr ""
 
 msgid "Package"

po/de.po

@@ -175,6 +175,17 @@ msgstr "cachy-update benachrichtigt ebenfalls über verfügbare Updates. Dessen
 msgid "cachy-update's update check has been disabled."
 msgstr "Die Update-Prüfung von cachy-update wurde abgeschaltet."
 
+msgid "CachyOS shows a \"Reboot recommended\" notification while an update is still running. Turn it off? [Y/n]"
+msgstr "CachyOS zeigt eine Benachrichtigung \"Neustart empfohlen\", während ein Update noch läuft. Abschalten? [J/n]"
+
+#, c-format
+msgid "The reboot notification has been turned off. Undo it by deleting %s."
+msgstr "Die Neustart-Benachrichtigung wurde abgeschaltet. Rückgängig durch Löschen von %s."
+
+#, c-format
+msgid "Could not write %s."
+msgstr "%s konnte nicht geschrieben werden."
+
 msgid "No log yet."
 msgstr "Noch kein Protokoll vorhanden."
 
@@ -220,20 +231,36 @@ msgid "Without a command an interactive menu is shown."
 msgstr "Ohne Befehl wird ein interaktives Menü angezeigt."
 
 #. Progress bar
-msgid "Repository packages"
+#. The headline of the desktop's progress entry. Whoever reads it has not gone
-msgstr "Paketquellen"
+#. looking for it - it appears next to whatever they were doing - so each one
+#. says outright that this is an update running, rather than naming the kind of
+#. package on its own.
+msgid "Checking for updates"
+msgstr "Nach Updates wird gesucht"
 
-msgid "AUR packages"
+msgid "Preparing the update"
-msgstr "AUR-Pakete"
+msgstr "Update wird vorbereitet"
 
-msgid "Flatpaks"
+msgid "Downloading updates"
-msgstr "Flatpaks"
+msgstr "Updates werden heruntergeladen"
 
-msgid "AppImages"
+msgid "Updating system packages"
-msgstr "AppImages"
+msgstr "Systempakete werden aktualisiert"
 
-msgid "Cleaning up"
+msgid "Updating AUR packages"
-msgstr "Wird aufgeräumt"
+msgstr "AUR-Pakete werden aktualisiert"
+
+msgid "Updating Flatpak apps"
+msgstr "Flatpak-Programme werden aktualisiert"
+
+msgid "Updating AppImages"
+msgstr "AppImages werden aktualisiert"
+
+msgid "Cleaning up after the update"
+msgstr "Aufräumen nach dem Update"
+
+msgid "Log"
+msgstr "Protokoll"
 
 msgid "Package"
 msgstr "Paket"

src/cachy-auto-update

@@ -84,6 +84,48 @@ cau_do_enable() {
 	fi
 
 	cau_offer_disable_cachy_update
+	cau_offer_disable_reboot_hook
+}
+
+# CachyOS ships a pacman hook that pops up "Reboot recommended!" the moment a
+# kernel, driver or systemd package is unpacked. During a manual upgrade that
+# is fine - the transaction is the last thing happening. During an unattended
+# one it lands in the middle: the run still has AUR packages to build and
+# Flatpaks to pull, and a notification asking for a restart right then is an
+# invitation to cut the update in half.
+#
+# pacman lets a hook be overridden by name from /etc/pacman.d/hooks, which takes
+# precedence over /usr/share/libalpm/hooks, and a symlink to /dev/null there
+# disables it. That is the standard way to switch off a distribution hook, and
+# it is undone by deleting the link.
+#
+# This one is offered, never decided: it is another package's behaviour and it
+# applies to manual upgrades too.
+CAU_REBOOT_HOOK="cachyos-reboot-required.hook"
+
+cau_offer_disable_reboot_hook() {
+	local system="/usr/share/libalpm/hooks/$CAU_REBOOT_HOOK"
+	local override="/etc/pacman.d/hooks/$CAU_REBOOT_HOOK"
+	local answer
+
+	[[ -t 0 && -t 1 ]] || return 0
+	[[ -f $system ]] || return 0
+	[[ -e $override || -L $override ]] && return 0
+
+	printf '\n  %s\n  ' \
+		"$(cau_msg "CachyOS shows a \"Reboot recommended\" notification while an update is still running. Turn it off? [Y/n]")"
+	read -r answer || return 0
+
+	case "${answer,,}" in
+		''|y|yes|j|ja) ;;
+		*) return 0 ;;
+	esac
+
+	if mkdir -p /etc/pacman.d/hooks 2>/dev/null && ln -sfn /dev/null "$override" 2>/dev/null; then
+		cau_ok "$(cau_msg "The reboot notification has been turned off. Undo it by deleting %s." "$override")"
+	else
+		cau_bad "$(cau_msg "Could not write %s." "$override")"
+	fi
 }
 
 # Whether an AUR helper exists at all, without the logging cau_aur_detect does.

src/cachy-auto-update-progress

@@ -8,6 +8,7 @@
 #
 #   info<TAB>text          headline, already translated by the caller
 #   detail<TAB>name<TAB>value  a labelled line under "Details"
+#   log<TAB>name<TAB>line<TAB>line...  the run log's last lines, one per field
 #   total<TAB>n            how many items this step has
 #   done<TAB>n             how many of them are finished
 #   percent<TAB>n          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":

src/cachy-auto-update-run

@@ -185,13 +185,18 @@ failed=0
 # Open the desktop's progress bar, told up front which steps this run will
 # perform. Only those count towards the bar, so a machine with no Flatpaks
 # does not sit at 85% for the last second of the run.
-progress_steps=(repo)
+progress_steps=(resolve download repo)
 [[ $CFG_AUR == yes ]]      && progress_steps+=(aur)
 [[ $CFG_FLATPAK == yes ]]  && progress_steps+=(flatpak)
 [[ $CFG_APPIMAGE == yes ]] && progress_steps+=(appimage)
 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

src/lib/pkg_appimage.sh

@@ -43,7 +43,27 @@ cau_appimage_update() {
 	local user uid count rc=0
 	local -a cmd
 
-	cau_progress_step appimage "AppImages"
+	# Is there a Gear Lever on this machine at all? Asked before the step is
+	# announced rather than discovered inside the loop: on a machine without
+	# one - the common case, it is an optional dependency - a step that exists
+	# only to hand its share of the bar straight to the next one is a jump the
+	# bar does not need. Stops at the first user who has it, so the extra probe
+	# costs anything only in the case it is there to remove.
+	local found=0
+	while read -r user uid; do
+		[[ -n $user ]] || continue
+		if _cau_gearlever_cmd "$user" "$uid" > /dev/null; then
+			found=1
+			break
+		fi
+	done < <(cau_active_session_users)
+
+	if (( ! found )); then
+		cau_progress_drop appimage
+		return 0
+	fi
+
+	cau_progress_step appimage "Updating AppImages"
 
 	while read -r user uid; do
 		[[ -n $user ]] || continue

src/lib/pkg_aur.sh

@@ -124,31 +124,40 @@ cau_aur_update() {
 	local pending failures
 	local -a args
 
-	cau_aur_ready || return 0
+	# No helper, no base-devel, no bar: a step that cannot run should not be
+	# holding a share of it.
+	cau_aur_ready || { cau_progress_drop aur; return 0; }
 
-	cau_progress_step aur "AUR packages"
+	cau_progress_step aur "Updating AUR packages"
 
 	pending="$(cau_aur_pending)"
 	if (( pending == 0 )); then
 		cau_info "No AUR updates pending"
 		cau_state_clear aur_failures
+		cau_progress_drop aur
 		return 0
 	fi
 
 	cau_info "Updating $pending AUR package(s) with $CAU_AUR_HELPER"
 
-	# The helper builds each package from source with no counter this side of
+	# The helper builds each package from source and prints plenty about it,
-	# its output, so the bar sits at the start of the step until it is done.
+	# none of it countable from this side. A single large package can take ten
+	# minutes, so the bar creeps through the step rather than sitting at its
+	# start for all of them; the item count stays where it is, because that is
+	# the number that would be lying if it moved.
 	cau_progress_item 0 "$pending"
 	mapfile -t args < <(cau_aur_helper_args)
+	cau_progress_creep_start
 
 	if cau_run_logged cau_as_build_user "$CAU_AUR_HELPER" "${args[@]}"; then
+		cau_progress_creep_stop
 		CAU_AUR_COUNT="$pending"
 		cau_progress_item "$pending"
 		cau_state_clear aur_failures
 		return 0
 	fi
 
+	cau_progress_creep_stop
 	CAU_AUR_COUNT=0
 	failures="$(cau_state_read aur_failures 0)"
 	[[ $failures =~ ^[0-9]+$ ]] || failures=0

src/lib/pkg_flatpak.sh

@@ -26,21 +26,31 @@ cau_flatpak_pending_system() {
 cau_flatpak_update() {
 	local rc=0 pending user uid home count
 
-	cau_have flatpak || return 0
+	cau_have flatpak || { cau_progress_drop flatpak; return 0; }
 
-	cau_progress_step flatpak "Flatpaks"
+	cau_progress_step flatpak "Updating Flatpak apps"
 
-	# refresh appstream metadata first so remote-ls sees current versions
+	# refresh appstream metadata first so remote-ls sees current versions.
+	# Nothing is countable until that has finished, so the bar creeps rather
+	# than waiting at the start of the step for it.
+	cau_progress_creep_start
 	cau_run_logged flatpak update --appstream --system --noninteractive || true
+	cau_progress_creep_stop
 
 	pending="$(cau_flatpak_pending_system)"
 	if (( pending > 0 )); then
 		cau_info "Updating $pending system Flatpak(s)"
 		cau_progress_item 0 "$pending"
+		# Started after the count above and stopped before the one below, so the
+		# only reports this side makes while a ticker is running are further
+		# along than the ticker ever gets.
+		cau_progress_creep_start
 		if cau_run_logged flatpak update --system --noninteractive --assumeyes; then
+			cau_progress_creep_stop
 			CAU_FLATPAK_COUNT=$(( CAU_FLATPAK_COUNT + pending ))
 			cau_progress_item "$pending"
 		else
+			cau_progress_creep_stop
 			cau_warn "System Flatpak update failed"
 			rc=1
 		fi

src/lib/pkg_pacman.sh

@@ -27,37 +27,148 @@ cau_pacman_flags() {
 	done
 }
 
+# The verbs pacman puts in front of a package as it works through a
+# transaction. Matched against English on purpose: the runner forces LC_ALL=C
+# precisely so pacman's output stays parseable.
+CAU_PACMAN_OP_RE='^(\([[:space:]]*[0-9]+/[0-9]+\) )?(upgrading|installing|reinstalling|downgrading|removing) [^[:space:]]+'
+
+# Before any of that, everything has to be fetched, and on a domestic line
+# that is the longer half of the run: two hundred packages take minutes to
+# arrive and seconds to unpack. pacman prints one line per package while it
+# does it,
+#
+#    glibc-2.44+r24+g16be1518495f-1-x86_64_v3 downloading...
+#
+# and nothing else - no counter, no total - so the position here is counted the
+# same way the transaction is.
+#
+# The database sync a few lines earlier prints the very same shape (" core
+# downloading..."), and pacman strips the suffix that would tell a database
+# from a package, so the count begins only after the header that separates the
+# two phases.
+CAU_PACMAN_DL_AWK='
+	/^:: Retrieving packages/ { retrieving = 1; next }
+	retrieving && / downloading\.\.\.$/ { n++; name = $1 }
+	END { print n + 0, name }'
+
 # _cau_pacman_progress_watch <logfile>
-# Feeds the desktop's progress bar from pacman's own transaction counter.
+# Feeds the desktop's progress bar by watching pacman work, through the three
-# --noprogressbar makes pacman print one "(120/260) upgrading foo" line per
+# phases a pacman run has: first it works out what the upgrade consists of,
-# package, and that is the only live measure of how far a transaction has got:
+# then everything is fetched, then everything is unpacked. Three steps on the
-# checkupdates knows the total beforehand, but nothing else knows the position.
+# bar rather than one, because they are three stretches to sit through - and
+# each one is silent in its own way.
 #
-# The other (n/m) sequences pacman prints - checking keys in keyring, checking
+# The first is the one that used to look like a hang. Between "starting full
-# package integrity, loading package files - are deliberately not matched. Each
+# system upgrade" and the transaction it eventually prepares, pacman says
-# counts up to the same total, so following them would run the bar to the end
+# nothing whatsoever, and on a large backlog that silence is minutes long. The
-# three times over before the first package was unpacked.
+# only honest thing to show there is a label and no counter at all: a tally
+# frozen at "0 of 161" reads as a stuck update, where "Preparing the update"
+# with no number reads as what it actually is.
 #
-# Read from the log by polling rather than from a pipe: the log is written
+# In the transaction, pacman announces each package twice over, in one of two
-# either by pacman directly or through tee, depending on whether a person is
+# shapes, and which one depends on a flag this program sets itself:
-# watching, and one reader that works for both is worth more here than the
+#
-# second or so of latency it costs.
+#   upgrading glibc...              with --noprogressbar, i.e. every timer run
+#   ( 12/218) upgrading glibc [##]  with the bar, i.e. an interactive `run`
+#
+# Only the second carries a counter, and the unattended runs that this bar
+# exists for are exactly the ones that do not get it. So the position is
+# counted here instead - one line per package - and the total taken from the
+# "Package (218)" header pacman prints before it starts. That header is the
+# better number anyway: checkupdates counts packages with an update available
+# and knows nothing about the new dependencies pulled in alongside them.
+#
+# What must not be counted is the other (n/m) sequence pacman prints, for
+# hooks and for checking keys, integrity and file conflicts. Each of those runs
+# up to its own total, so following them would drive the bar to the end several
+# times before the first package was unpacked. Requiring one of the verbs above
+# is what excludes them.
+#
+# Read by polling the log rather than from a pipe: the log is written either by
+# pacman directly or through tee depending on whether a person is watching, and
+# one reader that works for both is worth the second of latency it costs.
 _cau_pacman_progress_watch() {
-	local log="$1" line last='' pkg
+	local log="$1"
+	local total="${CAU_PACMAN_COUNT:-0}" announced processed line pkg last=''
+	local phase=resolve fetched shown='' labelled=''
+	local t0=$SECONDS
 
 	while :; do
 		sleep 1
 
-		line="$(grep -aoE '^\([[:space:]]*[0-9]+/[0-9]+\) (upgrading|installing|reinstalling|downgrading|removing) [^[:space:]]+' \
+		announced="$(grep -aoE '^Packages? \([0-9]+\)' "$log" 2>/dev/null \
-			"$log" 2>/dev/null | tail -n1)"
+			| head -n1 | grep -oE '[0-9]+')"
-		[[ -n $line && $line != "$last" ]] || continue
+		[[ $announced =~ ^[0-9]+$ ]] && (( announced > 0 )) && total="$announced"
+
+		line="$(grep -aoE "$CAU_PACMAN_OP_RE" "$log" 2>/dev/null | tail -n1)"
+
+		if [[ -n $line ]]; then
+			# Unpacking has started, so whatever came before it is over. If
+			# nothing was ever retrieved - every package already sitting in the
+			# cache, which is the ordinary state of affairs after a run that was
+			# interrupted once already - then the download step never happened,
+			# and it is dropped rather than handed its whole share of the bar in
+			# exchange for no work at all.
+			if [[ $phase != install ]]; then
+				[[ $phase == download ]] || cau_progress_drop download
+				phase=install
+				cau_progress_step repo "Updating system packages" "$total"
+			fi
+
+			# Nothing new since the last look. Checked before the counting grep
+			# because on a large upgrade this loop spends most of its life here.
+			[[ $line != "$last" ]] || continue
 			last="$line"
 
-		[[ $line =~ ^\([[:space:]]*([0-9]+)/([0-9]+)\)[[:space:]]+[a-z]+[[:space:]]+(.+)$ ]] || continue
+			processed="$(grep -acE "$CAU_PACMAN_OP_RE" "$log" 2>/dev/null)"
+			[[ $processed =~ ^[0-9]+$ ]] || continue
 
-		cau_progress_item "${BASH_REMATCH[1]}" "${BASH_REMATCH[2]}"
+			# Where pacman does carry a counter, believe it over the tally: it
-		pkg="${BASH_REMATCH[3]%...}"
+			# is the same number, but it also knows the true total.
-		cau_progress_detail "Package" "$pkg"
+			if [[ $line =~ ^\([[:space:]]*([0-9]+)/([0-9]+)\) ]]; then
+				processed="${BASH_REMATCH[1]}"
+				total="${BASH_REMATCH[2]}"
+			fi
+
+			cau_progress_item "$processed" "$total"
+
+			pkg="${line##* }"
+			cau_progress_detail "Package" "${pkg%...}"
+			continue
+		fi
+
+		# Fetching. The header is what tells this apart from the database sync
+		# a few lines earlier, which prints the very same shape.
+		if grep -qa '^:: Retrieving packages' "$log" 2>/dev/null; then
+			if [[ $phase == resolve ]]; then
+				phase=download
+				cau_progress_step download "Downloading updates" "$total"
+			fi
+
+			read -r fetched pkg < <(awk "$CAU_PACMAN_DL_AWK" "$log" 2>/dev/null)
+			[[ $fetched =~ ^[0-9]+$ ]] || continue
+			[[ $fetched != "$shown" ]] || continue
+			shown="$fetched"
+
+			cau_progress_item "$fetched" "$total"
+			# Down to the bare name, as the transaction reports it: the file
+			# pacman names here carries version, release and architecture.
+			[[ -n $pkg ]] && cau_progress_detail "Package" "${pkg%-*-*-*}"
+			continue
+		fi
+
+		# Still resolving. pacman does mark the point where it stops syncing
+		# databases and starts working out the upgrade, and that is the half
+		# worth naming, because it is the half that takes the minutes.
+		if [[ $phase == resolve && $labelled != upgrade ]] \
+			&& grep -qa '^:: Starting full system upgrade' "$log" 2>/dev/null; then
+			labelled=upgrade
+			cau_progress_step resolve "Preparing the update"
+		fi
+
+		# Nothing countable happens in here at all, so the bar creeps instead.
+		# This is the stretch that used to look like a hung update.
+		cau_progress_creep $(( SECONDS - t0 ))
 	done
 }
 
@@ -77,11 +188,21 @@ _cau_pacman_exec() {
 		watcher=$!
 	fi
 
+	# Line-buffered on purpose. pacman writes to a file or through a pipe here,
+	# never to a terminal, so libc buffers it in 4KB blocks - and 4KB of
+	# "upgrading foo..." is on the order of a hundred and sixty packages. The
+	# watcher would see nothing at all, then a hundred and sixty lines at once,
+	# which is exactly how a bar comes to sit still and then leap to the end.
+	# Guarded rather than assumed: without coreutils there is no bar to feed
+	# either, but there is still an update to run.
+	local -a buffered=()
+	cau_have stdbuf && buffered=(stdbuf -oL)
+
 	if [[ -n $CAU_INTERACTIVE ]]; then
-		pacman "$@" 2>&1 | tee "$log"
+		"${buffered[@]}" pacman "$@" 2>&1 | tee "$log"
 		rc="${PIPESTATUS[0]}"
 	else
-		pacman "$@" > "$log" 2>&1
+		"${buffered[@]}" pacman "$@" > "$log" 2>&1
 		rc=$?
 	fi
 
@@ -166,10 +287,18 @@ cau_pacman_update() {
 	local log kind
 	local -a flags
 
-	cau_progress_step repo "Repository packages"
+	# checkupdates goes first, against its own private database, and the bar
+	# says so rather than naming a step that has not begun. The watcher takes
+	# over from here and moves on to the download and repo steps as pacman
+	# actually reaches them.
+	cau_progress_step resolve "Checking for updates"
 
 	if ! cau_pacman_pending; then
 		cau_info "No repository updates pending"
+		# Neither of the two steps this would have led to is going to happen,
+		# so the rest of the run gets their share of the bar instead of
+		# watching it jump 70% the moment Flatpaks start.
+		cau_progress_drop download repo
 		return 0
 	fi
 
@@ -177,7 +306,10 @@ cau_pacman_update() {
 		CAU_PACMAN_COUNT="$(grep -c . <<< "$CAU_PACMAN_PENDING")"
 		[[ $CAU_PACMAN_COUNT =~ ^[0-9]+$ ]] || CAU_PACMAN_COUNT=0
 		cau_info "Updating $CAU_PACMAN_COUNT repository package(s)"
-		cau_progress_item 0 "$CAU_PACMAN_COUNT"
+		# Deliberately no item count yet. Until pacman has prepared a
+		# transaction there is nothing being worked through, and "0 of 161"
+		# against a bar that cannot move for the next few minutes is the exact
+		# impression the resolve step exists to avoid.
 	else
 		# checkupdates is unavailable, so the list is unknown and pacman is
 		# asked to work it out itself.
@@ -210,6 +342,13 @@ cau_pacman_update() {
 
 	while true; do
 		if _cau_pacman_exec "$log" -Syu "${flags[@]}" "${extra[@]}"; then
+			# The watcher decided the same thing in a subshell, so a step it
+			# dropped is still in the plan out here. Same question, same answer,
+			# and the two copies agree on what the rest of the run is scaled
+			# against. Only on the way out: a failed attempt is about to be
+			# retried, and that retry may well download after all.
+			grep -qa '^:: Retrieving packages' "$log" 2>/dev/null \
+				|| cau_progress_drop download
 			cat "$log" >> "$CAU_RUNLOG" 2>/dev/null
 			grep -E '^(removing|replacing) ' "$log" 2>/dev/null \
 				| while read -r line; do cau_info "  $line"; done
@@ -310,7 +449,7 @@ cau_pacman_pacnew_count() {
 cau_pacman_cleanup() {
 	local -a orphans
 
-	cau_progress_step cleanup "Cleaning up"
+	cau_progress_step cleanup "Cleaning up after the update"
 
 	if [[ $CFG_REMOVE_ORPHANS == yes ]]; then
 		mapfile -t orphans < <(pacman -Qtdq 2>/dev/null)

src/lib/progress.sh

@@ -26,11 +26,19 @@ CAU_PROGRESS_FIFOS=()
 CAU_PROGRESS_LOCALES=()
 
 # What each step is worth on the bar. Rough shares of a typical run rather than
-# anything measured: repositories dominate, the cleanup is a rounding error.
+# anything measured: the repositories dominate - fetching them and unpacking
+# them about equally, on a domestic line - and the cleanup is a rounding error.
 # They do not have to add up to 100 - only the steps a given run will actually
 # perform are counted, and the total is normalised against those.
+#
+# "resolve" is everything pacman does before it has a transaction: syncing the
+# databases and working out what the upgrade actually consists of. It is
+# usually seconds, which is why it is worth so little - but on a large backlog
+# it is minutes, and those minutes used to be spent looking at a bar that had
+# not moved yet.
 declare -A CAU_PROGRESS_WEIGHTS=(
-	[repo]=70 [aur]=15 [flatpak]=10 [appimage]=3 [cleanup]=2
+	[resolve]=10 [download]=30 [repo]=40 [aur]=15 [flatpak]=10 [appimage]=3
+	[cleanup]=2
 )
 
 CAU_PROGRESS_PLAN=()
@@ -132,6 +140,49 @@ cau_progress_active() {
 	(( ${#CAU_PROGRESS_FDS[@]} ))
 }
 
+# cau_progress_drop <step-id...>
+# Takes steps out of the plan and rescales the bar to what is left.
+#
+# Which steps a run will perform is only half known up front. The other half
+# turns up while it runs: nothing to download because every package was already
+# in the cache, no AUR updates pending, no Flatpaks installed. A step like that
+# keeps its whole share of the bar and then hands it over in a single jump the
+# moment the next one starts - which is precisely the stutter this is here to
+# remove. Dropping it hands its share to the steps that do have work instead,
+# so the bar advances at a steady pace rather than leaping across the gaps.
+#
+# It is also what lets the weights above stay rough: they never have to be
+# right about a step that does not run, only about the ones that do.
+#
+# Only ever called for a step that has not started, so nothing already behind
+# the bar is rescaled and the bar does not travel backwards.
+cau_progress_drop() {
+	local drop step
+	local -a kept=()
+
+	(( ${#CAU_PROGRESS_FDS[@]} )) || return 0
+
+	for step in "${CAU_PROGRESS_PLAN[@]}"; do
+		for drop in "$@"; do
+			[[ $step == "$drop" ]] && continue 2
+		done
+		kept+=("$step")
+	done
+
+	(( ${#kept[@]} == ${#CAU_PROGRESS_PLAN[@]} )) && return 0
+
+	CAU_PROGRESS_PLAN=("${kept[@]}")
+	CAU_PROGRESS_SCALE=0
+	for step in "${CAU_PROGRESS_PLAN[@]}"; do
+		CAU_PROGRESS_SCALE=$(( CAU_PROGRESS_SCALE + ${CAU_PROGRESS_WEIGHTS[$step]:-0} ))
+	done
+
+	# Nothing left to weigh against would divide by zero further down. Cannot
+	# happen while cleanup is unconditional, but this is cheaper than relying
+	# on that staying true.
+	(( CAU_PROGRESS_SCALE > 0 )) || CAU_PROGRESS_SCALE=1
+}
+
 # cau_progress_step <step-id> <label-msgid> [item-count]
 # Moves on to the next step. The bar jumps to where that step begins, so a step
 # that reported fewer items than it promised still completes rather than
@@ -142,11 +193,17 @@ cau_progress_step() {
 
 	(( ${#CAU_PROGRESS_FDS[@]} )) || return 0
 
+	local found=0
 	for step in "${CAU_PROGRESS_PLAN[@]}"; do
-		[[ $step == "$id" ]] && break
+		[[ $step == "$id" ]] && { found=1; break; }
 		base=$(( base + ${CAU_PROGRESS_WEIGHTS[$step]:-0} ))
 	done
 
+	# A step that was dropped for having no work is not a step to move to.
+	# Without this the loop above would fall off the end of the plan and hand
+	# back the sum of every weight, i.e. send the bar straight to 100%.
+	(( found )) || return 0
+
 	CAU_PROGRESS_BASE=$base
 	CAU_PROGRESS_SPAN=${CAU_PROGRESS_WEIGHTS[$id]:-0}
 	CAU_PROGRESS_TOTAL=$total
@@ -169,10 +226,38 @@ cau_progress_step() {
 	cau_progress_item 0
 }
 
+# _cau_progress_pct <numerator> <denominator>
+# How far through the current step we are, as a share of its span, turned into
+# one number for the whole run and sent on if it has moved.
+_cau_progress_pct() {
+	local num="$1" den="$2" pct scaled
+
+	if (( den > 0 )); then
+		scaled=$(( CAU_PROGRESS_BASE * 100 + CAU_PROGRESS_SPAN * 100 * num / den ))
+	else
+		scaled=$(( CAU_PROGRESS_BASE * 100 ))
+	fi
+
+	pct=$(( scaled / CAU_PROGRESS_SCALE ))
+	(( pct > 100 )) && pct=100
+
+	# Never backwards. Two honest things can ask for that: dropping a step
+	# rescales the run against a smaller total, and the conflict-recovery loop
+	# restarts pacman - and with it the item tally - from the top. Both are
+	# real, neither is a reason to show somebody a bar that retreats.
+	(( pct < CAU_PROGRESS_SHOWN )) && pct=$CAU_PROGRESS_SHOWN
+
+	# Only when the whole number changes. Percent is the one field the runner
+	# would otherwise rewrite for every package on a 500-package upgrade.
+	(( pct == CAU_PROGRESS_SHOWN )) && return 0
+	CAU_PROGRESS_SHOWN=$pct
+	_cau_progress_line 'percent\t%s' "$pct"
+}
+
 # cau_progress_item <processed> [total]
 # How far through the current step we are.
 cau_progress_item() {
-	local processed="$1" total="${2:-$CAU_PROGRESS_TOTAL}" pct scaled
+	local processed="$1" total="${2:-$CAU_PROGRESS_TOTAL}"
 
 	(( ${#CAU_PROGRESS_FDS[@]} )) || return 0
 	[[ $processed =~ ^[0-9]+$ ]] || return 0
@@ -184,19 +269,86 @@ cau_progress_item() {
 			_cau_progress_line 'total\t%s' "$total"
 		fi
 		_cau_progress_line 'done\t%s' "$processed"
-		scaled=$(( CAU_PROGRESS_BASE * 100 + CAU_PROGRESS_SPAN * 100 * processed / total ))
+		_cau_progress_pct "$processed" "$total"
 	else
-		scaled=$(( CAU_PROGRESS_BASE * 100 ))
+		_cau_progress_pct 0 0
 	fi
+}
 
-	pct=$(( scaled / CAU_PROGRESS_SCALE ))
+# cau_progress_creep <seconds-elapsed>
-	(( pct > 100 )) && pct=100
+# Moves the bar through a step whose length cannot be known in advance.
+#
+# Some of a run has no counter to offer and never will. pacman prints nothing
+# whatsoever between "starting full system upgrade" and the transaction it
+# eventually prepares; an AUR helper compiling a package prints plenty, none of
+# it countable. On a large backlog either is minutes. There is no honest number
+# to show for that - but a bar that has not moved since it appeared is read as
+# a hang, and somebody who reads it that way reaches for the power button in
+# the middle of an update. That is the failure this is here to prevent.
+#
+# So it creeps, along a curve that approaches the end of the step without ever
+# reaching it: half the step's share after HALFLIFE seconds, three quarters
+# after three times that, the whole of it never. Nothing is claimed that is not
+# known - the item counter stays empty throughout, which is the field that
+# would be lying if it moved - and the step still finishes the instant real
+# work reports in, because every real report is further along than the creep.
+#
+# Confined to the step's own span, so a creep can never overtake the step that
+# comes after it however long it is left running.
+CAU_PROGRESS_CREEP_HALFLIFE=45
 
-	# Only when the whole number changes. Percent is the one field the runner
+cau_progress_creep() {
-	# would otherwise rewrite for every package on a 500-package upgrade.
+	local elapsed="$1"
-	(( pct == CAU_PROGRESS_SHOWN )) && return 0
+
-	CAU_PROGRESS_SHOWN=$pct
+	(( ${#CAU_PROGRESS_FDS[@]} )) || return 0
-	_cau_progress_line 'percent\t%s' "$pct"
+	[[ $elapsed =~ ^[0-9]+$ ]] || return 0
+
+	_cau_progress_pct "$elapsed" $(( elapsed + CAU_PROGRESS_CREEP_HALFLIFE ))
+}
+
+# cau_progress_creep_start / cau_progress_creep_stop
+# The same, for a step that blocks in one long call instead of polling: the
+# ticker runs alongside it and is stopped when it returns. Only one at a time,
+# and starting a second one replaces the first.
+CAU_PROGRESS_CREEP_PID=0
+CAU_PROGRESS_CREEP_T0=0
+
+cau_progress_creep_start() {
+	cau_progress_creep_stop
+	(( ${#CAU_PROGRESS_FDS[@]} )) || return 0
+
+	CAU_PROGRESS_CREEP_T0=$SECONDS
+	local t0=$SECONDS
+	{
+		# Waiting without forking a sleep every two seconds, for the same
+		# reason cau_progress_begin opens its fifo read-write: a pipe held open
+		# at both ends never reports end-of-file, so a timed read on it blocks
+		# for exactly the timeout and nothing else. A forked sleep would also
+		# survive the kill below - it is a child of this subshell, not this
+		# subshell - and inherit the fifo's write end, which would keep the
+		# helper from seeing the end of its input until the sleep ran out.
+		local nap
+		exec {nap}<> <(:)
+		while :; do
+			read -r -t 2 -u "$nap" _ || true
+			cau_progress_creep $(( SECONDS - t0 ))
+		done
+	} &
+	CAU_PROGRESS_CREEP_PID=$!
+}
+
+cau_progress_creep_stop() {
+	(( CAU_PROGRESS_CREEP_PID )) || return 0
+	kill "$CAU_PROGRESS_CREEP_PID" 2>/dev/null
+	wait "$CAU_PROGRESS_CREEP_PID" 2>/dev/null
+	CAU_PROGRESS_CREEP_PID=0
+
+	# The ticker moved the bar from inside a subshell, so this side never saw
+	# it happen and still believes the bar is where it was left. Catching up
+	# costs one recomputation - the curve is a function of elapsed time and
+	# nothing else - and without it the next ordinary report from here would be
+	# measured against a stale percentage and send the bar backwards.
+	cau_progress_creep $(( SECONDS - CAU_PROGRESS_CREEP_T0 ))
 }
 
 # cau_progress_detail <label-msgid> <value>
@@ -215,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 <label-msgid> <text>
+# 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 <logfile> / 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
@@ -234,6 +463,12 @@ cau_progress_end() {
 	local outcome="${1:-ok}" msgid="${2:-}"
 	local i fd
 
+	# 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
 	# vanish there. Only on the way out of a run that actually worked, though: