Hi Rafael,
On 13/06/2019 22:59, Rafael J. Wysocki wrote:
> From: Rafael J. Wysocki <rafael.j.wysocki@xxxxxxxxx>
>
> Commit d491f2b75237 ("PCI: PM: Avoid possible suspend-to-idle issue")
> attempted to avoid a problem with devices whose drivers want them to
> stay in D0 over suspend-to-idle and resume, but it did not go as far
> as it should with that.
>
> Namely, first of all, the power state of a PCI bridge with a
> downstream device in D0 must be D0 (based on the PCI PM spec r1.2,
> sec 6, table 6-1, if the bridge is not in D0, there can be no PCI
> transactions on its secondary bus), but that is not actively enforced
> during system-wide PM transitions, so use the skip_bus_pm flag
> introduced by commit d491f2b75237 for that.
>
> Second, the configuration of devices left in D0 (whatever the reason)
> during suspend-to-idle need not be changed and attempting to put them
> into D0 again by force is pointless, so explicitly avoid doing that.
>
> Fixes: d491f2b75237 ("PCI: PM: Avoid possible suspend-to-idle issue")
> Reported-by: Kai-Heng Feng <kai.heng.feng@xxxxxxxxxxxxx>
> Signed-off-by: Rafael J. Wysocki <rafael.j.wysocki@xxxxxxxxx>
> Reviewed-by: Mika Westerberg <mika.westerberg@xxxxxxxxxxxxxxx>
> Tested-by: Kai-Heng Feng <kai.heng.feng@xxxxxxxxxxxxx>
I have noticed a regression in both the mainline and -next branches on
one of our boards when testing suspend. The bisect is point to this
commit and reverting on top of mainline does fix the problem. So far I
have not looked at this in close detail but kernel log is showing ...
[ 52.775138] PM: suspend entry (deep)
[ 52.779040] Filesystems sync: 0.000 seconds
[ 52.783476] Freezing user space processes ... (elapsed 0.001 seconds) done.
[ 52.791891] OOM killer disabled.
[ 52.795174] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
[ 52.803752] printk: Suspending console(s) (use no_console_suspend to debug)
[ 52.823750] r8169 0000:01:00.0 eth0: Link is Down
[ 52.823908] pci_generic_config_write32: 22 callbacks suppressed
[ 52.823914] pci_bus 0000:00: 2-byte config write to 0000:00:02.0 offset 0x9c may corrupt adjacent RW1C bits
[ 53.045383] Disabling non-boot CPUs ...
[ 53.048481] Entering suspend state LP1
[ 53.048508] Enabling non-boot CPUs ...
[ 53.049402] CPU1 is up
[ 53.050182] CPU2 is up
[ 53.051017] CPU3 is up
[ 53.051613] tegra-pcie 1003000.pcie: probing port 1, using 1 lanes
[ 53.069689] pcieport 0000:00:02.0: nv_msi_ht_cap_quirk didn't locate host bridge
[ 53.093751] r8169 0000:01:00.0: Refused to change power state, currently in D3
[ 53.156586] tegra-pcie 1003000.pcie: Slot present pin change, signature: 00000004
[ 53.156593] tegra-pcie 1003000.pcie: Response decoding error, signature: 10010045
[ 53.156596] tegra-pcie 1003000.pcie: FPCI address: fe10010044
[ 53.156711] tegra-pcie 1003000.pcie: Response decoding error, signature: 2000000c
[ 53.156714] tegra-pcie 1003000.pcie: FPCI address: 2000000c
[ 53.156719] tegra-pcie 1003000.pcie: Response decoding error, signature: 20000001
[ 53.156722] tegra-pcie 1003000.pcie: FPCI address: 20000000
[ 53.177372] pci_bus 0000:00: 2-byte config write to 0000:00:02.0 offset 0x88 may corrupt adjacent RW1C bits
[ 53.177379] pci_bus 0000:00: 2-byte config write to 0000:00:02.0 offset 0x90 may corrupt adjacent RW1C bits
[ 53.177384] pci_bus 0000:00: 2-byte config write to 0000:00:02.0 offset 0x98 may corrupt adjacent RW1C bits
[ 53.177389] pci_bus 0000:00: 2-byte config write to 0000:00:02.0 offset 0x9c may corrupt adjacent RW1C bits
[ 53.177394] pci_bus 0000:00: 2-byte config write to 0000:00:02.0 offset 0xa8 may corrupt adjacent RW1C bits
[ 53.177399] pci_bus 0000:00: 2-byte config write to 0000:00:02.0 offset 0xb0 may corrupt adjacent RW1C bits
[ 53.177451] pci_bus 0000:00: 2-byte config write to 0000:00:02.0 offset 0x52 may corrupt adjacent RW1C bits
[ 53.177461] pci_bus 0000:00: 2-byte config write to 0000:00:02.0 offset 0x52 may corrupt adjacent RW1C bits
[ 53.177470] pci_bus 0000:00: 2-byte config write to 0000:00:02.0 offset 0x5c may corrupt adjacent RW1C bits
[ 53.187746] r8169 0000:01:00.0 eth0: rtl_eriar_cond == 1 (loop: 100, delay: 100).
[ 53.188030] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.224105] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.224394] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.224679] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.224966] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.225247] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.225528] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.225813] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.226089] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.226372] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.226654] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.226934] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.227213] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.227495] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.227773] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.228050] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.228326] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.228609] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.228896] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 53.229181] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 54.064108] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 54.064429] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 54.064713] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 54.064996] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 54.065013] Generic Realtek PHY r8169-100:00: Master/Slave resolution failed, maybe conflicting manual settings?
[ 54.065016] ------------[ cut here ]------------
[ 54.065025] WARNING: CPU: 1 PID: 617 at /home/jonathanh/workdir/tegra/mlt-linux_torvalds/kernel/drivers/net/phy/phy.c:735 phy_error+0x1c/0x54
[ 54.065028] Modules linked in: ttm
[ 54.065039] CPU: 1 PID: 617 Comm: kworker/1:2 Not tainted 5.2.0-rc6 #1
[ 54.065041] Hardware name: NVIDIA Tegra SoC (Flattened Device Tree)
[ 54.065049] Workqueue: events_power_efficient phy_state_machine
[ 54.065068] [<c0112244>] (unwind_backtrace) from [<c010cad8>] (show_stack+0x10/0x14)
[ 54.065075] [<c010cad8>] (show_stack) from [<c0a60624>] (dump_stack+0xb4/0xc8)
[ 54.065082] [<c0a60624>] (dump_stack) from [<c0123cbc>] (__warn+0xe0/0xf8)
[ 54.065090] [<c0123cbc>] (__warn) from [<c0123dec>] (warn_slowpath_null+0x40/0x48)
[ 54.065095] [<c0123dec>] (warn_slowpath_null) from [<c06173f8>] (phy_error+0x1c/0x54)
[ 54.065101] [<c06173f8>] (phy_error) from [<c06184ec>] (phy_state_machine+0x64/0x1c0)
[ 54.065112] [<c06184ec>] (phy_state_machine) from [<c013e744>] (process_one_work+0x204/0x578)
[ 54.065119] [<c013e744>] (process_one_work) from [<c013f444>] (worker_thread+0x44/0x584)
[ 54.065123] [<c013f444>] (worker_thread) from [<c01445d4>] (kthread+0x148/0x150)
[ 54.065128] [<c01445d4>] (kthread) from [<c01010e8>] (ret_from_fork+0x14/0x2c)
[ 54.065131] Exception stack(0xe91b3fb0 to 0xe91b3ff8)
[ 54.065134] 3fa0: 00000000 00000000 00000000 00000000
[ 54.065138] 3fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[ 54.065141] 3fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[ 54.065145] ---[ end trace f59188238fc6fed4 ]---
[ 54.065168] r8169 0000:01:00.0 eth0: Link is Down
[ 54.075411] r8169 0000:01:00.0 eth0: rtl_chipcmd_cond == 1 (loop: 100, delay: 100).
[ 54.085652] r8169 0000:01:00.0 eth0: rtl_eriar_cond == 1 (loop: 100, delay: 100).
[ 54.095833] r8169 0000:01:00.0 eth0: rtl_eriar_cond == 1 (loop: 100, delay: 100).
[ 54.106017] r8169 0000:01:00.0 eth0: rtl_eriar_cond == 1 (loop: 100, delay: 100).
[ 54.116214] r8169 0000:01:00.0 eth0: rtl_eriar_cond == 1 (loop: 100, delay: 100).
[ 54.126419] r8169 0000:01:00.0 eth0: rtl_eriar_cond == 1 (loop: 100, delay: 100).
[ 54.136613] r8169 0000:01:00.0 eth0: rtl_eriar_cond == 1 (loop: 100, delay: 100).
[ 54.146829] r8169 0000:01:00.0 eth0: rtl_eriar_cond == 1 (loop: 100, delay: 100).
[ 54.157030] r8169 0000:01:00.0 eth0: rtl_eriar_cond == 1 (loop: 100, delay: 100).
[ 54.167223] r8169 0000:01:00.0 eth0: rtl_eriar_cond == 1 (loop: 100, delay: 100).
[ 54.177433] r8169 0000:01:00.0 eth0: rtl_eriar_cond == 1 (loop: 100, delay: 100).
[ 54.187635] r8169 0000:01:00.0 eth0: rtl_eriar_cond == 1 (loop: 100, delay: 100).
[ 54.197840] r8169 0000:01:00.0 eth0: rtl_eriar_cond == 1 (loop: 100, delay: 100).
[ 54.199008] r8169 0000:01:00.0 eth0: rtl_ephyar_cond == 1 (loop: 100, delay: 10).
[ 54.200173] r8169 0000:01:00.0 eth0: rtl_ephyar_cond == 1 (loop: 100, delay: 10).
[ 54.201336] r8169 0000:01:00.0 eth0: rtl_ephyar_cond == 1 (loop: 100, delay: 10).
[ 54.202502] r8169 0000:01:00.0 eth0: rtl_ephyar_cond == 1 (loop: 100, delay: 10).
[ 54.203018] r8169 0000:01:00.0 eth0: rtl_ocp_gphy_cond == 1 (loop: 10, delay: 25).
[ 54.546178] ata1: SATA link down (SStatus 0 SControl 300)
[ 56.810813] OOM killer enabled.
[ 56.813953] Restarting tasks ... done.
[ 56.819622] PM: suspend exit
[ 72.504381] nfs: server 192.168.99.1 not responding, still trying
[ 78.104369] nfs: server 192.168.99.1 not responding, still trying
Let me know if you have any thoughts.
Cheers
Jon
--
nvpublic
