QubesOS / qubes-issues

The Qubes OS Project issue tracker
https://www.qubes-os.org/doc/issue-tracking/
536 stars 47 forks source link

SysRq Power Off xen timeouts break Emergency Shutdown #5887

Closed maltfield closed 1 year ago

maltfield commented 4 years ago

Qubes OS version

Qubes OS R4.0.3

Affected component(s) or functionality

A sysrq "Power Off" for "Emergency Shutdown Feature"

Brief summary

When the SysRq "Power Off" signal is sent in dom0, the hypervisor should shutdown almost immediately. This is critical for developing "Emergency Shutdowns"

Unfortunately, in Qubes OS, rather than dom0 yanking its own plug as it should, it gets stuck in xenbus_dev_shutdown timeout, delaying would-be-immediate shutdown to >1 minute -- enough time to cause serious harm to security-critical users of QubesOS when operating in dangerous situations.

To Reproduce

# run this on dom0 to trigger the "Power Off" signal to sysrq
# WARNING: running this command could cause data corruption or data loss!
echo o > /proc/sysrq-trigger

Expected behavior

The machine should power off in less than 1 second.

Actual behavior

It took my laptop 1 minute and 42 seconds to power off after executing the command listed above.

Screenshots

Here's what journalctl logged from the time I triggered the SysRq Power Off until it was off.


