2023-03-14 02:28:36

by Jie Zhou (Fujitsu)

[permalink] [raw]
Subject: nfstest_delegation test can not stop

hi,

I run following test command and stuck at recall12 recall14 recall20
recall22 recall40 recall42 recall48 recall50.

./nfstest_delegation --nfsversion=4 -e /nfsroot --server <server ip>
--client <client2 ip> --trcdelay 10
./nfstest_delegation --nfsversion=4.1 -e /nfsroot --server <server ip>
--client <client2 ip> --trcdelay 10
./nfstest_delegation --nfsversion=4.2 -e /nfsroot --server <server ip>
--client <client2 ip> --trcdelay 10

recall12 recall14 recall20 recall22 recall40 recall42 recall48 recall50
tests write files after remove.
After comment out above testcases result is:
646 tests (588 passed, 58 failed)
FAIL: WRITE delegation should be granted

run ./nfstest_dio have following messages.
INFO: 16:19:51.455222 - WRITE delegations are not available -- skipping
tests expecting write delegations

test OS: RHEL9.2 Nightly Build
Why do these testcases can not stop?

best regards,
--
------------------------------------------------
zhoujie
Dept 1
No. 6 Wenzhu Road,
Nanjing, 210012, China
TEL:+86+25-86630566-8508
FUJITSU INTERNAL:7998-8508
E-Mail:[email protected]
------------------------------------------------


2023-03-15 11:40:09

by Jeffrey Layton

[permalink] [raw]
Subject: Re: nfstest_delegation test can not stop

On Tue, 2023-03-14 at 02:28 +0000, [email protected] wrote:
> hi,
>
> I run following test command and stuck at recall12 recall14 recall20
> recall22 recall40 recall42 recall48 recall50.
>
> ./nfstest_delegation --nfsversion=4 -e /nfsroot --server <server ip>
> --client <client2 ip> --trcdelay 10
> ./nfstest_delegation --nfsversion=4.1 -e /nfsroot --server <server ip>
> --client <client2 ip> --trcdelay 10
> ./nfstest_delegation --nfsversion=4.2 -e /nfsroot --server <server ip>
> --client <client2 ip> --trcdelay 10
>
> recall12 recall14 recall20 recall22 recall40 recall42 recall48 recall50
> tests write files after remove.
> After comment out above testcases result is:
> 646 tests (588 passed, 58 failed)
> FAIL: WRITE delegation should be granted
>
> run ./nfstest_dio have following messages.
> INFO: 16:19:51.455222 - WRITE delegations are not available -- skipping
> tests expecting write delegations
>
> test OS: RHEL9.2 Nightly Build
> Why do these testcases can not stop?

Are you asking why these testcases don't pass? If you're testing against
the kernel's NFS server then it's because it does not (yet) support
write delegations.
--
Jeff Layton <[email protected]>

2023-03-17 09:02:48

by Jie Zhou (Fujitsu)

[permalink] [raw]
Subject: Re: nfstest_delegation test can not stop

hi,

> Can you provide a log file for the run?
run following command and test result is attached.
./nfstest_delegation --nfsversion=4 -e /nfsroot --server 192.168.122.110
--client 192.168.122.109 --trcdelay 10 -v all --createlog --keeptraces
--rexeclog recall22 >nfstest-delegationv4-log_recall22 2>&1

In server run "cat /etc/exports" output is following.
/nfsroot *(rw,insecure,no_subtree_check,no_root_squash,fsid=1)

best regards,

On 3/15/23 22:28, Mora, Jorge wrote:
> Hello,
>
> Can you provide a log file for the run?
>
> ./nfstest_delegation -s 192.168.68.86 -e /export -v all --createlog
> --keeptraces --rexeclog recall22
>
> --Jorge
>
> *From: *Jeff Layton <[email protected]>
> *Date: *Wednesday, March 15, 2023 at 5:40 AM
> *To: *[email protected] <[email protected]>, Mora, Jorge
> <[email protected]>
> *Cc: *linux-nfs <[email protected]>
> *Subject: *Re: nfstest_delegation test can not stop
>
> NetApp Security WARNING: This is an external email. Do not click links
> or open attachments unless you recognize the sender and know the content
> is safe.
>
>
>
>
> On Tue, 2023-03-14 at 02:28 +0000, [email protected] wrote:
> > hi,
> >
> > I run following test command and stuck at recall12 recall14 recall20
> > recall22 recall40 recall42 recall48 recall50.
> >
> > ./nfstest_delegation --nfsversion=4 -e /nfsroot --server <server ip>
> > --client <client2 ip> --trcdelay 10
> > ./nfstest_delegation --nfsversion=4.1 -e /nfsroot --server  <server ip>
> > --client <client2 ip> --trcdelay 10
> > ./nfstest_delegation --nfsversion=4.2 -e /nfsroot --server  <server ip>
> > --client <client2 ip> --trcdelay 10
> >
> > recall12 recall14 recall20 recall22 recall40 recall42 recall48 recall50
> > tests write files after remove.
> > After comment out above testcases result is:
> > 646 tests (588 passed, 58 failed)
> > FAIL: WRITE delegation should be granted
> >
> > run ./nfstest_dio have following messages.
> > INFO: 16:19:51.455222 - WRITE delegations are not available -- skipping
> > tests expecting write delegations
> >
> > test OS: RHEL9.2 Nightly Build
> > Why do these testcases can not stop?
>
> Are you asking why these testcases don't pass? If you're testing against
> the kernel's NFS server then it's because it does not (yet) support
> write delegations.
> --
> Jeff Layton <[email protected]>
>

--
------------------------------------------------
zhoujie
Dept 1
No. 6 Wenzhu Road,
Nanjing, 210012, China
TEL:+86+25-86630566-8508
FUJITSU INTERNAL:7998-8508
E-Mail:[email protected]
------------------------------------------------


Attachments:
nfstest-delegationv4-log_recall22 (6.47 kB)
nfstest-delegationv4-log_recall22

2023-03-17 18:14:19

by Mora, Jorge

[permalink] [raw]
Subject: Re: nfstest_delegation test can not stop

Hello,
Could you send me all the files created by the run, both log files and the packet trace (/tmp/nfstest_delegation_20230317_170647*)?
 
--Jorge
 
