[libvirt] [PATCH] output status information during guest shutdown again

With SysV-init libvirt-guests wrote status information to the console during shutdown of the guests. Since the move to systemd libvirt-guests doesn't output this progress information anymore. This patch brings back this feature. It is helpful to show the admin what the system is waiting for and what is left of the timeout (e.g. for calibrating the shutdown timing of a ups). Rewriting the current line with \r doesn't work anymore in the context of systemd. So always write new lines, but move to 5 second intervals to avoid flooding the console. --- tools/libvirt-guests.init.sh | 65 +++++++++++++++++++++++++++++++---------- tools/libvirt-guests.service.in | 1 + 2 files changed, 51 insertions(+), 15 deletions(-) mode change 100644 => 100755 tools/libvirt-guests.init.sh diff --git a/tools/libvirt-guests.init.sh b/tools/libvirt-guests.init.sh old mode 100644 new mode 100755 index d5d42d6..0ffbb41 --- a/tools/libvirt-guests.init.sh +++ b/tools/libvirt-guests.init.sh @@ -225,22 +225,27 @@ suspend_guest() name=$(guest_name "$uri" "$guest") label=$(eval_gettext "Suspending \$name: ") bypass= + slept=0 test "x$BYPASS_CACHE" = x0 || bypass=--bypass-cache - printf %s "$label" + printf '%s%-12s\n' "$label" "..." run_virsh "$uri" managedsave $bypass "$guest" >/dev/null & virsh_pid=$! while true; do sleep 1 kill -0 "$virsh_pid" >/dev/null 2>&1 || break - progress=$(run_virsh_c "$uri" domjobinfo "$guest" 2>/dev/null | \ - awk '/^Data processed:/{print $3, $4}') - if [ -n "$progress" ]; then - printf '\r%s%12s ' "$label" "$progress" - else - printf '\r%s%-12s ' "$label" "..." + + slept=$(($slept + 1)) + if [ $(($slept%5)) -eq 0 ]; then + progress=$(run_virsh_c "$uri" domjobinfo "$guest" 2>/dev/null | \ + awk '/^Data processed:/{print $3, $4}') + if [ -n "$progress" ]; then + printf '%s%12s\n' "$label" "$progress" + else + printf '%s%-12s\n' "$label" "..." + fi fi done - retval wait "$virsh_pid" && printf '\r%s%-12s\n' "$label" "$(gettext "done")" + retval wait "$virsh_pid" && printf '%s%-12s\n' "$label" "$(gettext "done")" } # shutdown_guest URI GUEST @@ -252,30 +257,41 @@ shutdown_guest() guest=$2 name=$(guest_name "$uri" "$guest") - label=$(eval_gettext "Shutting down \$name: ") - printf %s "$label" + eval_gettext "Starting shutdown on guest: \$name" + echo retval run_virsh "$uri" shutdown "$guest" >/dev/null || return timeout=$SHUTDOWN_TIMEOUT check_timeout=false if [ $timeout -gt 0 ]; then check_timeout=true + format=$(eval_gettext "Waiting for guest %s to shut down, %4d seconds left\n") + else + slept=0 + format=$(eval_gettext "Waiting for guest %s to shut down\n") fi while ! $check_timeout || [ "$timeout" -gt 0 ]; do sleep 1 guest_is_on "$uri" "$guest" || return "$guest_running" || break + if $check_timeout; then - timeout=$((timeout - 1)) - printf '\r%s%-12d ' "$label" "$timeout" + if [ $(($timeout%5)) -eq 0 ]; then + printf "$format" "$name" "$timeout" + fi + timeout=$(($timeout - 1)) + else + slept=$(($slept + 1)) + if [ $(($slept%5)) -eq 0 ]; then + printf "$format" "$name" + fi fi done if guest_is_on "$uri" "$guest"; then if "$guest_running"; then - printf '\r%s%-12s\n' "$label" \ - "$(gettext "failed to shutdown in time")" + eval_gettext "Shutdown of guest \$name failed to complete in time." else - printf '\r%s%-12s\n' "$label" "$(gettext "done")" + eval_gettext "Shutdown of guest \$name complete." fi fi } @@ -356,6 +372,10 @@ shutdown_guests_parallel() timeout=$SHUTDOWN_TIMEOUT if [ $timeout -gt 0 ]; then check_timeout=true + format=$(eval_gettext "Waiting for %d guests to shut down, %4d seconds left\n") + else + slept=0 + format=$(eval_gettext "Waiting for %d guests to shut down\n") fi while [ -n "$on_shutdown" ] || [ -n "$guests" ]; do while [ -n "$guests" ] && @@ -368,14 +388,29 @@ shutdown_guests_parallel() on_shutdown="$on_shutdown $guest" done sleep 1 + + set -- $guests + guestcount=$# + set -- $on_shutdown + shutdowncount=$# + if $check_timeout; then + if [ $(($timeout%5)) -eq 0 ]; then + printf "$format" $(($guestcount+$shutdowncount)) "$timeout" + fi timeout=$(($timeout - 1)) if [ $timeout -le 0 ]; then eval_gettext "Timeout expired while shutting down domains"; echo RETVAL=1 return fi + else + slept=$(($slept + 1)) + if [ $(($slept%5)) -eq 0 ]; then + printf "$format" $(($guestcount+$shutdowncount)) + fi fi + on_shutdown_prev=$on_shutdown on_shutdown=$(check_guests_shutdown "$uri" "$on_shutdown") print_guests_shutdown "$uri" "$on_shutdown_prev" "$on_shutdown" diff --git a/tools/libvirt-guests.service.in b/tools/libvirt-guests.service.in index db28f3f..0f0c41c 100644 --- a/tools/libvirt-guests.service.in +++ b/tools/libvirt-guests.service.in @@ -10,6 +10,7 @@ ExecStart=/etc/init.d/libvirt-guests start ExecStop=/etc/init.d/libvirt-guests stop Type=oneshot RemainAfterExit=yes +StandardOutput=journal+console [Install] WantedBy=multi-user.target -- 1.7.11.2