Jun 08 13:03:50 dom0 kernel: sysrq: SysRq : Power Off
Jun 08 13:03:50 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/console/6/0: Initialising != Connected, skipping
Jun 08 13:03:50 dom0 kernel: vbd vbd-6-51760: 5 starting transaction
Jun 08 13:03:50 dom0 kernel: vbd vbd-6-51760: failed to write error node for backend/vbd/6/51760 (5 starting transaction)
Jun 08 13:03:50 dom0 kernel: vbd vbd-6-51760: 5 starting transaction
Jun 08 13:03:50 dom0 kernel: vbd vbd-6-51760: failed to write error node for backend/vbd/6/51760 (5 starting transaction)
Jun 08 13:03:55 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/6/51760 timeout closing device
Jun 08 13:03:55 dom0 kernel: vbd vbd-6-51744: 5 starting transaction
Jun 08 13:03:55 dom0 kernel: vbd vbd-6-51744: failed to write error node for backend/vbd/6/51744 (5 starting transaction)
Jun 08 13:03:55 dom0 kernel: vbd vbd-6-51744: 5 starting transaction
Jun 08 13:03:55 dom0 kernel: vbd vbd-6-51744: failed to write error node for backend/vbd/6/51744 (5 starting transaction)
Jun 08 13:04:00 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/6/51744 timeout closing device
Jun 08 13:04:00 dom0 kernel: vbd vbd-6-51728: 5 starting transaction
Jun 08 13:04:00 dom0 kernel: vbd vbd-6-51728: failed to write error node for backend/vbd/6/51728 (5 starting transaction)
Jun 08 13:04:00 dom0 kernel: vbd vbd-6-51728: 5 starting transaction
Jun 08 13:04:00 dom0 kernel: vbd vbd-6-51728: failed to write error node for backend/vbd/6/51728 (5 starting transaction)
Jun 08 13:04:05 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/6/51728 timeout closing device
Jun 08 13:04:05 dom0 kernel: vbd vbd-6-51712: 5 starting transaction
Jun 08 13:04:05 dom0 kernel: vbd vbd-6-51712: failed to write error node for backend/vbd/6/51712 (5 starting transaction)
Jun 08 13:04:05 dom0 kernel: vbd vbd-6-51712: 5 starting transaction
Jun 08 13:04:05 dom0 kernel: vbd vbd-6-51712: failed to write error node for backend/vbd/6/51712 (5 starting transaction)
Jun 08 13:04:10 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/6/51712 timeout closing device
Jun 08 13:04:10 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/console/5/0: Initialising != Connected, skipping
Jun 08 13:04:10 dom0 kernel: vbd vbd-5-51760: 5 starting transaction
Jun 08 13:04:10 dom0 kernel: vbd vbd-5-51760: failed to write error node for backend/vbd/5/51760 (5 starting transaction)
Jun 08 13:04:10 dom0 kernel: vbd vbd-5-51760: 5 starting transaction
Jun 08 13:04:10 dom0 kernel: vbd vbd-5-51760: failed to write error node for backend/vbd/5/51760 (5 starting transaction)
Jun 08 13:04:15 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/5/51760 timeout closing device
Jun 08 13:04:15 dom0 kernel: vbd vbd-5-51744: 5 starting transaction
Jun 08 13:04:15 dom0 kernel: vbd vbd-5-51744: failed to write error node for backend/vbd/5/51744 (5 starting transaction)
Jun 08 13:04:15 dom0 kernel: vbd vbd-5-51744: 5 starting transaction
Jun 08 13:04:15 dom0 kernel: vbd vbd-5-51744: failed to write error node for backend/vbd/5/51744 (5 starting transaction)
Jun 08 13:04:21 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/5/51744 timeout closing device
Jun 08 13:04:21 dom0 kernel: vbd vbd-5-51728: 5 starting transaction
Jun 08 13:04:21 dom0 kernel: vbd vbd-5-51728: failed to write error node for backend/vbd/5/51728 (5 starting transaction)
Jun 08 13:04:21 dom0 kernel: vbd vbd-5-51728: 5 starting transaction
Jun 08 13:04:21 dom0 kernel: vbd vbd-5-51728: failed to write error node for backend/vbd/5/51728 (5 starting transaction)
Jun 08 13:04:26 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/5/51728 timeout closing device
Jun 08 13:04:26 dom0 kernel: vbd vbd-5-51712: 5 starting transaction
Jun 08 13:04:26 dom0 kernel: vbd vbd-5-51712: failed to write error node for backend/vbd/5/51712 (5 starting transaction)
Jun 08 13:04:26 dom0 kernel: vbd vbd-5-51712: 5 starting transaction
Jun 08 13:04:26 dom0 kernel: vbd vbd-5-51712: failed to write error node for backend/vbd/5/51712 (5 starting transaction)
Jun 08 13:04:31 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/5/51712 timeout closing device
Jun 08 13:04:31 dom0 kernel: xen-pciback pci-4-0: 5 starting transaction
Jun 08 13:04:31 dom0 kernel: xen-pciback pci-4-0: failed to write error node for backend/pci/4/0 (5 starting transaction)
Jun 08 13:04:31 dom0 kernel: xen-pciback pci-4-0: 5 starting transaction
Jun 08 13:04:31 dom0 kernel: xen-pciback pci-4-0: failed to write error node for backend/pci/4/0 (5 starting transaction)
Jun 08 13:04:36 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/pci/4/0 timeout closing device
Jun 08 13:04:36 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/console/4/0: Initialising != Connected, skipping
Jun 08 13:04:36 dom0 kernel: vbd vbd-4-51760: 5 starting transaction
Jun 08 13:04:36 dom0 kernel: vbd vbd-4-51760: failed to write error node for backend/vbd/4/51760 (5 starting transaction)
Jun 08 13:04:36 dom0 kernel: vbd vbd-4-51760: 5 starting transaction
Jun 08 13:04:36 dom0 kernel: vbd vbd-4-51760: failed to write error node for backend/vbd/4/51760 (5 starting transaction)
Jun 08 13:04:41 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/4/51760 timeout closing device
Jun 08 13:04:41 dom0 kernel: vbd vbd-4-51744: 5 starting transaction
Jun 08 13:04:41 dom0 kernel: vbd vbd-4-51744: failed to write error node for backend/vbd/4/51744 (5 starting transaction)
Jun 08 13:04:41 dom0 kernel: vbd vbd-4-51744: 5 starting transaction
Jun 08 13:04:41 dom0 kernel: vbd vbd-4-51744: failed to write error node for backend/vbd/4/51744 (5 starting transaction)
Jun 08 13:04:46 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/4/51744 timeout closing device
Jun 08 13:04:46 dom0 kernel: vbd vbd-4-51728: 5 starting transaction
Jun 08 13:04:46 dom0 kernel: vbd vbd-4-51728: failed to write error node for backend/vbd/4/51728 (5 starting transaction)
Jun 08 13:04:46 dom0 kernel: vbd vbd-4-51728: 5 starting transaction
Jun 08 13:04:46 dom0 kernel: vbd vbd-4-51728: failed to write error node for backend/vbd/4/51728 (5 starting transaction)
Jun 08 13:04:51 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/4/51728 timeout closing device
Jun 08 13:04:51 dom0 kernel: vbd vbd-4-51712: 5 starting transaction
Jun 08 13:04:51 dom0 kernel: vbd vbd-4-51712: failed to write error node for backend/vbd/4/51712 (5 starting transaction)
Jun 08 13:04:51 dom0 kernel: vbd vbd-4-51712: 5 starting transaction
Jun 08 13:04:51 dom0 kernel: vbd vbd-4-51712: failed to write error node for backend/vbd/4/51712 (5 starting transaction)
Jun 08 13:04:53 dom0 qmemman.daemon.algo[1668]: balance_when_enough_memory(xen_free_memory=7603037, total_mem_pref=2312529587.2000003, total_available_memory=4911857206.8)
Jun 08 13:04:53 dom0 qmemman.daemon.algo[1668]: left_memory=236237963 acceptors_count=2
Jun 08 13:04:56 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/4/51712 timeout closing device
Jun 08 13:04:56 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/console/3/0: Initialising != Connected, skipping
Jun 08 13:04:56 dom0 kernel: vbd vbd-3-51760: 5 starting transaction
Jun 08 13:04:56 dom0 kernel: vbd vbd-3-51760: failed to write error node for backend/vbd/3/51760 (5 starting transaction)
Jun 08 13:04:56 dom0 kernel: vbd vbd-3-51760: 5 starting transaction
Jun 08 13:04:56 dom0 kernel: vbd vbd-3-51760: failed to write error node for backend/vbd/3/51760 (5 starting transaction)
Jun 08 13:05:01 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/3/51760 timeout closing device
Jun 08 13:05:01 dom0 kernel: vbd vbd-3-51744: 5 starting transaction
Jun 08 13:05:01 dom0 kernel: vbd vbd-3-51744: failed to write error node for backend/vbd/3/51744 (5 starting transaction)
Jun 08 13:05:01 dom0 kernel: vbd vbd-3-51744: 5 starting transaction
Jun 08 13:05:01 dom0 kernel: vbd vbd-3-51744: failed to write error node for backend/vbd/3/51744 (5 starting transaction)
Jun 08 13:05:07 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/3/51744 timeout closing device
Jun 08 13:05:07 dom0 kernel: vbd vbd-3-51728: 5 starting transaction
Jun 08 13:05:07 dom0 kernel: vbd vbd-3-51728: failed to write error node for backend/vbd/3/51728 (5 starting transaction)
Jun 08 13:05:07 dom0 kernel: vbd vbd-3-51728: 5 starting transaction
Jun 08 13:05:07 dom0 kernel: vbd vbd-3-51728: failed to write error node for backend/vbd/3/51728 (5 starting transaction)
Jun 08 13:05:12 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/3/51728 timeout closing device
Jun 08 13:05:12 dom0 kernel: vbd vbd-3-51712: 5 starting transaction
Jun 08 13:05:12 dom0 kernel: vbd vbd-3-51712: failed to write error node for backend/vbd/3/51712 (5 starting transaction)
Jun 08 13:05:12 dom0 kernel: vbd vbd-3-51712: 5 starting transaction
Jun 08 13:05:12 dom0 kernel: vbd vbd-3-51712: failed to write error node for backend/vbd/3/51712 (5 starting transaction)
Jun 08 13:05:17 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/3/51712 timeout closing device
Jun 08 13:05:17 dom0 kernel: xen-pciback pci-2-0: 5 starting transaction
Jun 08 13:05:17 dom0 kernel: xen-pciback pci-2-0: failed to write error node for backend/pci/2/0 (5 starting transaction)
Jun 08 13:05:17 dom0 kernel: xen-pciback pci-2-0: 5 starting transaction
Jun 08 13:05:17 dom0 kernel: xen-pciback pci-2-0: failed to write error node for backend/pci/2/0 (5 starting transaction)
Jun 08 13:05:22 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/pci/2/0 timeout closing device
Jun 08 13:05:22 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/console/2/0: Initialising != Connected, skipping
Jun 08 13:05:22 dom0 kernel: vbd vbd-2-51760: 5 starting transaction
Jun 08 13:05:22 dom0 kernel: vbd vbd-2-51760: failed to write error node for backend/vbd/2/51760 (5 starting transaction)
Jun 08 13:05:22 dom0 kernel: vbd vbd-2-51760: 5 starting transaction
Jun 08 13:05:22 dom0 kernel: vbd vbd-2-51760: failed to write error node for backend/vbd/2/51760 (5 starting transaction)
Jun 08 13:05:27 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/2/51760 timeout closing device
Jun 08 13:05:27 dom0 kernel: vbd vbd-2-51744: 5 starting transaction
Jun 08 13:05:27 dom0 kernel: vbd vbd-2-51744: failed to write error node for backend/vbd/2/51744 (5 starting transaction)
Jun 08 13:05:27 dom0 kernel: vbd vbd-2-51744: 5 starting transaction
Jun 08 13:05:27 dom0 kernel: vbd vbd-2-51744: failed to write error node for backend/vbd/2/51744 (5 starting transaction)
Jun 08 13:05:32 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/2/51744 timeout closing device
Jun 08 13:05:32 dom0 kernel: vbd vbd-2-51728: 5 starting transaction
Jun 08 13:05:32 dom0 kernel: vbd vbd-2-51728: failed to write error node for backend/vbd/2/51728 (5 starting transaction)
Jun 08 13:05:32 dom0 kernel: vbd vbd-2-51728: 5 starting transaction
Jun 08 13:05:32 dom0 kernel: vbd vbd-2-51728: failed to write error node for backend/vbd/2/51728 (5 starting transaction)
-- Reboot --

Additional context

@marmarek has already documented this issue here:

See also:

brendanhoar commented 4 years ago

Possibly bypass dom0 and go straight to xen? e.g. execute

xl debug-keys R # will reboot xen.
maltfield commented 4 years ago

@brendanhoar Thanks for the suggestion!

Using xl debug-keys R successfully reboots the system immediately. However, a power off is much safer than a reboot for the purposes of a panic situation. It's important to cut power to the RAM (where the master LUKS key is stored) ASAP.

Note that using xl debug-keys R is no different than sending the SysRq Reboot signal, which--unlike the SysRq Power Off signal--has an immediate effect when executed in dom0:

sudo bash -c 'echo b > /proc/sysrq-trigger'

It wasn't obvious, but I found that you can get a list of all the possible Xen "debug keys" by sending it the "h" key and checking xen's dmesg.

