[SRU] Hibernation events sometimes missed on repeated attempts

apport information

apport information

@fginther Are newer releases also affected?

By latest acpid do you mean the package in Focal or upstream's latest commit/release?

@rbalint,

In our testing, we used the lastest acpid from debian git, https://salsa.debian.org/debian/acpid:

last commit
commit 2c2edfc267a69258cff406bd663b305fbee35187 (HEAD -> master, tag: debian/2.0.32-1, origin/master, origin/HEAD)
Author: Josue Ortega <email address hidden>
Date: Sun Aug 18 18:42:41 2019 -0600

    Set release to unstable 2.0.32-1

tag: debian/2.0.32-1

This corresponds to this commit: https://salsa.debian.org/debian/acpid/-/commit/2c2edfc267a69258cff406bd663b305fbee35187

Marked Focal as fixed since it has the acpid version tested to be OK, working on finding the changes needed to be SRUd.

This bug is missing log files that will aid in diagnosing the problem. While running an Ubuntu kernel (not a mainline or third-party kernel) please enter the following command in a terminal window:

apport-collect 1864045

and then change the status of the bug to 'Confirmed'.

If, due to the nature of the issue you have encountered, you are unable to run this command, please add a comment stating that fact and change the bug status to 'Confirmed'.

This change has been made by an automated script, maintained by the Ubuntu Kernel Team.

I have tried the 'fixed' acpid version and also tried various versions with 5.0 and 5.3 kernels, but the issue does not seem to be fixed.

I've backported acpid 1:2.0.32-1ubuntu1 in ppa:rbalint/scratch2 which is practically the same as 2.0.32-1 compiled on Ubuntu, but the second hibernation attempt still fails.

Package versions used:
linux-aws-wip/5.3.0.1012.13
acpid/1:2.0.32-1ubuntu1~18.04.0~rbalint3 from ppa:rbalint/scratch2
ec2-hibinit-agent/1.0.0-0ubuntu8~18.04.0~rbalint3 from ppa:rbalint/scratch2

Instance type: c4.large

Vanilla Bionic, i.e. kernel 4.15.0-1060-aws and Bionic's acpid hibernates twice without any issue.

Could you please add detailed reproduction steps that show how the new acpid was used to fix the issue?

For now it looks like a kernel regression and bisecting the Linux commit changing the behaviour would be highly useful.

@rbalint if you can reproduce the problem easily, it would be interesting to monitor the received ACPI events via acpi_listen.

What I see during my tests is that acpi_listen is always showing the sleep events, meaning that the kernel receives them correctly at least, and then the failure happens in the delivery of these sleep events to the proper user-space daemon (acpid). So my guess is that something wrong is happening in the communication between kernel and user-space to deliver these events.

Just to make sure, when you say "the second hibernation attempt still fails" you mean that the system is still up & running (you can still ssh on it) and the sleep event is lost / not delivered properly, right?

> @rbalint if you can reproduce the problem easily, it would be
> interesting to monitor the received ACPI events via acpi_listen.

I believe the reproduction is very easy for everyone.

I could not reproduce newer acpid fixing the problem OTOH. I'd like to
have the reproduction steps for that experiment.

> What I see during my tests is that acpi_listen is always showing the
> sleep events, meaning that the kernel receives them correctly at least,
> and then the failure happens in the delivery of these sleep events to
> the proper user-space daemon (acpid). So my guess is that something
> wrong is happening in the communication between kernel and user-space to
> deliver these events.

Since only the kernel changed it may be a regression in the kernel or
a change in kernel's behaviour that is still valid but acpid somehow
breaks.
Please either provide the reproduction steps where a different acpid
fixes the issue or point at the change in the kernel to which acpid
should adapt.
I believe this can be found by bisecting the kernel, but I don't have
the setup to do it efficiently myself.

> Just to make sure, when you say "the second hibernation attempt still
> fails" you mean that the system is still up & running (you can still ssh
> on it) and the sleep event is lost / not delivered properly, right?

Yes, exactly. I can still log in back to the system after a few seconds.

@rbalint unfortunately bisecting the kernel is not a trivial task... there are many changes between the stock 4.15 and the 5.0 kernels and the process is probably going to take a long time. I'll check if it's possible to identify only a subset of potential commits that might have caused this problem.

The steps that I've used to verify that the problem was fixed (or at least it thought it was fixed) were pretty easy: I got acpid from https://salsa.debian.org/debian/acpid.git (version 2.0.32-1), recompiled it, moved it to /usr/sbin/acpid (replacing the stock 2.0.28) and then tested multiple hibernate/resume cycles via the AWS APIs.

With this "custom" acpid I wasn't able to trigger any failure. It's also worth mentioning that I was using 5.0.0-1019-aws. I'll repeat my tests again with the latest bionic aws 5.0 kernel and will check if I can reproduce the failures.

The Eoan Ermine has reached end of life, so this bug will not be fixed for that release