Bug 212561 - stucking kyua test (/usr/tests/sys/acl/01) with enabled INVARIANT on FreeBSD 10.3-RELEASE
Summary: stucking kyua test (/usr/tests/sys/acl/01) with enabled INVARIANT on FreeBSD ...
Status: Closed FIXED
Alias: None
Product: Base System
Classification: Unclassified
Component: kern (show other bugs)
Version: 10.3-RELEASE
Hardware: amd64 Any
: --- Affects Some People
Assignee: freebsd-bugs (Nobody)
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2016-09-10 14:53 UTC by op
Modified: 2019-04-22 05:03 UTC (History)
6 users (show)

See Also:
op: mfc-stable10?


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description op 2016-09-10 14:53:19 UTC
How to reproduce:

--8<--

echo "WITH_TESTS=" >> /etc/src.conf
echo "options INVARIANT_SUPPORT" >> /usr/src/sys/amd64/conf/GENERIC
echo "options INVARIANTS" >> /usr/src/sys/amd64/conf/GENERIC

make buildworld kernel installworld
reboot

cd /usr/tests/sys/acl
kldload zfs
kyua test

--8<--

And I got these results: 

--8<--
root@f10:~ # kldload zfs
ZFS NOTICE: Prefetch is disabled by default if less than 4GB of RAM is present;
            to enable, add "vfs.zfs.prefetch_disable=0" to /boot/loader.conf.
ZFS filesystem version: 5
ZFS storage pool version: features support (5000)
root@f10:~ # cd /usr/tests/sys/acl/
root@f10:/usr/tests/sys/acl # ls
00                      04                      tools-nfs4-psarc.test
01                      Kyuafile                tools-nfs4-trivial.test
02                      run                     tools-nfs4.test
03                      tools-crossfs.test      tools-posix.test
root@f10:/usr/tests/sys/acl # kyua test
00:main  ->  passed  [0.516s]
01:main  ->  ^C[-- Signal caught; please wait for cleanup --]
^C[-- Signal caught; please wait for cleanup --]
broken: Caught unexpected exception: Tester received signal 6; this is a bug  [96.360s]
kyua: E: Interrupted by signal 2.

root@f10:/usr/tests/sys/acl # uname -a
FreeBSD f10.3r 10.3-RELEASE FreeBSD 10.3-RELEASE #0: Sat Sep 10 16:29:10 UTC 2016     root@f10.3r:/usr/obj/usr/src/sys/GENERIC  amd64
--8<--

This is on unmodified (except the enabled INVARIANTS and enabled TESTS) FreeBSD 10.3-RELEASE.

It's full reproducible and possible relates to https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=209580
Comment 1 op 2016-09-10 14:55:38 UTC
root@f10:/usr/tests/sys/acl # procstat -kk 1476
  PID    TID COMM             TDNAME           KSTACK                       
 1476 100096 zpool            -                mi_switch+0x179 sleepq_switch+0x152 sleepq_wait+0x43 _sx_xlock_hard+0x4c8 _sx_xlock+0x9a spa_create+0x3f zfs_ioc_pool_create+0x1a0 zfsdev_ioctl+0x78b devfs_ioctl_f+0x121 kern_ioctl+0x22b sys_ioctl+0x140 amd64_syscall+0x2c4 Xfast_syscall+0xfb
