debug head -r368500 kernel (for example) : "lock order reversal: (sleepable after non-sleepable)" involving ure0 and a sysctl lock; more

From: Mark Millard <marklmi_at_yahoo.com>
Date: Fri, 18 Dec 2020 22:27:28 -0800
The following is from head -r368500's artifact kernel from:

https://artifact.ci.freebsd.org/snapshot/13.0-CURRENT/r368500/arm64/aarch64/kernel.txz

but the same sort of material showed for -r368000 .
(I was attempting a bisect for a different issue but
the debug kernels did not fail for what I was looking
for and all the debug versions that I tried reported
similarly to the below.)

Note also the mixing in of "uma_zalloc_debug" activity
after the initial LOR backtrace, ure0 still involved.

Autoloading module: if_ure.ko
ure0 on uhub0
ure0: <Realtek USB 10/100/1000 LAN, class 0/0, rev 3.00/30.00, addr 2> on usbus0
add host 127.0.0.1: gatelock order reversal: (sleepable after non-sleepable)
 1st 0xffffa00002b2cea0 ure0 (ure0, sleep mutex) _at_ /usr/src/sys/dev/usb/usb_request.c:714
 2nd 0xffff000000dd6858 sysctl lock (sysctl lock, sleepable rm) _at_ /usway lo0 fib 0: route alrr/src/sys/kern/kern_sysctl.c:836
lock order ure0 -> sysctl lock attempted at:
#0 0xffff00000056d068 at witness_checkorder+0xc54
#1 0xffff0000004f8f08 at _rm_wlock_debug+0x88
#2 0xffff00000050ee2c at sysctl_add_oid+0x60
#3 0xffff00009e415780 at ure_attach_post+0x1a78
#4 0xffff000000391d6c at ue_attach_post_task+0x3c
#5 0xffff0000003826e0 at usb_process+0x10c
#6 0xffff0000004baa1c at fork_exit+0x7c
#7 0xffff000000816544 at fork_trampoline+0x10
uma_zalloc_debug: zone "malloc-128eady in table
" with the following non-sleepable locks held:
exclusive sleep mutex ure0 (ure0) r = 0 (0xffffa00002b2cea0) locked _at_ /usr/src/sys/dev/usb/usb_request.c:714
stack backtrace:
#0 0xffff00000056d388 at witness_debugger+0x64
#1 0xffff00000056e518 at witness_warn+0x3ec
#2 0xffff000000778f9c at uma_zalloc_debug+0x2c
#3 0xffff000000778998 at uma_zalloc_arg+0x2c
#4 0xffff0000004d534c at malloc+0xa0
#5 0xffff00000050ee80 at sysctl_add_oid+0xb4
#6 0xffff00009e415780 at ure_attach_post+0x1a78
#7 0xffff000000391d6c at ue_attach_post_task+0x3c
#8 0xffff0000003826e0 at usb_process+0x10c
#9 0xffff0000004baa1c at fork_exit+0x7c
#10 0xffff000000816544 at fork_trampoline+0x10
uma_zalloc_debug: zone "malloc-16" with the following non-sleepable locks held:
exclusive sleep mutex ure0 (ure0) r = 0 (0xffffa00002b2cea0) locked _at_ /usr/src/sys/dev/usb/usb_request.c:714
stack backtrace:
#0 0xffff00000056d388 at witness_debugger+0x64
#1 0xffff00000056e518 at witness_warn+0x3ec
#2 0xffff000000778f9c at uma_zalloc_debug+0x2c
#3 0xffff000000778998 at uma_zalloc_arg+0x2c
#4 0xffff0000004d534c at malloc+0xa0
#5 0xffff0000005f8c80 at strdup+0x2c
#6 0xffff00000050eeb8 at sysctl_add_oid+0xec
#7 0xffff00009e415780 at ure_attach_post+0x1a78
#8 0xffff000000391d6c at ue_attach_post_task+0x3c
#9 0xffff0000003826e0 at usb_process+0x10c
#10 0xffff0000004baa1c at fork_exit+0x7c
#11 0xffff000000816544 at fork_trampoline+0x10
uma_zalloc_debug: zone "malloc-64" with the following non-sleepable locks held:
exclusive sleep mutex ure0 (ure0) r = 0 (0xffffa00002b2cea0) locked _at_ /usr/src/sys/dev/usb/usb_request.c:714
stack backtrace:
#0 0xffff00000056d388 at witness_debugger+0x64
#1 0xffff00000056e518 at witness_warn+0x3ec
#2 0xffff000000778f9c at uma_zalloc_debug+0x2c
#3 0xffff000000778998 at uma_zalloc_arg+0x2c
#4 0xffff0000004d534c at malloc+0xa0
#5 0xffff0000005f8c80 at strdup+0x2c
#6 0xffff00000050eee4 at sysctl_add_oid+0x118
#7 0xffff00009e415780 at ure_attach_post+0x1a78
#8 0xffff000000391d6c at ue_attach_post_task+0x3c
#9 0xffff0000003826e0 at usb_process+0x10c
#10 0xffff0000004baa1c at fork_exit+0x7c
#11 0xffff000000816544 at fork_trampoline+0x10
uma_zalloc_debug: zone "malloc-32" with the following non-sleepable locks held:
exclusive sleep mutex ure0 (ure0) r = 0 (0xffffa00002b2cea0) locked _at_ /usr/src/sys/dev/usb/usb_request.c:714
stack backtrace:
#0 0xffff00000056d388 at witness_debugger+0x64
#1 0xffff00000056e518 at witness_warn+0x3ec
#2 0xffff000000778f9c at uma_zalloc_debug+0x2c
#3 0xffff000000778998 at uma_zalloc_arg+0x2c
#4 0xffff0000004d534c at malloc+0xa0
#5 0xffff00000050ef3c at sysctl_add_oid+0x170
#6 0xffff00009e415780 at ure_attach_post+0x1a78
#7 0xffff000000391d6c at ue_attach_post_task+0x3c
#8 0xffff0000003826e0 at usb_process+0x10c
#9 0xffff0000004baa1c at fork_exit+0x7c
#10 0xffff000000816544 at fork_trampoline+0x10
miibus0: <MII bus> on ure0
rgephy0: <RTL8251/8153 1000BASE-T media interface> PHY 0 on miibus0
add hrgephy0:  none, 10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, 1000baseT-FDX, 1000baseT-FDX-master, auto
0 fib 0: route already iue0: <USB Ethernet> on ure0



