2006-08-07 19:32:39

by Andrew Clayton

[permalink] [raw]
Subject: 2.6.18-rc strange hotplug/udev/uevent problem

Hi,

Got a weird problem here.

On x86 Fedora Core 5 with 2.6.17 with GNOME, plugging in a usb stick
would result in it being mounted. With 2.6.18-rc this no longer occurs.
FC5 got an update to hal to work with 2.6.18 kernels, but it don't work
for me. I'm having the same problem on 3 x86 FC5 machines.

The weird thing is, this all works on my x86-64 FC5 workstation with
2.6.18-rc both before and after the hal update.

Anyway I submitted a bug report against HAL suspecting it broken

https://bugs.freedesktop.org/show_bug.cgi?id=7756

Perhaps not. So I turn my attention more to the kernel.


2.6.17 was working fine. You could plug/unplug/plug a USB memory stick
and it would get mounted each time.

2.6.18-rc[23] works the same as above on my x86-64 FC5 box.

2.6.18-rc[23] and 2.6.18-rc3-git7 on x86 built with
usb/scsi/sd/vfat/nls_* built as modules will mount on the first plug but
not subsequent plugs.

If you rmmod the sd_mod module and plug in, then it will get mounted.

When the kernel is built non-modular then plugging in will not mount it.
If you boot with the device plugged in then when you log into GNOME it
will be mounted. But subsequent unmount/plug ins will not get it mounted.

The following is from the udevmonitor program running under 2.6.18-rc
built modular.

Plugging device in with sd_mod not loaded.

UEVENT[1154789226.207797] add@/devices/pci0000:00/0000:00:11.2/usb1/1-2
UEVENT[1154789226.207985]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/usbdev1.11_ep00
UEVENT[1154789226.210770]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/1-2:1.0
UDEV [1154789226.210770] add@/devices/pci0000:00/0000:00:11.2/usb1/1-2
UEVENT[1154789226.211037] add@/class/scsi_host/host9
UEVENT[1154789226.211097]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/1-2:1.0/usbdev1.11_ep81
UEVENT[1154789226.211157]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/1-2:1.0/usbdev1.11_ep02
UEVENT[1154789226.211215]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/usbdev1.11
UDEV [1154789226.211690]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/usbdev1.11_ep00
UDEV [1154789226.452013]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/usbdev1.11
UDEV [1154789226.956997]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/1-2:1.0
UDEV [1154789226.959419]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/1-2:1.0/usbdev1.11_ep81
UDEV [1154789226.959466]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/1-2:1.0/usbdev1.11_ep02
UDEV [1154789226.959875] add@/class/scsi_host/host9
UEVENT[1154789231.647515]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/1-2:1.0/host9/target9:0:0/9:0:0:0
UDEV [1154789231.647515]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/1-2:1.0/host9/target9:0:0/9:0:0:0
UEVENT[1154789231.647570] add@/class/scsi_device/9:0:0:0
UEVENT[1154789231.749919] add@/module/sd_mod
UEVENT[1154789231.751494] add@/bus/scsi/drivers/sd
UEVENT[1154789231.752839] add@/class/scsi_disk/9:0:0:0
UDEV [1154789231.753751] add@/class/scsi_disk/9:0:0:0
UEVENT[1154789231.832312] add@/block/sda
UEVENT[1154789231.834681] add@/block/sda/sda1
UDEV [1154789231.836590] add@/class/scsi_device/9:0:0:0
UDEV [1154789231.933474] add@/block/sda
UDEV [1154789232.106892] add@/block/sda/sda1
UEVENT[1154789235.937510] mount@/block/sda/sda1
UDEV [1154789235.937510] mount@/block/sda/sda1


Plugging device in with sd_mod loaded.