Hi, On Friday 03 August 2012 16:52:15 Gerd v. Egidy wrote:
With SysV-init libvirt-guests wrote status information to the console during shutdown of the guests.
Since the move to systemd libvirt-guests doesn't output this progress information anymore. This patch brings back this feature.
It is helpful to show the admin what the system is waiting for and what is left of the timeout (e.g. for calibrating the shutdown timing of a ups).
Rewriting the current line with \r doesn't work anymore in the context of systemd. So always write new lines, but move to 5 second intervals to avoid flooding the console.
It would be nice if anybody could look at the patch I sent and comment or commit. Thanks. Kind regards, Gerd

On 08/03/2012 08:52 AM, Gerd v. Egidy wrote:
With SysV-init libvirt-guests wrote status information to the console during shutdown of the guests.
Since the move to systemd libvirt-guests doesn't output this progress information anymore. This patch brings back this feature.
It is helpful to show the admin what the system is waiting for and what is left of the timeout (e.g. for calibrating the shutdown timing of a ups).
Rewriting the current line with \r doesn't work anymore in the context of systemd. So always write new lines, but move to 5 second intervals to avoid flooding the console. --- tools/libvirt-guests.init.sh | 65 +++++++++++++++++++++++++++++++---------- tools/libvirt-guests.service.in | 1 + 2 files changed, 51 insertions(+), 15 deletions(-) mode change 100644 => 100755 tools/libvirt-guests.init.sh
The mode change is spurious, and should not be part of this patch.
+++ b/tools/libvirt-guests.init.sh @@ -225,22 +225,27 @@ suspend_guest() name=$(guest_name "$uri" "$guest") label=$(eval_gettext "Suspending \$name: ") bypass= + slept=0 test "x$BYPASS_CACHE" = x0 || bypass=--bypass-cache - printf %s "$label" + printf '%s%-12s\n' "$label" "..."
Why are you printing trailing whitespace? You are left-justifying the 3-byte ..., which means you now always have 9 bytes of trailing space Also, the "..." doesn't technically need quoting, although I guess it doesn't hurt. Would it be worth folding the ... into the format string itself, as in: printf '%s...\n' "$label" If we were using \r, then I would understand the trailing space as a means of blanking out longer text printed on a previous loop, but you are abandoning \r.
run_virsh "$uri" managedsave $bypass "$guest" >/dev/null & virsh_pid=$! while true; do sleep 1 kill -0 "$virsh_pid" >/dev/null 2>&1 || break - progress=$(run_virsh_c "$uri" domjobinfo "$guest" 2>/dev/null | \ - awk '/^Data processed:/{print $3, $4}') - if [ -n "$progress" ]; then - printf '\r%s%12s ' "$label" "$progress" - else - printf '\r%s%-12s ' "$label" "..." + + slept=$(($slept + 1)) + if [ $(($slept%5)) -eq 0 ]; then
Consistency argues that we should have spaces on both sides of '%'
+ progress=$(run_virsh_c "$uri" domjobinfo "$guest" 2>/dev/null | \ + awk '/^Data processed:/{print $3, $4}') + if [ -n "$progress" ]; then + printf '%s%12s\n' "$label" "$progress" + else + printf '%s%-12s\n' "$label" "..." + fi fi
Because you now print only every five seconds, you have lost out on the final printing when progress is non-empty if that happens on 4 of the 5 iterations. I think you want the logic to look more like: slept=$(($slept + 1)) progress=$(...) if [ -n "$progress" ]; then printf ... label progress elif [ $(($slept % 5)) -eq 0 ]; then printf ... label... fi
timeout=$SHUTDOWN_TIMEOUT check_timeout=false if [ $timeout -gt 0 ]; then check_timeout=true + format=$(eval_gettext "Waiting for guest %s to shut down, %4d seconds left\n")
Why the padding for the seconds left? If timeout is 60, I think this looks awkward: Waiting for guest foo to shut down, 60 seconds left
+ else + slept=0 + format=$(eval_gettext "Waiting for guest %s to shut down\n") fi while ! $check_timeout || [ "$timeout" -gt 0 ]; do sleep 1 guest_is_on "$uri" "$guest" || return "$guest_running" || break + if $check_timeout; then - timeout=$((timeout - 1)) - printf '\r%s%-12d ' "$label" "$timeout" + if [ $(($timeout%5)) -eq 0 ]; then
Spaces around %
+ printf "$format" "$name" "$timeout" + fi + timeout=$(($timeout - 1)) + else + slept=$(($slept + 1)) + if [ $(($slept%5)) -eq 0 ]; then
Again.
+ printf "$format" "$name"
This is new output that was not present beforehand. Is the intent that when there is no timeout, you want to show that the process is still alive waiting for the guest?
+ fi fi done
if guest_is_on "$uri" "$guest"; then if "$guest_running"; then - printf '\r%s%-12s\n' "$label" \ - "$(gettext "failed to shutdown in time")" + eval_gettext "Shutdown of guest \$name failed to complete in time." else - printf '\r%s%-12s\n' "$label" "$(gettext "done")" + eval_gettext "Shutdown of guest \$name complete." fi fi } @@ -356,6 +372,10 @@ shutdown_guests_parallel() timeout=$SHUTDOWN_TIMEOUT if [ $timeout -gt 0 ]; then check_timeout=true + format=$(eval_gettext "Waiting for %d guests to shut down, %4d seconds left\n")
Another awkward %4d.
+ else + slept=0 + format=$(eval_gettext "Waiting for %d guests to shut down\n") fi while [ -n "$on_shutdown" ] || [ -n "$guests" ]; do while [ -n "$guests" ] && @@ -368,14 +388,29 @@ shutdown_guests_parallel() on_shutdown="$on_shutdown $guest" done sleep 1 + + set -- $guests + guestcount=$# + set -- $on_shutdown + shutdowncount=$# + if $check_timeout; then + if [ $(($timeout%5)) -eq 0 ]; then + printf "$format" $(($guestcount+$shutdowncount)) "$timeout"
Spaces around % and +
+ fi timeout=$(($timeout - 1)) if [ $timeout -le 0 ]; then eval_gettext "Timeout expired while shutting down domains"; echo RETVAL=1 return fi + else + slept=$(($slept + 1)) + if [ $(($slept%5)) -eq 0 ]; then + printf "$format" $(($guestcount+$shutdowncount))
And again.
+ fi fi + on_shutdown_prev=$on_shutdown on_shutdown=$(check_guests_shutdown "$uri" "$on_shutdown") print_guests_shutdown "$uri" "$on_shutdown_prev" "$on_shutdown" diff --git a/tools/libvirt-guests.service.in b/tools/libvirt-guests.service.in index db28f3f..0f0c41c 100644 --- a/tools/libvirt-guests.service.in +++ b/tools/libvirt-guests.service.in @@ -10,6 +10,7 @@ ExecStart=/etc/init.d/libvirt-guests start ExecStop=/etc/init.d/libvirt-guests stop Type=oneshot RemainAfterExit=yes +StandardOutput=journal+console
Overall, it looks like this patch is headed in the right direction. Did you also check that on F16, where we still used sysvinit, that the output there is still reasonable? -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org