From: [email protected] <[email protected]>
Date: Friday, March 17, 2023 at 3:00 AM
To: Mora, Jorge <[email protected]>, Jeff Layton <[email protected]>
Cc: linux-nfs <[email protected]>
Subject: Re: nfstest_delegation test can not stop
NetApp Security WARNING: This is an external email. Do not click links or open attachments unless you recognize the sender and know the content is safe.




hi,

 > Can you provide a log file for the run?
run following command and test result is attached.
./nfstest_delegation --nfsversion=4 -e /nfsroot --server 192.168.122.110
--client 192.168.122.109 --trcdelay 10 -v all --createlog --keeptraces
--rexeclog recall22 >nfstest-delegationv4-log_recall22 2>&1

In server run "cat /etc/exports" output is following.
/nfsroot      *(rw,insecure,no_subtree_check,no_root_squash,fsid=1)

best regards,

On 3/15/23 22:28, Mora, Jorge wrote:
> Hello,
>
> Can you provide a log file for the run?
>
> ./nfstest_delegation -s 192.168.68.86 -e /export -v all --createlog
> --keeptraces --rexeclog recall22
>
> --Jorge
>
> *From: *Jeff Layton <[email protected]>
> *Date: *Wednesday, March 15, 2023 at 5:40 AM
> *To: *[email protected] <[email protected]>, Mora, Jorge
> <[email protected]>
> *Cc: *linux-nfs <[email protected]>
> *Subject: *Re: nfstest_delegation test can not stop
>
> NetApp Security WARNING: This is an external email. Do not click links
> or open attachments unless you recognize the sender and know the content
> is safe.
>
>
>
>
> On Tue, 2023-03-14 at 02:28 +0000, [email protected] wrote:
>  > hi,
>  >
>  > I run following test command and stuck at recall12 recall14 recall20
>  > recall22 recall40 recall42 recall48 recall50.
>  >
>  > ./nfstest_delegation --nfsversion=4 -e /nfsroot --server <server ip>
>  > --client <client2 ip> --trcdelay 10
>  > ./nfstest_delegation --nfsversion=4.1 -e /nfsroot --server  <server ip>
>  > --client <client2 ip> --trcdelay 10
>  > ./nfstest_delegation --nfsversion=4.2 -e /nfsroot --server  <server ip>
>  > --client <client2 ip> --trcdelay 10
>  >
>  > recall12 recall14 recall20 recall22 recall40 recall42 recall48 recall50
>  > tests write files after remove.
>  > After comment out above testcases result is:
>  > 646 tests (588 passed, 58 failed)
>  > FAIL: WRITE delegation should be granted
>  >
>  > run ./nfstest_dio have following messages.
>  > INFO: 16:19:51.455222 - WRITE delegations are not available -- skipping
>  > tests expecting write delegations
>  >
>  > test OS: RHEL9.2 Nightly Build
>  > Why do these testcases can not stop?
>
> Are you asking why these testcases don't pass? If you're testing against
> the kernel's NFS server then it's because it does not (yet) support
> write delegations.
> --
> Jeff Layton <[email protected]>
>

--
------------------------------------------------
zhoujie
Dept 1
No. 6 Wenzhu Road,
Nanjing, 210012, China
TEL:+86+25-86630566-8508
FUJITSU INTERNAL:7998-8508
E-Mail:[email protected]
------------------------------------------------

2023-03-29 00:18:22

by Jie Zhou (Fujitsu)

[permalink] [raw]
Subject: Re: nfstest_delegation test can not stop

ping

On 3/17/23 16:58, zhoujie2011 wrote:
> hi,
>
> > Can you provide a log file for the run?
> run following command and test result is attached.
> ./nfstest_delegation --nfsversion=4 -e /nfsroot --server 192.168.122.110
> --client 192.168.122.109 --trcdelay 10 -v all --createlog --keeptraces
> --rexeclog recall22 >nfstest-delegationv4-log_recall22 2>&1
>
> In server run "cat /etc/exports" output is following.
> /nfsroot      *(rw,insecure,no_subtree_check,no_root_squash,fsid=1)
>
> best regards,
>
> On 3/15/23 22:28, Mora, Jorge wrote:
>> Hello,
>>
>> Can you provide a log file for the run?
>>
>> ./nfstest_delegation -s 192.168.68.86 -e /export -v all --createlog
>> --keeptraces --rexeclog recall22
>>
>> --Jorge
>>
>> *From: *Jeff Layton <[email protected]>
>> *Date: *Wednesday, March 15, 2023 at 5:40 AM
>> *To: *[email protected] <[email protected]>, Mora, Jorge
>> <[email protected]>
>> *Cc: *linux-nfs <[email protected]>
>> *Subject: *Re: nfstest_delegation test can not stop
>>
>> NetApp Security WARNING: This is an external email. Do not click links
>> or open attachments unless you recognize the sender and know the
>> content is safe.
>>
>>
>>
>>
>> On Tue, 2023-03-14 at 02:28 +0000, [email protected] wrote:
>>  > hi,
>>  >
>>  > I run following test command and stuck at recall12 recall14 recall20
>>  > recall22 recall40 recall42 recall48 recall50.
>>  >
>>  > ./nfstest_delegation --nfsversion=4 -e /nfsroot --server <server ip>
>>  > --client <client2 ip> --trcdelay 10
>>  > ./nfstest_delegation --nfsversion=4.1 -e /nfsroot --server  <server
>> ip>
>>  > --client <client2 ip> --trcdelay 10
>>  > ./nfstest_delegation --nfsversion=4.2 -e /nfsroot --server  <server
>> ip>
>>  > --client <client2 ip> --trcdelay 10
>>  >
>>  > recall12 recall14 recall20 recall22 recall40 recall42 recall48
>> recall50
>>  > tests write files after remove.
>>  > After comment out above testcases result is:
>>  > 646 tests (588 passed, 58 failed)
>>  > FAIL: WRITE delegation should be granted
>>  >
>>  > run ./nfstest_dio have following messages.
>>  > INFO: 16:19:51.455222 - WRITE delegations are not available --
>> skipping
>>  > tests expecting write delegations
>>  >
>>  > test OS: RHEL9.2 Nightly Build
>>  > Why do these testcases can not stop?
>>
>> Are you asking why these testcases don't pass? If you're testing against
>> the kernel's NFS server then it's because it does not (yet) support
>> write delegations.
>> --
>> Jeff Layton <[email protected]>
>>
>

