Bug 56501

Summary: Sony VAIO VPCZ23A4R: PCI bus is not rescanned on docking/undocking (worked in 3.8.2)
Product: ACPI Reporter: Alexander E. Patrakov (patrakov)
Component: Config-HotplugAssignee: Huang Ying (ying.huang)
Status: CLOSED PATCH_ALREADY_AVAILABLE    
Severity: normal CC: aaron.lu, tianyu.lan, ying.huang
Priority: P1    
Hardware: All   
OS: Linux   
Kernel Version: 3.9-rc5 Subsystem:
Regression: Yes Bisected commit-id:
Attachments: 3.8.2 config (works)
3.9-rc5 config (fails)
Dmesg from 3.8.2
Dmesg from 3.9-rc5
Dmesg from 3.9-rc5, with echo on > control
Debug patch for acpi hotplug
Screen photo (1), sorry for the flash
Screen photo (2), again sorry for the flash
Screen photo (3), reproduced without flashlight
Screen photo (4), with better visibility of text at the bottom
Full dmesg from 3.9-rc5
Dmesg from 3.9-rc5 with debug flags
Dmesg from 3.9-rc5 with debug flags and custom DSDT
Debug patch 2 for acpi pci hotplug
Buggy dmesg with custom DSDT
Buggy dmesg without custom DSDT
Debug patch 3 for acpi pci hotplug
Full dmesg from 3.9-rc5 with custom DSDT
Full dmesg from 3.9-rc5 without custom DSDT

Description Alexander E. Patrakov 2013-04-12 08:06:44 UTC
This is a fork of bug #55611, which is invalid due to my old stupid kernel config.

As of linux-3.9-rc5, docking no longer results in rescanning the PCI bus on my laptop. With the correct kernel config, it worked in linux-3.8.2, but triggered other bugs.

I will bisect later and add the needed information to this bug report. For now, I will attach both configs, just in case if this is again a stupid mistake in the config.
Comment 1 Alexander E. Patrakov 2013-04-12 08:07:43 UTC
Created attachment 98341 [details]
3.8.2 config (works)
Comment 2 Alexander E. Patrakov 2013-04-12 08:08:19 UTC
Created attachment 98351 [details]
3.9-rc5 config (fails)
Comment 3 Alexander E. Patrakov 2013-04-12 08:10:05 UTC
Created attachment 98361 [details]
Dmesg from 3.8.2

This dmesg was obtained with a hacked dsdt from bug 55611
Comment 4 Alexander E. Patrakov 2013-04-12 08:10:43 UTC
Created attachment 98371 [details]
Dmesg from 3.9-rc5
Comment 5 Aaron Lu 2013-04-12 09:01:46 UTC
Hi Alex,

For the v3.9-rc5 problem, please make sure:
1 If you have installed any of the pmtool like laptop_mode, please do not use it for the test.
2 All control file for the pci devices should be set to on instead of auto before dock:
# cd /sys/devices/pci0000:00
# for i in `find . -name control`; do echo on > $i; done

Then do the dock/undock test, thanks.
Comment 6 Alexander E. Patrakov 2013-04-12 15:07:29 UTC
Created attachment 98411 [details]
Dmesg from 3.9-rc5, with echo on > control

As you directed, I uninstalled laptop-mode-tools and ran the for loop. Result: docking/undocking works, but results in kernel warnings that will be reported as a separate bug.
Comment 7 Alexander E. Patrakov 2013-04-12 15:14:22 UTC
It works even without the for loop. So the curlpit was in laptop-mode-tools.

Do I understand correctly that this observation makes the kernel bug invalid, and I should report this incompatibility to laptop-mode-tools maintainer? If so, please close the bug as invalid. If the new kernel should not have created the incompatibility, please keep the bug open, and I will bisect.
Comment 8 Alexander E. Patrakov 2013-04-13 07:08:02 UTC
I reinstalled laptop-mode-tools and bisected again. The commit that seems to interfere with laptop-mode-tools is:

commit 6c0cc950ae670403a362bdcbf3cde0df33744928
Author: Rafael J. Wysocki <rafael.j.wysocki@intel.com>
Date:   Wed Jan 9 22:33:37 2013 +0100

    ACPI / PCI: Set root bridge ACPI handle in advance

