Hans Petter Selasky
2017-Aug-07 16:10 UTC
[USB] hang after upgrade from 10.0 to 10.1, ZFS or callout() related?
On 08/07/17 17:59, Michael Schmiedgen wrote:> Hi list, > > after upgrading kernel from 11.0 to 11.1 the boot process stopped, > waiting forever for some USB stuff. I tried to skip waiting with > > hw.usb.no_boot_wait="1" > > in /boot/loader.conf but then I got a very strange ZFS 'mount error 5', > which I had some time ago upgrading from 10.0 to 10.1. That error did > magically went away with 11.0, and now it seems to pop up again: > > https://lists.freebsd.org/pipermail/freebsd-current/2014-October/052900.html > > > https://lists.freebsd.org/pipermail/freebsd-stable/2014-December/081192.html >Can you try getting the dmesg. You can also disable USB enumeration setting these: hw.usb.disable_enumeration: 0 dev.uhub.2.disable_enumeration: 0 dev.uhub.1.disable_enumeration: 0 dev.uhub.0.disable_enumeration: 0 Are you sure you loaded all drivers, like XHCI, EHCI, OHCI, UHCI ? DOes the BIOS offer any USB options? --HPS> > > So I reset the boot wait option to default again and switched on some USB > debug options: > > https://imgur.com/a/xzkrC > > > Anybody? Thanks, > Michael >
Michael Schmiedgen
2017-Aug-07 16:28 UTC
[USB] hang after upgrade from 11.0 to 11.1, ZFS or callout() related?
On 07.08.2017 18:10, Hans Petter Selasky wrote:> > Can you try getting the dmesg. > > You can also disable USB enumeration setting these: > > hw.usb.disable_enumeration: 0 > dev.uhub.2.disable_enumeration: 0 > dev.uhub.1.disable_enumeration: 0 > dev.uhub.0.disable_enumeration: 0 > > Are you sure you loaded all drivers, like XHCI, EHCI, OHCI, UHCI ? DOes the BIOS offer any USB options? >It is a generic 11.1 kernel. I already tried hw.usb.disable_enumeration="1" but that triggered the strange 'ZFS error 5'. Part of the debug dmesg with 11.0 kernel below. Thanks, Michael dmesg: Aug 7 18:26:34 antares kernel: usbd_pipe_enter: enter Aug 7 18:26:34 antares kernel: usbd_pipe_enter: enter Aug 7 18:26:34 antares kernel: usbd_pipe_start: start Aug 7 18:26:34 antares kernel: usbd_pipe_start: start Aug 7 18:26:34 antares kernel: usbd_transfer_done: err=USB_ERR_NORMAL_COMPLETION Aug 7 18:26:34 antares kernel: usbd_transfer_done: err=USB_ERR_NORMAL_COMPLETION Aug 7 18:26:34 antares kernel: usbd_callback_wrapper_sub: xfer=0xfffff80023165148 endpoint=0xfffff800231640d8 sts=0 alen=12, slen=12, afrm=2, nfrm=2 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=1 Aug 7 18:26:34 antares kernel: usbd_callback_wrapper_sub: xfer=0xfffff80023196148 endpoint=0xfffff8002318f0d8 sts=0 alen=12, slen=12, afrm=2, nfrm=2 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=1 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=0 Aug 7 18:26:34 antares kernel: usbd_transfer_submit: xfer=0xfffff80023165148, endpoint=0xfffff800231640d8, nframes=2, dir=read Aug 7 18:26:34 antares kernel: usb_dump_endpoint: endpoint=0xfffff800231640d8 edesc=0xfffff80023164720 isoc_next=0 toggle_next=0usbd_do_request_callback: st=0 Aug 7 18:26:34 antares kernel: bEndpointAddress=0x00usbd_transfer_submit: xfer=0xfffff80023196148, endpoint=0xfffff8002318f0d8, nframes=2, dir=read Aug 7 18:26:34 antares kernel: Aug 7 18:26:34 antares kernel: usb_dump_endpoint: endpoint=0xfffff8002318f0d8usb_dump_queue: endpoint=0xfffff800231640d8 xfer: edesc=0xfffff8002318f720 isoc_next=0 toggle_next=0 Aug 7 18:26:34 antares kernel: bEndpointAddress=0x00usbd_pipe_enter: enter Aug 7 18:26:34 antares kernel: Aug 7 18:26:34 antares kernel: usbd_pipe_start: start Aug 7 18:26:34 antares kernel: usb_dump_queue: endpoint=0xfffff8002318f0d8 xfer: Aug 7 18:26:34 antares kernel: usbd_pipe_enter: enter Aug 7 18:26:34 antares kernel: usbd_pipe_start: start Aug 7 18:26:34 antares kernel: usbd_transfer_done: err=USB_ERR_NORMAL_COMPLETION Aug 7 18:26:34 antares kernel: usbd_transfer_done: err=USB_ERR_NORMAL_COMPLETION Aug 7 18:26:34 antares kernel: usbd_callback_wrapper_sub: xfer=0xfffff80023196148 endpoint=0xfffff8002318f0d8 sts=0 alen=12, slen=12, afrm=2, nfrm=2 Aug 7 18:26:34 antares kernel: usbd_callback_wrapper_sub: xfer=0xfffff80023165148 endpoint=0xfffff800231640d8 sts=0 alen=12, slen=12, afrm=2, nfrm=2 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=1 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=1 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=0 Aug 7 18:26:34 antares kernel: usbd_transfer_submit: xfer=0xfffff80023165148, endpoint=0xfffff800231640d8, nframes=2, dir=read Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=0 Aug 7 18:26:34 antares kernel: usb_dump_endpoint: endpoint=0xfffff800231640d8usbd_transfer_submit: xfer=0xfffff80023196148, endpoint=0xfffff8002318f0d8, nframes=2, dir=read Aug 7 18:26:34 antares kernel: edesc=0xfffff80023164720 isoc_next=0 toggle_next=0usb_dump_endpoint: endpoint=0xfffff8002318f0d8 bEndpointAddress=0x00 edesc=0xfffff8002318f720 isoc_next=0 toggle_next=0 Aug 7 18:26:34 antares kernel: bEndpointAddress=0x00usb_dump_queue: endpoint=0xfffff800231640d8 xfer: Aug 7 18:26:34 antares kernel: Aug 7 18:26:34 antares kernel: usb_dump_queue: endpoint=0xfffff8002318f0d8 xfer: usbd_pipe_enter: enter Aug 7 18:26:34 antares kernel: Aug 7 18:26:34 antares kernel: usbd_pipe_start: start Aug 7 18:26:34 antares kernel: usbd_pipe_enter: enter Aug 7 18:26:34 antares kernel: usbd_pipe_start: start Aug 7 18:26:34 antares kernel: usbd_transfer_done: err=USB_ERR_NORMAL_COMPLETION Aug 7 18:26:34 antares kernel: usbd_callback_wrapper_sub: xfer=0xfffff80023196148 endpoint=0xfffff8002318f0d8 sts=0 alen=12, slen=12, afrm=2, nfrm=2 Aug 7 18:26:34 antares kernel: usbd_transfer_done: err=USB_ERR_NORMAL_COMPLETION Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=1 Aug 7 18:26:34 antares kernel: usbd_callback_wrapper_sub: xfer=0xfffff80023165148 endpoint=0xfffff800231640d8 sts=0 alen=12, slen=12, afrm=2, nfrm=2 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=0 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=1 Aug 7 18:26:34 antares kernel: usbd_transfer_submit: xfer=0xfffff80023196148, endpoint=0xfffff8002318f0d8, nframes=2, dir=read Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=0 Aug 7 18:26:34 antares kernel: usb_dump_endpoint: endpoint=0xfffff8002318f0d8usbd_transfer_submit: xfer=0xfffff80023165148, endpoint=0xfffff800231640d8, nframes=2, dir=read Aug 7 18:26:34 antares kernel: edesc=0xfffff8002318f720 isoc_next=0 toggle_next=0usb_dump_endpoint: endpoint=0xfffff800231640d8 bEndpointAddress=0x00 edesc=0xfffff80023164720 isoc_next=0 toggle_next=0 Aug 7 18:26:34 antares kernel: bEndpointAddress=0x00usb_dump_queue: endpoint=0xfffff8002318f0d8 xfer: Aug 7 18:26:34 antares kernel: Aug 7 18:26:34 antares kernel: usb_dump_queue: endpoint=0xfffff800231640d8 xfer: usbd_pipe_enter: enter Aug 7 18:26:34 antares kernel: Aug 7 18:26:34 antares kernel: usbd_pipe_start: start Aug 7 18:26:34 antares kernel: usbd_pipe_enter: enter Aug 7 18:26:34 antares kernel: usbd_pipe_start: start Aug 7 18:26:34 antares kernel: usbd_transfer_done: err=USB_ERR_NORMAL_COMPLETION Aug 7 18:26:34 antares kernel: usbd_callback_wrapper_sub: xfer=0xfffff80023196148 endpoint=0xfffff8002318f0d8 sts=0 alen=12, slen=12, afrm=2, nfrm=2 Aug 7 18:26:34 antares kernel: usbd_transfer_done: err=USB_ERR_NORMAL_COMPLETION Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=1 Aug 7 18:26:34 antares kernel: usbd_callback_wrapper_sub: xfer=0xfffff80023165148 endpoint=0xfffff800231640d8 sts=0 alen=12, slen=12, afrm=2, nfrm=2 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=0 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=1 Aug 7 18:26:34 antares kernel: usbd_transfer_submit: xfer=0xfffff80023196148, endpoint=0xfffff8002318f0d8, nframes=2, dir=read Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=0 Aug 7 18:26:34 antares kernel: usb_dump_endpoint: endpoint=0xfffff8002318f0d8usbd_transfer_submit: xfer=0xfffff80023165148, endpoint=0xfffff800231640d8, nframes=2, dir=read Aug 7 18:26:34 antares kernel: edesc=0xfffff8002318f720 isoc_next=0 toggle_next=0usb_dump_endpoint: endpoint=0xfffff800231640d8 bEndpointAddress=0x00 edesc=0xfffff80023164720 isoc_next=0 toggle_next=0 Aug 7 18:26:34 antares kernel: bEndpointAddress=0x00usb_dump_queue: endpoint=0xfffff8002318f0d8 xfer: Aug 7 18:26:34 antares kernel: Aug 7 18:26:34 antares kernel: usb_dump_queue: endpoint=0xfffff800231640d8 xfer: usbd_pipe_enter: enter Aug 7 18:26:34 antares kernel: Aug 7 18:26:34 antares kernel: usbd_pipe_start: start Aug 7 18:26:34 antares kernel: usbd_pipe_enter: enter Aug 7 18:26:34 antares kernel: usbd_pipe_start: start Aug 7 18:26:34 antares kernel: usbd_transfer_done: err=USB_ERR_NORMAL_COMPLETION Aug 7 18:26:34 antares kernel: usbd_callback_wrapper_sub: xfer=0xfffff80023196148 endpoint=0xfffff8002318f0d8 sts=0 alen=12, slen=12, afrm=2, nfrm=2 Aug 7 18:26:34 antares kernel: usbd_transfer_done: err=USB_ERR_NORMAL_COMPLETION Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=1 Aug 7 18:26:34 antares kernel: usbd_callback_wrapper_sub: xfer=0xfffff80023165148 endpoint=0xfffff800231640d8 sts=0 alen=12, slen=12, afrm=2, nfrm=2 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=1 Aug 7 18:26:34 antares kernel: usbd_do_request_flags: Handle Request function is set Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=0 Aug 7 18:26:34 antares kernel: usbd_transfer_submit: xfer=0xfffff800231c5148, endpoint=0xfffff800231c00d8, nframes=2, dir=read Aug 7 18:26:34 antares kernel: usb_dump_endpoint: endpoint=0xfffff800231c00d8 edesc=0xfffff800231c0720 isoc_next=0 toggle_next=0 bEndpointAddress=0x00 Aug 7 18:26:34 antares kernel: usb_dump_queue: endpoint=0xfffff800231c00d8 xfer: Aug 7 18:26:34 antares kernel: usbd_pipe_enter: enter Aug 7 18:26:34 antares kernel: usbd_pipe_start: start Aug 7 18:26:34 antares kernel: usbd_transfer_done: err=USB_ERR_NORMAL_COMPLETION Aug 7 18:26:34 antares kernel: usbd_callback_wrapper_sub: xfer=0xfffff800231c5148 endpoint=0xfffff800231c00d8 sts=0 alen=12, slen=12, afrm=2, nfrm=2 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=1 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=0 Aug 7 18:26:34 antares kernel: usbd_transfer_submit: xfer=0xfffff800231c5148, endpoint=0xfffff800231c00d8, nframes=2, dir=read Aug 7 18:26:34 antares kernel: usb_dump_endpoint: endpoint=0xfffff800231c00d8 edesc=0xfffff800231c0720 isoc_next=0 toggle_next=0 bEndpointAddress=0x00 Aug 7 18:26:34 antares kernel: usb_dump_queue: endpoint=0xfffff800231c00d8 xfer: Aug 7 18:26:34 antares kernel: usbd_pipe_enter: enter Aug 7 18:26:34 antares kernel: usbd_pipe_start: start Aug 7 18:26:34 antares kernel: usbd_transfer_done: err=USB_ERR_NORMAL_COMPLETION Aug 7 18:26:34 antares kernel: usbd_callback_wrapper_sub: xfer=0xfffff800231c5148 endpoint=0xfffff800231c00d8 sts=0 alen=12, slen=12, afrm=2, nfrm=2 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=1 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=0 Aug 7 18:26:34 antares kernel: usbd_transfer_submit: xfer=0xfffff800231c5148, endpoint=0xfffff800231c00d8, nframes=2, dir=read Aug 7 18:26:34 antares kernel: usb_dump_endpoint: endpoint=0xfffff800231c00d8 edesc=0xfffff800231c0720 isoc_next=0 toggle_next=0 bEndpointAddress=0x00 Aug 7 18:26:34 antares kernel: usb_dump_queue: endpoint=0xfffff800231c00d8 xfer: Aug 7 18:26:34 antares kernel: usbd_pipe_enter: enter Aug 7 18:26:34 antares kernel: usbd_pipe_start: start Aug 7 18:26:34 antares kernel: usbd_transfer_done: err=USB_ERR_NORMAL_COMPLETION Aug 7 18:26:34 antares kernel: usbd_callback_wrapper_sub: xfer=0xfffff800231c5148 endpoint=0xfffff800231c00d8 sts=0 alen=12, slen=12, afrm=2, nfrm=2 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=1 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=0 Aug 7 18:26:34 antares kernel: usbd_transfer_submit: xfer=0xfffff800231c5148, endpoint=0xfffff800231c00d8, nframes=2, dir=read Aug 7 18:26:34 antares kernel: usb_dump_endpoint: endpoint=0xfffff800231c00d8 edesc=0xfffff800231c0720 isoc_next=0 toggle_next=0 bEndpointAddress=0x00 Aug 7 18:26:34 antares kernel: usb_dump_queue: endpoint=0xfffff800231c00d8 xfer: Aug 7 18:26:34 antares kernel: usbd_pipe_enter: enter Aug 7 18:26:34 antares kernel: usbd_pipe_start: start Aug 7 18:26:34 antares kernel: usbd_transfer_done: err=USB_ERR_NORMAL_COMPLETION Aug 7 18:26:34 antares kernel: usbd_callback_wrapper_sub: xfer=0xfffff800231c5148 endpoint=0xfffff800231c00d8 sts=0 alen=12, slen=12, afrm=2, nfrm=2 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=1 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=0 Aug 7 18:26:34 antares kernel: usbd_transfer_submit: xfer=0xfffff80023196148, endpoint=0xfffff8002318f0d8, nframes=2, dir=read Aug 7 18:26:34 antares kernel: usb_dump_endpoint: endpoint=0xfffff8002318f0d8 edesc=0xfffff8002318f720 isoc_next=0 toggle_next=0 bEndpointAddress=0x00 Aug 7 18:26:34 antares kernel: usb_dump_queue: endpoint=0xfffff8002318f0d8 xfer: Aug 7 18:26:34 antares kernel: usbd_pipe_enter: enter Aug 7 18:26:34 antares kernel: usbd_pipe_start: start Aug 7 18:26:34 antares kernel: usbd_transfer_done: err=USB_ERR_NORMAL_COMPLETION Aug 7 18:26:34 antares kernel: usbd_callback_wrapper_sub: xfer=0xfffff80023196148 endpoint=0xfffff8002318f0d8 sts=0 alen=12, slen=12, afrm=2, nfrm=2 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=1 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=0 Aug 7 18:26:34 antares kernel: usbd_transfer_submit: xfer=0xfffff80023196148, endpoint=0xfffff8002318f0d8, nframes=2, dir=read Aug 7 18:26:34 antares kernel: usb_dump_endpoint: endpoint=0xfffff8002318f0d8 edesc=0xfffff8002318f720 isoc_next=0 toggle_next=0 bEndpointAddress=0x00 Aug 7 18:26:34 antares kernel: usb_dump_queue: endpoint=0xfffff8002318f0d8 xfer: Aug 7 18:26:34 antares kernel: usbd_pipe_enter: enter Aug 7 18:26:34 antares kernel: usbd_pipe_start: start Aug 7 18:26:34 antares kernel: usbd_transfer_done: err=USB_ERR_NORMAL_COMPLETION Aug 7 18:26:34 antares kernel: usbd_callback_wrapper_sub: xfer=0xfffff80023196148 endpoint=0xfffff8002318f0d8 sts=0 alen=12, slen=12, afrm=2, nfrm=2 Aug 7 18:26:34 antares kernel: usbd_do_request_callback: st=1 Aug 7 18:26:34 antares kernel: usbd_do_request_flags: Handle Request function is set Aug 7 18:26:38 antares kernel: usb_needs_explore: Aug 7 18:26:38 antares kernel: usb_bus_powerd: bus=0xfffffe000118a428 Aug 7 18:26:38 antares kernel: usb_bus_powerd: Recomputing power masks Aug 7 18:26:38 antares kernel: usbd_do_request_flags: Handle Request function is set -- ___________________________ Michael Schmiedgen, BSc Senior Software Engineer Takwa GmbH Friedrich-List-Str. 36 99096 Erfurt GERMANY Tel +49 361 6534096 Fax +49 361 6534097 Mail schmiedgen at takwa.de Web http://www.takwa.de/ ___________________________ Amtsgericht Jena HRB 112964 Gesch?ftsf?hrung: Ingo Buchholz
Michael Schmiedgen
2017-Aug-07 16:48 UTC
[USB] hang after upgrade from 10.0 to 10.1, ZFS or callout() related?
On 07.08.2017 18:10, Hans Petter Selasky wrote:> > Are you sure you loaded all drivers, like XHCI, EHCI, OHCI, UHCI ? DOes the BIOS offer any USB options?https://imgur.com/a/YN428 It seems like some cheapo hardware. BTW, after the hang I requested KVM access at our hoster, so there is possible new USB interference with the (crappy) KVM hardware too. But the hang exist before the KVM was attached. Disabeling dev.uhub.2.disable_enumeration="1" dev.uhub.1.disable_enumeration="1" dev.uhub.0.disable_enumeration="1" leads to a hang and this console output: https://imgur.com/a/WiiQW Thanks, Michael -- ___________________________ Michael Schmiedgen, BSc Senior Software Engineer Takwa GmbH Friedrich-List-Str. 36 99096 Erfurt GERMANY Tel +49 361 6534096 Fax +49 361 6534097 Mail schmiedgen at takwa.de Web http://www.takwa.de/ ___________________________ Amtsgericht Jena HRB 112964 Gesch?ftsf?hrung: Ingo Buchholz
Michael Schmiedgen
2017-Aug-07 17:07 UTC
[USB] hang after upgrade from 11.0 to 11.1, ZFS or callout() related?
On 07.08.2017 18:10, Hans Petter Selasky wrote:> > Are you sure you loaded all drivers, like XHCI, EHCI, OHCI, UHCI ? DOes the BIOS offer any USB options? >After enabling the 'USB hands off' in BIOS I got the strange 'error 5' with 11.1, disable_enumeration was not enabled BTW: https://imgur.com/a/67jV1 Switching back to 11.0 but still with 'USB hands off' activated, everything is fine. Michael -- ___________________________ Michael Schmiedgen, BSc Senior Software Engineer Takwa GmbH Friedrich-List-Str. 36 99096 Erfurt GERMANY Tel +49 361 6534096 Fax +49 361 6534097 Mail schmiedgen at takwa.de Web http://www.takwa.de/ ___________________________ Amtsgericht Jena HRB 112964 Gesch?ftsf?hrung: Ingo Buchholz