fastboot: usbmon WARNING

From: Alan Jenkins
Date: Wed Sep 24 2008 - 06:41:59 EST


Arjan van de Ven wrote:
> The fastboot.git tree has a set of patches (all posted and reviewed on lkml before)
> that speed up the kernel boot process of the kernel.
>
> There's 3 major pieces of this
> 1) The creation of an asynchronous initcall level (6a) that runs asynchronous from
> the regular driver init, and is for non-boot critical initcalls only
> 2) A rework of the non-initrd boot code to try mounting /, and if that fails,
> only THEN wait for all the various driver probings to finish (and then retry)
> 3) A tool "bootgraph.pl" that outputs a SVG graphic of where the kernel boot spends
> its time

Enabling fastboot makes usbmon (CONFIG_USB_MON) squawk, trying to create duplicate sysfs files.

I see mon_init is run in parallel with uhci_hcd_init (see attached bootgraph.pl output). Maybe it would go away if mon_init was also moved to the asynchronous runlevel - it should be non-boot critical.

And maybe this was a latent bug that needs fixing regardless.

Yours
Alan

[ 1.030041] usb 1-8: new high speed USB device using ehci_hcd and address 3
[ 1.030359] uhci_hcd 0000:00:1d.0: PCI INT A -> Link[LNKH] -> GSI 3 (level, low) -> IRQ 3
[ 1.030512] uhci_hcd 0000:00:1d.0: setting latency timer to 64
[ 1.030522] uhci_hcd 0000:00:1d.0: UHCI Host Controller
[ 1.030736] initcall piix_init+0x0/0x20 returned 0 after 525 msecs
[ 1.030844] calling mon_init+0x0/0xd1 @ 1
[ 1.031038] uhci_hcd 0000:00:1d.0: new USB bus registered, assigned bus number 2
[ 1.031218] uhci_hcd 0000:00:1d.0: irq 3, io base 0x0000e400
[ 1.031731] usb usb2: configuration #1 chosen from 1 choice
[ 1.031997] hub 2-0:1.0: USB hub found
[ 1.032109] hub 2-0:1.0: 2 ports detected
[ 1.133721] uhci_hcd 0000:00:1d.1: PCI INT B -> Link[LNKD] -> GSI 7 (level, low) -> IRQ 7
[ 1.133871] uhci_hcd 0000:00:1d.1: setting latency timer to 64
[ 1.133879] uhci_hcd 0000:00:1d.1: UHCI Host Controller
[ 1.134224] ------------[ cut here ]------------
[ 1.134320] WARNING: at fs/sysfs/dir.c:463 sysfs_add_one+0x27/0x2f()
[ 1.134422] sysfs: duplicate filename 'usbmon3' can not be created
[ 1.134522] Modules linked in:
[ 1.134656] Pid: 1, comm: swapper Not tainted 2.6.27-rc6eeepc #30
[ 1.134760] [<c0119215>] warn_slowpath+0x61/0x85
[ 1.134908] [<c01ae295>] number+0x13d/0x217
[ 1.135050] [<c0114819>] __dequeue_entity+0x1f/0x71
[ 1.135197] [<c01aacd0>] idr_get_empty_slot+0x122/0x1e6
[ 1.135341] [<c01aae63>] ida_get_new_above+0xcf/0x148
[ 1.135483] [<c018cf4e>] sysfs_new_dirent+0x24/0xc7
[ 1.135625] [<c018cc1f>] sysfs_ilookup_test+0x0/0xd
[ 1.135769] [<c016c9e2>] ifind+0xa/0x49
[ 1.135909] [<c018ce10>] sysfs_find_dirent+0x13/0x23
[ 1.136052] [<c018cea2>] sysfs_add_one+0x27/0x2f
[ 1.136193] [<c018d279>] create_dir+0x3c/0x6b
[ 1.136332] [<c018d2d1>] sysfs_create_dir+0x29/0x3b
[ 1.136474] [<c01ab6a8>] kobject_get+0xf/0x13
[ 1.136613] [<c01ab787>] kobject_add_internal+0x9b/0x134
[ 1.136777] [<c01abb0d>] kobject_add+0x4a/0x4e
[ 1.136916] [<c01fa6a0>] device_add+0x75/0x4b6
[ 1.137058] [<c01fa3ec>] device_initialize+0x77/0x9f
[ 1.137199] [<c01fab69>] device_create_vargs+0x78/0x99
[ 1.137342] [<c03da27c>] mon_init+0x0/0xd1
[ 1.137484] [<c01fabae>] device_create+0x24/0x28
[ 1.137625] [<c022e2a8>] mon_bin_add+0x3b/0x54
[ 1.137769] [<c022c69b>] mon_bus_init+0x45/0x77
[ 1.137909] [<c03da30d>] mon_init+0x91/0xd1
[ 1.138047] [<c010112b>] _stext+0x43/0x111
[ 1.138188] [<c0113c00>] __sched_fork+0x4b/0x6f
[ 1.138329] [<c011671e>] __wake_up+0xf/0x15
[ 1.138469] [<c0124298>] insert_work+0x40/0x44
[ 1.138611] [<c03c2719>] kernel_init+0xcb/0x12e
[ 1.138757] [<c03c264e>] kernel_init+0x0/0x12e
[ 1.138895] [<c010415f>] kernel_thread_helper+0x7/0x10
[ 1.139040] =======================
[ 1.139142] ---[ end trace 32b8bb2cd8e5acac ]---
[ 1.139240] kobject_add_internal failed for usbmon3 with -EEXIST, don't try to register things with the same name in the same directory.
[ 1.139401] Pid: 1, comm: swapper Tainted: G W 2.6.27-rc6eeepc #30
[ 1.139504] [<c01ab7ea>] kobject_add_internal+0xfe/0x134
[ 1.139650] [<c01abb0d>] kobject_add+0x4a/0x4e
[ 1.139789] [<c01fa6a0>] device_add+0x75/0x4b6
[ 1.139928] [<c01fa3ec>] device_initialize+0x77/0x9f
[ 1.140077] [<c01fab69>] device_create_vargs+0x78/0x99
[ 1.140219] [<c03da27c>] mon_init+0x0/0xd1
[ 1.140357] [<c01fabae>] device_create+0x24/0x28
[ 1.140497] [<c022e2a8>] mon_bin_add+0x3b/0x54
[ 1.140637] [<c022c69b>] mon_bus_init+0x45/0x77
[ 1.140777] [<c03da30d>] mon_init+0x91/0xd1
[ 1.140916] [<c010112b>] _stext+0x43/0x111
[ 1.141053] [<c0113c00>] __sched_fork+0x4b/0x6f
[ 1.141193] [<c011671e>] __wake_up+0xf/0x15
[ 1.141333] [<c0124298>] insert_work+0x40/0x44
[ 1.141473] [<c03c2719>] kernel_init+0xcb/0x12e
[ 1.141612] [<c03c264e>] kernel_init+0x0/0x12e
[ 1.141751] [<c010415f>] kernel_thread_helper+0x7/0x10
[ 1.141893] =======================
[ 1.142142] uhci_hcd 0000:00:1d.1: new USB bus registered, assigned bus number 3
[ 1.142334] uhci_hcd 0000:00:1d.1: irq 7, io base 0x0000e480
[ 1.142699] initcall mon_init+0x0/0xd1 returned 0 after 106 msecs


image/svg