UEVENT[1154789359.096963] add@/devices/pci0000:00/0000:00:11.2/usb1/1-2
UDEV [1154789359.096963] add@/devices/pci0000:00/0000:00:11.2/usb1/1-2
UEVENT[1154789359.097052]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/usbdev1.12_ep00
UDEV [1154789359.098126]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/usbdev1.12_ep00
UEVENT[1154789359.100369]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/1-2:1.0
UEVENT[1154789359.100418] add@/class/scsi_host/host10
UEVENT[1154789359.100427]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/1-2:1.0/usbdev1.12_ep81
UEVENT[1154789359.100435]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/1-2:1.0/usbdev1.12_ep02
UEVENT[1154789359.100444]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/usbdev1.12
UDEV [1154789359.106148]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/usbdev1.12
UDEV [1154789359.187500]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/1-2:1.0
UDEV [1154789359.189198] add@/class/scsi_host/host10
UDEV [1154789359.190078]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/1-2:1.0/usbdev1.12_ep81
UDEV [1154789359.191020]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/1-2:1.0/usbdev1.12_ep02
UEVENT[1154789364.540249]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/1-2:1.0/host10/target10:0:0/10:0:0:0
UDEV [1154789364.540249]
add@/devices/pci0000:00/0000:00:11.2/usb1/1-2/1-2:1.0/host10/target10:0:0/10:0:0:0
UEVENT[1154789364.540355] add@/class/scsi_disk/10:0:0:0
UDEV [1154789364.541272] add@/class/scsi_disk/10:0:0:0
UEVENT[1154789364.586896] add@/block/sda
UEVENT[1154789364.586954] add@/block/sda/sda1
UEVENT[1154789364.586963] add@/class/scsi_device/10:0:0:0
UDEV [1154789364.598962] add@/class/scsi_device/10:0:0:0
UDEV [1154789364.719350] add@/block/sda
UDEV [1154789364.874149] add@/block/sda/sda1


No mount events here, this is similar output to the non-modular case..


Here's udevmonitor output from my x86-64 FC5 2.6.18-rc[23]

UEVENT[1154510664.116702] add@/devices/pci0000:00/0000:00:10.4/usb1/1-8
UEVENT[1154510664.116905]
add@/devices/pci0000:00/0000:00:10.4/usb1/1-8/usbdev1.12_ep00
UEVENT[1154510664.116911]
add@/devices/pci0000:00/0000:00:10.4/usb1/1-8/1-8:1.0
UEVENT[1154510664.116915] add@/class/scsi_host/host12
UEVENT[1154510664.116919]
add@/devices/pci0000:00/0000:00:10.4/usb1/1-8/1-8:1.0/usbdev1.12_ep81
UEVENT[1154510664.116924]
add@/devices/pci0000:00/0000:00:10.4/usb1/1-8/1-8:1.0/usbdev1.12_ep02
UEVENT[1154510664.116928]
add@/devices/pci0000:00/0000:00:10.4/usb1/1-8/1-8:1.0/usbdev1.12_ep83
UEVENT[1154510664.116932]
add@/devices/pci0000:00/0000:00:10.4/usb1/1-8/usbdev1.12
UDEV [1154510664.200847] add@/devices/pci0000:00/0000:00:10.4/usb1/1-8
UDEV [1154510664.364513]
add@/devices/pci0000:00/0000:00:10.4/usb1/1-8/usbdev1.12_ep00
UDEV [1154510664.371420]
add@/devices/pci0000:00/0000:00:10.4/usb1/1-8/usbdev1.12
UDEV [1154510664.631746]
add@/devices/pci0000:00/0000:00:10.4/usb1/1-8/1-8:1.0
UDEV [1154510664.652152] add@/class/scsi_host/host12
UDEV [1154510664.776377]
add@/devices/pci0000:00/0000:00:10.4/usb1/1-8/1-8:1.0/usbdev1.12_ep81
UDEV [1154510664.785827]
add@/devices/pci0000:00/0000:00:10.4/usb1/1-8/1-8:1.0/usbdev1.12_ep02
UDEV [1154510664.795277]
add@/devices/pci0000:00/0000:00:10.4/usb1/1-8/1-8:1.0/usbdev1.12_ep83
UEVENT[1154510669.116889]
add@/devices/pci0000:00/0000:00:10.4/usb1/1-8/1-8:1.0/host12/target12:0:0/12:0:0:0
UEVENT[1154510669.116915] add@/class/scsi_disk/12:0:0:0
UDEV [1154510669.118308]
add@/devices/pci0000:00/0000:00:10.4/usb1/1-8/1-8:1.0/host12/target12:0:0/12:0:0:0
UDEV [1154510669.136236] add@/class/scsi_disk/12:0:0:0
UEVENT[1154510670.246094] add@/block/sdb
UEVENT[1154510670.246115] add@/block/sdb/sdb1
UEVENT[1154510670.246119] add@/class/scsi_device/12:0:0:0
UDEV [1154510670.250690] add@/class/scsi_device/12:0:0:0
UDEV [1154510670.383650] add@/block/sdb
UDEV [1154510670.555570] add@/block/sdb/sdb1
UEVENT[1154510671.433544] mount@/block/sdb/sdb1
UDEV [1154510671.434129] mount@/block/sdb/sdb1


