Kernel panic with usbverbose (?)

[BERTRAND Joël <joel.bertrand%systella.fr@localhost>]

	Hello,

	I have recently filled a PR (55699) as one of my NetBSD server
(NetBSD-9 built from sources tree) panics when it launches a bacula jobs.

[  3409.124192] uvm_fault(0xffffffff8151f760, 0xffffffff819ca000, 4) -> e
[  3409.124192] fatal page fault in supervisor mode
[  3409.124192] trap type 6 code 0x10 rip 0xffffffff819ca061 cs 0x8 rflags
0x10293 cr2 0xffffffff819ca061 ilevel 0 rsp 0xffffae013d79abb0
[  3409.124192] curlwp 0xfffffa749e1ef060 pid 160.1 lowest kstack
0xffffae013d7982c0
[  3409.124192] panic: trap
[  3409.124192] cpu5: Begin traceback...
[  3409.133355] vpanic() at netbsd:vpanic+0x160
[  3409.133355] snprintf() at netbsd:snprintf
[  3409.133355] startlwp() at netbsd:startlwp
[  3409.133355] alltraps() at netbsd:alltraps+0xbb
[  3409.133355] usbd_devinfo_vp() at netbsd:usbd_devinfo_vp+0xa9
[  3409.143358] usbd_fill_deviceinfo() at netbsd:usbd_fill_deviceinfo+0x68
[  3409.143358] usbioctl() at netbsd:usbioctl+0xdc
[  3409.143358] cdev_ioctl() at netbsd:cdev_ioctl+0xc4
[  3409.153361] VOP_IOCTL() at netbsd:VOP_IOCTL+0x54
[  3409.153361] vn_ioctl() at netbsd:vn_ioctl+0xa5
[  3409.153361] sys_ioctl() at netbsd:sys_ioctl+0x5ab
[  3409.163364] syscall() at netbsd:syscall+0x157
[  3409.163364] --- syscall (number 54) ---
[  3409.163364] 735f5396824a:
[  3409.163364] cpu5: End traceback...

	This server was stable before I have added :
- iSCSI initiator (to connect a NAS) ;
- jumbo frames (on re0)
- bacula (-dir, -sd and -fd)

	I have tested the same configuration without jumbo frame, same panic,
but later.

	I don't understand why kernel panics in usbverbose module as only usb
devices on this server is keyboard and mouse.

	If I configure traces with kern.module.verbose=1, I obtain when I
launch a bacul job (certainly from bacula-fd or -sd) :

[ 10736.911324] DEBUG: module: Loading plist from
 /stand/amd64/9.0/modules/usbverbose/usbverbose.plist
 [ 10736.911324] DEBUG: module: plist load returned error 2 for
 `/stand/amd64/9.0/modules/usbverbose/usbverbose.kmod'
 [ 10736.921726] DEBUG: module: module `usbverbose' loaded successfully
 [ 10746.925138] DEBUG: module: unload requested for 'usbverbose' (FALSE)
 [ 10746.925138] DEBUG: module: unloaded module `usbverbose'
 [ 10746.965153] DEBUG: module: Loading module from
 /stand/amd64/9.0/modules/usbverbose/usbverbose.kmod
 [ 10746.965153] DEBUG: module: Loading plist from
 /stand/amd64/9.0/modules/usbverbose/usbverbose.plist
 [ 10746.965153] DEBUG: module: plist load returned error 2 for
 `/stand/amd64/9.0/modules/usbverbose/usbverbose.kmod'
 [ 10746.975404] DEBUG: module: module `usbverbose' loaded successfully
 [ 10753.947813] DEBUG: module: unload requested for 'usbverbose' (TRUE)
 [ 10753.947813] DEBUG: module: unloaded module `usbverbose'
 [ 10756.998976] DEBUG: module: Loading module from
 /stand/amd64/9.0/modules/usbverbose/usbverbose.kmod
 [ 10756.998976] DEBUG: module: Loading plist from
 /stand/amd64/9.0/modules/usbverbose/usbverbose.plist
 [ 10756.998976] DEBUG: module: plist load returned error 2 for
 `/stand/amd64/9.0/modules/usbverbose/usbverbose.kmod'
 [ 10757.019631] DEBUG: module: module `usbverbose' loaded successfully
 [ 10767.012792] DEBUG: module: unload requested for 'usbverbose' (FALSE)
 [ 10767.012792] DEBUG: module: unloaded module `usbverbose'
 [ 10767.042803] DEBUG: module: Loading module from
 /stand/amd64/9.0/modules/usbverbose/usbverbose.kmod
 [ 10767.042803] DEBUG: module: Loading plist from
 /stand/amd64/9.0/modules/usbverbose/usbverbose.plist
 [ 10767.042803] DEBUG: module: plist load returned error 2 for
 `/stand/amd64/9.0/modules/usbverbose/usbverbose.kmod'
 [ 10767.052828] DEBUG: module: module `usbverbose' loaded successfully
 [ 10777.056620] DEBUG: module: unload requested for 'usbverbose' (FALSE)
 [ 10777.056620] DEBUG: module: unloaded module `usbverbose'
 [ 10777.076627] DEBUG: module: Loading module from
 /stand/amd64/9.0/modules/usbverbose/usbverbose.kmod
 [ 10777.076627] DEBUG: module: Loading plist from
 /stand/amd64/9.0/modules/usbverbose/usbverbose.plist
 [ 10777.076627] DEBUG: module: plist load returned error 2 for
 `/stand/amd64/9.0/modules/usbverbose/usbverbose.kmod'
 [ 10777.096792] DEBUG: module: module `usbverbose' loaded successfully
 [ 10787.090445] DEBUG: module: unload requested for 'usbverbose' (FALSE)
 [ 10787.090445] DEBUG: module: unloaded module `usbverbose'
 [ 10787.120456] DEBUG: module: Loading module from
 /stand/amd64/9.0/modules/usbverbose/usbverbose.kmod

	Thus, bacula seems to call a syscall that continually load and unload
this module. I have checked into bacula sources and only syscall I have
found that could indirectly load this module seems to be statvfs().
Maybe there are other syscalls, but it's the only syscall I have found.

	I remember I have seen the same backtrace recently on another
workstation (and of course without bacula).

	Something in kernel seems to use a module that has been unloaded. I
don't know how debug this panic.

	Please note that the first time, usbverbose module is correctly unloaded :

 [ 10753.947813] DEBUG: module: unload requested for 'usbverbose' (TRUE)
 [ 10753.947813] DEBUG: module: unloaded module `usbverbose'

After, all requests returns FALSE :

 [ 10787.090445] DEBUG: module: unload requested for 'usbverbose' (FALSE)

	Another question : what is the signification of " [ 10767.042803]
DEBUG: module: plist load returned error 2 for
 `/stand/amd64/9.0/modules/usbverbose/usbverbose.kmod'" ? 2 for ENOENT ?

	Is there any workaround ?

	Best regards,

	JKB