Hi Eric, thanks for the in-depth review. Sorry for answering so late but I had some urgent stuff popping up here. I'll send an updated version of my patch in the next mail.
tools/libvirt-guests.service.in | 1 + 2 files changed, 51 insertions(+), 15 deletions(-) mode change 100644 => 100755 tools/libvirt-guests.init.sh
The mode change is spurious, and should not be part of this patch.
This was accidental. Removed.
- printf %s "$label" + printf '%s%-12s\n' "$label" "..."
Why are you printing trailing whitespace? You are left-justifying the 3-byte ..., which means you now always have 9 bytes of trailing space Also, the "..." doesn't technically need quoting, although I guess it doesn't hurt. Would it be worth folding the ... into the format string itself, as in:
printf '%s...\n' "$label"
If we were using \r, then I would understand the trailing space as a means of blanking out longer text printed on a previous loop, but you are abandoning \r.
done as you suggested. It was a leftover from the previous code with \r.
+ slept=$(($slept + 1)) + if [ $(($slept%5)) -eq 0 ]; then
Consistency argues that we should have spaces on both sides of '%'
done everywhere.
+ progress=$(run_virsh_c "$uri" domjobinfo "$guest" 2>/dev/null | \ + awk '/^Data processed:/{print $3, $4}') + if [ -n "$progress" ]; then + printf '%s%12s\n' "$label" "$progress" + else + printf '%s%-12s\n' "$label" "..." + fi
fi
Because you now print only every five seconds, you have lost out on the final printing when progress is non-empty if that happens on 4 of the 5 iterations. I think you want the logic to look more like:
slept=$(($slept + 1)) progress=$(...) if [ -n "$progress" ]; then printf ... label progress elif [ $(($slept % 5)) -eq 0 ]; then printf ... label... fi
for the final printing I have the "done" printf a few lines below. Or did I misunderstand you there? I think we should still print a line every 5 seconds even if we don't have any progress information to tell. The reason is that otherwise the user will miss what is going on when using systemd: a lot of stuff is happening in parallel at first, then only the suspend/shutdown of guests is left because it usually takes the longest time. The shutdown notice is lost between tons of other stuff.
+ format=$(eval_gettext "Waiting for guest %s to shut down, %4d seconds left\n") Why the padding for the seconds left? If timeout is 60, I think this looks awkward:
Waiting for guest foo to shut down, 60 seconds left
you are right. This padding stuff is a leftover from \r, there it was nice to have constant positions on the screen, here it doesn't matter. removed everywhere.
+ printf "$format" "$name"
This is new output that was not present beforehand. Is the intent that when there is no timeout, you want to show that the process is still alive waiting for the guest?
exactly, see above.
Overall, it looks like this patch is headed in the right direction.
very good.
Did you also check that on F16, where we still used sysvinit, that the output there is still reasonable?
I see, F16 uses systemd but libvirt is still accessed via sysvinit. I just set up a box with F16 and compiled the current libvirt rpm from F17 with my patch applied: it works, the shutdown messages are shown as soon as you switch off the quiet and rhgb kernel parameters. But they appear twice. I think this is a systemd issue because messages from other sysvinit-scripts appear twice on the console too. Kind regards, Gerd -- Address (better: trap) for people I really don't want to get mail from: jonas@cactusamerica.com

