NetBSD Problem Report #57371

From www@netbsd.org  Wed Apr 19 21:29:35 2023
Return-Path: <www@netbsd.org>
Received: from mail.netbsd.org (mail.netbsd.org [199.233.217.200])
	(using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits))
	(Client CN "mail.NetBSD.org", Issuer "mail.NetBSD.org CA" (not verified))
	by mollari.NetBSD.org (Postfix) with ESMTPS id 225381A9239
	for <gnats-bugs@gnats.NetBSD.org>; Wed, 19 Apr 2023 21:29:35 +0000 (UTC)
Message-Id: <20230419212933.CBF841A923A@mollari.NetBSD.org>
Date: Wed, 19 Apr 2023 21:29:33 +0000 (UTC)
From: jspath55@gmail.com
Reply-To: jspath55@gmail.com
To: gnats-bugs@NetBSD.org
Subject: Automated test fs/vfs/t_vnops:nfs_rename_reg_nodir fails intermittently on Rpi3 and Rpi4
X-Send-Pr-Version: www-1.0

>Number:         57371
>Category:       kern
>Synopsis:       Automated test fs/vfs/t_vnops:nfs_rename_reg_nodir fails intermittently on Rpi3 and Rpi4
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    kern-bug-people
>State:          open
>Class:          sw-bug
>Submitter-Id:   net
>Arrival-Date:   Wed Apr 19 21:30:00 +0000 2023
>Last-Modified:  Sun May 14 01:35:00 +0000 2023
>Originator:     Jim Spath
>Release:        10.0_BETA
>Organization:
>Environment:
NetBSD nb4 10.0_BETA NetBSD 10.0_BETA (GENERIC64) #0: Fri Jan 13 19:15:32 UTC 2023  mkrepro@mkrepro.NetBSD.org:/usr/src/sys/arch/evbarm/compile/GENERIC64 evbarm

>Description:
After seeing a pass then a failure for the test case, I ran it alone frequently and found intermittent failures.

cd /usr/tests
atf-run fs/vfs/t_vnops:nfs_rename_reg_nodir

Example failure message

tc-end: 1681852322.816669, nfs_rename_reg_nodir, failed, /usr/src/tests/fs/vfs/t_vnops.c:486: sb.st_nlink != 1



More lines from a failure:
tc-se:Here we go.
tc-se:can't register with udp6 portmap
tc-se:can't register with tcp6 portmap
tc-se:got mount request from 10.3.2.2
tc-se:-> rpcpath: /myexport
tc-se:-> dirpath: /myexport
tc-se:Mount successful.
tc-so:[   1.0000000] entropy: ready
tc-so:[   1.0200050] ZFS filesystem version: 5
tc-so:[   1.4500050] 10.3.2.1:/myexport: inaccurate wcc data (ctime) detected, disabling wcc (ctime 1681912801.213091809 1681912801.213091809, mtime 1681912801.213091809 1681912801.213091809)
tc-end: 1681912801.324130, nfs_rename_reg_nodir, failed, /usr/src/tests/fs/vfs/t_vnops.c:486: sb.st_nlink != 1
tp-end: 1681912801.324689, fs/vfs/t_vnops
info: time.end, Wed Apr 19 14:00:01 UTC 2023


Other lines from a pass:
tc-se:Getting mount list.
tc-se:Here we go.
tc-se:can't register with udp6 portmap
tc-se:can't register with tcp6 portmap
tc-se:got mount request from 10.3.2.2
tc-se:-> rpcpath: /myexport
tc-se:-> dirpath: /myexport
tc-se:Mount successful.
tc-so:[   1.0000000] entropy: ready
tc-so:[   1.0200050] ZFS filesystem version: 5
tc-so:[   1.5700050] 10.3.2.1:/myexport: inaccurate wcc data (ctime) detected, disabling wcc (ctime 1681913161.729552120 1681913161.729552120, mtime 1681913161.729552120 1681913161.729552120)
tc-end: 1681913162.432160, nfs_rename_reg_nodir, passed
tp-end: 1681913162.432711, fs/vfs/t_vnops
info: time.end, Wed Apr 19 14:06:02 UTC 2023

>How-To-Repeat:
The failure occurs only a few percentage of the runs I have done:

$ grep tc-end t_vnops.log | wc -l
      21
$ grep tc-end t_vnops.log | grep passed | wc -l
      20

>Fix:
Unknown.

>Audit-Trail:
From: David Holland <dholland-bugs@netbsd.org>
To: gnats-bugs@netbsd.org
Cc: 
Subject: Re: kern/57371: Automated test fs/vfs/t_vnops:nfs_rename_reg_nodir
 fails intermittently on Rpi3 and Rpi4
Date: Sun, 14 May 2023 01:32:20 +0000

 On Wed, Apr 19, 2023 at 09:30:00PM +0000, jspath55@gmail.com wrote:
  > tc-end: 1681852322.816669, nfs_rename_reg_nodir, failed, /usr/src/tests/fs/vfs/t_vnops.c:486: sb.st_nlink != 1

 so it seems what this test does is:

    touch file1 file2
    link file1 file_link
    rename file1 file3
    rename file3 file2
    rename file2 file_link

 that is, after hardlinking file1 it successively renames it (a) to a
 fresh name, (b) over file2, then (c) over the hard link to itself.

 It would be nice to see the state of the filesystem when it fails, and
 in particular whether the nfs sillyrename logic has (incorrectly)
 fired. However, I realize that between atf hiding everything and the
 difficulty of inspecting things happening inside rump that's not going
 to happen, so someone's going to have to set up a test VM and
 experiment.

 Do you know if the prints mentioning ZFS are because it's nfs
 exporting a ZFS volume or if they're just random prints? I can't tell
 from the maze of driver logic.

 -- 
 David A. Holland
 dholland@netbsd.org

Home	PR Database Search