Bug 244163

Summary:	Lock-order reversals triggered by tests under sys.net.if_lagg_test.* on i386
Product:	Base System	Reporter:	Li-Wen Hsu <lwhsu>
Component:	tests	Assignee:	freebsd-testing (Nobody) <testing>
Status:	Open ---
Severity:	Affects Only Me	CC:	bdrewery
Priority:	---
Version:	CURRENT
Hardware:	i386
OS:	Any

Description Li-Wen Hsu freebsd_committer

2020-02-16 11:12:34 UTC

Lock-order reversals can be triggered by tests under sys.net.if_lagg_test.*

https://ci.freebsd.org/job/FreeBSD-head-i386-test/8444/testReport/junit/sys.net/if_lagg_test/witness/

Error Message

Lock-order reversals involving if_lagg.c detected

Standard Output

debug.witness.badstacks: Number of known direct relationships is 1408

Lock order reversal between "proctree"(sx) and "GEOM topology"(sx)!
Lock order "GEOM topology"(sx) -> "proctree"(sx) first seen at:
#0 0x1031a3b at witness_checkorder+0x3ab
#1 0xfda33d at _sx_xlock+0x4d
#2 0xf9491f at fork1+0xe5f
#3 0xf9ff8c at kproc_create+0x6c
#4 0x270ba4fb at g_eli_create+0x53b
#5 0x270bdc87 at g_eli_config+0x1b57
#6 0xf25b56 at g_ctl_req+0xe6
#7 0xf29b8e at g_run_events+0x15e
#8 0xf95a69 at fork_exit+0x69
#9 0xffc033de at lagg_detach_cookie+0xd8ada046


Lock order reversal between "allproc"(sx) and "GEOM topology"(sx)!
Lock order "GEOM topology"(sx) -> "allproc"(sx) first seen at:
#0 0x1031a3b at witness_checkorder+0x3ab
#1 0xfda33d at _sx_xlock+0x4d
#2 0xf94252 at fork1+0x792
#3 0xf9ff8c at kproc_create+0x6c
#4 0x270ba4fb at g_eli_create+0x53b
#5 0x270bdc87 at g_eli_config+0x1b57
#6 0xf25b56 at g_ctl_req+0xe6
#7 0xf29b8e at g_run_events+0x15e
#8 0xf95a69 at fork_exit+0x69
#9 0xffc033de at lagg_detach_cookie+0xd8ada046


Lock order reversal between "allprison"(sx) and "vnet_sysinit_sxlock"(sx)!
Lock order "allprison"(sx) -> "vnet_sysinit_sxlock"(sx) first seen at:
#0 0x1031a3b at witness_checkorder+0x3ab
#1 0xfdb339 at _sx_slock_int+0x49
#2 0x10ec4c1 at vnet_alloc+0xf1
#3 0xf9a8d7 at kern_jail_set+0x17b7
#4 0xf9bfe8 at sys_jail_set+0x38
#5 0x1410b51 at syscall+0x2e1
#6 0xffc033c9 at lagg_detach_cookie+0xd8ada031


Lock order reversal between "in_multi_sx"(sx) and "pfsync"(sleep mutex)!
Lock order "pfsync"(sleep mutex) -> "in_multi_sx"(sx) first seen at:
#0 0x1031a3b at witness_checkorder+0x3ab
#1 0xfda33d at _sx_xlock+0x4d
#2 0x113aa65 at in_joingroup+0x25
#3 0x25653f08 at pfsyncioctl+0x688
#4 0x1135f5d at in_control+0x2ed
#5 0x10c1798 at ifioctl+0x5e8
#6 0x103d908 at soo_ioctl+0x178
#7 0x10363b1 at kern_ioctl+0x251
#8 0x10360f9 at sys_ioctl+0xf9
#9 0x1410b51 at syscall+0x2e1
#10 0xffc033c9 at lagg_detach_cookie+0xd8ada031


Lock order reversal between "bufwait"(lockmgr) and "tmpfs"(lockmgr)!
Lock order "bufwait"(lockmgr) -> "tmpfs"(lockmgr) first seen at:
#0 0x1031a3b at witness_checkorder+0x3ab
#1 0xfa93b4 at lockmgr_xlock+0x44
#2 0x108160a at vop_lock+0x6a
#3 0x1425c5f at VOP_LOCK1_APV+0x2f
#4 0x10a4b2f at _vn_lock+0x4f
#5 0xbe251e at mdstart_vnode+0x41e
#6 0xbe09eb at md_kthread+0x1db
#7 0xf95a69 at fork_exit+0x69
#8 0xffc033de at lagg_detach_cookie+0xd8ada046

