Bug 208595 - boot performance: 400 ms spent in power resource detection - Dell Precision 3540
Summary: boot performance: 400 ms spent in power resource detection - Dell Precision 3540
Status: ASSIGNED
Alias: None
Product: Power Management
Classification: Unclassified
Component: Other (show other bugs)
Hardware: All Linux
: P1 normal
Assignee: Zhang Rui
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2020-07-17 07:58 UTC by Paul Menzel
Modified: 2023-02-27 11:58 UTC (History)
3 users (show)

See Also:
Kernel Version: 5.7.6
Subsystem:
Regression: No
Bisected commit-id:


Attachments
Linux 5.7.6 messages (output of `dmesg`) (99.19 KB, text/plain)
2020-07-17 07:58 UTC, Paul Menzel
Details
Output of `acpidump` (1.62 MB, text/plain)
2020-11-30 10:07 UTC, Paul Menzel
Details

Description Paul Menzel 2020-07-17 07:58:32 UTC
Created attachment 290327 [details]
Linux 5.7.6 messages (output of `dmesg`)

On a Dell Precision 3540 with Debian Sid/unstable and Linux 5.7.6, 400 ms are spent in the ACPI code in the BTPR power resource detection. This is over half of the time in the Linux kernel before loading the initramfs.

```
[    0.000000] Linux version 5.7.0-1-amd64 (debian-kernel@lists.debian.org) (gcc version 9.3.0 (Debian 9.3.0-14), GNU ld (GNU Binutils for Debian) 2.34) #1 SMP Debian 5.7.6-1 (2020-06-24)
[…]
[    0.000000] DMI: Dell Inc. Precision 3540/0M14W7, BIOS 1.7.4 05/12/2020
[…]
[    0.313896] ACPI: Enabled 11 GPEs in block 00 to 7F                      
[    0.317990] ACPI: Power Resource [PXP] (on)               
[    0.319192] ACPI: Power Resource [PC05] (on)                     
[    0.737448] ACPI: Power Resource [BTPR] (off)
[    0.738335] ACPI: Power Resource [USBC] (on)
[    0.738431] ACPI: Power Resource [PAUD] (on)
[    0.740291] ACPI: Power Resource [V0PR] (on)
[    0.740379] ACPI: Power Resource [V1PR] (on)
[    0.740463] ACPI: Power Resource [V2PR] (on)
[    0.743716] ACPI: Power Resource [WRST] (on)
[    0.753151] ACPI: Power Resource [PIN] (off)
[    0.753398] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-7e])
[…]
```
Comment 1 Zhang Rui 2020-11-26 07:36:40 UTC
please attach the acpidump output.
Comment 2 Paul Menzel 2020-11-30 10:07:43 UTC
Created attachment 293881 [details]
Output of `acpidump`
Comment 3 Paul Menzel 2022-02-18 09:48:36 UTC
It’s still happening with system firmware 1.10.1 and Linux 5.16.7.
Comment 4 Zhang Rui 2022-06-21 06:48:34 UTC
Hmm, below is the dump of the BTPR power resource.
                PowerResource (BTPR, 0x00, 0x0000)
                {
                    Method (_STA, 0, NotSerialized)  // _STA: Status
                    {
                        If ((\_SB.GBTR () == One))
                        {
                            Return (One)
                        }
                        Else
                        {
                            Return (Zero)
                        }
                    }

                    Method (_ON, 0, Serialized)  // _ON_: Power On
                    {
                        \_SB.BTRK (One)
                    }

                    Method (_OFF, 0, Serialized)  // _OFF: Power Off
                    {
                        \_SB.BTRK (Zero)
                    }
                }

Both GBTR and BTRK methods only contain some memory accesses.
Can not explain why it takes such a long time.
Comment 5 Paul Menzel 2022-06-21 06:55:52 UTC
Zhang, thank you for looking into this.

Does Intel have access to such a device, or arrange some access to reproduce the issue?

What ACPI debug settings would I need to see timing data for the GBTR and BTRK calls?
Comment 6 Zhang Rui 2022-06-21 08:12:26 UTC
There is a way to dump the method executing start and end time via acpi.debug_layer/acpi.debug_level command, but that would introduce tons of unrelated messages.

Let me check with @Todd first to see if we can leverage bootgraph tool.
Comment 7 Paul Menzel 2022-06-21 08:22:27 UTC
> Let me check with @Todd first to see if we can leverage bootgraph tool.

That is using ftrace to my knowledge. If you tell me the function to trace, I can do that, the next time the user can give me access to the device, which is not very convenient as that is the work system.
Comment 8 Zhang Rui 2022-06-27 01:24:21 UTC
you can try acpi_add_power_resource() first.
Comment 9 Paul Menzel 2023-02-27 11:58:33 UTC
For the record, this is still problem with the latest firmware 1.23.0:

```
[    0.000000] Linux version 6.1.0-5-amd64 (debian-kernel@lists.debian.org) (gcc-12 (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40) #1 SMP PREEMPT_DYNAMIC Debian 6.1.12-1 (2023-02-15)
[    0.000000] Command line: BOOT_IMAGE=/vmlinuz-6.1.0-5-amd64 root=UUID=c9342a55-b747-4442-b2f4-bc03eb7a51cf ro quiet noisapnp log_buf_len=2M cryptomgr.notests btusb.enable_autosuspend=y random.trust_cpu=on drm
.debug=0xe log_buf_len=8M
[…]
[    0.000000] SMBIOS 3.2.1 present.
[    0.000000] DMI: Dell Inc. Precision 3540/0M14W7, BIOS 1.23.0 12/19/2022
[    0.000000] tsc: Detected 2100.000 MHz processor
[    0.000000] tsc: Detected 2099.944 MHz TSC
[…]
[    0.277538] PCI: Using E820 reservations for host bridge windows
[    0.277951] ACPI: Enabled 11 GPEs in block 00 to 7F
[    0.281658] ACPI: PM: Power Resource [PXP]
[    0.282945] ACPI: PM: Power Resource [PC05]
[    0.698385] ACPI: PM: Power Resource [BTPR]
[    0.699202] ACPI: PM: Power Resource [USBC]
[    0.699339] ACPI: PM: Power Resource [PAUD]
[    0.701282] ACPI: PM: Power Resource [V0PR]
[    0.701376] ACPI: PM: Power Resource [V1PR]
[    0.701465] ACPI: PM: Power Resource [V2PR]
[    0.704851] ACPI: PM: Power Resource [WRST]
[    0.713813] ACPI: PM: Power Resource [PIN]
[    0.714078] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-7e])
[…]
[    0.844385] microcode: sig=0x806ec, pf=0x80, revision=0xf0
[    0.844579] microcode: Microcode Update Driver: v2.2.
[…]
```

Note You need to log in before you can comment on or make changes to this bug.