Since the move to systemd libvirt-guests doesn't output this progress information anymore. This patch brings back this feature. It is helpful to show the admin what the system is waiting for and what is left of the timeout (e.g. for calibrating the shutdown timing of a ups). Rewriting the current line with \r doesn't work anymore in the context of systemd. So always write new lines, but move to 5 second intervals to avoid flooding the console. This is version 2 of the patch and includes fixes as suggested by Eric Blake. --- tools/libvirt-guests.init.sh | 65 +++++++++++++++++++++++++++++++---------- tools/libvirt-guests.service.in | 1 + 2 files changed, 51 insertions(+), 15 deletions(-) diff --git a/tools/libvirt-guests.init.sh b/tools/libvirt-guests.init.sh index d5d42d6..99ef331 100644 --- a/tools/libvirt-guests.init.sh +++ b/tools/libvirt-guests.init.sh @@ -225,22 +225,27 @@ suspend_guest() name=$(guest_name "$uri" "$guest") label=$(eval_gettext "Suspending \$name: ") bypass= + slept=0 test "x$BYPASS_CACHE" = x0 || bypass=--bypass-cache - printf %s "$label" + printf '%s...\n' "$label" run_virsh "$uri" managedsave $bypass "$guest" >/dev/null & virsh_pid=$! while true; do sleep 1 kill -0 "$virsh_pid" >/dev/null 2>&1 || break - progress=$(run_virsh_c "$uri" domjobinfo "$guest" 2>/dev/null | \ - awk '/^Data processed:/{print $3, $4}') - if [ -n "$progress" ]; then - printf '\r%s%12s ' "$label" "$progress" - else - printf '\r%s%-12s ' "$label" "..." + + slept=$(($slept + 1)) + if [ $(($slept % 5)) -eq 0 ]; then + progress=$(run_virsh_c "$uri" domjobinfo "$guest" 2>/dev/null | \ + awk '/^Data processed:/{print $3, $4}') + if [ -n "$progress" ]; then + printf '%s%s\n' "$label" "$progress" + else + printf '%s%s\n' "$label" "..." + fi fi done - retval wait "$virsh_pid" && printf '\r%s%-12s\n' "$label" "$(gettext "done")" + retval wait "$virsh_pid" && printf '%s%s\n' "$label" "$(gettext "done")" } # shutdown_guest URI GUEST @@ -252,30 +257,41 @@ shutdown_guest() guest=$2 name=$(guest_name "$uri" "$guest") - label=$(eval_gettext "Shutting down \$name: ") - printf %s "$label" + eval_gettext "Starting shutdown on guest: \$name" + echo retval run_virsh "$uri" shutdown "$guest" >/dev/null || return timeout=$SHUTDOWN_TIMEOUT check_timeout=false if [ $timeout -gt 0 ]; then check_timeout=true + format=$(eval_gettext "Waiting for guest %s to shut down, %d seconds left\n") + else + slept=0 + format=$(eval_gettext "Waiting for guest %s to shut down\n") fi while ! $check_timeout || [ "$timeout" -gt 0 ]; do sleep 1 guest_is_on "$uri" "$guest" || return "$guest_running" || break + if $check_timeout; then - timeout=$((timeout - 1)) - printf '\r%s%-12d ' "$label" "$timeout" + if [ $(($timeout % 5)) -eq 0 ]; then + printf "$format" "$name" "$timeout" + fi + timeout=$(($timeout - 1)) + else + slept=$(($slept + 1)) + if [ $(($slept % 5)) -eq 0 ]; then + printf "$format" "$name" + fi fi done if guest_is_on "$uri" "$guest"; then if "$guest_running"; then - printf '\r%s%-12s\n' "$label" \ - "$(gettext "failed to shutdown in time")" + eval_gettext "Shutdown of guest \$name failed to complete in time." else - printf '\r%s%-12s\n' "$label" "$(gettext "done")" + eval_gettext "Shutdown of guest \$name complete." fi fi } @@ -356,6 +372,10 @@ shutdown_guests_parallel() timeout=$SHUTDOWN_TIMEOUT if [ $timeout -gt 0 ]; then check_timeout=true + format=$(eval_gettext "Waiting for %d guests to shut down, %d seconds left\n") + else + slept=0 + format=$(eval_gettext "Waiting for %d guests to shut down\n") fi while [ -n "$on_shutdown" ] || [ -n "$guests" ]; do while [ -n "$guests" ] && @@ -368,14 +388,29 @@ shutdown_guests_parallel() on_shutdown="$on_shutdown $guest" done sleep 1 + + set -- $guests + guestcount=$# + set -- $on_shutdown + shutdowncount=$# + if $check_timeout; then + if [ $(($timeout % 5)) -eq 0 ]; then + printf "$format" $(($guestcount + $shutdowncount)) "$timeout" + fi timeout=$(($timeout - 1)) if [ $timeout -le 0 ]; then eval_gettext "Timeout expired while shutting down domains"; echo RETVAL=1 return fi + else + slept=$(($slept + 1)) + if [ $(($slept % 5)) -eq 0 ]; then + printf "$format" $(($guestcount + $shutdowncount)) + fi fi + on_shutdown_prev=$on_shutdown on_shutdown=$(check_guests_shutdown "$uri" "$on_shutdown") print_guests_shutdown "$uri" "$on_shutdown_prev" "$on_shutdown" diff --git a/tools/libvirt-guests.service.in b/tools/libvirt-guests.service.in index db28f3f..0f0c41c 100644 --- a/tools/libvirt-guests.service.in +++ b/tools/libvirt-guests.service.in @@ -10,6 +10,7 @@ ExecStart=/etc/init.d/libvirt-guests start ExecStop=/etc/init.d/libvirt-guests stop Type=oneshot RemainAfterExit=yes +StandardOutput=journal+console [Install] WantedBy=multi-user.target -- 1.7.11.4