Lock order "tmpfs"(lockmgr) -> "bufwait"(lockmgr) first seen at:
#0 0x1031a3b at witness_checkorder+0x3ab
#1 0xfa7edd at lockmgr_xlock_hard+0x4d
#2 0xfa8b1c at __lockmgr_args+0x6bc
#3 0x1070ca5 at getblkx+0x125
#4 0x1073886 at getblk+0x26
#5 0x12a3bb6 at ffs_unmount+0x1b6
#6 0x1089b51 at dounmount+0x3f1
#7 0x10896fd at kern_unmount+0x25d
#8 0x1089493 at sys_unmount+0x13
#9 0x1410b51 at syscall+0x2e1
#10 0xffc033c9 at lagg_detach_cookie+0xd8ada031


Lock order reversal between "cpslk"(sx) and "pf rulesets"(rm)!
Lock order "pf rulesets"(rm) -> "cpslk"(sx) first seen at:
#0 0x1031a3b at witness_checkorder+0x3ab
#1 0xfda33d at _sx_xlock+0x4d
#2 0x13eacac at cp_slow0+0x12c
#3 0x13eaed7 at copyin+0xa7
#4 0x25683701 at pfioctl+0x1c11
#5 0xea6de4 at devfs_ioctl+0xa4
#6 0x1424ab8 at VOP_IOCTL_APV+0x28
#7 0x10a34cb at vn_ioctl+0x1cb
#8 0xea736c at devfs_ioctl_f+0x2c
#9 0x10363b1 at kern_ioctl+0x251
#10 0x10360f9 at sys_ioctl+0xf9
#11 0x1410b51 at syscall+0x2e1
#12 0xffc033c9 at lagg_detach_cookie+0xd8ada031


Lock order reversal between "filedesc structure"(sx) and "GEOM topology"(sx)!
Lock order "GEOM topology"(sx) -> "filedesc structure"(sx) first seen at:
#0 0x1031a3b at witness_checkorder+0x3ab
#1 0xfdb339 at _sx_slock_int+0x49
#2 0xf81ce6 at fdinit+0x96
#3 0xf81f4c at fdcopy+0x1c
#4 0xf94502 at fork1+0xa42
#5 0xf9ff8c at kproc_create+0x6c
#6 0x270ba4fb at g_eli_create+0x53b
#7 0x270bdc87 at g_eli_config+0x1b57
#8 0xf25b56 at g_ctl_req+0xe6
#9 0xf29b8e at g_run_events+0x15e
#10 0xf95a69 at fork_exit+0x69
#11 0xffc033de at lagg_detach_cookie+0xd8ada046


Lock order reversal between "GEOM topology"(sx) and "tmpfs"(lockmgr)!
Lock order "tmpfs"(lockmgr) -> "GEOM topology"(sx) first seen at:
#0 0x1031a3b at witness_checkorder+0x3ab
#1 0xfda33d at _sx_xlock+0x4d
#2 0x12a3ccd at ffs_unmount+0x2cd
#3 0x1089b51 at dounmount+0x3f1
#4 0x10896fd at kern_unmount+0x25d
#5 0x1089493 at sys_unmount+0x13
#6 0x1410b51 at syscall+0x2e1
#7 0xffc033c9 at lagg_detach_cookie+0xd8ada031


Lock order reversal between "devfs"(lockmgr) and "ufs"(lockmgr)!
Lock order "devfs"(lockmgr) -> "ufs"(lockmgr) first seen at:
#0 0x1031a3b at witness_checkorder+0x3ab
#1 0xfa7edd at lockmgr_xlock_hard+0x4d
#2 0xfa8b1c at __lockmgr_args+0x6bc
#3 0x12a5c5c at ffs_lock+0x5c
#4 0x1425c5f at VOP_LOCK1_APV+0x2f
#5 0x10a4b2f at _vn_lock+0x4f
#6 0x1088e2a at vfs_domount+0xc2a
#7 0x108788a at vfs_donmount+0x7da
#8 0x108ad97 at kernel_mount+0x57
#9 0x108cdb2 at parse_mount+0x462
#10 0x108b723 at vfs_mountroot+0x493
#11 0xf71052 at start_init+0x22
#12 0xf95a69 at fork_exit+0x69
#13 0xffc033de at lagg_detach_cookie+0xd8ada046

Lock order "ufs"(lockmgr) -> "devfs"(lockmgr) first seen at:
#0 0x1031a3b at witness_checkorder+0x3ab
#1 0xfa79c0 at lockmgr_lock_fast_path+0x140
#2 0x107ffce at vop_stdlock+0x1e
#3 0x1425c5f at VOP_LOCK1_APV+0x2f
#4 0x10a4b2f at _vn_lock+0x4f
#5 0x12a1456 at ffs_flushfiles+0x106
#6 0x12a3a7c at ffs_unmount+0x7c
#7 0x1089b51 at dounmount+0x3f1
#8 0x10896fd at kern_unmount+0x25d
#9 0x1089493 at sys_unmount+0x13
#10 0x1410b51 at syscall+0x2e1
#11 0xffc033c9 at lagg_detach_cookie+0xd8ada031