Could you please explain why such bad interaction of this commit with laptop-mode-tools exists on my laptop?
Comment 9 Aaron Lu 2013-04-13 10:53:30 UTC
Hi Alex,

No need to file another bug, let's just use this bug to solve automatic re-scan problem.

And I'll add Ying, he probably knows what happened here.
Comment 10 Huang Ying 2013-04-15 00:57:15 UTC
Created attachment 98661 [details]
Debug patch for acpi hotplug

Could you try this patch against 3.9-rc5, with laptop-mode-tools installed and enabled?  Please use the following command line to collect some information before/after hotplug.

grep . /sys/bus/pci/devices/*/power/runtime_status
Comment 11 Aaron Lu 2013-04-15 01:00:20 UTC
Hi Alex,

If you have windows installed, can windows handle the dock automatically?
Comment 12 Alexander E. Patrakov 2013-04-15 07:32:32 UTC
Aaron: I don't have Windows installed now. But it definitely worked there. Unfortunately, it is rather problematic to install it again, as that would mean erasing the whole hard drive (the recovery flash stick is the only way to install Windows 7 on this laptop, and it can do only that).

Huang:

before docking, with your patch:

# grep -H . /sys/bus/pci/devices/*/power/runtime_status
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:active
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:04:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:active

After docking:

# grep -H . /sys/bus/pci/devices/*/power/runtime_status
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:active
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:04:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:08:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:0a:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:0a:03.0/power/runtime_status:active
/sys/bus/pci/devices/0000:0a:04.0/power/runtime_status:active
/sys/bus/pci/devices/0000:14:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:15:03.0/power/runtime_status:active
/sys/bus/pci/devices/0000:15:04.0/power/runtime_status:active
/sys/bus/pci/devices/0000:16:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:16:00.1/power/runtime_status:active
/sys/bus/pci/devices/0000:17:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:18:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:18:01.0/power/runtime_status:active
/sys/bus/pci/devices/0000:18:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:18:03.0/power/runtime_status:active
/sys/bus/pci/devices/0000:18:04.0/power/runtime_status:active
/sys/bus/pci/devices/0000:19:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:1a:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:1b:00.0/power/runtime_status:active

and all devices show up in lspci. So your debugging patch actually fixes or at least hides the bus-rescanning problem.
Comment 13 Alexander E. Patrakov 2013-04-15 07:33:47 UTC
s/the whole hard drive/the whole RAID of SSDs/
Comment 14 Alexander E. Patrakov 2013-04-15 07:46:01 UTC
Please disregard the comment above. I thought that laptop-mode-tools were installed and enabled, but they weren't. Will retest now.
Comment 15 Alexander E. Patrakov 2013-04-15 07:58:08 UTC
Before docking:

# grep -H . /sys/bus/pci/devices/*/power/runtime_status
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:active
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:04:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:active

After docking attempt:

# grep -H . /sys/bus/pci/devices/*/power/runtime_status
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:suspended
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:04:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:suspended

After undocking:

# grep -H . /sys/bus/pci/devices/*/power/runtime_status
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:suspended
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:04:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:suspended
Comment 16 Alexander E. Patrakov 2013-04-15 08:30:21 UTC
Played a bit more with that. Here "after find" = after the following commands originally suggested by Aaron:

# cd /sys/devices/pci0000:00
# for i in `find . -name control`; do echo on > $i; done

