(arm64) suspend to ram from inside a virt KVM guest hangs

[Sean Feole]

[ Impact ]

  On ARM64, VM's can not wakeup after a dompmsuspend is issued.

[Test Case]

Configure a system with Xenial, install qemu from cloud-archive:pike
Install: qemu-efi virt-manager libvirt-bin qemu-guest-agent qemu-system-aarch64

qemu-system-aarch64:
  Installed: 1:2.10+dfsg-0ubuntu3.1~cloud0
  Candidate: 1:2.10+dfsg-0ubuntu3.1~cloud0

libvirt-bin:
  Installed: 3.6.0-1ubuntu5~cloud0
  Candidate: 3.6.0-1ubuntu5~cloud0

On the test system:

   1. create a virtual machine that runs fine (in this example Ubuntu 17.10)
   2. Install qemu-guest-agent on the VM

qemu-guest-agent:
  Installed: 1:2.10+dfsg-0ubuntu3.1
  Candidate: 1:2.10+dfsg-0ubuntu3.1

   3. Power off the VM and edit the xml to enable qemu-guest-agent:
    <channel type='unix'>
      <target type='virtio' name='org.qemu.guest_agent.0'/>
      <address type='virtio-serial' controller='0' bus='0' port='1'/>
    </channel>

   4. suspend it
      $ sudo virsh dompmsuspend ubuntu1710 --target mem

      Console will report:
       $ sudo virsh dompmsuspend ubuntu1710 --target mem
       Domain ubuntu1710 successfully suspended

   5. confirm that the VM suspends
      virsh-list will still identify the VM as running however the VM is now inaccessible via console. We appear to be suspended. But no logs can be found actually confirming this is happening.

   3. wake it up
      $ sudo virsh dompmwakeup ubuntu1710
        Domain ubuntu1710 successfully woken up

Observed Result:
      The VM will never wakeup, the console will not respond to keystrokes, the VM must be reset in order to recover it.

Expected Result:
      The VM wakesup as expected and is fully functional

[Christian Ehrhardt  (paelzer)]

Thanks for splitting this issue out of our former work Sean.
I must admit I mostly use save/restore but less so suspend to ram - and even if so I don#t use the guest agent to do so, but all of that is worth testing.
I started with a repro of said case.

Usual updating to the latest versions of all packages - running on artful in host and guest.
Machine is a

Just like you I added the xml and installed the pkg qemu-guest-agent
 <channel type='unix'>
   <target type='virtio' name='org.qemu.guest_agent.0'/>
 </channel>
Note: I never specify the target to get the defaults of libvirt also if you want you can hot-attach such a channel (for the sake of staying with the case I did like you did with shutdown and in the static guest xml).

As guest agent is not strictly required (unless you have custom freezing/thaw operations) I did one guest to test with it and one without.

For better debugging in regard to the case I added "debug no_console_suspend" and removed "quiet splash" kernel options in /etc/default/grub and ran update-grub in the guests.
Also set the guest agent to verbose via:
$ echo 'DAEMON_ARGS="--verbose --logfile=/var/log/qemu-ga.log"' | sudo tee /etc/default/qemu-guest-agent

Tested the guest agent prior to the actual suspend/resume tests.
Agent is active in the guest and happy also guest ping works:
$ sudo virsh qemu-agent-command artful-uvt-test-agent '{"execute":"guest-ping"}'
Also guest-info confirms that at least the agent "thinks" pm suspend should be supported:
$ sudo virsh qemu-agent-command artful-uvt-test-agent '{"execute":"guest-info"}'
[...]
{"enabled":true,"name":"guest-suspend-ram","success-response":false}

