Skip site navigation (1)Skip section navigation (2)
Date:      Fri, 18 Dec 2020 22:44:24 -0800
From:      Mark Millard <marklmi@yahoo.com>
To:        freebsd-arm <freebsd-arm@freebsd.org>, FreeBSD Current <freebsd-current@freebsd.org>
Cc:        John-Mark Gurney <jmg@funkthat.com>
Subject:   Re: debug head -r368500 kernel (for example) : "lock order reversal: (sleepable after non-sleepable)" involving ure0 and a sysctl lock; more
Message-ID:  <3392879C-F0DC-4F14-9C48-1ADD94214D49@yahoo.com>
In-Reply-To: <E58350E3-EB33-410C-AC20-E25A9A78D5C2@yahoo.com>
References:  <E58350E3-EB33-410C-AC20-E25A9A78D5C2@yahoo.com>

next in thread | previous in thread | raw e-mail | index | archive | help
[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:
>=20
> =
https://artifact.ci.freebsd.org/snapshot/13.0-CURRENT/r368500/arm64/aarch6=
4/kernel.txz
>=20
> 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.)
>=20
> Note also the mixing in of "uma_zalloc_debug" activity
> after the initial LOR backtrace, ure0 still involved.
>=20
> 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) @ =
/usr/src/sys/dev/usb/usb_request.c:714
> 2nd 0xffff000000dd6858 sysctl lock (sysctl lock, sleepable rm) @ =
/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 =3D 0 (0xffffa00002b2cea0) locked =
@ /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 =3D 0 (0xffffa00002b2cea0) locked =
@ /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 =3D 0 (0xffffa00002b2cea0) locked =
@ /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 =3D 0 (0xffffa00002b2cea0) locked =
@ /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
>=20
>=20
>=20
> The context here is an RPi4 (aarch64 cortex-a72) with:
>=20
> # uname -apKU
> FreeBSD RPi4B 13.0-CURRENT FreeBSD 13.0-CURRENT #0 r368500: Thu Dec 10 =
07:52:39 UTC 2020     =
root@FreeBSD-head-aarch64-build.jail.ci.FreeBSD.org:/usr/obj/usr/src/arm64=
.aarch64/sys/GENERIC  arm64 aarch64 1300131 1300131
>=20
> 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.
>=20
>=20
> Some context in case it contributes something for the above
> (probably not) . . .
>=20
> 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=3Dcortex-a72 . (This combination has caught
> missing synchronization activity before.)
>=20
> In the failing case the following never shows up:
>=20
> 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=3D0x2<NO_6_BYTE>
>=20
> and the message:
>=20
> Root mount waiting for: usbus0
>=20
> repeats indefinitely, unlike historically for my configuration.
>=20
> With the artifact debug kernel instead of the non-debug
> kernel, the RPi4 boots fine, other things held constant.


=3D=3D=3D
Mark Millard
marklmi at yahoo.com
( dsl-only.net went
away in early 2018-Mar)




Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?3392879C-F0DC-4F14-9C48-1ADD94214D49>