# Initially
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:active
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:04:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:active
# After find
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:active
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:04:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:active
# After dock (1)
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:suspended
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:04:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:suspended
# After undock (1)
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:suspended
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:04:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:suspended
# After find (2)
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:active
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:04:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:active
# After dock (2)
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:suspended
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:04:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:08:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:09:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:09:03.0/power/runtime_status:active
/sys/bus/pci/devices/0000:09:04.0/power/runtime_status:active
/sys/bus/pci/devices/0000:0c:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:0d:03.0/power/runtime_status:active
/sys/bus/pci/devices/0000:0d:04.0/power/runtime_status:active
/sys/bus/pci/devices/0000:0e:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:0e:00.1/power/runtime_status:active
/sys/bus/pci/devices/0000:0f:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:10:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:10:01.0/power/runtime_status:active
/sys/bus/pci/devices/0000:10:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:10:03.0/power/runtime_status:active
/sys/bus/pci/devices/0000:10:04.0/power/runtime_status:active
/sys/bus/pci/devices/0000:11:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:12:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:13:00.0/power/runtime_status:active
# After undock (2)
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:suspended
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:04:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:suspended
# After find (3)
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:suspended
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:04:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:suspended
# After dock (3)
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:suspended
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:04:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:08:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:09:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:09:03.0/power/runtime_status:active
/sys/bus/pci/devices/0000:09:04.0/power/runtime_status:active
/sys/bus/pci/devices/0000:0c:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:0d:03.0/power/runtime_status:active
/sys/bus/pci/devices/0000:0d:04.0/power/runtime_status:active
/sys/bus/pci/devices/0000:0e:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:0e:00.1/power/runtime_status:active
/sys/bus/pci/devices/0000:0f:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:10:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:10:01.0/power/runtime_status:active
/sys/bus/pci/devices/0000:10:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:10:03.0/power/runtime_status:active
/sys/bus/pci/devices/0000:10:04.0/power/runtime_status:active
/sys/bus/pci/devices/0000:11:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:12:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:13:00.0/power/runtime_status:active
# After undock (3)
/sys/bus/pci/devices/0000:00:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:16.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
/sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:suspended
/sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
/sys/bus/pci/devices/0000:04:00.0/power/runtime_status:suspended
/sys/bus/pci/devices/0000:05:00.0/power/runtime_status:suspended
# After dock (4)
# CPU lockup, recursive fault
Comment 17 Alexander E. Patrakov 2013-04-15 08:33:23 UTC
Created attachment 98711 [details]
Screen photo (1), sorry for the flash
Comment 18 Alexander E. Patrakov 2013-04-15 08:34:20 UTC
Created attachment 98721 [details]
Screen photo (2), again sorry for the flash
Comment 19 Alexander E. Patrakov 2013-04-15 08:37:08 UTC
Created attachment 98731 [details]
Screen photo (3), reproduced without flashlight
Comment 20 Alexander E. Patrakov 2013-04-15 08:41:23 UTC
Created attachment 98751 [details]
Screen photo (4), with better visibility of text at the bottom