[root@dom0 ~]# xl debug-keys h
[root@dom0 ~]# xl dmesg | tail -n 31
(XEN) 'h' pressed -> showing installed handlers
(XEN)  key '%' (ascii '25') => trap to xendbg
(XEN)  key '*' (ascii '2a') => print all diagnostics
(XEN)  key '0' (ascii '30') => dump Dom0 registers
(XEN)  key 'A' (ascii '41') => toggle alternative key handling
(XEN)  key 'D' (ascii '44') => dump VT-x EPT tables
(XEN)  key 'H' (ascii '48') => dump heap info
(XEN)  key 'I' (ascii '49') => dump HVM irq info
(XEN)  key 'M' (ascii '4d') => dump MSI state
(XEN)  key 'N' (ascii '4e') => trigger an NMI
(XEN)  key 'Q' (ascii '51') => dump PCI devices
(XEN)  key 'R' (ascii '52') => reboot machine
(XEN)  key 'V' (ascii '56') => dump iommu info
(XEN)  key 'a' (ascii '61') => dump timer queues
(XEN)  key 'c' (ascii '63') => dump ACPI Cx structures
(XEN)  key 'd' (ascii '64') => dump registers
(XEN)  key 'e' (ascii '65') => dump evtchn info
(XEN)  key 'g' (ascii '67') => print grant table usage
(XEN)  key 'h' (ascii '68') => show this message
(XEN)  key 'i' (ascii '69') => dump interrupt bindings
(XEN)  key 'm' (ascii '6d') => memory info
(XEN)  key 'n' (ascii '6e') => NMI statistics
(XEN)  key 'o' (ascii '6f') => dump iommu p2m table
(XEN)  key 'q' (ascii '71') => dump domain (and guest debug) info
(XEN)  key 'r' (ascii '72') => dump run queues
(XEN)  key 's' (ascii '73') => dump softtsc stats
(XEN)  key 't' (ascii '74') => display multi-cpu clock info
(XEN)  key 'u' (ascii '75') => dump NUMA info
(XEN)  key 'v' (ascii '76') => dump VT-x VMCSs
(XEN)  key 'w' (ascii '77') => synchronously dump console ring buffer (dmesg)
(XEN)  key 'z' (ascii '7a') => dump IOAPIC info

Unfortunately I don't see an option for powering off (as opposed to rebooting) the xen hypervisor using a xl debug-keys.

Is there any other way to tell the hypervisor to shutdown immediately?

maltfield commented 4 years ago

I was successfully able to reduce the shutdown time to 20-25 seconds (down from 1 minute 42 seconds above) by preceeding the SysRq Power Off signal with a qvm-kill command

This is executed in dom0:

[user@dom0 ~]$ sudo bash -c 'qvm-kill --all; echo o > /proc/sysrq-triger'

This is an improvement, but I think it's very important that QubesOS can shutdown faster in an emergency situation.

Is there any other way to shutdown QubesOS in less than 2 seconds?

brendanhoar commented 4 years ago

Does the old fashioned way work in dom0?

sudo /bin/poweroff --poweroff --no-sync --no-wall --force

B

PS - likely to corrupt your LVM/filesystems, but that's what a fast poweroff almost always does. You can try it without the no-sync, but not sure that'll meet the requirements.

maltfield commented 4 years ago

Does the old fashioned way work in dom0?

Unfortunately, a test of the following command using poweroff run as root on dom0 took 2 minutes and 37 seconds from the time I executed it to the time my machine was off.

/sbin/poweroff --poweroff --no-sync --no-wall --force

So far 25 seconds with qvm-kill ... sysrq-trigger is the best, then sysrq-trigger at 1 minuite 42 seconds, then poweroff at 2 minutes 37 seconds.

PS - likely to corrupt your LVM/filesystems, but that's what a fast poweroff almost always does.

That's an expected risk. Better to corrupt the fs than have the user's unencrypted disk (or RAM containing the master decryption key) fall into Mallory's hands when attempting to do an emergency shutdown.

fwiw I've only been testing on a burner, but I haven't encountered any issues yet..

maltfield commented 4 years ago

So the main reason it's so critical to cut power ASAP is to power-down the RAM. There's a lot of important secrets stored in RAM, but I think the most critical one is the master LUKS key.

By executing the following script as root in dom0, I found that I could execute luksSuspend to wipe the master LUKS keys from RAM in <10 seconds, even though the time from execution to poweroff is 2-3 minutes.

#!/usr/bin/bash

############
# SETTINGS #
############

WHICH="/usr/bin/which"
CRYPTSETUP=`${WHICH} --skip-alias cryptsetup` || echo "ERROR: Unable to find cryptsetup"
LS=`${WHICH} --skip-alias ls` || echo "ERROR: Unable to find ls"
CP=`${WHICH} --skip-alias cp` || echo "ERROR: Unable to find cp"
MV=`${WHICH} --skip-alias mv` || echo "ERROR: Unable to find mv"
LN=`${WHICH} --skip-alias ln` || echo "ERROR: Unable to find ln"
MKDIR=`${WHICH} --skip-alias mkdir` || echo "ERROR: Unable to find mkdir"
MOUNT=`${WHICH} --skip-alias mount` || echo "ERROR: Unable to find mount"
CAT=`${WHICH} --skip-alias cat` || echo "ERROR: Unable to find cat"
GREP=`${WHICH} --skip-alias grep` || echo "ERROR: Unable to find grep"
ECHO=`${WHICH} --skip-alias echo` || echo "ERROR: Unable to find echo"
SUDO=`${WHICH} --skip-alias sudo` || echo "ERROR: Unable to find sudo"
CHMOD=`${WHICH} --skip-alias chmod` || echo "ERROR: Unable to find chmod"
BASH=`${WHICH} --skip-alias bash` || echo "ERROR: Unable to find bash"
SLEEP=`${WHICH} --skip-alias sleep` || echo "ERROR: Unable to find sleep"
POWEROFF=`${WHICH} --skip-alias poweroff` || echo "ERROR: Unable to find poweroff"
CHROOT=`${WHICH} --skip-alias chroot` || echo "ERROR: Unable to find chroot"
SYNC=`${WHICH} --skip-alias sync` || echo "ERROR: Unable to find sync"
LDD=`${WHICH} --skip-alias ldd` || echo "ERROR: Unable to find ldd"

CHROOT_PATH='/dev/shm/chroot'
DIE_SCRIPT='/usr/bin/die.sh'

#################
# CREATE CHROOT #
#################

# we have to create a ramfs chroot with cryptsetup, poweroff, and a few other
# basic depends for after we luksSuspend our rootfs from under our feet

${MKDIR} -p "${CHROOT_PATH}/proc"
${MKDIR} -p "${CHROOT_PATH}/sys"
${MKDIR} -p "${CHROOT_PATH}/dev"
${MKDIR} -p "${CHROOT_PATH}/pts"
${MKDIR} -p "${CHROOT_PATH}/bin"
${MKDIR} -p "${CHROOT_PATH}/lib64"
${MKDIR} -p "${CHROOT_PATH}/lib/systemd"
${MKDIR} -p "${CHROOT_PATH}/usr/sbin"
${MKDIR} -p "${CHROOT_PATH}/usr/bin"

${MOUNT} -t proc none "${CHROOT_PATH}/proc"
${MOUNT} -t sysfs none "${CHROOT_PATH}/sys"
${MOUNT} -o bind /dev "${CHROOT_PATH}/dev"
${MOUNT} -o bind /dev/pts "${CHROOT_PATH}/dev/pts"

