Re: 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:44:24 -0800
[I managed to not cc the primary person that I intended but to cc the secondary person.
So this resend just adds jmg and removes hps.]

On 2020-Dec-18, at 22:27, Mark Millard <marklmi at yahoo.com> wrote:


> 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:44:31 UTC

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