Also have to differ the suspend options on the two guest types I test.
There is:
- virsh suspend/resume - the host will do the suspend to memory
 (this is what is used mostly as the guest doesn't need anything to know about it)
- virsh dompmsuspend/dompmwakeup - goes through guest agent to call ACPI states - S3 for mem
  (less common in general as more setup is required)

As I assumed the outer suspend/resume - which is like a lock in time for the guest worked quite well. Reached paused state and woke up - no issues.
But as guests don't like that if you do this for a longer period of time I understand the need for dompmsuspend so lets get to that.

Note: you said you don't see it reaching a non running state - it should reach "pmsuspended" state in your case if suspending correctly - so I'd assume it failing on the suspend already.

Tracking on all kind of logs while doing suspend and resume now.
- host journal
- host dmesg
- host guest libvirt/qemu log
- guest console
- guest journal
- guest qemu-agent log

I get a success response from virsh (which only knows that it submitted the cmd - see response false in the general agent command).
$ virsh dompmsuspend artful-uvt-test-agent --target mem
Domain artful-uvt-test-agent successfully suspended

But just like you it stays in state "running" so something is incomplete.
The guest is dead thou so some freeze happened.
No other log even moved - the only thing is the guest agent, that says:

1513156829.72735: debug: read data, count: 59, data: {"execute":"guest-sync", "a...

[Christian Ehrhardt  (paelzer)]

Sorry - found some other qemu-guest-agent issues along that were easier to address and I did so right away.
Back on this now.

The actions run by the guest-agent are:
- guest-sync (this is only to ensure no old content is on the channel, no relation to suspend)
- guest-suspend-ram (the actual suspend)

To do so it tries to call pm-utils (for it's quirks) and falls back to sysfs if not available.
Note: by default pm-utils is not even a suggest so we WILL use the sysfs write usually.

As I mentioned before there is no direct response by the command.
Instead a QMP event will be emitted.
Either the event or the query for status via qmp will be what should set libvirt to "pmsuspended"
We should assume that it doesn't reach that state.

With pm-utils it would call those
$ pm-is-supported --suspend
$ pm-suspend

But without it is a slighly more advanced echo, it will:
1. open /sys/power/state read only
2. check if "mem" is in there (it is in our case)
3. open /sys/power/state write only
4. writes "mem" into that

So not qemu-guest-agent is broken, but the suspend in kernel (this might still be related to the qemu environment it runs in thou).

[Christian Ehrhardt  (paelzer)]

qemu-guest-agent and pm-utils are both universe so adding a dependency or better a recommends as that is what it correctly is is an option if that turns out to help.
Independent to a fix of this issue (which we don't know yet if it is one) it would also ensure that anything that plug into /usr/lib/pm-utils/sleep.d would be correctly processed on in-guest suspend.

Checking kernel ram suspend in increasing test modes:
$ echo "freezer" | sudo tee /sys/power/pm_test
$ cat /sys/power/pm_test
$ echo "mem" | sudo tee /sys/power/state
$ sudo cat /sys/kernel/debug/suspend_stats

This iterates the stages:
1. freeze
/sys/kernel/debug/suspend_stats - success, no fails
dmesg:
[ 6591.187071] PM: Syncing filesystems ... done.
[ 6591.191328] PM: Preparing system for sleep (freeze)
[ 6591.196663] Freezing user space processes ... (elapsed 0.001 seconds) done.
[ 6591.197909] OOM killer disabled.
[ 6591.197912] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
[ 6591.199096] suspend debug: Waiting for 5 second(s).
[ 6596.199897] PM: Finishing wakeup.
[ 6596.199901] OOM killer enabled.
[ 6596.199903] Restarting tasks ... done.

2. devices
/sys/kernel/debug/suspend_stats - success, no fails
dmesg:
As above plus this on wakeup:
[ 6714.731269] pciehp 0000:00:01.0:pcie004: Slot(0): Already enabled
[ 6714.731607] pciehp 0000:00:01.1:pcie004: Slot(0-1): Already enabled
[ 6714.731945] pciehp 0000:00:01.2:pcie004: Slot(0-2): Already enabled
[ 6714.732282] pciehp 0000:00:01.3:pcie004: Slot(0-3): Already enabled
[ 6714.761113] Suspended for 0.828 seconds
[ 6714.823542] PM: resume of devices complete after 92.743 msecs

3. platform
/sys/kernel/debug/suspend_stats - success, no fails
dmesg:
As above plus:
[ 6873.053837] PM: late suspend of devices complete after 0.546 msecs
[ 6873.079422] PM: noirq suspend of devices complete after 25.579 msecs
[ 6873.079426] suspend debug: Waiting for 5 second(s).
[ 6878.162582] PM: noirq resume of devices complete after 82.393 msecs
[ 6878.163888] PM: early resume of devices complete after 0.931 msecs

processors/core tests are not supported for suspend to idle.
So as far as testable all works.

Test the "real thing" => hangs just as much.
Doing the same via pm-utils looks just the same :-/

So by the tests this isn't any process or device freeze on the suspend.
Instead it is the "core" change of state into the sleep that breaks it.
This requires all sorts of acpi magic which might after all just not fully apply to the (virtual) arm environment.

I enabled all kernel logs to be on the serial console, but see on that just what I saw on the tests. All good until the effective
[ 435.748784] PM: suspend-to-idle

But on the other end this state isn't found
$ virsh qemu-monitor-command artful-uvt-test-agent --pretty '{"execute":"query-status"}'
[...]
    "status": "running",

I use guests I spawned with a template that explicitly adds acpi, which might after all be wrong.
So I try modifying the features now hoping that the defaults are better than my xml.

[Christian Ehrhardt  (paelzer)]

Note: it really isn't suspended as after a while the guest console shows:
[ 606.312026] INFO: task pm-suspend:1258 blocked for more than 120 seconds.
[ 606.316500] Not tainted 4.13.0-19-generic #22-Ubuntu
[ 606.320080] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 606.325221] pm-suspend D 0 1258 1257 0x00000008
[ 606.328838] Call trace:
[ 606.330434] [<ffff000008086020>] __switch_to+0x98/0xb0
[ 606.333873] [<ffff000008a7e748>] __schedule+0x288/0x8d8
[ 606.337347] [<ffff000008a7edc4>] schedule+0x2c/0x88
[ 606.340563] [<ffff0000081313b0>] suspend_devices_and_enter+0x530/0x888
[ 606.344846] [<ffff000008131b9c>] pm_suspend+0x494/0x628
[ 606.348267] [<ffff00000812fef0>] state_store+0x90/0x110
[ 606.351663] [<ffff000008a6df2c>] kobj_attr_store+0x14/0x28
[ 606.355393] [<ffff000008358cf0>] sysfs_kf_write+0x58/0x80
[ 606.359036] [<ffff000008357e20>] kernfs_fop_write+0xe0/0x1f8
[ 606.362854] [<ffff0000082bad40>] __vfs_write+0x48/0x80
[ 606.366315] [<ffff0000082bc2ec>] vfs_write+0xa4/0x1a8
[ 606.369691] [<ffff0000082bdb0c>] SyS_write+0x6c/0xd8
[ 606.372973] [<ffff000008083930>] el0_svc_naked+0x24/0x28

So we see it hangs on the switch_to idle but should on that be gone to sleep.

[Christian Ehrhardt  (paelzer)]

Taking away acpi, apic, pae features in libvirt.
I know I need <gic version='3'/> to work on my platform so I leave that as-is.

It still freezes up at the same step:
[ 924.376385] PM: Syncing filesystems ... done.
[ 924.380381] PM: Preparing system for sleep (freeze)
[ 924.394818] Freezing user space processes ... (elapsed 0.001 seconds) done.
[ 924.400926] OOM killer disabled.
[ 924.403215] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
[ 924.409505] PM: Suspending system (freeze)
[ 924.474616] PM: suspend of devices complete after 61.930 msecs
[ 924.480707] PM: late suspend of devices complete after 0.489 msecs
[ 924.508651] PM: noirq suspend of devices complete after 23.659 msecs
[ 924.513058] PM: suspend-to-idle
[ 1088.635826] INFO: task pm-suspend:1215 blocked for more than 120 seconds.
[ 1088.640407] Not tainted 4.13.0-19-generic #22-Ubuntu
[ 1088.644083] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 1088.649326] pm-suspend D 0 1215 751 0x00000008
[ 1088.653040] Call trace:
[ 1088.654708] [<ffff000008086020>] __switch_to+0x98/0xb0
[ 1088.658267] [<ffff000008a7e748>] __schedule+0x288/0x8d8
[ 1088.661859] [<ffff000008a7edc4>] schedule+0x2c/0x88
[ 1088.665192] [<ffff0000081313b0>] suspend_devices_and_enter+0x530/0x888
[ 1088.669616] [<ffff000008131b9c>] pm_suspend+0x494/0x628
[ 1088.673172] [<ffff00000812fef0>] state_store+0x90/0x110
[ 1088.676720] [<ffff000008a6df2c>] kobj_attr_store+0x14/0x28
[ 1088.680413] [<ffff000008358cf0>] sysfs_kf_write+0x58/0x80
[ 1088.684036] [<ffff000008357e20>] kernfs_fop_write+0xe0/0x1f8
[ 1088.687811] [<ffff0000082bad40>] __vfs_write+0x48/0x80
[ 1088.691238] [<ffff0000082bc2ec>] vfs_write+0xa4/0x1a8
[ 1088.694753] [<ffff0000082bdb0c>] SyS_write+0x6c/0xd8
[ 1088.698200] [<ffff000008083930>] el0_svc_naked+0x24/0x28

Note: still nothing in any host log showing up - as if the try to suspend would vanish.

[Christian Ehrhardt  (paelzer)]

There is no other mode in /sys/power/mem_sleep than the default s2sleep to try.

[Christian Ehrhardt  (paelzer)]

I tried a few things more but not worth to mention - all dead ends.
Eventually I asked upstream if anybody ever achieved that and got no yes.

@Sean - given that this might have never worked so far and the package being "only" universe did you ever see that succeed in a former version? If not maybe you have HWE contacts who might know.