Linux hangs at ACPI init on Medion P15648 MD63490

Linux hangs at ACPI init on Medion P15648 MD63490

[Jan Engelhardt]

Greetings.


I have a problem with a certain x86 laptop, and judging from the
kernel's output, this looks very much like a broken ACPI table.
Versions tried are 5.3.8 (Fedora31 liveimage), 5.5.2 (openSUSE
Tumbleweed installer) and 5.6.0-rc1+
(b19e8c68470385dd2c5440876591fddb02c8c402; self compile), all
exhibiting the same hang.

The last messages emitted by 5.6.0-rc1+ are:

	ACPI: 11 ACPI AML tables successfully acquired and loaded
	ACPI: EC: EC started
	ACPI: EC: interrupt blocked
	ACPI: \: Used as first EC
	ACPI: \: GPE=0x10, IRQ=-1, EC_CMD/EC_SC=0x66, EC_DATA=0x62
	ACPI: EC: Boot ECDT EC used to handle transactions
	<hang>

The full boot procedure is made available at
http://inai.de/files/m921.mp4 [79MB].
Curiously, FreeBSD 12.1 can be booted without issues, so either they
already workaround the issue, or don't trigger it in the first place.

After about 20 minutes, the kernel issues a stack trace.
http://inai.de/files/m922.mp4 [4.2M]; this seems to repeat every 
20 minutes:

	Task swapper blocked for more than 491 seconds.
	schedule
	schedule_timeout
	__down_timeout
	down_timeout
	acpi_os_wait_semaphore
	acpi_ex_system_wait_semaphore
	acpi_ev_acquire_global_lock
	acpi_ex_acquire_mutex_object
	acpi_ex_acquire_global_lock
	acpi_ex_write_data_to_field
	acpi_ex_store_object_to_node
	acpi_ex_store
	acpi_ex_opcode_1A_1T_1R
	acpi_ds_exec_end_op
	acpi_ps_parse_loop
	[a few frames more]

For comparison, a (vastly) different laptop with a proper firmware,
the EC messages go like this:

	<Fujitsu U728 for comparison>
	ACPI: EC: EC started
	ACPI: EC: interrupt blocked
	ACPI: \_SB_.PCI0.LPCB.EC__: Used as first EC
	ACPI: \_SB_.PCI0.LPCB.EC__: GPE=0x22, EC_CMD/EC_SC=0x66, EC_DATA=0x62
	ACPI: \_SB_.PCI0.LPCB.EC__: Boot DSDT EC used to handle transactions
	ACPI: Interpreter enabled

It kind of makes sense that, if "\" is seen as an EC in the Medion that 
it is not going to work.

Re: Linux hangs at ACPI init on Medion P15648 MD63490

[Rafael J. Wysocki]

On Fri, Feb 14, 2020 at 8:28 PM Jan Engelhardt <jengelh@inai.de> wrote:
>
> Greetings.
>
>
> I have a problem with a certain x86 laptop, and judging from the
> kernel's output, this looks very much like a broken ACPI table.
> Versions tried are 5.3.8 (Fedora31 liveimage), 5.5.2 (openSUSE
> Tumbleweed installer) and 5.6.0-rc1+
> (b19e8c68470385dd2c5440876591fddb02c8c402; self compile), all
> exhibiting the same hang.
>
> The last messages emitted by 5.6.0-rc1+ are:
>
>         ACPI: 11 ACPI AML tables successfully acquired and loaded
>         ACPI: EC: EC started
>         ACPI: EC: interrupt blocked
>         ACPI: \: Used as first EC
>         ACPI: \: GPE=0x10, IRQ=-1, EC_CMD/EC_SC=0x66, EC_DATA=0x62
>         ACPI: EC: Boot ECDT EC used to handle transactions
>         <hang>
>
> The full boot procedure is made available at
> http://inai.de/files/m921.mp4 [79MB].
> Curiously, FreeBSD 12.1 can be booted without issues, so either they
> already workaround the issue, or don't trigger it in the first place.

Would it be possible to try 5.0 or earlier on the problematic machine?

You may be hitting a regression here.

> After about 20 minutes, the kernel issues a stack trace.
> http://inai.de/files/m922.mp4 [4.2M]; this seems to repeat every
> 20 minutes:
>
>         Task swapper blocked for more than 491 seconds.
>         schedule
>         schedule_timeout
>         __down_timeout
>         down_timeout
>         acpi_os_wait_semaphore
>         acpi_ex_system_wait_semaphore
>         acpi_ev_acquire_global_lock
>         acpi_ex_acquire_mutex_object
>         acpi_ex_acquire_global_lock
>         acpi_ex_write_data_to_field
>         acpi_ex_store_object_to_node
>         acpi_ex_store
>         acpi_ex_opcode_1A_1T_1R
>         acpi_ds_exec_end_op
>         acpi_ps_parse_loop
>         [a few frames more]
>
> For comparison, a (vastly) different laptop with a proper firmware,
> the EC messages go like this:
>
>         <Fujitsu U728 for comparison>
>         ACPI: EC: EC started
>         ACPI: EC: interrupt blocked
>         ACPI: \_SB_.PCI0.LPCB.EC__: Used as first EC
>         ACPI: \_SB_.PCI0.LPCB.EC__: GPE=0x22, EC_CMD/EC_SC=0x66, EC_DATA=0x62
>         ACPI: \_SB_.PCI0.LPCB.EC__: Boot DSDT EC used to handle transactions
>         ACPI: Interpreter enabled
>
> It kind of makes sense that, if "\" is seen as an EC in the Medion that
> it is not going to work.