I guess the next thing is to try and narrow down when this started, but
as that could take some time, I'm posting this now.


Cheers,

Andrew


2006-08-08 06:04:14

by Greg KH

[permalink] [raw]
Subject: Re: 2.6.18-rc strange hotplug/udev/uevent problem

On Mon, Aug 07, 2006 at 08:33:08PM +0100, Andrew Clayton wrote:
> Hi,
>
> Got a weird problem here.
>
> On x86 Fedora Core 5 with 2.6.17 with GNOME, plugging in a usb stick
> would result in it being mounted. With 2.6.18-rc this no longer occurs.
> FC5 got an update to hal to work with 2.6.18 kernels, but it don't work
> for me. I'm having the same problem on 3 x86 FC5 machines.
>
> The weird thing is, this all works on my x86-64 FC5 workstation with
> 2.6.18-rc both before and after the hal update.
>
> Anyway I submitted a bug report against HAL suspecting it broken
>
> https://bugs.freedesktop.org/show_bug.cgi?id=7756
>
> Perhaps not. So I turn my attention more to the kernel.
>
>
> 2.6.17 was working fine. You could plug/unplug/plug a USB memory stick
> and it would get mounted each time.
>
> 2.6.18-rc[23] works the same as above on my x86-64 FC5 box.
>
> 2.6.18-rc[23] and 2.6.18-rc3-git7 on x86 built with
> usb/scsi/sd/vfat/nls_* built as modules will mount on the first plug but
> not subsequent plugs.
>
> If you rmmod the sd_mod module and plug in, then it will get mounted.

That's just wierd. I can't think of anything that has changed recently
to cause this.

Can you use 'git bisect' to try to narrow it down which change caused
the problem?

thansk,

greg k-h

2006-08-08 09:14:44

by Andrew Clayton

[permalink] [raw]
Subject: Re: 2.6.18-rc strange hotplug/udev/uevent problem

On Mon, 7 Aug 2006 23:02:11 -0700, Greg KH wrote:

> On Mon, Aug 07, 2006 at 08:33:08PM +0100, Andrew Clayton wrote:
> > plug but not subsequent plugs.
> >
> > If you rmmod the sd_mod module and plug in, then it will get
> > mounted.
>
> That's just wierd. I can't think of anything that has changed

Heh, yeah I thought so.

> recently to cause this.
>
> Can you use 'git bisect' to try to narrow it down which change caused
> the problem?

Yeah, I'll start looking tonight.

> thansk,
>
> greg k-h


Cheers,

Andrew

2006-08-08 21:33:25

by Andrew Clayton

[permalink] [raw]
Subject: Re: 2.6.18-rc strange hotplug/udev/uevent problem

On Mon, 7 Aug 2006 23:02:11 -0700, Greg KH wrote:

> On Mon, Aug 07, 2006 at 08:33:08PM +0100, Andrew Clayton wrote:

> > If you rmmod the sd_mod module and plug in, then it will get
> > mounted.
>
> That's just wierd. I can't think of anything that has changed
> recently to cause this.
>
> Can you use 'git bisect' to try to narrow it down which change caused
> the problem?

I've done a binary search of kernels and found that the breakage occurs
between 2.6.17-git3 and 2.6.17-git4

Next I'll figure out git bisect to try and narrow it further.

> thansk,
>
> greg k-h


Cheers,

Andrew

2006-08-09 00:41:07

by Andrew Clayton

[permalink] [raw]
Subject: Re: 2.6.18-rc strange hotplug/udev/uevent problem

On Mon, 7 Aug 2006 23:02:11 -0700, Greg KH wrote:

> Can you use 'git bisect' to try to narrow it down which change caused
> the problem?

I did

git bisect start drivers/scsi drivers/usb
git bad v2.6.18-rc1
git good v2.6.17

Heres what git bisect came up with

c32ba30f76eb18b3d4449072fe9c345a9574796b is first bad commit
commit c32ba30f76eb18b3d4449072fe9c345a9574796b
Author: Paul Serice <[email protected]>
Date: Wed Jun 7 10:23:38 2006 -0700

[PATCH] USB: EHCI works again on NVidia controllers with >2GB RAM