--
------------------------------------------------
zhoujie
Dept 1
No. 6 Wenzhu Road,
Nanjing, 210012, China
TEL:+86+25-86630566-8508
FUJITSU INTERNAL:7998-8508
E-Mail:[email protected]
------------------------------------------------

2023-03-29 18:35:28

by Mora, Jorge

[permalink] [raw]
Subject: Re: nfstest_delegation test can not stop

Hello,

I am still waiting for all the files created for the run, not just the output to the screen:

/tmp/nfstest_delegation_20230317_170647*


--Jorge

________________________________________
From: [email protected] <[email protected]>
Sent: Tuesday, March 28, 2023 6:15 PM
To: Mora, Jorge; Jeff Layton
Cc: linux-nfs
Subject: Re: nfstest_delegation test can not stop

NetApp Security WARNING: This is an external email. Do not click links or open attachments unless you recognize the sender and know the content is safe.




ping

On 3/17/23 16:58, zhoujie2011 wrote:
> hi,
>
> > Can you provide a log file for the run?
> run following command and test result is attached.
> ./nfstest_delegation --nfsversion=4 -e /nfsroot --server 192.168.122.110
> --client 192.168.122.109 --trcdelay 10 -v all --createlog --keeptraces
> --rexeclog recall22 >nfstest-delegationv4-log_recall22 2>&1
>
> In server run "cat /etc/exports" output is following.
> /nfsroot *(rw,insecure,no_subtree_check,no_root_squash,fsid=1)
>
> best regards,
>
> On 3/15/23 22:28, Mora, Jorge wrote:
>> Hello,
>>
>> Can you provide a log file for the run?
>>
>> ./nfstest_delegation -s 192.168.68.86 -e /export -v all --createlog
>> --keeptraces --rexeclog recall22
>>
>> --Jorge
>>
>> *From: *Jeff Layton <[email protected]>
>> *Date: *Wednesday, March 15, 2023 at 5:40 AM
>> *To: *[email protected] <[email protected]>, Mora, Jorge
>> <[email protected]>
>> *Cc: *linux-nfs <[email protected]>
>> *Subject: *Re: nfstest_delegation test can not stop
>>
>> NetApp Security WARNING: This is an external email. Do not click links
>> or open attachments unless you recognize the sender and know the
>> content is safe.
>>
>>
>>
>>
>> On Tue, 2023-03-14 at 02:28 +0000, [email protected] wrote:
>> > hi,
>> >
>> > I run following test command and stuck at recall12 recall14 recall20
>> > recall22 recall40 recall42 recall48 recall50.
>> >
>> > ./nfstest_delegation --nfsversion=4 -e /nfsroot --server <server ip>
>> > --client <client2 ip> --trcdelay 10
>> > ./nfstest_delegation --nfsversion=4.1 -e /nfsroot --server <server
>> ip>
>> > --client <client2 ip> --trcdelay 10
>> > ./nfstest_delegation --nfsversion=4.2 -e /nfsroot --server <server
>> ip>
>> > --client <client2 ip> --trcdelay 10
>> >
>> > recall12 recall14 recall20 recall22 recall40 recall42 recall48
>> recall50
>> > tests write files after remove.
>> > After comment out above testcases result is:
>> > 646 tests (588 passed, 58 failed)
>> > FAIL: WRITE delegation should be granted
>> >
>> > run ./nfstest_dio have following messages.
>> > INFO: 16:19:51.455222 - WRITE delegations are not available --
>> skipping
>> > tests expecting write delegations
>> >
>> > test OS: RHEL9.2 Nightly Build
>> > Why do these testcases can not stop?
>>
>> Are you asking why these testcases don't pass? If you're testing against
>> the kernel's NFS server then it's because it does not (yet) support
>> write delegations.
>> --
>> Jeff Layton <[email protected]>
>>
>

--
------------------------------------------------
zhoujie
Dept 1
No. 6 Wenzhu Road,
Nanjing, 210012, China
TEL$B!'(B+86+25-86630566-8508
FUJITSU INTERNAL$B!'(B7998-8508
E-Mail$B!'([email protected]
------------------------------------------------

2023-03-30 16:59:16

by Mora, Jorge

[permalink] [raw]
Subject: Re: nfstest_delegation test can not stop

Hello,

First of all, the --client option can be used successfully when the system in which you are running the test is able to capture the traffic for both clients, e.g., when you are running VMware and both clients are VMs. If you are using real clients, tcpdump will only capture traffic for the local system.

./nfstest_delegation -h
Test options:
--runtest=RUNTEST
Comma separated list of tests to run, if list starts with a '^' then
all tests are run except the ones listed [default: 'all']
--client=CLIENT
Remote NFS client and options used for recall delegation tests.
Clients are separated by a ',' and each client definition is a list
of arguments separated by a ':' given in the following order if
positional arguments is used (see examples):
clientname:server:export:nfsversion:port:proto:sec:mtpoint [default:
'nfsversion=3:proto=tcp:port=2049']
--client-nfsvers=CLIENT_NFSVERS
Comma separated list of valid NFS versions to use in the --client
option. An NFS version from this list, which is different than that
given by --nfsversion, is selected and included in the --client
option [default: 4.0,4.1]

The second client is a combination of --client and --client-nfsvers and the default for --client is 'nfsversion=3:proto=tcp:port=2049'. This means that the mount for the second 'client' is on the main client with the following nfs mount options: 'nfsversion=4.0:proto=tcp:port=2049' or 'nfsversion=4.1:proto=tcp:port=2049' depending on the value for option --nfsversion. In you case, --nfsversion=4 (if you mean 4.0) the mount options for the second client should be 'nfsversion=4.1...'. This way main mount is 4.0 (holding delegation) and the second mount is 4.1 (recall delegation) on the same system so the network traffic could be fully captured.

Of course, if you specify --nfsversion=4, the client will mount either 4.2, 4.1 or 4.0 (in your logs: NFS version of mount point: 4.2). You need to explicitly specify the NFS version as 4.0, 4.1 or 4.2.