The context here is an RPi4 (aarch64 cortex-a72) with:

# uname -apKU
FreeBSD RPi4B 13.0-CURRENT FreeBSD 13.0-CURRENT #0 r368500: Thu Dec 10 07:52:39 UTC 2020     root_at_FreeBSD-head-aarch64-build.jail.ci.FreeBSD.org:/usr/obj/usr/src/arm64.aarch64/sys/GENERIC  arm64 aarch64 1300131 1300131

The boot attempts were via uefi/ACPI using https://github.com/pftf/RPi4
v1.21 materials, directly booting from the USB3 SSD, no microsd card
involved.


Some context in case it contributes something for the above
(probably not) . . .

The reason for the bisect was: such boot attempts fail to mount
route with my non-debug head -r368500 kernel build. (Previously
the RPi4 was back at head -r365932 or so.) But my non-debug
builds use -mcpu=cortex-a72 . (This combination has caught
missing synchronization activity before.)

In the failing case the following never shows up:

da0 at umass-sim0 bus 0 scbus0 target 0 lun 0
da0: <OWC Envoy Pro mini 0> Fixed Direct Access SPC-4 SCSI device
da0: Serial Number REPLACED
da0: 400.000MB/s transfers
da0: 228936MB (468862128 512 byte sectors)
da0: quirks=0x2<NO_6_BYTE>

and the message:

Root mount waiting for: usbus0

repeats indefinitely, unlike historically for my configuration.

With the artifact debug kernel instead of the non-debug
kernel, the RPi4 boots fine, other things held constant.

===
Mark Millard
marklmi at yahoo.com
( dsl-only.net went
away in early 2018-Mar)
Received on Sat Dec 19 2020 - 05:27:40 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:41:26 UTC