Comment 2 op 2016-09-10 14:57:30 UTC
PID TT  STAT      TIME COMMAND
   0  -  DLs  343:18.61 [kernel/swapper]
   0  -  DLs    0:00.00 [kernel/firmware tas]
   0  -  DLs    0:00.00 [kernel/acpi_task_0]
   0  -  DLs    0:00.00 [kernel/acpi_task_1]
   0  -  DLs    0:00.00 [kernel/acpi_task_2]
   0  -  DLs    0:00.00 [kernel/ffs_trim tas]
   0  -  DLs    0:00.01 [kernel/thread taskq]
   0  -  DLs    0:00.00 [kernel/kqueue taskq]
   0  -  DLs    0:00.00 [kernel/vtnet0 rxq 0]
   0  -  DLs    0:00.00 [kernel/vtnet0 txq 0]
   0  -  DLs    0:00.00 [kernel/CAM taskq]
   0  -  DLs    0:00.00 [kernel/system_taskq]
   0  -  DLs    0:00.00 [kernel/system_taskq]
   0  -  DLs    0:00.00 [kernel/dbu_evict]
   0  -  DLs    0:00.01 [kernel/zio_null_iss]
   0  -  DLs    0:00.01 [kernel/zio_null_int]
   0  -  DLs    0:00.00 [kernel/zio_read_iss]
   0  -  DLs    0:00.00 [kernel/zio_read_iss]
   0  -  DLs    0:00.00 [kernel/zio_read_iss]
   0  -  DLs    0:00.00 [kernel/zio_read_iss]
   0  -  DLs    0:00.00 [kernel/zio_read_iss]
   0  -  DLs    0:00.00 [kernel/zio_read_iss]
   0  -  DLs    0:00.00 [kernel/zio_read_iss]
   0  -  DLs    0:00.00 [kernel/zio_read_iss]
   0  -  DLs    0:00.00 [kernel/zio_read_int]
   0  -  DLs    0:00.00 [kernel/zio_write_is]
   0  -  DLs    0:00.00 [kernel/zio_write_is]
   0  -  DLs    0:00.00 [kernel/zio_write_is]
   0  -  DLs    0:00.00 [kernel/zio_write_is]
   0  -  DLs    0:00.00 [kernel/zio_write_is]
   0  -  DLs    0:00.00 [kernel/zio_write_is]
   0  -  DLs    0:00.00 [kernel/zio_write_in]
   0  -  DLs    0:00.00 [kernel/zio_write_in]
   0  -  DLs    0:00.00 [kernel/zio_write_in]
   0  -  DLs    0:00.00 [kernel/zio_write_in]
   0  -  DLs    0:00.00 [kernel/zio_write_in]
   0  -  DLs    0:00.00 [kernel/zio_write_in]
   0  -  DLs    0:00.00 [kernel/zio_write_in]
   0  -  DLs    0:00.00 [kernel/zio_write_in]
   0  -  DLs    0:00.00 [kernel/zio_write_in]
   0  -  DLs    0:00.00 [kernel/zio_write_in]
   0  -  DLs    0:00.00 [kernel/zio_write_in]
   0  -  DLs    0:00.00 [kernel/zio_write_in]
   0  -  DLs    0:00.00 [kernel/zio_write_in]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_iss]
   0  -  DLs    0:00.00 [kernel/zio_free_int]
   0  -  DLs    0:00.00 [kernel/zio_claim_is]
   0  -  DLs    0:00.00 [kernel/zio_claim_in]
   0  -  DLs    0:00.00 [kernel/zio_ioctl_is]
   0  -  DLs    0:00.00 [kernel/zio_ioctl_in]
   0  -  DLs    0:00.00 [kernel/zfs_vn_rele_]
   1  -  ILs    0:00.01 /sbin/init --
   2  -  DL     0:00.00 [cam/doneq0]
   2  -  DL     0:00.00 [cam/scanner]
   3  -  DL     0:00.00 [sctp_iterator]
   4  -  DL     0:00.01 [pagedaemon/pagedaem]
   4  -  DL     0:00.00 [pagedaemon/uma]
   5  -  DL     0:00.00 [vmdaemon]
   6  -  DL     0:00.00 [pagezero]
   7  -  DL     0:00.00 [bufdaemon/bufdaemon]
   7  -  DL     0:00.01 [bufdaemon// worker]
   8  -  DL     0:00.01 [vnlru]
   9  -  DL     0:00.02 [syncer]
  10  -  DL     0:00.00 [audit]
  11  -  RL    12:04.20 [idle/idle: cpu0]
  11  -  RL    12:04.02 [idle/idle: cpu1]
  12  -  WL     0:00.00 [intr/swi1: netisr 0]
  12  -  WL     0:00.00 [intr/swi3: vm]
  12  -  WL     0:00.29 [intr/swi4: clock]
  12  -  WL     0:00.00 [intr/swi4: clock]
  12  -  WL     0:00.00 [intr/swi6: task que]
  12  -  WL     0:00.00 [intr/swi6: Giant ta]
  12  -  WL     0:00.00 [intr/swi5: fast tas]
  12  -  WL     0:00.18 [intr/irq264: ahci0:]
  12  -  WL     0:00.00 [intr/irq265: ahci0:]
  12  -  WL     0:00.00 [intr/irq266: ahci0:]
  12  -  WL     0:00.00 [intr/irq267: ahci0:]
  12  -  WL     0:00.00 [intr/irq268: ahci0:]
  12  -  WL     0:00.00 [intr/irq269: ahci0:]
  12  -  WL     0:00.00 [intr/irq270: ahci0:]
  12  -  WL     0:00.00 [intr/irq271: ahci0:]
  12  -  WL     0:00.00 [intr/irq272: virtio]
  12  -  WL     0:00.00 [intr/irq273: virtio]
  12  -  WL     0:00.00 [intr/irq274: virtio]
  12  -  WL     0:00.00 [intr/irq1: atkbd0]
  12  -  WL     0:00.00 [intr/irq12: psm0]
  12  -  WL     0:00.36 [intr/swi0: uart uar]
  13  -  DL     0:00.01 [geom/g_event]
  13  -  DL     0:00.00 [geom/g_up]
  13  -  DL     0:00.01 [geom/g_down]
  14  -  DL     0:00.11 [rand_harvestq]
 319  -  Is     0:00.01 dhclient: vtnet0 [priv] (dhclient)
 381  -  Is     0:00.00 dhclient: vtnet0 (dhclient)
 382  -  Is     0:00.00 /sbin/devd
 466  -  Ss     0:00.01 /usr/sbin/syslogd -s
 654  -  Is     0:00.00 /usr/sbin/sshd
 657  -  Ss     0:00.01 sendmail: accepting connections (sendmail)
 660  -  Is     0:00.00 sendmail: Queue runner@00:30:00 for /var/spool/clientmq
 664  -  Ss     0:00.00 /usr/sbin/cron -s
 723  -  DL     0:00.01 [zfskern/arc_reclaim]
 723  -  DL     0:00.01 [zfskern/arc_user_ev]
 723  -  DL     0:00.00 [zfskern/l2arc_feed_]
 926  -  DL     0:00.01 [md0]
1254  -  D      0:00.00 zpool destroy -f acltools
1269  -  Ss     0:00.26 tmux: server (/tmp/tmux-0/default) (tmux)
1468  -  Is     0:00.00 /bin/sh /usr/tests/sys/acl/01
1474  -  DL     0:00.00 [md1]
1476  -  D      0:00.00 zpool create -m /tmp/kyua.tap-tester.saNnMu/acltools.On
 719 u0  Is     0:00.04 login [pam] (login)
 720 u0  I      0:00.02 -csh (csh)
1267 u0  I+     0:00.00 tmux: client (/tmp/tmux-0/default) (tmux)
 711 v0  Is+    0:00.00 /usr/libexec/getty Pc ttyv0
 712 v1  Is+    0:00.02 /usr/libexec/getty Pc ttyv1
 713 v2  Is+    0:00.03 /usr/libexec/getty Pc ttyv2
 714 v3  Is+    0:00.00 /usr/libexec/getty Pc ttyv3
 715 v4  Is+    0:00.00 /usr/libexec/getty Pc ttyv4
 716 v5  Is+    0:00.00 /usr/libexec/getty Pc ttyv5
 717 v6  Is+    0:00.00 /usr/libexec/getty Pc ttyv6
 718 v7  Is+    0:00.03 /usr/libexec/getty Pc ttyv7
1270  0  Is     0:00.01 -csh (csh)
1273  0  I+     0:00.01 kyua test
1467  0  I      0:00.00 /usr/local/libexec/kyua-tap-tester -t300 -vhas.cleanup=
1477  1  Ss     0:00.02 -csh (csh)
1494  1  R+     0:00.00 ps -AH
1495  1  S+     0:00.00 nc -l 9999
1487  2  Ss+    0:00.01 -csh (csh)
Comment 3 Edward Tomasz Napierala freebsd_committer freebsd_triage 2016-09-12 10:23:52 UTC
It looks like a ZFS bug.  If you look at the process list, you'll see both "zpool destroy" and "zpool create".
Comment 4 op 2016-09-12 20:00:25 UTC
This is a locking error or deadlock, what triggered by INVARIANTS. A similar issue is linked under the See Also sections.
Comment 5 Alexander Motin freebsd_committer freebsd_triage 2016-09-14 19:20:01 UTC
I've tried to reproduce it and failed: on stable/10 tests just passed, on head first test has failed, but not hanged.
Comment 6 Oliver Pinter 2016-09-16 10:01:42 UTC
Have you enabled in your kernel config?
Comment 7 Oliver Pinter 2016-09-16 10:02:29 UTC
Sorry, have you enabled the INVARIANTS in your kernel config?
Comment 8 Peter Holm freebsd_committer freebsd_triage 2016-09-16 12:05:43 UTC
I see no problems with 10.3-STABLE #3 r303848

$ cat bug212561.sh 
#!/bin/sh

uname -a
strings -a /boot/kernel/kernel | egrep "options.*INVARIANT"

kldload zfs
cd /usr/tests/sys/acl
for i in `jot 100`; do
        kyua test > /dev/null 2>&1
done
$ ./bug212561.sh 
FreeBSD t1.osted.lan 10.3-STABLE FreeBSD 10.3-STABLE #3 r303848: Fri Sep 16 13:31:52 CEST 2016     pho@t1.osted.lan:/usr/src/sys/amd64/compile/PHO  amd64
options INVARIANT_SUPPORT
options INVARIANTS
$
Comment 9 Peter Holm freebsd_committer freebsd_triage 2016-09-16 12:34:08 UTC
That of cause proved to be not quite true:
panic: failed to set signal flags for ast p 0xfffff8016fa659f0 td 0xfffff8016faa3960 fl 4

https://people.freebsd.org/~pho/stress/log/bug212561.txt
I can repeat this.
Comment 10 Peter Holm freebsd_committer freebsd_triage 2016-09-16 21:27:02 UTC
Ah!, never mind. The panic is unrelated and was fixed in r303914.
So, "no problems with 10.3-STABLE #3 r303848".
Comment 11 op 2016-09-16 22:22:24 UTC
I can retry it soon.

Additional info: my setup is a bhyve VM with 2 CPU and 2 GB of RAM and 20 GB of HDD image, on a Haswell based i5-4670 and a Skylake based i7-6700. I use the vmrun.sh script from the installed examples on Skylake machine and iohyve on Haswell.
Comment 12 Yuri Pankov freebsd_committer freebsd_triage 2018-10-28 21:15:49 UTC
Looks like we can close this one?

$ uname -v
FreeBSD 13.0-CURRENT r339827 GENERIC
$ config -x /boot/kernel/kernel | grep INVARIANT
options INVARIANT_SUPPORT
options INVARIANTS
# kyua test -k /usr/tests/Kyuafile sys/acl
sys/acl/00:main  ->  passed  [1.228s]
sys/acl/01:main  ->  passed  [2.356s]
sys/acl/02:main  ->  passed  [2.127s]
sys/acl/03:main  ->  passed  [1.936s]
sys/acl/04:main  ->  passed  [0.563s]
Comment 13 Peter Holm freebsd_committer freebsd_triage 2018-10-29 07:36:32 UTC
No problem seen with 13.0-CURRENT cc6ee48(projects/epochrw) PHO-GENERIC  amd64
Comment 14 Enji Cooper freebsd_committer freebsd_triage 2019-04-22 05:03:20 UTC
Closing based on comment # 12 and comment # 13 and due to lack of submitter feedback.