Bug #2244

usb - system hangs during boot when USB mass storage device/stick is connected - 2.13.0.357.gcdb8af

Added by ak almost 3 years ago. Updated almost 3 years ago.

Status:NewStart date:11/22/2011
Priority:NormalDue date:
Assignee:-% Done:

0%

Category:-
Target version:-

Description

Versions:

Workstation: Lenovo Thinkcentre M58p
DragonFlyBSD: v2.13.0.357.gcdb8af-DEVELOPMENT X86_64_GENERIC x86_64

################

Problem Description:

My system hangs during boot if a USB mass storage device/stick is connected.
By hang I mean no more output is shown and I cannot turn off/on num lock key on keyboard.
A hard reset is needed at this stage.

This prevents me from installing DragonFlyBSD from a USB stick.

I first noticed the problem when trying to boot via USB using the 2011 Nov 17th "DragonFly-x86_64-LATEST-IMG.img".
I haven't tried older versions.

I can connect and use the USB mass storage device/stick after boot without problem, and shutdown while attached without problem.

################

I recompiled kernel with "options USB_DEBUG" and booted with verbose logging option.
The last lines shown are:

uhci1: <UHCI (generic) USB controller> [tentative] port 0x1860-0x187f irq 17 at device 26.1 on pci0
uhci1: Reserved 0x20 bytes for rid 0x20 type 4 at 0x1860
uhci1: LegSup = 0x0010

################

From pciconf -lv:

uhci0@pci0:0:26:0: class=0x0c0300 card=0x304817aa chip=0x3a678086 rev=0x02 hdr=0x00
vendor = 'Intel Corporation'
device = 'USB UHCI Controller'
class = serial bus
subclass = USB
uhci1@pci0:0:26:1: class=0x0c0300 card=0x304817aa chip=0x3a688086 rev=0x02 hdr=0x00
vendor = 'Intel Corporation'
device = 'USB UHCI Controller'
class = serial bus
subclass = USB

################

I put kprintf's in various kernel source files to find where it hangs.
(Please note that I do not know anything about the kernel and very little about C).
This is what I found:

Function "uhci_pci_attach(device_t self)" is called from /usr/src/sys/bus/usb/uhci_pci.c

uhci_pci_attach() calls "err = uhci_init(sc);" which is in /usr/src/sys/bus/usb/uhci.c

uhci_init() calls "uhci_globalreset(sc);" which is in /usr/src/sys/bus/usb/uhci.c

uhci_globalreset() calls "usb_delay_ms(&sc->sc_bus, USB_BUS_RESET_DELAY);" which is in /usr/src/sys/bus/usb/usb_subr.c

usb_delay_ms calls "delay((ms+1) * 1000);" with value 101000 (ms is 100).

...
...

It appears that "delay((ms+1) * 1000);" never returns. I think this because I have a kprintf() after the delay().

delay() is defined as DELAY in /usr/src/sys/bus/usb/usb_subr.c.
DELAY is defined in sys/systm.h but I cannot find the source file containing the DELAY function.

################

/usr/src/sys/bus/usb/usb_subr.c with the extra kprintfs:

/* Delay for a certain number of ms */
void
usb_delay_ms(usbd_bus_handle bus, u_int ms)
{
kprintf("AK: at start of function usb_delay_ms\n");

/* Wait at least two clock ticks so we know the time has passed. */
if (bus->use_polling || cold) {
kprintf("AK: usb_delay_ms: in if cold and calling delay.\nAK: Value of ms after math: %d\n", (ms+1)*1000);
delay((ms+1) * 1000);
kprintf("AK: usb_delay_ms: finished delay\n");
}
else {
kprintf("AK: usb_delay_ms: in else about about to do tsleep\n");
tsleep(&ms, 0, "usbdly", (ms*hz+999)/1000 + 1);
}

kprintf("AK: at end of usb_delay_ms\n");
}

################

Attached dmesg and messages files taken after verbose boot without the usb stick attached.

messages (207 KB) ak, 11/22/2011 05:33 PM

dmesg (125 KB) ak, 11/22/2011 05:33 PM

History

#1 Updated by ak almost 3 years ago

I got abit further with the kprintf's though not sure if its helpful!

"usb_delay_ms(&sc->sc_bus, USB_BUS_RESET_DELAY);" is in /usr/src/sys/bus/usb/usb_subr.c