# copy-in our binaries and their depends
binaries="${BASH} ${CRYPTSETUP} ${ECHO} ${LS} ${SLEEP} ${SYNC} ${POWEROFF}"
for binary in ${binaries}; do
  ${CP} -vf "${binary}" "${CHROOT_PATH}/${binary}"
  libs="$( ${LDD} "${binary}" | ${GREP} -Eo '/lib.*\.so(\.[0-9]*)*' )"
  for lib in ${libs}; do
    ${CP} -vf "${lib}" "${CHROOT_PATH}/${lib}"
  done
done

# fix around some libs and symlink issues
${MV} "${CHROOT_PATH}/lib" "${CHROOT_PATH}/usr/lib"
${LN} -s "usr/lib" "${CHROOT_PATH}/lib"

${CAT} << EOF > "${CHROOT_PATH}/${DIE_SCRIPT}"
#!${BASH}

#################################
# WIPE DECRYPTION KEYS FROM RAM #
#################################

# suspend each currently-decrypted LUKS volume
${ECHO} "INFO: removing decryption keys from memory"
waits=''
for device in \$( ${LS} -1 "/dev/mapper" ); do

  ${ECHO} -e "\t\${device}";
  ${CRYPTSETUP} luksSuspend "\${device}" &

  waits="${waits} $!"

done
${ECHO} "INFO: finished luksSuspend calls"

wait ${waits}
${ECHO} "INFO: finished waiting"

# clear page caches in memory (again)
sync; echo 3 > /proc/sys/vm/drop_caches
${ECHO} "INFO: finished syncing"

#############################
# (IMMEDIATE) HARD SHUTDOWN #
#############################
${ECHO} "INFO: Powering Down"

# do whatever works; this is important.
${ECHO} o > /proc/sysrq-trigger &
${SLEEP} 1
${POWEROFF} --poweroff --no-sync --no-wall --force &
EOF
${CHMOD} +x "${CHROOT_PATH}/${DIE_SCRIPT}"

# finally, enter the chroot and call the above die.sh script inside it
${CHROOT} "${CHROOT_PATH}" "${DIE_SCRIPT}"

Note that a ramfs chroot is required to store some binaries like cryptsetup and poweroff for the end of the script so it doesn't get locked-up after luksSuspending the rootfs where those binaries live.

How would the QubesOS devs feel about making a dom0:/etc/qubes-rpc/emergencyShutdown service out of the script above? It could be further be improved by shredding the RAM before shutdown, similar to TAILS.

brendanhoar commented 4 years ago

Does the old fashioned way work in dom0?

Unfortunately, a test of the following command using poweroff run as root on dom0 took 2 minutes and 37 seconds from the time I executed it to the time my machine was off.

/sbin/poweroff --poweroff --no-sync --no-wall --force

Huh. On a fresh install of 4.1 (20200528), installed tonight on a lenovo thinkpad P52, updated w/ current-testing and kernel-latest, it took about 5s or so to shut off after invoking that command (well the “sudo poweroff -p -n -f“ variant) from dom0 with only sys-net and sys-firewall running.

Performance might relate to acpi features on the host?

B

maltfield commented 4 years ago

Does the old fashioned way work in dom0?

Unfortunately, a test of the following command using poweroff run as root on dom0 took 2 minutes and 37 seconds from the time I executed it to the time my machine was off.

Huh. On a fresh install of 4.1 (20200528), installed tonight on a lenovo thinkpad P52, updated w/ current-testing and kernel-latest, it took about 5s or so to shut off after invoking that command

I've been testing on a fresh install of 4.0.3 without updates running on an Asus UX305. Do you have sys-net as your USB Qube or are you not using one at all? It definitely shuts-down faster with less Qubes running.

fwiw, I've been sure to start firefox in the personal Qube before running my poweroff timer tests to at least have some minimal realistic baseline (with sys-net, sys-firewall, sys-usb, and personal running--but, in practice, I usually have ~10 Qubes open day-to-day).

Performance might relate to acpi features on the host?

I'm assuming that all those arguments to poweroff would bypass any acpi-related features, no? Also, it's worth repeating that on this hardware, the sysrq reboot trigger is immediately effective.

andrewdavidwong commented 4 years ago

How would the QubesOS devs feel about making a dom0:/etc/qubes-rpc/emergencyShutdown service out of the script above? It could be further be improved by shredding the RAM before shutdown, similar to TAILS.

This seems like an enhancement request separate from the original bug report.

@marmarek, what do you think?

andrewdavidwong commented 4 years ago

Huh. On a fresh install of 4.1 (20200528), installed tonight on a lenovo thinkpad P52, updated w/ current-testing and kernel-latest, it took about 5s or so to shut off after invoking that command

I've been testing on a fresh install of 4.0.3 without updates running on an Asus UX305. Do you have sys-net as your USB Qube or are you not using one at all? It definitely shuts-down faster with less Qubes running.

My shutdowns also seem very quick, but I shut down all of my running VMs (except for dom0) before shutting down dom0. Have you tried something like this?

#!/bin/bash
qvm-shutdown --wait --timeout 0 --all
shutdown now
marmarek commented 4 years ago

How would the QubesOS devs feel about making a dom0:/etc/qubes-rpc/emergencyShutdown service out of the script above?

Why qrexec service? Do you envision making it callable from some VM?

As to the script itself, you can re-use initramfs. In fact, something similar is already used during normal shutdown - see /usr/lib/dracut/dracut-initramfs-restore called from dracut-shutdown.service.

maltfield commented 4 years ago

I captured the journalctl output from dom0 after initiating the following command as root in dom0:

/sbin/poweroff --poweroff --no-sync --no-wall --force

The output spans 2 minutes and 2 seconds. It looks like it's stuck on the same xenbus_dev_shutdown ... timeout issues that are referenced at top of this issue.