Re: Linux hangs at ACPI init on Medion P15648 MD63490

[Jan Engelhardt]

On Sunday 2020-02-16 01:32, Rafael J. Wysocki wrote:
>On Fri, Feb 14, 2020 at 8:28 PM Jan Engelhardt <jengelh@inai.de> wrote:
>>
>> I have a problem with a certain x86 laptop, and judging from the
>> kernel's output, this looks very much like a broken ACPI table.
>> Versions tried are 5.3.8 (Fedora31 liveimage), 5.5.2 (openSUSE
>> Tumbleweed installer) and 5.6.0-rc1+
>> (b19e8c68470385dd2c5440876591fddb02c8c402; self compile), all
>> exhibiting the same hang.
>>         ACPI: \: Used as first EC
>>         ACPI: \: GPE=0x10, IRQ=-1, EC_CMD/EC_SC=0x66, EC_DATA=0x62
>
>Would it be possible to try 5.0 or earlier on the problematic machine?
>You may be hitting a regression here.

Seems not to be the case. The same hang shows, with slightly different messages.

	5.0
	unable to progress to the problem point...
	the NMI watchdog causes a panic due to the slow scrolling of
	earlyprintk=efi

	4.12.14 (openSUSE)
	ACPI: : EC: EC started
	ACPI: : EC: interrupt blocked
	ACPI: \: Used as first EC
	ACPI: \: GPE=0x10, EC_CMD/EC_SC=0x66, EC_DATA=0x62
		(no mention of IRQ=-1)
	ACPI: \: Used as boot ECDT EC to handle transactions
	<hang>

	4.4.76 (openSUSE)
	ACPI : EC: EC description table is found, configuring boot EC
	ACPI : EC: EC started
	<hang>

I thus went back to 5.6-rc and enabled full ACPI tracing
(layer=0xffffffff/level=0xffffffff) starting from

nsinit.c:213	/* Walk namespace to execute all _INIs on present devices */

onwards. That log output is at http://inai.de/files/m923.mp4 [53MB].

Re: Linux hangs at ACPI init on Medion P15648 MD63490

[Rafael J. Wysocki]

On Sun, Feb 16, 2020 at 3:16 PM Jan Engelhardt <jengelh@inai.de> wrote:
>
>
> On Sunday 2020-02-16 01:32, Rafael J. Wysocki wrote:
> >On Fri, Feb 14, 2020 at 8:28 PM Jan Engelhardt <jengelh@inai.de> wrote:
> >>
> >> I have a problem with a certain x86 laptop, and judging from the
> >> kernel's output, this looks very much like a broken ACPI table.
> >> Versions tried are 5.3.8 (Fedora31 liveimage), 5.5.2 (openSUSE
> >> Tumbleweed installer) and 5.6.0-rc1+
> >> (b19e8c68470385dd2c5440876591fddb02c8c402; self compile), all
> >> exhibiting the same hang.
> >>         ACPI: \: Used as first EC
> >>         ACPI: \: GPE=0x10, IRQ=-1, EC_CMD/EC_SC=0x66, EC_DATA=0x62
> >
> >Would it be possible to try 5.0 or earlier on the problematic machine?
> >You may be hitting a regression here.
>
> Seems not to be the case. The same hang shows, with slightly different messages.
>
>         5.0
>         unable to progress to the problem point...
>         the NMI watchdog causes a panic due to the slow scrolling of
>         earlyprintk=efi
>
>         4.12.14 (openSUSE)
>         ACPI: : EC: EC started
>         ACPI: : EC: interrupt blocked
>         ACPI: \: Used as first EC
>         ACPI: \: GPE=0x10, EC_CMD/EC_SC=0x66, EC_DATA=0x62
>                 (no mention of IRQ=-1)
>         ACPI: \: Used as boot ECDT EC to handle transactions
>         <hang>
>
>         4.4.76 (openSUSE)
>         ACPI : EC: EC description table is found, configuring boot EC
>         ACPI : EC: EC started
>         <hang>
>
> I thus went back to 5.6-rc and enabled full ACPI tracing
> (layer=0xffffffff/level=0xffffffff) starting from
>
> nsinit.c:213    /* Walk namespace to execute all _INIs on present devices */
>
> onwards. That log output is at http://inai.de/files/m923.mp4 [53MB].