usb_delay_ms() calls "delay((ms+1) * 1000);" with value 101000 (ms is 100).

delay() is defined as DELAY in /usr/src/sys/bus/usb/usb_subr.c

"DELAY(int n)" is in /usr/src/sys/platform/pc64/isa/clock.c

DELAY() calls "DODELAY(n, 0);" which is in /usr/src/sys/platform/pc64/isa/clock.c

while loop is entered: "while "(ticks_left > 0)"

Lots of "cpu_pause()"'s are done. Finally one of these calls does not return.

The last line printed on screen is:
"AK: calling cpu_pause. ticks_left: 1151353"

################

The while loop from "DODELAY(int n, int doswitch)" in /usr/src/sys/platform/pc64/isa/clock.c :

/*
* Loop until done.
*/
kprintf("AK: DODELAY: Loop until done.\n");
while (ticks_left > 0) {
tick = sys_cputimer->count();
#ifdef DELAYDEBUG
++getit_calls;
#endif
delta = tick - prev_tick;
prev_tick = tick;
if (delta < 0)
delta = 0;
ticks_left -= delta;
if (doswitch && ticks_left > 0) {
kprintf("AK: calling lwkt_switch\n");
lwkt_switch();
}

kprintf("AK: calling cpu_pause. ticks_left: %d\n", ticks_left);

cpu_pause();

kprintf("AK: just after cpu_pause. ticks_left: %d\n", ticks_left);
}

kprintf("AK: just finished while loop\n");

#2 Updated by ak almost 3 years ago

I did a few more restarts. Sometimes it hangs after the cpu_pause i.e. outputs "AK: just after cpu_pause. ticks_left 1161010" with a gray cursor at the bottom left corner of the screen.

And sometimes it hangs in the middle of showing the output from "kprintf("AK: just after cpu_pause. ticks_left: %d\n", ticks_left)"
i.e. it outputs "AK: just after cpu_p" with a gray cursor at the end.

cdrom eject button works fine when in this hung state.

#3 Updated by ak almost 3 years ago

I tested with dfly-x86_64-2.12.0_RC.img. It doesn't have the problem.

This led me to test different stages of the master branch.

The problem appears to first start with commit 7e370202e053de3ef8357ef02e8b6f1e97694f97

The problem does not occur before that commit (i.e. with 95874ffdec65823430464b7869d8f0acf75cc226 or older).

##########

http://gitweb.dragonflybsd.org/dragonfly.git/commit/7e370202e053de3ef8357ef02e8b6f1e97694f97

x86_64/nexus: Per-cpu IRQ rman

Now interrupt thread will be pin to the same CPU as where its GSI
will go.sys/platform/pc64/x86_64/nexus.c

#4 Updated by sepherosa almost 3 years ago

On Fri, Nov 25, 2011 at 8:24 AM, Alan K via Redmine
<> wrote:
>
> Issue #2244 has been updated by Alan K.
>
>
> I tested with dfly-x86_64-2.12.0_RC.img. It doesn't have the problem.
>
> This led me to test different stages of the master branch.
>
> The problem appears to first start with commit 7e370202e053de3ef8357ef02e8b6f1e97694f97
>
> The problem does not occur before that commit (i.e. with 95874ffdec65823430464b7869d8f0acf75cc226 or older).
>
> ##########
>
> http://gitweb.dragonflybsd.org/dragonfly.git/commit/7e370202e053de3ef8357ef02e8b6f1e97694f97
>
> x86_64/nexus: Per-cpu IRQ rman
>
>  Now interrupt thread will be pin to the same CPU as where its GSI
>  will go.sys/platform/pc64/x86_64/nexus.c
> ----------------------------------------
> Bug #2244: usb - system hangs during boot when USB mass storage device/stick is connected - 2.13.0.357.gcdb8af
> http://bugs.dragonflybsd.org/issues/2244

Please test the master:
2b195d6a566cb8441f5d6d66363235683bbd92af