Photos (1) and (2) are from the first occurrence of the lockup, photos (3) and (4) are from another attempt to reproduce. In both cases, the lockup happened on docking.
Comment 21 Huang Ying 2013-04-15 14:30:40 UTC
(In reply to comment #16)
> Played a bit more with that. Here "after find" = after the following commands
> originally suggested by Aaron:
> 
> # cd /sys/devices/pci0000:00
> # for i in `find . -name control`; do echo on > $i; done
> 
> # Initially
> /sys/bus/pci/devices/0000:00:00.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:16.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:active
> /sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:04:00.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:05:00.0/power/runtime_status:active
> # After find
> /sys/bus/pci/devices/0000:00:00.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:16.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:active
> /sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:04:00.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:05:00.0/power/runtime_status:active
> # After dock (1)
> /sys/bus/pci/devices/0000:00:00.0/power/runtime_status:suspended
> /sys/bus/pci/devices/0000:00:02.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:16.0/power/runtime_status:suspended
> /sys/bus/pci/devices/0000:00:1a.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1b.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1c.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1c.1/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1c.2/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1c.3/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1c.6/power/runtime_status:suspended
> /sys/bus/pci/devices/0000:00:1d.0/power/runtime_status:suspended
> /sys/bus/pci/devices/0000:00:1f.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1f.2/power/runtime_status:active
> /sys/bus/pci/devices/0000:00:1f.3/power/runtime_status:suspended
> /sys/bus/pci/devices/0000:02:00.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:03:00.0/power/runtime_status:active
> /sys/bus/pci/devices/0000:04:00.0/power/runtime_status:suspended
> /sys/bus/pci/devices/0000:05:00.0/power/runtime_status:suspended

It appears that docking does not work for the first time, but it works for the second and third time.  So is it possible for you to test the comment #10 patch with multiple times docking/undocking?
Comment 22 Aaron Lu 2013-04-16 01:28:52 UTC
Hi Alex,

If you have another computer, can you please try to setup netconsole to check the crash message? The standard netconsole document is here:
https://www.kernel.org/doc/Documentation/networking/netconsole.txt
And there are a lot others you can google if you need. Thanks.
Comment 23 Aaron Lu 2013-04-16 04:50:42 UTC
BTW, if you dock/undock several times with a v3.8 kernel, will it also crash?
Comment 24 Alexander E. Patrakov 2013-04-16 07:29:13 UTC
For comment #21: yes, the second docking attempt works.
Comment 25 Alexander E. Patrakov 2013-04-16 07:42:46 UTC
For comment #23: thanks for prompting me to try. The result is that, with laptop-mode-tools installed, on 3.8.2 docking works only on the first attempt. On the second and further attempts, the PCI bus is not rescanned. I.e. I get the opposite of the 3.9-rc5 behaviour, where the rescan happens only on the second docking attempt and later.

As for the crash - yes, with laptop-mode-tools uninstalled, the crash is reliably triggered by the second docking on any kernel. I will capture it using netconsole later today.
Comment 26 Huang Ying 2013-04-16 08:02:50 UTC
A little confused about the exact testing steps.  Could you test with

- 3.9-rc5 + comment #10 patch
- laptop-mode-tools installed and enabled
- without "for i in `find . -name control`; do echo on > $i; done" script

And could you post the result of

grep . /sys/bus/pci/devices/*/power/runtime_status

before/after dock, and post the dmesg?
Comment 27 Alexander E. Patrakov 2013-04-16 08:39:49 UTC
Huang, the result of grep during and after your testing steps is in comment #15. Dmesg will be posted later today.
Comment 28 Alexander E. Patrakov 2013-04-16 16:09:39 UTC
Created attachment 98871 [details]
Full dmesg from 3.9-rc5

I have attached a complete dmesg from 3.9-rc5, with the debugging patch, with laptop-mode-tools installed. This dmesg was stitched from two parts. The part before "netconsole test" is the output of the local "dmesg" command, and after that, I have added all lines captured over the netconsole.

In the middle, I have logged the active/suspended state by modifying the command as follows:

for line in `grep -H . /sys/bus/pci/devices/*/power/runtime_status` ; do echo $line  > /dev/kmsg ; done

There was no messing with the control files this time.

Timeline:

@177 seconds: initial grep test before docking
@191-194: first docking, unsuccessful
@212: grep test while "docked" but with PCI devices invisible
@223-224: undocking
@234-235: grep test
@247-250: docking, with PCI devices detected
@255: grep test
@270-271: undocked
@283: grep test
@300-303: dock + crash
later: aftermath
Comment 29 Huang Ying 2013-04-17 00:20:05 UTC
(In reply to comment #28)
> Created an attachment (id=98871) [details]
> Full dmesg from 3.9-rc5

From your dmesg, it appears that acpiphp.debug=1 is not in kernel command line.  If not, could retest it with that kernel command option?
Comment 30 Aaron Lu 2013-04-17 05:11:04 UTC
And please also add acpi.aml_debug_output=1 to the command line, thanks.
Comment 31 Alexander E. Patrakov 2013-04-17 07:29:29 UTC
Created attachment 98931 [details]
Dmesg from 3.9-rc5 with debug flags

I have recaptured the dmesg with the debug flags. However, as there is no AML debug output in the dmesg, I think that Aaron wanted me to use his custom DSDT. Will redo the log now.
Comment 32 Alexander E. Patrakov 2013-04-17 07:49:23 UTC
Created attachment 98951 [details]
Dmesg from 3.9-rc5 with debug flags and custom DSDT

Just in case, here is a full dmesg with Huang's debug patch, various debug flags,  and Aaron's custom DSDT from bug #55611 (the one that only adds debug output and does not call _Q07).
Comment 33 Huang Ying 2013-04-17 14:14:53 UTC
(In reply to comment #32)
> Created an attachment (id=98951) [details]
> Dmesg from 3.9-rc5 with debug flags and custom DSDT
> 
> Just in case, here is a full dmesg with Huang's debug patch, various debug
> flags,  and Aaron's custom DSDT from bug #55611 (the one that only adds debug
> output and does not call _Q07).

This is very helpful!  Thanks a lot!
Comment 34 Huang Ying 2013-04-17 14:17:25 UTC
Created attachment 98971 [details]
Debug patch 2 for acpi pci hotplug

I found a bug in my previous debug patch.  Could you test this new version?  Please test it similar as that in comment #32.  With and without Aaron's custom DSDT.
Comment 35 Alexander E. Patrakov 2013-04-17 15:06:25 UTC
Created attachment 98991 [details]
Buggy dmesg with custom DSDT

Sorry, it seems that you added a bug (or exposed it), not fixed. Now the kernel crashes on the first dock attempt.
Comment 36 Alexander E. Patrakov 2013-04-17 15:07:17 UTC
Created attachment 99001 [details]
Buggy dmesg without custom DSDT

Without custom DSDT, the kernel cannot even write the complete crash log to network.
Comment 37 Huang Ying 2013-04-18 07:18:47 UTC
Created attachment 99171 [details]
Debug patch 3 for acpi pci hotplug

Sorry, the comment #34 patch introduce a new bug.  Please test with this new version.  Hopefully it can fix that bug.
Comment 38 Alexander E. Patrakov 2013-04-18 08:00:40 UTC
Created attachment 99181 [details]
Full dmesg from 3.9-rc5 with custom DSDT

With your debugging patch, PCI devices show up on the first docking attempt, even with laptop-mode-tools installed. So it looks like the non-rescanning problem is solved.

However, as before, on the second docking attempt the kernel crashes. Please see details in the attached dmesg output.
Comment 39 Alexander E. Patrakov 2013-04-18 08:02:24 UTC
Created attachment 99191 [details]
Full dmesg from 3.9-rc5 without custom DSDT

You also asked for a dmesg without custom DSDT, so here it is.
Comment 40 Aaron Lu 2013-04-18 08:12:43 UTC
Thanks Alex.

And the custom DSDT shouldn't be needed, I missed some code in the PCI dock hotplug processing code. On dock, the driver will notify the pci device about dock event, so no need to add _Q07 in _DCK.
Comment 41 Huang Ying 2013-04-19 12:56:01 UTC
Thanks Alex.  Could create another bug report for kernel crashes on the second docking?  Because it appears that the root cause and fixing patch will be different.
Comment 42 Alexander E. Patrakov 2013-04-19 13:03:15 UTC
Sure, I will open that second bug from home. See also bug #56531 for the resource assignment issue that may be the root cause.

As for this bug: do I understand correctly that the "debug patch" from comment #37 is the proper fix for the non-rescanning problem? If so, this bug can be closed as CODE_FIX once the patch enters some public git tree.
Comment 43 Alexander E. Patrakov 2013-04-19 14:53:31 UTC
Moved the crash on the second docking attempt to bug 56841
Comment 44 Huang Ying 2013-04-19 23:17:52 UTC
(In reply to comment #42)
> Sure, I will open that second bug from home. See also bug #56531 for the
> resource assignment issue that may be the root cause.
> 
> As for this bug: do I understand correctly that the "debug patch" from
> comment
> #37 is the proper fix for the non-rescanning problem? If so, this bug can be
> closed as CODE_FIX once the patch enters some public git tree.

At least, I think the issue is root caused.  I will work on a more formal fix patch.
Comment 45 Huang Ying 2013-05-02 00:47:16 UTC
Hi, Alex, I found this bug has been fixed by commit de7d5f7 "PCI/PM: Disable runtime PM of PCIe ports" in another way, which has been merged by kernel v3.9.  Could you help us to verify whether v3.9 fixed this bug?
Comment 46 Alexander E. Patrakov 2013-05-02 05:42:27 UTC
Sorry, cannot test due to a physical mishap. The bag with the laptop fell, and now it shuts itself down under the lightest load.
Comment 47 Aaron Lu 2013-05-06 02:02:01 UTC
Kernel 3.9 includes commit de7d5f7 "PCI/PM: Disable runtime PM of PCIe ports"  that should fix the problem reported here.
Comment 48 Alexander E. Patrakov 2013-06-03 01:17:56 UTC
The laptop has been repaired. The bug indeed no longer exists in kernel 3.9.4, but the 3.10-rc3 kernel also does not want to rescan the PCI bus, regardless of laptop-mode-tools. I will open a separate bug for that once I examine the kernel config once again and bisect the regression.