Jun 11 08:46:21 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/console/7/0: Initialising != Connected, skipping
Jun 11 08:46:21 dom0 kernel: vbd vbd-7-51760: 5 starting transaction
Jun 11 08:46:21 dom0 kernel: vbd vbd-7-51760: failed to write error node for backend/vbd/7/51760 (5 starting transaction)
Jun 11 08:46:21 dom0 kernel: vbd vbd-7-51760: 5 starting transaction
Jun 11 08:46:21 dom0 kernel: vbd vbd-7-51760: failed to write error node for backend/vbd/7/51760 (5 starting transaction)
Jun 11 08:46:25 dom0 qmemman.daemon.algo[1650]: balance_when_enough_memory(xen_free_memory=7188309, total_mem_pref=3191212108.8, total_available_memory=3997063024.2)
Jun 11 08:46:25 dom0 qmemman.systemstate[1650]: stat: dom '0' act=3374262100 pref=1528713702.4 last_target=3374262100
Jun 11 08:46:25 dom0 qmemman.systemstate[1650]: stat: dom '5' act=912224259 pref=413284352.0 last_target=912224259
Jun 11 08:46:25 dom0 qmemman.systemstate[1650]: stat: dom '6' act=904902019 pref=409967001.6 last_target=904902019
Jun 11 08:46:25 dom0 qmemman.systemstate[1650]: stat: dom '7' act=1989698446 pref=839247052.8000001 last_target=1989698446
Jun 11 08:46:25 dom0 qmemman.systemstate[1650]: stat: xenfree=59617109 memset_reqs=[('7', 1888531935), ('0', 3440017618), ('6', 922536185), ('5', 930001117)]
Jun 11 08:46:25 dom0 qmemman.systemstate[1650]: mem-set domain 7 to 1888531935
Jun 11 08:46:25 dom0 qmemman.systemstate[1650]: mem-set domain 0 to 3440017618
Jun 11 08:46:25 dom0 qmemman.systemstate[1650]: mem-set domain 6 to 922536185
Jun 11 08:46:25 dom0 qmemman.systemstate[1650]: mem-set domain 5 to 930001117
Jun 11 08:46:26 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/7/51760 timeout closing device
Jun 11 08:46:26 dom0 kernel: vbd vbd-7-51744: 5 starting transaction
Jun 11 08:46:26 dom0 kernel: vbd vbd-7-51744: failed to write error node for backend/vbd/7/51744 (5 starting transaction)
Jun 11 08:46:26 dom0 kernel: vbd vbd-7-51744: 5 starting transaction
Jun 11 08:46:26 dom0 kernel: vbd vbd-7-51744: failed to write error node for backend/vbd/7/51744 (5 starting transaction)
Jun 11 08:46:31 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/7/51744 timeout closing device
Jun 11 08:46:31 dom0 kernel: vbd vbd-7-51728: 5 starting transaction
Jun 11 08:46:31 dom0 kernel: vbd vbd-7-51728: failed to write error node for backend/vbd/7/51728 (5 starting transaction)
Jun 11 08:46:31 dom0 kernel: vbd vbd-7-51728: 5 starting transaction
Jun 11 08:46:31 dom0 kernel: vbd vbd-7-51728: failed to write error node for backend/vbd/7/51728 (5 starting transaction)
Jun 11 08:46:36 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/7/51728 timeout closing device
Jun 11 08:46:36 dom0 kernel: vbd vbd-7-51712: 5 starting transaction
Jun 11 08:46:36 dom0 kernel: vbd vbd-7-51712: failed to write error node for backend/vbd/7/51712 (5 starting transaction)
Jun 11 08:46:36 dom0 kernel: vbd vbd-7-51712: 5 starting transaction
Jun 11 08:46:36 dom0 kernel: vbd vbd-7-51712: failed to write error node for backend/vbd/7/51712 (5 starting transaction)
Jun 11 08:46:41 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/7/51712 timeout closing device
Jun 11 08:46:41 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/console/6/0: Initialising != Connected, skipping
Jun 11 08:46:41 dom0 kernel: vbd vbd-6-51760: 5 starting transaction
Jun 11 08:46:41 dom0 kernel: vbd vbd-6-51760: failed to write error node for backend/vbd/6/51760 (5 starting transaction)
Jun 11 08:46:41 dom0 kernel: vbd vbd-6-51760: 5 starting transaction
Jun 11 08:46:41 dom0 kernel: vbd vbd-6-51760: failed to write error node for backend/vbd/6/51760 (5 starting transaction)
Jun 11 08:46:47 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/6/51760 timeout closing device
Jun 11 08:46:47 dom0 kernel: vbd vbd-6-51744: 5 starting transaction
Jun 11 08:46:47 dom0 kernel: vbd vbd-6-51744: failed to write error node for backend/vbd/6/51744 (5 starting transaction)
Jun 11 08:46:47 dom0 kernel: vbd vbd-6-51744: 5 starting transaction
Jun 11 08:46:47 dom0 kernel: vbd vbd-6-51744: failed to write error node for backend/vbd/6/51744 (5 starting transaction)
Jun 11 08:46:52 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/6/51744 timeout closing device
Jun 11 08:46:52 dom0 kernel: vbd vbd-6-51728: 5 starting transaction
Jun 11 08:46:52 dom0 kernel: vbd vbd-6-51728: failed to write error node for backend/vbd/6/51728 (5 starting transaction)
Jun 11 08:46:52 dom0 kernel: vbd vbd-6-51728: 5 starting transaction
Jun 11 08:46:52 dom0 kernel: vbd vbd-6-51728: failed to write error node for backend/vbd/6/51728 (5 starting transaction)
Jun 11 08:46:57 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/6/51728 timeout closing device
Jun 11 08:46:57 dom0 kernel: vbd vbd-6-51712: 5 starting transaction
Jun 11 08:46:57 dom0 kernel: vbd vbd-6-51712: failed to write error node for backend/vbd/6/51712 (5 starting transaction)
Jun 11 08:46:57 dom0 kernel: vbd vbd-6-51712: 5 starting transaction
Jun 11 08:46:57 dom0 kernel: vbd vbd-6-51712: failed to write error node for backend/vbd/6/51712 (5 starting transaction)
Jun 11 08:47:02 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/6/51712 timeout closing device
Jun 11 08:47:02 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/console/5/0: Initialising != Connected, skipping
Jun 11 08:47:02 dom0 kernel: vbd vbd-5-51760: 5 starting transaction
Jun 11 08:47:02 dom0 kernel: vbd vbd-5-51760: failed to write error node for backend/vbd/5/51760 (5 starting transaction)
Jun 11 08:47:02 dom0 kernel: vbd vbd-5-51760: 5 starting transaction
Jun 11 08:47:02 dom0 kernel: vbd vbd-5-51760: failed to write error node for backend/vbd/5/51760 (5 starting transaction)
Jun 11 08:47:07 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/5/51760 timeout closing device
Jun 11 08:47:07 dom0 kernel: vbd vbd-5-51744: 5 starting transaction
Jun 11 08:47:07 dom0 kernel: vbd vbd-5-51744: failed to write error node for backend/vbd/5/51744 (5 starting transaction)
Jun 11 08:47:07 dom0 kernel: vbd vbd-5-51744: 5 starting transaction
Jun 11 08:47:07 dom0 kernel: vbd vbd-5-51744: failed to write error node for backend/vbd/5/51744 (5 starting transaction)
Jun 11 08:47:12 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/5/51744 timeout closing device
Jun 11 08:47:12 dom0 kernel: vbd vbd-5-51728: 5 starting transaction
Jun 11 08:47:12 dom0 kernel: vbd vbd-5-51728: failed to write error node for backend/vbd/5/51728 (5 starting transaction)
Jun 11 08:47:12 dom0 kernel: vbd vbd-5-51728: 5 starting transaction
Jun 11 08:47:12 dom0 kernel: vbd vbd-5-51728: failed to write error node for backend/vbd/5/51728 (5 starting transaction)
Jun 11 08:47:13 dom0 qrexec[4132]: qubes.NotifyUpdates: sys-whonix -&gt; dom0: allowed to dom0
Jun 11 08:47:14 dom0 qmemman.daemon.algo[1650]: balance_when_enough_memory(xen_free_memory=6678695, total_mem_pref=3231590067.2000003, total_available_memory=3956175482.7999997)
Jun 11 08:47:17 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/5/51728 timeout closing device
Jun 11 08:47:17 dom0 kernel: vbd vbd-5-51712: 5 starting transaction
Jun 11 08:47:17 dom0 kernel: vbd vbd-5-51712: failed to write error node for backend/vbd/5/51712 (5 starting transaction)
Jun 11 08:47:17 dom0 kernel: vbd vbd-5-51712: 5 starting transaction
Jun 11 08:47:17 dom0 kernel: vbd vbd-5-51712: failed to write error node for backend/vbd/5/51712 (5 starting transaction)
Jun 11 08:47:22 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/5/51712 timeout closing device
Jun 11 08:47:22 dom0 kernel: xen-pciback pci-4-0: 5 starting transaction
Jun 11 08:47:22 dom0 kernel: xen-pciback pci-4-0: failed to write error node for backend/pci/4/0 (5 starting transaction)
Jun 11 08:47:22 dom0 kernel: xen-pciback pci-4-0: 5 starting transaction
Jun 11 08:47:22 dom0 kernel: xen-pciback pci-4-0: failed to write error node for backend/pci/4/0 (5 starting transaction)
Jun 11 08:47:27 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/pci/4/0 timeout closing device
Jun 11 08:47:27 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/console/4/0: Initialising != Connected, skipping
Jun 11 08:47:27 dom0 kernel: vbd vbd-4-51760: 5 starting transaction
Jun 11 08:47:27 dom0 kernel: vbd vbd-4-51760: failed to write error node for backend/vbd/4/51760 (5 starting transaction)
Jun 11 08:47:27 dom0 kernel: vbd vbd-4-51760: 5 starting transaction
Jun 11 08:47:27 dom0 kernel: vbd vbd-4-51760: failed to write error node for backend/vbd/4/51760 (5 starting transaction)
Jun 11 08:47:33 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/4/51760 timeout closing device
Jun 11 08:47:33 dom0 kernel: vbd vbd-4-51744: 5 starting transaction
Jun 11 08:47:33 dom0 kernel: vbd vbd-4-51744: failed to write error node for backend/vbd/4/51744 (5 starting transaction)
Jun 11 08:47:33 dom0 kernel: vbd vbd-4-51744: 5 starting transaction
Jun 11 08:47:33 dom0 kernel: vbd vbd-4-51744: failed to write error node for backend/vbd/4/51744 (5 starting transaction)
Jun 11 08:47:38 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/4/51744 timeout closing device
Jun 11 08:47:38 dom0 kernel: vbd vbd-4-51728: 5 starting transaction
Jun 11 08:47:38 dom0 kernel: vbd vbd-4-51728: failed to write error node for backend/vbd/4/51728 (5 starting transaction)
Jun 11 08:47:38 dom0 kernel: vbd vbd-4-51728: 5 starting transaction
Jun 11 08:47:38 dom0 kernel: vbd vbd-4-51728: failed to write error node for backend/vbd/4/51728 (5 starting transaction)
Jun 11 08:47:43 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/4/51728 timeout closing device
Jun 11 08:47:43 dom0 kernel: vbd vbd-4-51712: 5 starting transaction
Jun 11 08:47:43 dom0 kernel: vbd vbd-4-51712: failed to write error node for backend/vbd/4/51712 (5 starting transaction)
Jun 11 08:47:43 dom0 kernel: vbd vbd-4-51712: 5 starting transaction
Jun 11 08:47:43 dom0 kernel: vbd vbd-4-51712: failed to write error node for backend/vbd/4/51712 (5 starting transaction)
Jun 11 08:47:44 dom0 qmemman.daemon.algo[1650]: balance_when_enough_memory(xen_free_memory=6678695, total_mem_pref=3271818931.2000003, total_available_memory=3915946618.7999997)
Jun 11 08:47:48 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/4/51712 timeout closing device
Jun 11 08:47:48 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/console/3/0: Initialising != Connected, skipping
Jun 11 08:47:48 dom0 kernel: vbd vbd-3-51760: 5 starting transaction
Jun 11 08:47:48 dom0 kernel: vbd vbd-3-51760: failed to write error node for backend/vbd/3/51760 (5 starting transaction)
Jun 11 08:47:48 dom0 kernel: vbd vbd-3-51760: 5 starting transaction
Jun 11 08:47:48 dom0 kernel: vbd vbd-3-51760: failed to write error node for backend/vbd/3/51760 (5 starting transaction)
Jun 11 08:47:53 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/3/51760 timeout closing device
Jun 11 08:47:53 dom0 kernel: vbd vbd-3-51744: 5 starting transaction
Jun 11 08:47:53 dom0 kernel: vbd vbd-3-51744: failed to write error node for backend/vbd/3/51744 (5 starting transaction)
Jun 11 08:47:53 dom0 kernel: vbd vbd-3-51744: 5 starting transaction
Jun 11 08:47:53 dom0 kernel: vbd vbd-3-51744: failed to write error node for backend/vbd/3/51744 (5 starting transaction)
Jun 11 08:47:58 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/3/51744 timeout closing device
Jun 11 08:47:58 dom0 kernel: vbd vbd-3-51728: 5 starting transaction
Jun 11 08:47:58 dom0 kernel: vbd vbd-3-51728: failed to write error node for backend/vbd/3/51728 (5 starting transaction)
Jun 11 08:47:58 dom0 kernel: vbd vbd-3-51728: 5 starting transaction
Jun 11 08:47:58 dom0 kernel: vbd vbd-3-51728: failed to write error node for backend/vbd/3/51728 (5 starting transaction)
Jun 11 08:47:59 dom0 qmemman.daemon.algo[1650]: balance_when_enough_memory(xen_free_memory=6678695, total_mem_pref=3228789222.4, total_available_memory=3958976327.6)
Jun 11 08:47:59 dom0 qmemman.systemstate[1650]: stat: dom '0' act=3440017618 pref=1526061952.0 last_target=3440017618
Jun 11 08:47:59 dom0 qmemman.systemstate[1650]: stat: dom '5' act=930001117 pref=453513216.0 last_target=930001117
Jun 11 08:47:59 dom0 qmemman.systemstate[1650]: stat: dom '6' act=922536185 pref=409967001.6 last_target=922536185
Jun 11 08:47:59 dom0 qmemman.systemstate[1650]: stat: dom '7' act=1888531935 pref=839247052.8000001 last_target=1888531935
Jun 11 08:47:59 dom0 qmemman.systemstate[1650]: stat: xenfree=59107495 memset_reqs=[('0', 3393843882), ('6', 911734938), ('7', 1866420607), ('5', 1008578355)]
Jun 11 08:47:59 dom0 qmemman.systemstate[1650]: mem-set domain 0 to 3393843882
Jun 11 08:47:59 dom0 qmemman.systemstate[1650]: mem-set domain 6 to 911734938
Jun 11 08:47:59 dom0 qmemman.systemstate[1650]: mem-set domain 7 to 1866420607
Jun 11 08:47:59 dom0 qmemman.systemstate[1650]: mem-set domain 5 to 1008578355
Jun 11 08:48:03 dom0 qmemman.daemon.algo[1650]: balance_when_enough_memory(xen_free_memory=7541626, total_mem_pref=3269902003.2, total_available_memory=3918217404.8)
Jun 11 08:48:03 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/3/51728 timeout closing device
Jun 11 08:48:03 dom0 kernel: vbd vbd-3-51712: 5 starting transaction
Jun 11 08:48:03 dom0 kernel: vbd vbd-3-51712: failed to write error node for backend/vbd/3/51712 (5 starting transaction)
Jun 11 08:48:03 dom0 kernel: vbd vbd-3-51712: 5 starting transaction
Jun 11 08:48:03 dom0 kernel: vbd vbd-3-51712: failed to write error node for backend/vbd/3/51712 (5 starting transaction)
Jun 11 08:48:08 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/3/51712 timeout closing device
Jun 11 08:48:08 dom0 kernel: xen-pciback pci-2-0: 5 starting transaction
Jun 11 08:48:08 dom0 kernel: xen-pciback pci-2-0: failed to write error node for backend/pci/2/0 (5 starting transaction)
Jun 11 08:48:08 dom0 kernel: xen-pciback pci-2-0: 5 starting transaction
Jun 11 08:48:08 dom0 kernel: xen-pciback pci-2-0: failed to write error node for backend/pci/2/0 (5 starting transaction)
Jun 11 08:48:14 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/pci/2/0 timeout closing device
Jun 11 08:48:14 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/console/2/0: Initialising != Connected, skipping
Jun 11 08:48:14 dom0 kernel: vbd vbd-2-51760: 5 starting transaction
Jun 11 08:48:14 dom0 kernel: vbd vbd-2-51760: failed to write error node for backend/vbd/2/51760 (5 starting transaction)
Jun 11 08:48:14 dom0 kernel: vbd vbd-2-51760: 5 starting transaction
Jun 11 08:48:14 dom0 kernel: vbd vbd-2-51760: failed to write error node for backend/vbd/2/51760 (5 starting transaction)
Jun 11 08:48:19 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/2/51760 timeout closing device
Jun 11 08:48:19 dom0 kernel: vbd vbd-2-51744: 5 starting transaction
Jun 11 08:48:19 dom0 kernel: vbd vbd-2-51744: failed to write error node for backend/vbd/2/51744 (5 starting transaction)
Jun 11 08:48:19 dom0 kernel: vbd vbd-2-51744: 5 starting transaction
Jun 11 08:48:19 dom0 kernel: vbd vbd-2-51744: failed to write error node for backend/vbd/2/51744 (5 starting transaction)
Jun 11 08:48:23 dom0 qmemman.daemon.algo[1650]: balance_when_enough_memory(xen_free_memory=7541626, total_mem_pref=3314060569.6, total_available_memory=3874058838.4)
Jun 11 08:48:23 dom0 qmemman.systemstate[1650]: stat: dom '0' act=3393843882 pref=1526061952.0 last_target=3393843882
Jun 11 08:48:23 dom0 qmemman.systemstate[1650]: stat: dom '5' act=1008578355 pref=453513216.0 last_target=1008578355
Jun 11 08:48:23 dom0 qmemman.systemstate[1650]: stat: dom '6' act=911734938 pref=409967001.6 last_target=911734938
Jun 11 08:48:23 dom0 qmemman.systemstate[1650]: stat: dom '7' act=1866420607 pref=924518400.0 last_target=1866420607
Jun 11 08:48:23 dom0 qmemman.systemstate[1650]: stat: xenfree=59970426 memset_reqs=[('0', 3306682478), ('6', 888319572), ('5', 982675836), ('7', 2003253400)]
Jun 11 08:48:23 dom0 qmemman.systemstate[1650]: mem-set domain 0 to 3306682478
Jun 11 08:48:23 dom0 qmemman.systemstate[1650]: mem-set domain 6 to 888319572
Jun 11 08:48:23 dom0 qmemman.systemstate[1650]: mem-set domain 5 to 982675836
Jun 11 08:48:23 dom0 qmemman.systemstate[1650]: dom '0' still hold more memory than have assigned (3357483008 &gt; 3306682478)
Jun 11 08:48:23 dom0 qmemman.systemstate[1650]: mem-set domain 7 to 1959258820
Jun 11 08:48:24 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/2/51744 timeout closing device
Jun 11 08:48:24 dom0 kernel: vbd vbd-2-51728: 5 starting transaction
Jun 11 08:48:24 dom0 kernel: vbd vbd-2-51728: failed to write error node for backend/vbd/2/51728 (5 starting transaction)
Jun 11 08:48:24 dom0 kernel: vbd vbd-2-51728: 5 starting transaction
Jun 11 08:48:24 dom0 kernel: vbd vbd-2-51728: failed to write error node for backend/vbd/2/51728 (5 starting transaction)
-- Reboot --