If that is the case, then AFAICS the issue may not be directly related
to the EC at all.  This output only means that the system has an ECDT,
but that should not be a problem by itself.

The system appears to hang somewhere in acpi_ns_initialize_devices()
and it is hard to say where exactly.

I would suggest creating a BZ entry at bugzilla.kernel.org for this
issue and attaching the output of acpidump from the affected system in
there.

Re: Linux hangs at ACPI init on Medion P15648 MD63490

[Jan Engelhardt]

On Sunday 2020-02-16 21:49, Rafael J. Wysocki wrote:

>> I thus went back to 5.6-rc and enabled full ACPI tracing
>> (layer=0xffffffff/level=0xffffffff) starting from
>>
>> nsinit.c:213    /* Walk namespace to execute all _INIs on present devices */
>>
>> onwards. That log output is at http://inai.de/files/m923.mp4 [53MB].
>
>If that is the case, then AFAICS the issue may not be directly related
>to the EC at all.  This output only means that the system has an ECDT,
>but that should not be a problem by itself.
>
>The system appears to hang somewhere in acpi_ns_initialize_devices()
>and it is hard to say where exactly.

I had an exact stack trace. (Stashed in all those videos - now extracted and
posted to the bug)

>I would suggest creating a BZ entry at bugzilla.kernel.org for this
>issue and attaching the output of acpidump from the affected system in
>there.

https://bugzilla.kernel.org/show_bug.cgi?id=206553

Re: Linux hangs at ACPI init on Medion P15648 MD63490

[Rafael J. Wysocki]

On Mon, Feb 17, 2020 at 1:10 AM Jan Engelhardt <jengelh@inai.de> wrote:
>
>
> On Sunday 2020-02-16 21:49, Rafael J. Wysocki wrote:
>
> >> I thus went back to 5.6-rc and enabled full ACPI tracing
> >> (layer=0xffffffff/level=0xffffffff) starting from
> >>
> >> nsinit.c:213    /* Walk namespace to execute all _INIs on present devices */
> >>
> >> onwards. That log output is at http://inai.de/files/m923.mp4 [53MB].
> >
> >If that is the case, then AFAICS the issue may not be directly related
> >to the EC at all.  This output only means that the system has an ECDT,
> >but that should not be a problem by itself.
> >
> >The system appears to hang somewhere in acpi_ns_initialize_devices()
> >and it is hard to say where exactly.
>
> I had an exact stack trace. (Stashed in all those videos - now extracted and
> posted to the bug)
>
> >I would suggest creating a BZ entry at bugzilla.kernel.org for this
> >issue and attaching the output of acpidump from the affected system in
> >there.
>
> https://bugzilla.kernel.org/show_bug.cgi?id=206553

Erik, Bob, can you please have a look at this BZ?  It looks like there
is a deadlock on the global lock while processing some AML during
acpi_ns_initialize_devices() execution.

RE: Linux hangs at ACPI init on Medion P15648 MD63490

[Moore, Robert]

-----Original Message-----
From: Rafael J. Wysocki <rafael@kernel.org> 
Sent: Monday, February 17, 2020 12:24 PM
To: Jan Engelhardt <jengelh@inai.de>; Kaneda, Erik <erik.kaneda@intel.com>; Moore, Robert <robert.moore@intel.com>
Cc: Rafael J. Wysocki <rafael@kernel.org>; ACPI Devel Maling List <linux-acpi@vger.kernel.org>
Subject: Re: Linux hangs at ACPI init on Medion P15648 MD63490

On Mon, Feb 17, 2020 at 1:10 AM Jan Engelhardt <jengelh@inai.de> wrote:
>
>
> On Sunday 2020-02-16 21:49, Rafael J. Wysocki wrote:
>
> >> I thus went back to 5.6-rc and enabled full ACPI tracing
> >> (layer=0xffffffff/level=0xffffffff) starting from
> >>
> >> nsinit.c:213    /* Walk namespace to execute all _INIs on present devices */
> >>
> >> onwards. That log output is at http://inai.de/files/m923.mp4 [53MB].
> >
> >If that is the case, then AFAICS the issue may not be directly 
> >related to the EC at all.  This output only means that the system has 
> >an ECDT, but that should not be a problem by itself.
> >
> >The system appears to hang somewhere in acpi_ns_initialize_devices() 
> >and it is hard to say where exactly.
>
> I had an exact stack trace. (Stashed in all those videos - now 
> extracted and posted to the bug)
>
> >I would suggest creating a BZ entry at bugzilla.kernel.org for this 
> >issue and attaching the output of acpidump from the affected system 
> >in there.
>
> https://bugzilla.kernel.org/show_bug.cgi?id=206553

Erik, Bob, can you please have a look at this BZ?  It looks like there is a deadlock on the global lock while processing some AML during
acpi_ns_initialize_devices() execution.

Yes, we are looking at this.
Bob