Lock order reversal between "devfs"(lockmgr) and "tmpfs"(lockmgr)!
Lock order "tmpfs"(lockmgr) -> "devfs"(lockmgr) first seen at:
#0 0x1031a3b at witness_checkorder+0x3ab
#1 0xfa79c0 at lockmgr_lock_fast_path+0x140
#2 0x107ffce at vop_stdlock+0x1e
#3 0x1425c5f at VOP_LOCK1_APV+0x2f
#4 0x10a4b2f at _vn_lock+0x4f
#5 0x12a1456 at ffs_flushfiles+0x106
#6 0x12860ab at softdep_flushfiles+0x9b
#7 0x12a3a72 at ffs_unmount+0x72
#8 0x1089b51 at dounmount+0x3f1
#9 0x10896fd at kern_unmount+0x25d
#10 0x1089493 at sys_unmount+0x13
#11 0x1410b51 at syscall+0x2e1
#12 0xffc033c9 at lagg_detach_cookie+0xd8ada031


Lock order reversal between "ufs"(lockmgr) and "tmpfs"(lockmgr)!
Lock order "ufs"(lockmgr) -> "tmpfs"(lockmgr) first seen at:
#0 0x1031a3b at witness_checkorder+0x3ab
#1 0xfa93b4 at lockmgr_xlock+0x44
#2 0x108160a at vop_lock+0x6a
#3 0x1425c5f at VOP_LOCK1_APV+0x2f
#4 0x10a4b2f at _vn_lock+0x4f
#5 0x1088e2a at vfs_domount+0xc2a
#6 0x108788a at vfs_donmount+0x7da
#7 0x108707d at sys_nmount+0x5d
#8 0x1410b51 at syscall+0x2e1
#9 0xffc033c9 at lagg_detach_cookie+0xd8ada031

Lock order "tmpfs"(lockmgr) -> "ufs"(lockmgr) first seen at:
#0 0x1031a3b at witness_checkorder+0x3ab
#1 0xfa7edd at lockmgr_xlock_hard+0x4d
#2 0xfa8b1c at __lockmgr_args+0x6bc
#3 0x12a5c5c at ffs_lock+0x5c
#4 0x1425c5f at VOP_LOCK1_APV+0x2f
#5 0x10a4b2f at _vn_lock+0x4f
#6 0x1088e2a at vfs_domount+0xc2a
#7 0x108788a at vfs_donmount+0x7da
#8 0x108707d at sys_nmount+0x5d
#9 0x1410b51 at syscall+0x2e1
#10 0xffc033c9 at lagg_detach_cookie+0xd8ada031


Lock order reversal between "syncer"(lockmgr) and "tmpfs"(lockmgr)!
Lock order "tmpfs"(lockmgr) -> "syncer"(lockmgr) first seen at:
#0 0x1031a3b at witness_checkorder+0x3ab
#1 0xfa79c0 at lockmgr_lock_fast_path+0x140
#2 0x107ffce at vop_stdlock+0x1e
#3 0x1425c5f at VOP_LOCK1_APV+0x2f
#4 0x10a4b2f at _vn_lock+0x4f
#5 0x10910e2 at vput_final+0x132
#6 0x1089b43 at dounmount+0x3e3
#7 0x10896fd at kern_unmount+0x25d
#8 0x1089493 at sys_unmount+0x13
#9 0x1410b51 at syscall+0x2e1
#10 0xffc033c9 at lagg_detach_cookie+0xd8ada031


Standard Error

Test case metadata
------------------

allowed_architectures is empty
allowed_platforms is empty
description = Check witness(4) for lock-order reversals in if_lagg
has_cleanup = false
is_exclusive = false
required_configs is empty
required_disk_space = 0
required_files is empty
required_memory = 0
required_programs is empty
required_user is empty
timeout = 300

Timing information
------------------

Start time: 2020-02-13T17:16:25.985145Z
End time:   2020-02-13T17:16:26.140134Z
Duration:   0.155s

Original stderr
---------------

<EMPTY>

Comment 1 commit-hook freebsd_committer

2020-02-16 11:16:50 UTC

A commit references this bug:

Author: lwhsu
Date: Sun Feb 16 11:16:06 UTC 2020
New revision: 357997
URL: https://svnweb.freebsd.org/changeset/base/357997

Log:
  Temporarily skip failing sys.net.if_lagg_test.witness on i386 CI

  PR:		244163
  Sponsored by:	The FreeBSD Foundation

Changes:
  head/tests/sys/net/if_lagg_test.sh

Comment 2 Bryan Drewery freebsd_committer

2020-06-15 17:41:50 UTC

This is weird. Is lagg actually involved here?

Comment 3 Li-Wen Hsu freebsd_committer

2020-07-13 19:43:09 UTC

(In reply to Bryan Drewery from comment #2)
This test case is simply doing:
`sysctl -n debug.witness.badstacks | grep -q 'at lagg_'`

and fails if there is anything found. Is it possible due to kyua has running other tests before and affects this?