I also tested the same poweroff command with only 2 Qubes running: sys-net and sys-firewall. This time the journalctl output spans for 56 seconds:

Jun 11 09:04:19 dom0 user[5725]: INFO: about to poweroff
Jun 11 09:04:19 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/console/5/0: Initialising != Connected, skipping
Jun 11 09:04:19 dom0 kernel: vbd vbd-5-51760: 5 starting transaction
Jun 11 09:04:19 dom0 kernel: vbd vbd-5-51760: failed to write error node for backend/vbd/5/51760 (5 starting transaction)
Jun 11 09:04:19 dom0 kernel: vbd vbd-5-51760: 5 starting transaction
Jun 11 09:04:19 dom0 kernel: vbd vbd-5-51760: failed to write error node for backend/vbd/5/51760 (5 starting transaction)
Jun 11 09:04:24 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/5/51760 timeout closing device
Jun 11 09:04:24 dom0 kernel: vbd vbd-5-51744: 5 starting transaction
Jun 11 09:04:24 dom0 kernel: vbd vbd-5-51744: failed to write error node for backend/vbd/5/51744 (5 starting transaction)
Jun 11 09:04:24 dom0 kernel: vbd vbd-5-51744: 5 starting transaction
Jun 11 09:04:24 dom0 kernel: vbd vbd-5-51744: failed to write error node for backend/vbd/5/51744 (5 starting transaction)
Jun 11 09:04:29 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/5/51744 timeout closing device
Jun 11 09:04:29 dom0 kernel: vbd vbd-5-51728: 5 starting transaction
Jun 11 09:04:29 dom0 kernel: vbd vbd-5-51728: failed to write error node for backend/vbd/5/51728 (5 starting transaction)
Jun 11 09:04:29 dom0 kernel: vbd vbd-5-51728: 5 starting transaction
Jun 11 09:04:29 dom0 kernel: vbd vbd-5-51728: failed to write error node for backend/vbd/5/51728 (5 starting transaction)
Jun 11 09:04:34 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/5/51728 timeout closing device
Jun 11 09:04:34 dom0 kernel: vbd vbd-5-51712: 5 starting transaction
Jun 11 09:04:34 dom0 kernel: vbd vbd-5-51712: failed to write error node for backend/vbd/5/51712 (5 starting transaction)
Jun 11 09:04:34 dom0 kernel: vbd vbd-5-51712: 5 starting transaction
Jun 11 09:04:34 dom0 kernel: vbd vbd-5-51712: failed to write error node for backend/vbd/5/51712 (5 starting transaction)
Jun 11 09:04:39 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/5/51712 timeout closing device
Jun 11 09:04:39 dom0 kernel: xen-pciback pci-2-0: 5 starting transaction
Jun 11 09:04:39 dom0 kernel: xen-pciback pci-2-0: failed to write error node for backend/pci/2/0 (5 starting transaction)
Jun 11 09:04:39 dom0 kernel: xen-pciback pci-2-0: 5 starting transaction
Jun 11 09:04:39 dom0 kernel: xen-pciback pci-2-0: failed to write error node for backend/pci/2/0 (5 starting transaction)
Jun 11 09:04:43 dom0 systemd[1]: Starting Cleanup of Temporary Directories...
Jun 11 09:04:43 dom0 systemd[1]: Started Cleanup of Temporary Directories.
Jun 11 09:04:43 dom0 audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-clean comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jun 11 09:04:43 dom0 audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-clean comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jun 11 09:04:43 dom0 kernel: kauditd_printk_skb: 1 callbacks suppressed
Jun 11 09:04:43 dom0 kernel: audit: type=1130 audit(1591880683.521:208): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-clean comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jun 11 09:04:43 dom0 kernel: audit: type=1131 audit(1591880683.521:209): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-clean comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Jun 11 09:04:44 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/pci/2/0 timeout closing device
Jun 11 09:04:44 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/console/2/0: Initialising != Connected, skipping
Jun 11 09:04:44 dom0 kernel: vbd vbd-2-51760: 5 starting transaction
Jun 11 09:04:44 dom0 kernel: vbd vbd-2-51760: failed to write error node for backend/vbd/2/51760 (5 starting transaction)
Jun 11 09:04:44 dom0 kernel: vbd vbd-2-51760: 5 starting transaction
Jun 11 09:04:44 dom0 kernel: vbd vbd-2-51760: failed to write error node for backend/vbd/2/51760 (5 starting transaction)
Jun 11 09:04:49 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/2/51760 timeout closing device
Jun 11 09:04:49 dom0 kernel: vbd vbd-2-51744: 5 starting transaction
Jun 11 09:04:49 dom0 kernel: vbd vbd-2-51744: failed to write error node for backend/vbd/2/51744 (5 starting transaction)
Jun 11 09:04:49 dom0 kernel: vbd vbd-2-51744: 5 starting transaction
Jun 11 09:04:49 dom0 kernel: vbd vbd-2-51744: failed to write error node for backend/vbd/2/51744 (5 starting transaction)
Jun 11 09:04:55 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/2/51744 timeout closing device
Jun 11 09:04:55 dom0 kernel: vbd vbd-2-51728: 5 starting transaction
Jun 11 09:04:55 dom0 kernel: vbd vbd-2-51728: failed to write error node for backend/vbd/2/51728 (5 starting transaction)
Jun 11 09:04:55 dom0 kernel: vbd vbd-2-51728: 5 starting transaction
Jun 11 09:04:55 dom0 kernel: vbd vbd-2-51728: failed to write error node for backend/vbd/2/51728 (5 starting transaction)
Jun 11 09:05:00 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/2/51728 timeout closing device
Jun 11 09:05:00 dom0 kernel: vbd vbd-2-51712: 5 starting transaction
Jun 11 09:05:00 dom0 kernel: vbd vbd-2-51712: failed to write error node for backend/vbd/2/51712 (5 starting transaction)
Jun 11 09:05:00 dom0 kernel: vbd vbd-2-51712: 5 starting transaction
Jun 11 09:05:00 dom0 kernel: vbd vbd-2-51712: failed to write error node for backend/vbd/2/51712 (5 starting transaction)
Jun 11 09:05:05 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/2/51712 timeout closing device
Jun 11 09:05:05 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/console/1/0: Initialising != Connected, skipping
Jun 11 09:05:05 dom0 kernel: vbd vbd-1-51760: 5 starting transaction
Jun 11 09:05:05 dom0 kernel: vbd vbd-1-51760: failed to write error node for backend/vbd/1/51760 (5 starting transaction)
Jun 11 09:05:05 dom0 kernel: vbd vbd-1-51760: 5 starting transaction
Jun 11 09:05:05 dom0 kernel: vbd vbd-1-51760: failed to write error node for backend/vbd/1/51760 (5 starting transaction)
Jun 11 09:05:10 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/1/51760 timeout closing device
Jun 11 09:05:10 dom0 kernel: vbd vbd-1-51744: 5 starting transaction
Jun 11 09:05:10 dom0 kernel: vbd vbd-1-51744: failed to write error node for backend/vbd/1/51744 (5 starting transaction)
Jun 11 09:05:10 dom0 kernel: vbd vbd-1-51744: 5 starting transaction
Jun 11 09:05:10 dom0 kernel: vbd vbd-1-51744: failed to write error node for backend/vbd/1/51744 (5 starting transaction)
Jun 11 09:05:15 dom0 qrexec[5728]: qubes.NotifyUpdates: sys-net -&gt; dom0: allowed to dom0
Jun 11 09:05:15 dom0 kernel: xenbus: xenbus_dev_shutdown: backend/vbd/1/51744 timeout closing device
Jun 11 09:05:15 dom0 kernel: vbd vbd-1-51728: 5 starting transaction
Jun 11 09:05:15 dom0 kernel: vbd vbd-1-51728: failed to write error node for backend/vbd/1/51728 (5 starting transaction)
Jun 11 09:05:15 dom0 kernel: vbd vbd-1-51728: 5 starting transaction
Jun 11 09:05:15 dom0 kernel: vbd vbd-1-51728: failed to write error node for backend/vbd/1/51728 (5 starting transaction)
-- Reboot --