From: Paul Serice <[email protected]>

The workaround in commit f7201c3dcd7799f2aa3d6ec427b194225360ecee
broke. The work around requires memory for DMA transfers for some
NVidia EHCI controllers to be below 2GB, but recent changes have
caused some DMA memory to be allocated before the DMA mask is set.

Signed-off-by: Paul Serice <[email protected]>
Signed-off-by: David Brownell <[email protected]>
Signed-off-by: Greg Kroah-Hartman <[email protected]>

:040000 040000 754a9f8cccedc71e8e3689f2b0dee811d94fdc11 5559c0eafe042377430052272d027f0458805126 M drivers


What would be the way to revert that patch from 2.6.18-rc4 to confirm it's the culprit?

Heres the output from git bisect log

git-bisect start 'drivers/scsi' 'drivers/usb'
# bad: [7df8ea909888d4856d3aff1c41192739d715a393] Linux 2.6.18-rc1
git-bisect bad 7df8ea909888d4856d3aff1c41192739d715a393
# good: [8ba130df4b67fa40878ccf80d54615132d24bc68] Linux v2.6.17
git-bisect good 8ba130df4b67fa40878ccf80d54615132d24bc68
# good: [d7a80dad2fe19a2b8c119c8e9cba605474a75a2b] libata: convert several bmdma-style controllers to new EH, take #3
git-bisect good d7a80dad2fe19a2b8c119c8e9cba605474a75a2b
# bad: [d5681fe8110e1169902df37a8fd8bd01c2b7810e] USB: unusual_devs entry for Nokia N80
git-bisect bad d5681fe8110e1169902df37a8fd8bd01c2b7810e
# bad: [7327413c745c2f8e8d4b92f76759821263b095c1] USB: added support for ASIX 88178 chipset USB Gigabit Ethernet adaptor
git-bisect bad 7327413c745c2f8e8d4b92f76759821263b095c1
# good: [cb63067a772c0149184309a1f232d62c81a93673] [SCSI] qla2xxx: Consolidate "qla2xxx" string usage to a #define.
git-bisect good cb63067a772c0149184309a1f232d62c81a93673
# good: [beb40487508290f5d6565598c60a3f44261beef2] [SCSI] remove scsi_request infrastructure
git-bisect good beb40487508290f5d6565598c60a3f44261beef2
# good: [67d59dfdeb21df2c16dcd478b66177e91178ecd0] [SCSI] 53c700: remove reliance on deprecated cmnd fields
git-bisect good 67d59dfdeb21df2c16dcd478b66177e91178ecd0
# good: [c6387a48cf5958e43c201fc27a158c328927531a] [SPARC]: Kill __irq_itoa().
git-bisect good c6387a48cf5958e43c201fc27a158c328927531a
# bad: [5cd330f4f30eb154e7af9210bed42dfcd447997f] USB: add YEALINK phones to the HID_QUIRK_IGNORE blacklist
git-bisect bad 5cd330f4f30eb154e7af9210bed42dfcd447997f
# bad: [c32ba30f76eb18b3d4449072fe9c345a9574796b] USB: EHCI works again on NVidia controllers with >2GB RAM
git-bisect bad c32ba30f76eb18b3d4449072fe9c345a9574796b
# good: [28e4b224955cbe30275b2a7842e729023a4f4b03] Merge master.kernel.org:/pub/scm/linux/kernel/git/jejb/scsi-misc-2.6
git-bisect good 28e4b224955cbe30275b2a7842e729023a4f4b03

> thansk,
>
> greg k-h


Cheers,

Andrew

2006-08-09 07:54:22

by Andrew Morton

[permalink] [raw]
Subject: Re: 2.6.18-rc strange hotplug/udev/uevent problem

On Wed, 9 Aug 2006 01:41:04 +0100
Andrew Clayton <[email protected]> wrote:

> On Mon, 7 Aug 2006 23:02:11 -0700, Greg KH wrote:
>
> > Can you use 'git bisect' to try to narrow it down which change caused
> > the problem?
>
> I did
>
> git bisect start drivers/scsi drivers/usb
> git bad v2.6.18-rc1
> git good v2.6.17
>
> Heres what git bisect came up with
>
> c32ba30f76eb18b3d4449072fe9c345a9574796b is first bad commit
> commit c32ba30f76eb18b3d4449072fe9c345a9574796b
> Author: Paul Serice <[email protected]>
> Date: Wed Jun 7 10:23:38 2006 -0700
>
> [PATCH] USB: EHCI works again on NVidia controllers with >2GB RAM
>
> From: Paul Serice <[email protected]>
>
> The workaround in commit f7201c3dcd7799f2aa3d6ec427b194225360ecee
> broke. The work around requires memory for DMA transfers for some
> NVidia EHCI controllers to be below 2GB, but recent changes have
> caused some DMA memory to be allocated before the DMA mask is set.
>
> Signed-off-by: Paul Serice <[email protected]>
> Signed-off-by: David Brownell <[email protected]>
> Signed-off-by: Greg Kroah-Hartman <[email protected]>
>
> :040000 040000 754a9f8cccedc71e8e3689f2b0dee811d94fdc11 5559c0eafe042377430052272d027f0458805126 M drivers
>
>
> What would be the way to revert that patch from 2.6.18-rc4 to confirm it's the culprit?
>

Here's a backout patch, against 2.6.18-rc4:

From: Andrew Morton <[email protected]>

Revert c32ba30f76eb18b3d4449072fe9c345a9574796b: it broke Andrew Clayton's
machine.

Cc: Andrew Clayton <[email protected]>
Cc: Paul Serice <[email protected]>
Cc: David Brownell <[email protected]>
Cc: Greg Kroah-Hartman <[email protected]>
Signed-off-by: Andrew Morton <[email protected]>
---

drivers/usb/host/ehci-pci.c | 39 +++++++++++++---------------------
1 file changed, 15 insertions(+), 24 deletions(-)

diff -puN drivers/usb/host/ehci-pci.c~revert-usb-ehci-works-again-on-nvidia-controllers-with-2gb-ram drivers/usb/host/ehci-pci.c
--- a/drivers/usb/host/ehci-pci.c~revert-usb-ehci-works-again-on-nvidia-controllers-with-2gb-ram
+++ a/drivers/usb/host/ehci-pci.c
@@ -76,30 +76,6 @@ static int ehci_pci_setup(struct usb_hcd
dbg_hcs_params(ehci, "reset");
dbg_hcc_params(ehci, "reset");

- /* ehci_init() causes memory for DMA transfers to be
- * allocated. Thus, any vendor-specific workarounds based on
- * limiting the type of memory used for DMA transfers must
- * happen before ehci_init() is called. */
- switch (pdev->vendor) {
- case PCI_VENDOR_ID_NVIDIA:
- /* NVidia reports that certain chips don't handle
- * QH, ITD, or SITD addresses above 2GB. (But TD,
- * data buffer, and periodic schedule are normal.)
- */
- switch (pdev->device) {
- case 0x003c: /* MCP04 */
- case 0x005b: /* CK804 */
- case 0x00d8: /* CK8 */
- case 0x00e8: /* CK8S */
- if (pci_set_consistent_dma_mask(pdev,
- DMA_31BIT_MASK) < 0)
- ehci_warn(ehci, "can't enable NVidia "
- "workaround for >2GB RAM\n");
- break;
- }
- break;
- }
-
/* cache this readonly data; minimize chip reads */
ehci->hcs_params = readl(&ehci->caps->hcs_params);

@@ -112,6 +88,8 @@ static int ehci_pci_setup(struct usb_hcd
if (retval)
return retval;

+ /* NOTE: only the parts below this line are PCI-specific */
+
switch (pdev->vendor) {
case PCI_VENDOR_ID_TDI:
if (pdev->device == PCI_DEVICE_ID_TDI_EHCI) {
@@ -129,6 +107,19 @@ static int ehci_pci_setup(struct usb_hcd
break;
case PCI_VENDOR_ID_NVIDIA:
switch (pdev->device) {
+ /* NVidia reports that certain chips don't handle
+ * QH, ITD, or SITD addresses above 2GB. (But TD,
+ * data buffer, and periodic schedule are normal.)
+ */
+ case 0x003c: /* MCP04 */
+ case 0x005b: /* CK804 */
+ case 0x00d8: /* CK8 */
+ case 0x00e8: /* CK8S */
+ if (pci_set_consistent_dma_mask(pdev,
+ DMA_31BIT_MASK) < 0)
+ ehci_warn(ehci, "can't enable NVidia "
+ "workaround for >2GB RAM\n");
+ break;
/* Some NForce2 chips have problems with selective suspend;
* fixed in newer silicon.
*/
_