Re: kern/54023: assertion panic during shutdown

[Hauke Fath <hf%spg.tu-darmstadt.de@localhost>]

The following reply was made to PR kern/54023; it has been noted by GNATS.

From: Hauke Fath <hf%spg.tu-darmstadt.de@localhost>
To: gnats-bugs%NetBSD.org@localhost
Cc: kern-bug-people%NetBSD.org@localhost, gnats-admin%netbsd.org@localhost
Subject: Re: kern/54023: assertion panic during shutdown
Date: Thu, 7 Mar 2019 10:28:54 +0100

 On 3/1/19 10:30 PM, matthew green wrote:
 >   can you turn on USB_DEBUG and UHID_DEBUG, make sure that usb_debug
 >   is set in sysctl, make sure ddb will be entered (ddb.onpanic=1),
 >   and since the keyboard probably won't work (it is either the kbd
 >   or mouse that is triggering this fault), also set ddb.commandonenter
 >   to something like "show kernhist usbhist", then we may even get a
 >   useful usb log of what it was doing before the crash.  it may
 >   scroll a lot -- but the really useful stuff is likely in the last
 >   part, 
 
 
 I tried a 'show kernhist ,100' - not clear what the meaning of "address" 
 is here:
 
 [   501.173862] panic: kernel diagnostic assertion "xfer->ux_status != 
 USBD_CANCELLED" failed: file 
 "/public/netbsd-developer/sys/dev/usb/ehci.c", line 3264
 [   501.193860] cpu1: Begin traceback...
 [   501.193860] trace fp ffffffc044d57820
 [   501.203861] fp ffffffc044d57840 vpanic() at ffffffc000439640 
 netbsd:vpanic+0x198
 [   501.203861] fp ffffffc044d578a0 kern_assert() at ffffffc000569bc4 
 netbsd:kern_assert+0x5c
 [   501.223864] fp ffffffc044d57930 ehci_abort_xfer() at 
 ffffffc000178ac4 netbsd:ehci_abort_xfer+0x2c4
 [   501.233862] fp ffffffc044d57990 usbd_ar_pipe() at ffffffc0000c1000 
 netbsd:usbd_ar_pipe+0x1c8
 [   501.243863] fp ffffffc044d579e0 usbd_abort_pipe() at 
 ffffffc0000c1390 netbsd:usbd_abort_pipe+0x28
 [   501.253864] fp ffffffc044d57a00 uhidev_stop() at ffffffc0000de8e8 
 netbsd:uhidev_stop+0x30
 [   501.263864] fp ffffffc044d57a20 uhidclose() at ffffffc0000df374 
 netbsd:uhidclose+0x64
 [   501.273865] fp ffffffc044d57a50 cdev_close() at ffffffc000425e58 
 netbsd:cdev_close+0xb8
 [   501.283868] fp ffffffc044d57a90 spec_close() at ffffffc0004ae990 
 netbsd:spec_close+0x1a0
 [   501.293868] fp ffffffc044d57ae0 VOP_CLOSE() at ffffffc0004a2084 
 netbsd:VOP_CLOSE+0x3c
 [   501.303868] fp ffffffc044d57b20 vn_close() at ffffffc00049a67c 
 netbsd:vn_close+0x34
 [   501.313869] fp ffffffc044d57b50 closef() at ffffffc0003d7ea8 
 netbsd:closef+0x50
 [   501.323870] fp ffffffc044d57b90 fd_free() at ffffffc0003db3b4 
 netbsd:fd_free+0x1ac
 [   501.333870] fp ffffffc044d57c00 exit1() at ffffffc0003e2d18 
 netbsd:exit1+0xe8
 [   501.343872] fp ffffffc044d57cc0 sigexit() at ffffffc000407e78 
 netbsd:sigexit+0x1d8
 [   501.353872] fp ffffffc044d57d10 postsig() at ffffffc00040822c 
 netbsd:postsig+0x26c
 [   501.363873] fp ffffffc044d57db0 lwp_userret() at ffffffc0003eccf0 
 netbsd:lwp_userret+0x1a0
 [   501.373874] fp ffffffc044d57e00 userret() at ffffffc00007063c 
 netbsd:userret+0x6c
 [   501.383875] fp ffffffc044d57e20 syscall() at ffffffc0000703cc 
 netbsd:syscall+0x104
 [   501.403877] tf ffffffc044d57ed0 el0_trap() at ffffffc00006ea10 
 netbsd:el0_trap
 [   501.403877] ---- trapframe 0xffffffc044d57ed0 (304 bytes) ----
 [   501.413877] pc=0000fc069c623e90,   spsr=0000000080000000
 [   501.413877] esr=0000000056000003,    far=ffffffc0440dd000
 [   501.423878] x0=0000000000000003,     x1=0000ffffff999318
 [   501.433879] x2=0000000000000001,     x3=0000fc069c706c98
 [   501.433879] x4=0000ffffff998029,     x5=0000000000000000
 [   501.443880] x6=0000ffffff9988fc,     x7=0000000000000000
 [   501.443880] x8=0000ffffff998029,     x9=0000000000000011
 [   501.453881] x10=0000000000000004,    x11=0000000000000001
 [   501.453881] x12=000003fffffe661e,    x13=000003fffffe6622
 [   501.463882] x14=0000fc069c43c254,    x15=0000ffffff998880
 [   501.473883] x16=0000000200112b38,    x17=0000fc069c623e90
 [   501.473883] x18=0000000000004040,    x19=0000ffffff99a71f
 [   501.483883] x20=0000ffffff99a758,    x21=0000000000000008
 [   501.483883] x22=0000000200112000,    x23=0000fc069c43c140
 [   501.493884] x24=0000ffffff999318,    x25=0000ffffff99ad15
 [   501.493884] x26=0000ffffff99ad23,    x27=0000000000000000
 [   501.503885] x28=0000000000000001, fp=x29=0000000000000000
 [   501.503885] lr=x30=00000002001020fc,     sp=0000ffffff999260
 [   501.513886] ------------------------------------------------
 [   501.523887] cpu1: End traceback...
 Stopped in pid 549.1 (usbhidaction) at  netbsd:cpu_Debugger+0x4: 
 [ 501.5238873] ret
 [   501.523887] ?
 db{1}> [ 501.5238873] kernhist 'usbhist': at 0xffffffc000a31820 total 
 50000 next free 36181
 db{1}> 1551944051.721767 usb_insert_transfer#14265@1: xfer = 
 0xffff0000bf79a5c0 pipe = 0xffff0000bee80e58 running = 0 timeout = 10000
 1551944051.721768 usb_insert_transfer#14265@1: <- done xfer 
 0xffff0000bf79a5c0, err 0
 1551944051.721785 usbd_transfer#14265@1: <- done transfer 
 0xffff0000bf79a5c0, err = 1
 1551944051.721786 usbd_transfer#14265@1: <- done xfer 
 0xffff0000bf79a5c0, not sync (err 1)
 1551944051.721929 usb_schedsoftintr#14066@3: called!
 1551944051.721951 usb_rem_task#14271@3: called!
 1551944051.721956 usb_transfer_complete#14271@3: called!
 1551944051.721956 usb_transfer_complete#14271@3: pipe = 
 0xffff0000bee80e58 xfer = 0xffff0000bf79a5c0 status = 0 actlen = 282
 1551944051.721957 usb_transfer_complete#14271@3: xfer 
 0xffff0000bf79a5c0: repeat 0 new head = 0
 1551944051.721958 usb_transfer_complete#14271@3: xfer 0xffff0000bf79a5c0 
 doing done 0xffffffc000172158
 1551944051.721959 usb_transfer_complete#14271@3: xfer 0xffff0000bf79a5c0 
 doing callback 0xffffffc000104230 status 0
 1551944051.721965 usbd_start_next#14271@3: called!
 1551944051.721966 usbd_start_next#14271@3: pipe = 0xffff0000bee80e58, 
 xfer = 0
 1551944051.737180 usb_schedsoftintr#14067@2: called!
 1551944051.737198 usb_transfer_complete#16762@1: xfer 0xffff0000bf79ab80 
 doing done 0xffffffc0001721e8
 1551950377.204744 usb_transfer_complete#16762@1: xfer 0xffff0000bf79ab80 
 doing callback 0xffffffc0000dddb8 status 0
 1551950377.204760 usbd_start_next#16761@1: called!
 1551950377.204761 usbd_start_next#16761@1: pipe = 0xffff0000bf90c0c8, 
 xfer = 0xffff0000bf79ab80
 db{1}>