The reason why the test is hanging is because the server is sending NFS4ERR_DELAY to COMMIT:
133 2023-03-30 07:46:22.533580 192.168.122.110 -> 192.168.122.108 NFS v4.2 reply xid:0xfd10f3db SEQUENCE;PUTFH;OPEN;GETFH;ACCESS;GETATTR stid:1,0xe37587e3 rd_deleg_stid:1,0xf1c0280d FH:0x634cb2d9
135 2023-03-30 07:46:22.533973 192.168.122.110 -> 192.168.122.108 NFS v4.2 reply xid:0xfe10f3db SEQUENCE;PUTFH;OPEN;GETFH;ACCESS;GETATTR stid:1,0x497c4f68 FH:0x62ab8136
136 2023-03-30 07:46:22.534191 192.168.122.108 -> 192.168.122.110 NFS v4.2 call xid:0xff10f3db SEQUENCE;PUTFH;LOCK FH:0x62ab8136 WRITE_LT off:0 len:4096 open(stid:1,0x497c4f68, seqid:0) seqid:0
137 2023-03-30 07:46:22.534304 192.168.122.110 -> 192.168.122.108 NFS v4.2 reply xid:0xff10f3db SEQUENCE;PUTFH;LOCK stid:1,0xd4ab77d1
146 2023-03-30 07:46:22.659988 192.168.122.108 -> 192.168.122.110 NFS v4.2 call xid:0x0011f3db SEQUENCE;PUTFH;WRITE;GETATTR FH:0x62ab8136 stid:0,0xd4ab77d1 off:0 len:4096 UNSTABLE4
147 2023-03-30 07:46:22.660009 192.168.122.108 -> 192.168.122.110 NFS v4.2 call xid:0x0111f3db SEQUENCE;PUTFH;WRITE;GETATTR FH:0x62ab8136 stid:0,0xd4ab77d1 off:4096 len:4096 UNSTABLE4
...
191 2023-03-30 07:46:22.660695 192.168.122.108 -> 192.168.122.110 NFS v4.2 call xid:0x1011f3db SEQUENCE;PUTFH;COMMIT FH:0x62ab8136 off:0 len:0
192 2023-03-30 07:46:22.672090 192.168.122.110 -> 192.168.122.108 NFS v4.2 reply xid:0x1011f3db SEQUENCE;PUTFH;COMMIT NFS4ERR_DELAY
194 2023-03-30 07:46:22.778177 192.168.122.108 -> 192.168.122.110 NFS v4.2 call xid:0x1111f3db SEQUENCE;PUTFH;COMMIT FH:0x62ab8136 off:0 len:0
195 2023-03-30 07:46:22.779064 192.168.122.110 -> 192.168.122.108 NFS v4.2 reply xid:0x1111f3db SEQUENCE;PUTFH;COMMIT NFS4ERR_DELAY
197 2023-03-30 07:46:22.882100 192.168.122.108 -> 192.168.122.110 NFS v4.2 call xid:0x1211f3db SEQUENCE;PUTFH;COMMIT FH:0x62ab8136 off:0 len:0
198 2023-03-30 07:46:22.882566 192.168.122.110 -> 192.168.122.108 NFS v4.2 reply xid:0x1211f3db SEQUENCE;PUTFH;COMMIT NFS4ERR_DELAY
200 2023-03-30 07:46:22.986157 192.168.122.108 -> 192.168.122.110 NFS v4.2 call xid:0x1311f3db SEQUENCE;PUTFH;COMMIT FH:0x62ab8136 off:0 len:0
201 2023-03-30 07:46:22.986931 192.168.122.110 -> 192.168.122.108 NFS v4.2 reply xid:0x1311f3db SEQUENCE;PUTFH;COMMIT NFS4ERR_DELAY

As Jeff mentioned earlier, Linux server does not grant write delegations. I don't know what server are you using but the OPEN clearly shows it did not grant a write delegation so this test should fail.

Here is a sample run against a RHEL 8.6 server:
./nfstest_delegation -s 192.168.68.86 -e /export --nfsversion 4.0 -v all --createlog --keeptraces --rexeclog --tracepoints nfs,nfs4 recall22

*** Recall WRITE delegation with RENAME (DST) with file lock
TEST: Running test 'recall22'
DBG5: 10:48:51.644258 - Sync all buffers to disk
DBG2: 10:48:51.651724 - Unmount volume: /usr/bin/sudo umount -f /mnt/t
DBG5: 10:48:51.684054 - Sync all buffers to disk
DBG2: 10:48:51.685482 - Unmount volume: /usr/bin/sudo umount -f /mnt/t_01
DBG2: 10:48:51.719133 - Enable trace points: /usr/bin/sudo sh -c "echo 1 > /sys/kernel/debug/tracing/events/nfs/enable"
DBG2: 10:48:51.761795 - Enable trace points: /usr/bin/sudo sh -c "echo 1 > /sys/kernel/debug/tracing/events/nfs4/enable"
DBG2: 10:48:51.805703 - Capturing trace points: /usr/bin/sudo sh -c "cat /sys/kernel/debug/tracing/trace_pipe > /tmp/nfstest_delegation_20230330_104846_001.out"
DBG2: 10:48:51.808284 - Trace start: /usr/bin/sudo /usr/sbin/tcpdump -i ens160 -n -B 196608 -s 0 -w /tmp/nfstest_delegation_20230330_104846_001.cap host 192.168.68.87
DBG2: 10:48:52.904843 - Mount volume: /usr/bin/sudo mount -o vers=4.0,proto=tcp,sec=sys,hard,rsize=4096,wsize=4096 192.168.68.86:/export /mnt/t
DBG5: 10:48:53.045345 - Get the actual NFS version of mount point: findmnt /mnt/t
DBG6: 10:48:53.053811 - NFS version of mount point: 4.0
DBG2: 10:48:53.054069 - Mount volume: /usr/bin/sudo mount -o vers=4.1,proto=tcp,sec=sys,hard,rsize=4096,wsize=4096 192.168.68.86:/export /mnt/t_01
DBG5: 10:48:53.194449 - Get the actual NFS version of mount point: findmnt /mnt/t_01
DBG6: 10:48:53.202076 - NFS version of mount point: 4.1
DBG4: 10:48:53.202297 - Open /mnt/t/nfstest_delegation_20230330_104846_f_001 so open owner sticks around
DBG2: 10:48:53.207257 - Open file for WRITE [/mnt/t/nfstest_delegation_20230330_104846_f_002]
PASS: Open file for WRITE should succeed
DBG3: 10:48:53.208168 - Lock /mnt/t/nfstest_delegation_20230330_104846_f_002 (F_SETLK, F_WRLCK) start=0 len=4096
PASS: Lock file with F_WRLCK should succeed
DBG3: 10:48:53.209489 - Write file on client holding delegation [/mnt/t/nfstest_delegation_20230330_104846_f_002]
PASS: Write file on client holding delegation should succeed
DBG2: 10:48:53.310548 - Rename into the file (DST) from another client to recall delegation [nfstest_delegation_20230330_104846_f_003 -> nfstest_delegation_20230330_104846_f_002]
PASS: Rename into the file (DST) from another client should succeed
DBG3: 10:48:53.320851 - Write file after conflicting operation [/mnt/t/nfstest_delegation_20230330_104846_f_002]
PASS: Write file after conflicting operation may succeed
DBG4: 10:48:53.447733 - Close /mnt/t/nfstest_delegation_20230330_104846_f_002
DBG5: 10:48:53.450185 - Sync all buffers to disk
DBG2: 10:48:53.457125 - Unmount volume: /usr/bin/sudo umount -f /mnt/t
DBG5: 10:48:53.515896 - Sync all buffers to disk
DBG2: 10:48:53.520120 - Unmount volume: /usr/bin/sudo umount -f /mnt/t_01
DBG5: 10:48:55.580838 - Get all processes: ps -ef
DBG5: 10:48:55.621321 - Stopping packet trace capture: /usr/bin/sudo /usr/bin/kill -SIGINT 348494
DBG5: 10:48:55.656126 - Stopping packet trace capture: /usr/bin/sudo /usr/bin/kill -SIGINT 348489
DBG2: 10:48:55.788319 - Disable trace points: /usr/bin/sudo sh -c "echo 0 > /sys/kernel/debug/tracing/events/nfs/enable"
DBG2: 10:48:55.829243 - Disable trace points: /usr/bin/sudo sh -c "echo 0 > /sys/kernel/debug/tracing/events/nfs4/enable"
DBG5: 10:48:55.875925 - Get all processes: ps -ef
DBG2: 10:48:55.908161 - Stopping trace points capture: /usr/bin/sudo /usr/bin/kill -SIGINT 348493
DBG2: 10:48:55.939992 - Stopping trace points capture: /usr/bin/sudo /usr/bin/kill -SIGINT 348492
DBG2: 10:48:55.972241 - Stopping trace points capture: /usr/bin/sudo /usr/bin/kill -SIGINT 348488
DBG1: 10:48:56.104525 - trace_open [/tmp/nfstest_delegation_20230330_104846_001.cap]
PASS: OPEN should be sent
PASS: OPEN should be sent with CLAIM_NULL
PASS: OPEN should be sent with the name of the file to be opened
PASS: OPEN should be sent with the filehandle of the directory
FAIL: WRITE delegation should be granted
TIME: 4.570563s