Finally, I tested the same poweroff command with 0 Qubes running (only dom0). This time there was no ouput in journalctl after I initiated the command; the machine was off in 2.66 seconds.

qvm-shutdown --wait --timeout 0 --all

Thanks. I'll give that a try next, but is there any reason to expect that this command will finish sooner than qvm-kill --all?

maltfield commented 4 years ago

How would the QubesOS devs feel about making a dom0:/etc/qubes-rpc/emergencyShutdown service out of the script above?

Why qrexec service? Do you envision making it callable from some VM?

Yes, I'd like to give sys-usb permission to initiate an emergency shutdown in dom0. I'm essentially building a "panic button" usb peripheral (actually a kill cord).

Is this something you'd consider as a valuable feature in QubesOS? Should I open a distinct ticket for it?

As to the script itself, you can re-use initramfs. In fact, something similar is already used during normal shutdown - see /usr/lib/dracut/dracut-initramfs-restore called from dracut-shutdown.service.

Sorry, I haven't played with ramfs or initramfs before this. I'll check it out, thanks :)

brendanhoar commented 4 years ago

qvm-shutdown --wait --timeout 0 --all

Thanks. I'll give that a try next, but is there any reason to expect that this command will finish sooner than qvm-kill --all?

Due to a recent change, (included in 4.0.3 current-testing, not sure if it has made it to 4.0.3 release), qvm-shutdown --all now implicitly includes --force, so that VMs do not have to wait until upstream network consumers are shutdown before they shutdown. In other words, all are shut down in parallel.