On 08/21/2012 09:03 AM, Gerd v. Egidy wrote:
Since the move to systemd libvirt-guests doesn't output this progress information anymore. This patch brings back this feature.
It is helpful to show the admin what the system is waiting for and what is left of the timeout (e.g. for calibrating the shutdown timing of a ups).
Rewriting the current line with \r doesn't work anymore in the context of systemd. So always write new lines, but move to 5 second intervals to avoid flooding the console.
This is version 2 of the patch and includes fixes as suggested by Eric Blake.
This last sentence can go...
---
after the ---, so that git doesn't store it in the log (it's informative for the email review, but not relevant to the long-term history). Beyond that, you met my comments on v1, and I didn't spot anything else, so: ACK and pushed. -- Eric Blake eblake@redhat.com +1-919-301-3266 Libvirt virtualization library http://libvirt.org

Hi Eric,
Beyond that, you met my comments on v1, and I didn't spot anything else, so:
ACK and pushed.
Thanks.
This is version 2 of the patch and includes fixes as suggested by Eric Blake. This last sentence can go...
---
after the ---, so that git doesn't store it in the log (it's informative for the email review, but not relevant to the long-term history).
ok, will move it below the --- next time. Kind regards, Gerd -- Address (better: trap) for people I really don't want to get mail from: jonas@cactusamerica.com
participants (2)
-
Eric Blake
-
Gerd v. Egidy