I also added option --tracepoints to collect all nfs and nfs4 tracepoints. These are the files that are created:
ll /tmp/nfstest_delegation_20230330_104846*
-rw-r--r--. 1 tcpdump tcpdump 106776 Mar 30 10:48 /tmp/nfstest_delegation_20230330_104846_001.cap (packet trace)
-rw-r--r--. 1 root root 64218 Mar 30 10:48 /tmp/nfstest_delegation_20230330_104846_001.out (tracepoints)
-rw-rw-r--. 1 mora mora 317 Mar 30 10:48 /tmp/nfstest_delegation_20230330_104846_01.log (second 'client' process log file)
-rw-rw-r--. 1 mora mora 9779 Mar 30 10:48 /tmp/nfstest_delegation_20230330_104846.log (main logfile)


--Jorge

________________________________________
From: [email protected] <[email protected]>
Sent: Wednesday, March 29, 2023 7:42 PM
To: Mora, Jorge; Jeff Layton
Cc: linux-nfs
Subject: Re: nfstest_delegation test can not stop

NetApp Security WARNING: This is an external email. Do not click links or open attachments unless you recognize the sender and know the content is safe.




hi,

> I am still waiting for all the files created for the run, not just the output to the screen:
>
> /tmp/nfstest_delegation_20230317_170647*
The log file is attached.

best regards,

>
> ping
>
> On 3/17/23 16:58, zhoujie2011 wrote:
>> hi,
>>
>> > Can you provide a log file for the run?
>> run following command and test result is attached.
>> ./nfstest_delegation --nfsversion=4 -e /nfsroot --server 192.168.122.110
>> --client 192.168.122.109 --trcdelay 10 -v all --createlog --keeptraces
>> --rexeclog recall22 >nfstest-delegationv4-log_recall22 2>&1
>>
>> In server run "cat /etc/exports" output is following.
>> /nfsroot *(rw,insecure,no_subtree_check,no_root_squash,fsid=1)
>>
>> best regards,
>>
>> On 3/15/23 22:28, Mora, Jorge wrote:
>>> Hello,
>>>
>>> Can you provide a log file for the run?
>>>
>>> ./nfstest_delegation -s 192.168.68.86 -e /export -v all --createlog
>>> --keeptraces --rexeclog recall22
>>>
>>> --Jorge
>>>
>>> *From: *Jeff Layton <[email protected]>
>>> *Date: *Wednesday, March 15, 2023 at 5:40 AM
>>> *To: *[email protected] <[email protected]>, Mora, Jorge
>>> <[email protected]>
>>> *Cc: *linux-nfs <[email protected]>
>>> *Subject: *Re: nfstest_delegation test can not stop
>>>
>>> NetApp Security WARNING: This is an external email. Do not click links
>>> or open attachments unless you recognize the sender and know the
>>> content is safe.
>>>
>>>
>>>
>>>
>>> On Tue, 2023-03-14 at 02:28 +0000, [email protected] wrote:
>>> > hi,
>>> >
>>> > I run following test command and stuck at recall12 recall14 recall20
>>> > recall22 recall40 recall42 recall48 recall50.
>>> >
>>> > ./nfstest_delegation --nfsversion=4 -e /nfsroot --server <server ip>
>>> > --client <client2 ip> --trcdelay 10
>>> > ./nfstest_delegation --nfsversion=4.1 -e /nfsroot --server <server
>>> ip>
>>> > --client <client2 ip> --trcdelay 10
>>> > ./nfstest_delegation --nfsversion=4.2 -e /nfsroot --server <server
>>> ip>
>>> > --client <client2 ip> --trcdelay 10
>>> >
>>> > recall12 recall14 recall20 recall22 recall40 recall42 recall48
>>> recall50
>>> > tests write files after remove.
>>> > After comment out above testcases result is:
>>> > 646 tests (588 passed, 58 failed)
>>> > FAIL: WRITE delegation should be granted
>>> >
>>> > run ./nfstest_dio have following messages.
>>> > INFO: 16:19:51.455222 - WRITE delegations are not available --
>>> skipping
>>> > tests expecting write delegations
>>> >
>>> > test OS: RHEL9.2 Nightly Build
>>> > Why do these testcases can not stop?
>>>
>>> Are you asking why these testcases don't pass? If you're testing against
>>> the kernel's NFS server then it's because it does not (yet) support
>>> write delegations.
>>> --
>>> Jeff Layton <[email protected]>
>>>
>>
>
> --
> ------------------------------------------------
> zhoujie
> Dept 1
> No. 6 Wenzhu Road,
> Nanjing, 210012, China
> TEL$B!'(B+86+25-86630566-8508
> FUJITSU INTERNAL$B!'(B7998-8508
> E-Mail$B!'([email protected]
> ------------------------------------------------

