linux-kernel - Re: close() on some Intel CNP-LP PCI devices takes up to 2.7 s

lists.openwall.net		lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC
Open Source and information security mailing list archives

Hash Suite: Windows password security audit tool. GUI, reports in PDF.

[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]

Message-ID: <3854150d-f193-d34e-557e-41090e4f39b5@molgen.mpg.de>
Date:   Wed, 10 Jun 2020 08:18:07 +0200
From:   Paul Menzel <pmenzel@...gen.mpg.de>
To:     Mika Westerberg <mika.westerberg@...ux.intel.com>
Cc:     Bjorn Helgaas <bhelgaas@...gle.com>, linux-pci@...r.kernel.org,
        LKML <linux-kernel@...r.kernel.org>,
        Mario Limonciello <mario.limonciello@...l.com>,
        it+linux-pci@...gen.mpg.de, amd-gfx@...ts.freedesktop.org
Subject: Re: close() on some Intel CNP-LP PCI devices takes up to 2.7 s

Dear Mika,


Am 09.06.20 um 17:44 schrieb Mika Westerberg:
> On Tue, Jun 09, 2020 at 05:39:21PM +0200, Paul Menzel wrote:

>> On the Intel Cannon Point-LP laptop Dell Precision 3540 with a dedicated AMD
>> graphics card (both graphics devices can be used) with Debian Sid/unstable
>> with Linux 5.6.14, running lspci takes quite some time, and the screen even
>> flickers a short moment before the result is displayed.
>>
>> Tracing lspci with strace, shows that the close() function of the three
>> devices takes from
>>
>> •   00:1d.0 PCI bridge: Intel Corporation Cannon Point-LP PCI Express Root
>> Port #9
>>
>> •   04:00.0 System peripheral: Intel Corporation JHL6340 Thunderbolt 3 NHI
>> (C step) [Alpine Ridge 2C 2016] (rev 02)
>>
>> •   3b:00.0 Display controller: Advanced Micro Devices, Inc. [AMD/ATI] Lexa
>> XT [Radeon PRO WX 3100]
>>
>> takes from 270 ms to 2.5 s.
>>
>>> 11:43:21.714391 openat(AT_FDCWD, "/sys/bus/pci/devices/0000:04:00.0/config", O_RDONLY) = 3
>>> 11:43:21.714448 pread64(3, "\206\200\331\25\6\4\20\0\2\0\200\10 \0\0\0\0\0\0\352\0\0\4\352\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0(\20\272\10\0\0\0\0\
>>> 200\0\0\0\0\0\0\0\377\1\0\0", 64, 0) = 64
>>> 11:43:24.487818 close(3)                = 0
>>
>>> 11:43:24.489508 openat(AT_FDCWD, "/sys/bus/pci/devices/0000:00:1d.0/config", O_RDONLY) = 3
>>> 11:43:24.489598 pread64(3, "\206\200\260\235\7\4\20\0\360\0\4\6\20\0\201\0\0\0\0\0\0\0\0\0\0;;\00000\0  \354 \354\1\300\21\320\0\0\0\0\0\0\0\0\0\0\0\0
>>> @\0\0\0\0\0\0\0\377\1\22\0", 64, 0) = 64
>>> 11:43:24.966661 close(3)                = 0
>>
>>> 11:43:24.988544 openat(AT_FDCWD, "/sys/bus/pci/devices/0000:3b:00.0/config", O_RDONLY) = 3
>>> 11:43:24.988584 pread64(3, "\2\20\205i\7\4\20\0\0\0\200\3\20\0\0\0\f\0\0\300\0\0\0\0\f\0\0\320\0\0\0\0\0010\0\0\0\0 \354\0\0\0\0(\20\272\10\0\0$\354H\0\0\0\0\0\0\0\377\1\0\0", 64, 0) = 64
>>> 11:43:25.252745 close(3)
>>
>> Unfortunately, I forgot to collect the tree output, but hopefully the
>> attached Linux messages and strace of lspci output will be enough for the
>> start.
>>
>> Please tell me, if you want me to create a bug report in the Linux bug
>> tracker.
> 
> Can you try this commit?
> 
>    https://git.kernel.org/pub/scm/linux/kernel/git/helgaas/pci.git/commit/?h=pci/pm&id=ec411e02b7a2e785a4ed9ed283207cd14f48699d
> 
> It should be in the mainline already as well.
> 
> Note we still need to obey the delays required by the PCIe spec so 100ms
> after the link is trained but this one should at least get it down from
> 1100ms.

Thank you for replying so quickly. Hopefully, I’ll be able to test the 
commit tomorrow.

One question though. The commit talks about resuming from suspend. I 
understand that training happens there.

In my case the system is already running. So I wonder, why link(?) 
training would still happening.


Kind regards,

Paul