>
> Author: Alan K
> Status: New
> Priority: Normal
> Assignee:
> Category:
> Target version:
>
>
> Versions:
>
> Workstation: Lenovo Thinkcentre M58p
> DragonFlyBSD: v2.13.0.357.gcdb8af-DEVELOPMENT X86_64_GENERIC x86_64
>
> ################
>
> Problem Description:
>
> My system hangs during boot if a USB mass storage device/stick is connected.
> By hang I mean no more output is shown and I cannot turn off/on num lock key on keyboard.
> A hard reset is needed at this stage.
>
> This prevents me from installing DragonFlyBSD from a USB stick.
>
> I first noticed the problem when trying to boot via USB using the 2011 Nov 17th "DragonFly-x86_64-LATEST-IMG.img".
> I haven't tried older versions.
>
> I can connect and use the USB mass storage device/stick after boot without problem, and shutdown while attached without problem.
>
> ################
>
> I recompiled kernel with "options USB_DEBUG" and booted with verbose logging option.
> The last lines shown are:
>
> uhci1: <UHCI (generic) USB controller> [tentative] port 0x1860-0x187f irq 17 at device 26.1 on pci0
> uhci1: Reserved 0x20 bytes for rid 0x20 type 4 at 0x1860
> uhci1: LegSup = 0x0010
>
> ################
>
> From pciconf -lv:
>
> uhci0@pci0:0:26:0:      class=0x0c0300 card=0x304817aa chip=0x3a678086 rev=0x02 hdr=0x00
>    vendor     = 'Intel Corporation'
>    device     = 'USB UHCI Controller'
>    class      = serial bus
>    subclass   = USB
> uhci1@pci0:0:26:1:      class=0x0c0300 card=0x304817aa chip=0x3a688086 rev=0x02 hdr=0x00
>    vendor     = 'Intel Corporation'
>    device     = 'USB UHCI Controller'
>    class      = serial bus
>    subclass   = USB
>
> ################
>
> I put kprintf's in various kernel source files to find where it hangs.
> (Please note that I do not know anything about the kernel and very little about C).
> This is what I found:
>
> Function "uhci_pci_attach(device_t self)" is called from /usr/src/sys/bus/usb/uhci_pci.c
>
> uhci_pci_attach() calls "err = uhci_init(sc);" which is in /usr/src/sys/bus/usb/uhci.c
>
> uhci_init() calls "uhci_globalreset(sc);" which is in /usr/src/sys/bus/usb/uhci.c
>
> uhci_globalreset() calls "usb_delay_ms(&sc->sc_bus, USB_BUS_RESET_DELAY);" which is in /usr/src/sys/bus/usb/usb_subr.c
>
> usb_delay_ms calls "delay((ms+1) * 1000);" with value 101000 (ms is 100).
>
> ...
> ...
>
> It appears that "delay((ms+1) * 1000);" never returns. I think this because I have a kprintf() after the delay().
>
> delay() is defined as DELAY in /usr/src/sys/bus/usb/usb_subr.c.
> DELAY is defined in sys/systm.h but I cannot find the source file containing the DELAY function.
>
> ################
>
> /usr/src/sys/bus/usb/usb_subr.c with the extra kprintfs:
>
> /* Delay for a certain number of ms */
> void
> usb_delay_ms(usbd_bus_handle bus, u_int ms)
> {
>        kprintf("AK: at start of function usb_delay_ms\n");
>
>        /* Wait at least two clock ticks so we know the time has passed. */
>        if (bus->use_polling || cold) {
>                kprintf("AK: usb_delay_ms: in if cold and calling delay.\nAK: Value of ms after math: %d\n", (ms+1)*1000);
>                delay((ms+1) * 1000);
>                kprintf("AK: usb_delay_ms: finished delay\n");
>        }
>        else {
>                kprintf("AK: usb_delay_ms: in else about about to do tsleep\n");
>                tsleep(&ms, 0, "usbdly", (ms*hz+999)/1000 + 1);
>        }
>
>        kprintf("AK: at end of usb_delay_ms\n");
> }
>
> ################
>
> Attached dmesg and messages files taken after verbose boot without the usb stick attached.
>
>
>
> --
> You have received this notification because you have either subscribed to it, or are involved in it.
> To change your notification preferences, please click here: http://bugs.dragonflybsd.org/my/account
>

--
Tomorrow Will Never Die

#5 Updated by ak almost 3 years ago

> Please test the master:
> 2b195d6a566cb8441f5d6d66363235683bbd92af

It works - I can now boot with USB stick attached. Thanks!

Also available in: Atom PDF