--
------------------------------------------------
zhoujie
Dept 1
No. 6 Wenzhu Road,
Nanjing, 210012, China
TEL$B!'(B+86+25-86630566-8508
FUJITSU INTERNAL$B!'(B7998-8508
E-Mail$B!'([email protected]
------------------------------------------------

2023-03-31 02:23:48

by Jie Zhou (Fujitsu)

[permalink] [raw]
Subject: Re: nfstest_delegation test can not stop

hi,

Thanks for reply.

> Of course, if you specify --nfsversion=4, the client will mount
either 4.2, 4.1 or 4.0 (in your logs: NFS version of mount point: 4.2).
You need to explicitly specify the NFS version as 4.0, 4.1 or 4.2.

I understand.

> Here is a sample run against a RHEL 8.6 server:
> ./nfstest_delegation -s 192.168.68.86 -e /export --nfsversion 4.0 -v
all --createlog --keeptraces --rexeclog --tracepoints nfs,nfs4 recall22

I run test OK in RHEL 8.6 server.

best regards,

On 3/31/23 00:57, Mora, Jorge wrote:
> Hello,
>
> First of all, the --client option can be used successfully when the system in which you are running the test is able to capture the traffic for both clients, e.g., when you are running VMware and both clients are VMs. If you are using real clients, tcpdump will only capture traffic for the local system.
>
> ./nfstest_delegation -h
> Test options:
> --runtest=RUNTEST
> Comma separated list of tests to run, if list starts with a '^' then
> all tests are run except the ones listed [default: 'all']
> --client=CLIENT
> Remote NFS client and options used for recall delegation tests.
> Clients are separated by a ',' and each client definition is a list
> of arguments separated by a ':' given in the following order if
> positional arguments is used (see examples):
> clientname:server:export:nfsversion:port:proto:sec:mtpoint [default:
> 'nfsversion=3:proto=tcp:port=2049']
> --client-nfsvers=CLIENT_NFSVERS
> Comma separated list of valid NFS versions to use in the --client
> option. An NFS version from this list, which is different than that
> given by --nfsversion, is selected and included in the --client
> option [default: 4.0,4.1]
>
> The second client is a combination of --client and --client-nfsvers and the default for --client is 'nfsversion=3:proto=tcp:port=2049'. This means that the mount for the second 'client' is on the main client with the following nfs mount options: 'nfsversion=4.0:proto=tcp:port=2049' or 'nfsversion=4.1:proto=tcp:port=2049' depending on the value for option --nfsversion. In you case, --nfsversion=4 (if you mean 4.0) the mount options for the second client should be 'nfsversion=4.1...'. This way main mount is 4.0 (holding delegation) and the second mount is 4.1 (recall delegation) on the same system so the network traffic could be fully captured.
>
> Of course, if you specify --nfsversion=4, the client will mount either 4.2, 4.1 or 4.0 (in your logs: NFS version of mount point: 4.2). You need to explicitly specify the NFS version as 4.0, 4.1 or 4.2.
>
> The reason why the test is hanging is because the server is sending NFS4ERR_DELAY to COMMIT:
> 133 2023-03-30 07:46:22.533580 192.168.122.110 -> 192.168.122.108 NFS v4.2 reply xid:0xfd10f3db SEQUENCE;PUTFH;OPEN;GETFH;ACCESS;GETATTR stid:1,0xe37587e3 rd_deleg_stid:1,0xf1c0280d FH:0x634cb2d9
> 135 2023-03-30 07:46:22.533973 192.168.122.110 -> 192.168.122.108 NFS v4.2 reply xid:0xfe10f3db SEQUENCE;PUTFH;OPEN;GETFH;ACCESS;GETATTR stid:1,0x497c4f68 FH:0x62ab8136
> 136 2023-03-30 07:46:22.534191 192.168.122.108 -> 192.168.122.110 NFS v4.2 call xid:0xff10f3db SEQUENCE;PUTFH;LOCK FH:0x62ab8136 WRITE_LT off:0 len:4096 open(stid:1,0x497c4f68, seqid:0) seqid:0
> 137 2023-03-30 07:46:22.534304 192.168.122.110 -> 192.168.122.108 NFS v4.2 reply xid:0xff10f3db SEQUENCE;PUTFH;LOCK stid:1,0xd4ab77d1
> 146 2023-03-30 07:46:22.659988 192.168.122.108 -> 192.168.122.110 NFS v4.2 call xid:0x0011f3db SEQUENCE;PUTFH;WRITE;GETATTR FH:0x62ab8136 stid:0,0xd4ab77d1 off:0 len:4096 UNSTABLE4
> 147 2023-03-30 07:46:22.660009 192.168.122.108 -> 192.168.122.110 NFS v4.2 call xid:0x0111f3db SEQUENCE;PUTFH;WRITE;GETATTR FH:0x62ab8136 stid:0,0xd4ab77d1 off:4096 len:4096 UNSTABLE4
> ...
> 191 2023-03-30 07:46:22.660695 192.168.122.108 -> 192.168.122.110 NFS v4.2 call xid:0x1011f3db SEQUENCE;PUTFH;COMMIT FH:0x62ab8136 off:0 len:0
> 192 2023-03-30 07:46:22.672090 192.168.122.110 -> 192.168.122.108 NFS v4.2 reply xid:0x1011f3db SEQUENCE;PUTFH;COMMIT NFS4ERR_DELAY
> 194 2023-03-30 07:46:22.778177 192.168.122.108 -> 192.168.122.110 NFS v4.2 call xid:0x1111f3db SEQUENCE;PUTFH;COMMIT FH:0x62ab8136 off:0 len:0
> 195 2023-03-30 07:46:22.779064 192.168.122.110 -> 192.168.122.108 NFS v4.2 reply xid:0x1111f3db SEQUENCE;PUTFH;COMMIT NFS4ERR_DELAY
> 197 2023-03-30 07:46:22.882100 192.168.122.108 -> 192.168.122.110 NFS v4.2 call xid:0x1211f3db SEQUENCE;PUTFH;COMMIT FH:0x62ab8136 off:0 len:0
> 198 2023-03-30 07:46:22.882566 192.168.122.110 -> 192.168.122.108 NFS v4.2 reply xid:0x1211f3db SEQUENCE;PUTFH;COMMIT NFS4ERR_DELAY
> 200 2023-03-30 07:46:22.986157 192.168.122.108 -> 192.168.122.110 NFS v4.2 call xid:0x1311f3db SEQUENCE;PUTFH;COMMIT FH:0x62ab8136 off:0 len:0
> 201 2023-03-30 07:46:22.986931 192.168.122.110 -> 192.168.122.108 NFS v4.2 reply xid:0x1311f3db SEQUENCE;PUTFH;COMMIT NFS4ERR_DELAY
>
> As Jeff mentioned earlier, Linux server does not grant write delegations. I don't know what server are you using but the OPEN clearly shows it did not grant a write delegation so this test should fail.
>
> Here is a sample run against a RHEL 8.6 server:
> ./nfstest_delegation -s 192.168.68.86 -e /export --nfsversion 4.0 -v all --createlog --keeptraces --rexeclog --tracepoints nfs,nfs4 recall22
>
> *** Recall WRITE delegation with RENAME (DST) with file lock
> TEST: Running test 'recall22'
> DBG5: 10:48:51.644258 - Sync all buffers to disk
> DBG2: 10:48:51.651724 - Unmount volume: /usr/bin/sudo umount -f /mnt/t
> DBG5: 10:48:51.684054 - Sync all buffers to disk
> DBG2: 10:48:51.685482 - Unmount volume: /usr/bin/sudo umount -f /mnt/t_01
> DBG2: 10:48:51.719133 - Enable trace points: /usr/bin/sudo sh -c "echo 1 > /sys/kernel/debug/tracing/events/nfs/enable"
> DBG2: 10:48:51.761795 - Enable trace points: /usr/bin/sudo sh -c "echo 1 > /sys/kernel/debug/tracing/events/nfs4/enable"
> DBG2: 10:48:51.805703 - Capturing trace points: /usr/bin/sudo sh -c "cat /sys/kernel/debug/tracing/trace_pipe > /tmp/nfstest_delegation_20230330_104846_001.out"
> DBG2: 10:48:51.808284 - Trace start: /usr/bin/sudo /usr/sbin/tcpdump -i ens160 -n -B 196608 -s 0 -w /tmp/nfstest_delegation_20230330_104846_001.cap host 192.168.68.87
> DBG2: 10:48:52.904843 - Mount volume: /usr/bin/sudo mount -o vers=4.0,proto=tcp,sec=sys,hard,rsize=4096,wsize=4096 192.168.68.86:/export /mnt/t
> DBG5: 10:48:53.045345 - Get the actual NFS version of mount point: findmnt /mnt/t
> DBG6: 10:48:53.053811 - NFS version of mount point: 4.0
> DBG2: 10:48:53.054069 - Mount volume: /usr/bin/sudo mount -o vers=4.1,proto=tcp,sec=sys,hard,rsize=4096,wsize=4096 192.168.68.86:/export /mnt/t_01
> DBG5: 10:48:53.194449 - Get the actual NFS version of mount point: findmnt /mnt/t_01
> DBG6: 10:48:53.202076 - NFS version of mount point: 4.1
> DBG4: 10:48:53.202297 - Open /mnt/t/nfstest_delegation_20230330_104846_f_001 so open owner sticks around
> DBG2: 10:48:53.207257 - Open file for WRITE [/mnt/t/nfstest_delegation_20230330_104846_f_002]
> PASS: Open file for WRITE should succeed
> DBG3: 10:48:53.208168 - Lock /mnt/t/nfstest_delegation_20230330_104846_f_002 (F_SETLK, F_WRLCK) start=0 len=4096
> PASS: Lock file with F_WRLCK should succeed
> DBG3: 10:48:53.209489 - Write file on client holding delegation [/mnt/t/nfstest_delegation_20230330_104846_f_002]
> PASS: Write file on client holding delegation should succeed
> DBG2: 10:48:53.310548 - Rename into the file (DST) from another client to recall delegation [nfstest_delegation_20230330_104846_f_003 -> nfstest_delegation_20230330_104846_f_002]
> PASS: Rename into the file (DST) from another client should succeed
> DBG3: 10:48:53.320851 - Write file after conflicting operation [/mnt/t/nfstest_delegation_20230330_104846_f_002]
> PASS: Write file after conflicting operation may succeed
> DBG4: 10:48:53.447733 - Close /mnt/t/nfstest_delegation_20230330_104846_f_002
> DBG5: 10:48:53.450185 - Sync all buffers to disk
> DBG2: 10:48:53.457125 - Unmount volume: /usr/bin/sudo umount -f /mnt/t
> DBG5: 10:48:53.515896 - Sync all buffers to disk
> DBG2: 10:48:53.520120 - Unmount volume: /usr/bin/sudo umount -f /mnt/t_01
> DBG5: 10:48:55.580838 - Get all processes: ps -ef
> DBG5: 10:48:55.621321 - Stopping packet trace capture: /usr/bin/sudo /usr/bin/kill -SIGINT 348494
> DBG5: 10:48:55.656126 - Stopping packet trace capture: /usr/bin/sudo /usr/bin/kill -SIGINT 348489
> DBG2: 10:48:55.788319 - Disable trace points: /usr/bin/sudo sh -c "echo 0 > /sys/kernel/debug/tracing/events/nfs/enable"
> DBG2: 10:48:55.829243 - Disable trace points: /usr/bin/sudo sh -c "echo 0 > /sys/kernel/debug/tracing/events/nfs4/enable"
> DBG5: 10:48:55.875925 - Get all processes: ps -ef
> DBG2: 10:48:55.908161 - Stopping trace points capture: /usr/bin/sudo /usr/bin/kill -SIGINT 348493
> DBG2: 10:48:55.939992 - Stopping trace points capture: /usr/bin/sudo /usr/bin/kill -SIGINT 348492
> DBG2: 10:48:55.972241 - Stopping trace points capture: /usr/bin/sudo /usr/bin/kill -SIGINT 348488
> DBG1: 10:48:56.104525 - trace_open [/tmp/nfstest_delegation_20230330_104846_001.cap]
> PASS: OPEN should be sent
> PASS: OPEN should be sent with CLAIM_NULL
> PASS: OPEN should be sent with the name of the file to be opened
> PASS: OPEN should be sent with the filehandle of the directory
> FAIL: WRITE delegation should be granted
> TIME: 4.570563s
>
> I also added option --tracepoints to collect all nfs and nfs4 tracepoints. These are the files that are created:
> ll /tmp/nfstest_delegation_20230330_104846*
> -rw-r--r--. 1 tcpdump tcpdump 106776 Mar 30 10:48 /tmp/nfstest_delegation_20230330_104846_001.cap (packet trace)
> -rw-r--r--. 1 root root 64218 Mar 30 10:48 /tmp/nfstest_delegation_20230330_104846_001.out (tracepoints)
> -rw-rw-r--. 1 mora mora 317 Mar 30 10:48 /tmp/nfstest_delegation_20230330_104846_01.log (second 'client' process log file)
> -rw-rw-r--. 1 mora mora 9779 Mar 30 10:48 /tmp/nfstest_delegation_20230330_104846.log (main logfile)
>
>
> --Jorge
>
> ________________________________________
> From: [email protected] <[email protected]>
> Sent: Wednesday, March 29, 2023 7:42 PM
> To: Mora, Jorge; Jeff Layton
> Cc: linux-nfs
> Subject: Re: nfstest_delegation test can not stop
>
> NetApp Security WARNING: This is an external email. Do not click links or open attachments unless you recognize the sender and know the content is safe.
>
>
>
>
> hi,
>
>> I am still waiting for all the files created for the run, not just the output to the screen:
>>
>> /tmp/nfstest_delegation_20230317_170647*
> The log file is attached.
>
> best regards,
>
>>
>> ping
>>
>> On 3/17/23 16:58, zhoujie2011 wrote:
>>> hi,
>>>
>>> > Can you provide a log file for the run?
>>> run following command and test result is attached.
>>> ./nfstest_delegation --nfsversion=4 -e /nfsroot --server 192.168.122.110
>>> --client 192.168.122.109 --trcdelay 10 -v all --createlog --keeptraces
>>> --rexeclog recall22 >nfstest-delegationv4-log_recall22 2>&1
>>>
>>> In server run "cat /etc/exports" output is following.
>>> /nfsroot *(rw,insecure,no_subtree_check,no_root_squash,fsid=1)
>>>
>>> best regards,
>>>
>>> On 3/15/23 22:28, Mora, Jorge wrote:
>>>> Hello,
>>>>
>>>> Can you provide a log file for the run?
>>>>
>>>> ./nfstest_delegation -s 192.168.68.86 -e /export -v all --createlog
>>>> --keeptraces --rexeclog recall22
>>>>
>>>> --Jorge
>>>>
>>>> *From: *Jeff Layton <[email protected]>
>>>> *Date: *Wednesday, March 15, 2023 at 5:40 AM
>>>> *To: *[email protected] <[email protected]>, Mora, Jorge
>>>> <[email protected]>
>>>> *Cc: *linux-nfs <[email protected]>
>>>> *Subject: *Re: nfstest_delegation test can not stop
>>>>
>>>> NetApp Security WARNING: This is an external email. Do not click links
>>>> or open attachments unless you recognize the sender and know the
>>>> content is safe.
>>>>
>>>>
>>>>
>>>>
>>>> On Tue, 2023-03-14 at 02:28 +0000, [email protected] wrote:
>>>> > hi,
>>>> >
>>>> > I run following test command and stuck at recall12 recall14 recall20
>>>> > recall22 recall40 recall42 recall48 recall50.
>>>> >
>>>> > ./nfstest_delegation --nfsversion=4 -e /nfsroot --server <server ip>
>>>> > --client <client2 ip> --trcdelay 10
>>>> > ./nfstest_delegation --nfsversion=4.1 -e /nfsroot --server <server
>>>> ip>
>>>> > --client <client2 ip> --trcdelay 10
>>>> > ./nfstest_delegation --nfsversion=4.2 -e /nfsroot --server <server
>>>> ip>
>>>> > --client <client2 ip> --trcdelay 10
>>>> >
>>>> > recall12 recall14 recall20 recall22 recall40 recall42 recall48
>>>> recall50
>>>> > tests write files after remove.
>>>> > After comment out above testcases result is:
>>>> > 646 tests (588 passed, 58 failed)
>>>> > FAIL: WRITE delegation should be granted
>>>> >
>>>> > run ./nfstest_dio have following messages.
>>>> > INFO: 16:19:51.455222 - WRITE delegations are not available --
>>>> skipping
>>>> > tests expecting write delegations
>>>> >
>>>> > test OS: RHEL9.2 Nightly Build
>>>> > Why do these testcases can not stop?
>>>>
>>>> Are you asking why these testcases don't pass? If you're testing against
>>>> the kernel's NFS server then it's because it does not (yet) support
>>>> write delegations.
>>>> --
>>>> Jeff Layton <[email protected]>
>>>>
>>>
>>
>> --
>> ------------------------------------------------
>> zhoujie
>> Dept 1
>> No. 6 Wenzhu Road,
>> Nanjing, 210012, China
>> TEL:+86+25-86630566-8508
>> FUJITSU INTERNAL:7998-8508
>> E-Mail:[email protected]
>> ------------------------------------------------
>
> --
> ------------------------------------------------
> zhoujie
> Dept 1
> No. 6 Wenzhu Road,
> Nanjing, 210012, China
> TEL:+86+25-86630566-8508
> FUJITSU INTERNAL:7998-8508
> E-Mail:[email protected]
> ------------------------------------------------

--
------------------------------------------------
zhoujie
Dept 1
No. 6 Wenzhu Road,
Nanjing, 210012, China
TEL:+86+25-86630566-8508
FUJITSU INTERNAL:7998-8508
E-Mail:[email protected]
------------------------------------------------