Not instantaneous, but much less likely to have open device or volume connections over time.

I haven't tried qvm-kill --all recently. I don't imagine parallel shutdown with qvm-shutdown -all would be any faster, of course. But always worth experimenting.

B

maltfield commented 2 years ago

I haven't experimented with this for a while, but I wanted to update this ticket by saying that I finally published a guide for BusKill users with QubesOS

The guide references this ticket for why no hard shutdown trigger was provided.

DemiMarie commented 2 years ago

@maltfield Have you considered causing dom0 to kernel panic instead, after setting panics to reboot?

marmarek commented 2 years ago

If you want quick hard reboot, you can try xl debug-key R, although that won't clear the RAM.

github-actions[bot] commented 1 year ago

This issue is being closed because:

If anyone believes that this issue should be reopened and reassigned to an active milestone, please leave a brief comment. (For example, if a bug still affects Qubes OS 4.1, then the comment "Affects 4.1" will suffice.)

DemiMarie commented 1 year ago

@maltfield I think the correct way to do this is luksSuspend followed by systemctl poweroff --force --force. That causes systemctl to power down the system directly (reboot syscall) without waiting for anything to be synced. Is this sufficient?

maltfield commented 1 year ago

@DemiMarie I haven't tested this in a loong time, but I just did. Good news: it's fixed (for me, anyway).

the correct way to do this is luksSuspend followed by systemctl poweroff --force --force

Well, that may be more "correct" but it's not as fast. And for some high-risk folks (eg our BusKill community on QubesOS), it's better to tell the kernel to poweroff immediately with echo o > /proc/sysrq-trigger.

I tested this today on a Lenovo Thinkpad X1 Carbon Gen9 running QubesOS 4.1.2.

# run this on dom0 to trigger the "Power Off" signal to sysrq
# WARNING: running this command could cause data corruption or data loss!
echo o > /proc/sysrq-trigger

Immediately after I pressed enter, the screen went black. Then the screen came back-on for a half-second, then it went black again. Within 5 seconds entering the command, the machine was off.