Linux-NFS Archive on lore.kernel.org
 help / color / Atom feed
* kerberized NFSv4 client reporting operation not permitted when mounting with sec=sys
@ 2020-01-22  9:22 Felix Rubio
  2020-01-22 18:30 ` Benjamin Coddington
  0 siblings, 1 reply; 7+ messages in thread
From: Felix Rubio @ 2020-01-22  9:22 UTC (permalink / raw)
  To: linux-nfs

Hi everybody,

I have a kerberized NFSv4 server that is exporting a mountpoint:

     /home 10.0.0.0/8(rw,no_subtree_check,sec=krb5:krb5i:krb5p)

if I mount that export with this command on the client, it works as 
expected:

     /sbin/mount.nfs4 NFS.domain:/home /network/home -o 
_netdev,noatime,hard,sec=krb5

However, if I modify the export to be

     /home 10.0.0.0/8(rw,no_subtree_check,sec=sys:krb5:krb5i:krb5p)

and I mount that export with sec=sys, as

     /sbin/mount.nfs4 NFS.domain:/home /network/home -o 
_netdev,noatime,hard,sec=sys

I get the following error:

     mount.nfs4: timeout set for Fri Jan 17 14:11:32 2020
     mount.nfs4: trying text-based options 
'hard,sec=sys,vers=4.1,addr=10.2.2.9,clientaddr=10.2.0.12'
     mount.nfs4: mount(2): Operation not permitted
     mount.nfs4: Operation not permitted

What might be the reason for this behavior?

-- 
Felix Rubio
"Don't believe what you're told. Double check."

^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: kerberized NFSv4 client reporting operation not permitted when mounting with sec=sys
  2020-01-22  9:22 kerberized NFSv4 client reporting operation not permitted when mounting with sec=sys Felix Rubio
@ 2020-01-22 18:30 ` Benjamin Coddington
  2020-01-23  9:03   ` Felix Rubio
  0 siblings, 1 reply; 7+ messages in thread
From: Benjamin Coddington @ 2020-01-22 18:30 UTC (permalink / raw)
  To: Felix Rubio; +Cc: linux-nfs

On 22 Jan 2020, at 4:22, Felix Rubio wrote:

> Hi everybody,
>
> I have a kerberized NFSv4 server that is exporting a mountpoint:
>
>     /home 10.0.0.0/8(rw,no_subtree_check,sec=krb5:krb5i:krb5p)
>
> if I mount that export with this command on the client, it works as 
> expected:
>
>     /sbin/mount.nfs4 NFS.domain:/home /network/home -o 
> _netdev,noatime,hard,sec=krb5
>
> However, if I modify the export to be
>
>     /home 10.0.0.0/8(rw,no_subtree_check,sec=sys:krb5:krb5i:krb5p)
>
> and I mount that export with sec=sys, as
>
>     /sbin/mount.nfs4 NFS.domain:/home /network/home -o 
> _netdev,noatime,hard,sec=sys
>
> I get the following error:
>
>     mount.nfs4: timeout set for Fri Jan 17 14:11:32 2020
>     mount.nfs4: trying text-based options 
> 'hard,sec=sys,vers=4.1,addr=10.2.2.9,clientaddr=10.2.0.12'
>     mount.nfs4: mount(2): Operation not permitted
>     mount.nfs4: Operation not permitted
>
> What might be the reason for this behavior?

Hi Felix,

I don't know.  Can you get more information?  Try again after `rpcdebug 
-m
nfs -s mount`.  That will turn up debugging for messages labeled for 
mount,
and the output will be in the kernel log.  There are other facilities 
there,
see rpcdebug(8).

Another good option is getting a network capture of the mount attempt 
and
trying to figure out if the server is returning an error, or the client 
is
generating the error.

There are also a lot of "nfs", "nfs4", and "rpc" tracepoints you can 
enable
to get more information.

Ben


^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: kerberized NFSv4 client reporting operation not permitted when mounting with sec=sys
  2020-01-22 18:30 ` Benjamin Coddington
@ 2020-01-23  9:03   ` Felix Rubio
  2020-01-24 14:45     ` Benjamin Coddington
  0 siblings, 1 reply; 7+ messages in thread
From: Felix Rubio @ 2020-01-23  9:03 UTC (permalink / raw)
  To: Benjamin Coddington; +Cc: linux-nfs

Hi Ben,

     Thank your for trying to help. Indeed, I can get as much information 
as you might need (I am the administrator of those machines). After 
enabling rpcdebug -m nfs -s mount on the client this is what I get:

     [  461.238568] NFS: nfs mount 
opts='hard,sec=sys,vers=4.1,addr=10.0.2.9,clientaddr=10.1.0.12'
     [  461.243621] NFS:   parsing nfs mount option 'hard'
     [  461.246573] NFS:   parsing nfs mount option 'sec=sys'
     [  461.249809] NFS: parsing sec=sys option
     [  461.252364] NFS:   parsing nfs mount option 'vers=4.1'
     [  461.255472] NFS:   parsing nfs mount option 'addr=10.0.2.9'
     [  461.258864] NFS:   parsing nfs mount option 
'clientaddr=10.1.0.12'
     [  461.262610] NFS: MNTPATH: '/home'
     [  461.264757] --> nfs4_try_mount()
     [  461.273063] <-- nfs4_try_mount() = -1 [error]

when running tcpdump on the nfs server (tcpdump -i eth0 host 10.1.0.12 
and port nfs -n -s 0 -vvv), and mounting on the client, this is what I 
get:

     tcpdump: listening on eth0, link-type EN10MB (Ethernet), capture 
size 262144 bytes
     09:55:01.603947 IP (tos 0x0, ttl 64, id 15242, offset 0, flags [DF], 
proto TCP (6), length 188)
         10.1.0.12.epp > 10.0.2.9.nfs: Flags [P.], cksum 0x1fdf 
(correct), seq 1347340908:1347341056, ack 1722815553, win 1919, length 
148: NFS request xid 3760933574 144 getattr fh 0,1/53
     09:55:01.604325 IP (tos 0x0, ttl 64, id 38336, offset 0, flags [DF], 
proto TCP (6), length 132)
         10.0.2.9.nfs > 10.1.0.12.epp: Flags [P.], cksum 0x168c 
(incorrect -> 0x08f4), seq 1:93, ack 148, win 1432, length 92: NFS reply 
xid 3760933574 reply ok 88 getattr ERROR: unk 10016
     09:55:01.604717 IP (tos 0x0, ttl 64, id 15243, offset 0, flags [DF], 
proto TCP (6), length 40)
         10.1.0.12.epp > 10.0.2.9.nfs: Flags [.], cksum 0xf0e6 (correct), 
seq 148, ack 93, win 1919, length 0
     09:55:01.612334 IP (tos 0x0, ttl 64, id 15244, offset 0, flags [DF], 
proto TCP (6), length 252)
         10.1.0.12.epp > 10.0.2.9.nfs: Flags [P.], cksum 0xe9ed 
(correct), seq 148:360, ack 93, win 1919, length 212: NFS request xid 
3777710790 208 getattr fh 0,1/53
     09:55:01.612495 IP (tos 0x0, ttl 64, id 38337, offset 0, flags [DF], 
proto TCP (6), length 240)
         10.0.2.9.nfs > 10.1.0.12.epp: Flags [P.], cksum 0x16f8 
(incorrect -> 0x417f), seq 93:293, ack 360, win 1432, length 200: NFS 
reply xid 3777710790 reply ok 196 getattr NON 4 ids 0/47982174 sz 
-1769090185
     09:55:01.652270 IP (tos 0x0, ttl 64, id 15245, offset 0, flags [DF], 
proto TCP (6), length 40)
         10.1.0.12.epp > 10.0.2.9.nfs: Flags [.], cksum 0xef34 (correct), 
seq 360, ack 293, win 1941, length 0

I have noticed there is this error 10016, that in nfs4.h translates to 
NFS4ERR_WRONGSEC, suggesting that the server does not allow 'sys', but I 
have checked again my /etc/exports file and contains

     /home 10.0.0.0/8(rw,no_subtree_check,sec=sys:krb5:krb5i:krb5p)

and also is reported by the operating system:

     # cat /proc/fs/nfsd/exports
     /export/home    
10.0.0.0/8(rw,root_squash,sync,wdelay,no_subtree_check,uuid=0743ce63:00c1185a:00000000:00000000,sec=1:390003:390004:390005)

Any ideas?

Thank you!
Felix


---
Felix Rubio
"Don't believe what you're told. Double check."

On 2020-01-22 19:30, Benjamin Coddington wrote:
> On 22 Jan 2020, at 4:22, Felix Rubio wrote:
> 
>> Hi everybody,
>> 
>> I have a kerberized NFSv4 server that is exporting a mountpoint:
>> 
>>     /home 10.0.0.0/8(rw,no_subtree_check,sec=krb5:krb5i:krb5p)
>> 
>> if I mount that export with this command on the client, it works as 
>> expected:
>> 
>>     /sbin/mount.nfs4 NFS.domain:/home /network/home -o 
>> _netdev,noatime,hard,sec=krb5
>> 
>> However, if I modify the export to be
>> 
>>     /home 10.0.0.0/8(rw,no_subtree_check,sec=sys:krb5:krb5i:krb5p)
>> 
>> and I mount that export with sec=sys, as
>> 
>>     /sbin/mount.nfs4 NFS.domain:/home /network/home -o 
>> _netdev,noatime,hard,sec=sys
>> 
>> I get the following error:
>> 
>>     mount.nfs4: timeout set for Fri Jan 17 14:11:32 2020
>>     mount.nfs4: trying text-based options 
>> 'hard,sec=sys,vers=4.1,addr=10.2.2.9,clientaddr=10.2.0.12'
>>     mount.nfs4: mount(2): Operation not permitted
>>     mount.nfs4: Operation not permitted
>> 
>> What might be the reason for this behavior?
> 
> Hi Felix,
> 
> I don't know.  Can you get more information?  Try again after `rpcdebug 
> -m
> nfs -s mount`.  That will turn up debugging for messages labeled for 
> mount,
> and the output will be in the kernel log.  There are other facilities 
> there,
> see rpcdebug(8).
> 
> Another good option is getting a network capture of the mount attempt 
> and
> trying to figure out if the server is returning an error, or the client 
> is
> generating the error.
> 
> There are also a lot of "nfs", "nfs4", and "rpc" tracepoints you can 
> enable
> to get more information.
> 
> Ben

^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: kerberized NFSv4 client reporting operation not permitted when mounting with sec=sys
  2020-01-23  9:03   ` Felix Rubio
@ 2020-01-24 14:45     ` Benjamin Coddington
  2020-01-24 16:49       ` Felix Rubio
  0 siblings, 1 reply; 7+ messages in thread
From: Benjamin Coddington @ 2020-01-24 14:45 UTC (permalink / raw)
  To: Felix Rubio; +Cc: linux-nfs

Hi Felix - now see if you can turn up the nfsd debug messages on the 
server
during that mount.  It does seem odd.  Its also hard to see from your
capture what security the client is trying to use for that GETATTR.  You 
can
use `tshark -r/path/to/pcap` to get a nicer summary, then `tshark -V
-r/path/to/pcap frame.number==<frame of interest> to get very verbose
results..

Ben

On 23 Jan 2020, at 4:03, Felix Rubio wrote:

> Hi Ben,
>
>     Thank your for trying to help. Indeed, I can get as much 
> information as you might need (I am the administrator of those 
> machines). After enabling rpcdebug -m nfs -s mount on the client this 
> is what I get:
>
>     [  461.238568] NFS: nfs mount 
> opts='hard,sec=sys,vers=4.1,addr=10.0.2.9,clientaddr=10.1.0.12'
>     [  461.243621] NFS:   parsing nfs mount option 'hard'
>     [  461.246573] NFS:   parsing nfs mount option 'sec=sys'
>     [  461.249809] NFS: parsing sec=sys option
>     [  461.252364] NFS:   parsing nfs mount option 'vers=4.1'
>     [  461.255472] NFS:   parsing nfs mount option 'addr=10.0.2.9'
>     [  461.258864] NFS:   parsing nfs mount option 
> 'clientaddr=10.1.0.12'
>     [  461.262610] NFS: MNTPATH: '/home'
>     [  461.264757] --> nfs4_try_mount()
>     [  461.273063] <-- nfs4_try_mount() = -1 [error]
>
> when running tcpdump on the nfs server (tcpdump -i eth0 host 10.1.0.12 
> and port nfs -n -s 0 -vvv), and mounting on the client, this is what I 
> get:
>
>     tcpdump: listening on eth0, link-type EN10MB (Ethernet), capture 
> size 262144 bytes
>     09:55:01.603947 IP (tos 0x0, ttl 64, id 15242, offset 0, flags 
> [DF], proto TCP (6), length 188)
>         10.1.0.12.epp > 10.0.2.9.nfs: Flags [P.], cksum 0x1fdf 
> (correct), seq 1347340908:1347341056, ack 1722815553, win 1919, length 
> 148: NFS request xid 3760933574 144 getattr fh 0,1/53
>     09:55:01.604325 IP (tos 0x0, ttl 64, id 38336, offset 0, flags 
> [DF], proto TCP (6), length 132)
>         10.0.2.9.nfs > 10.1.0.12.epp: Flags [P.], cksum 0x168c 
> (incorrect -> 0x08f4), seq 1:93, ack 148, win 1432, length 92: NFS 
> reply xid 3760933574 reply ok 88 getattr ERROR: unk 10016
>     09:55:01.604717 IP (tos 0x0, ttl 64, id 15243, offset 0, flags 
> [DF], proto TCP (6), length 40)
>         10.1.0.12.epp > 10.0.2.9.nfs: Flags [.], cksum 0xf0e6 
> (correct), seq 148, ack 93, win 1919, length 0
>     09:55:01.612334 IP (tos 0x0, ttl 64, id 15244, offset 0, flags 
> [DF], proto TCP (6), length 252)
>         10.1.0.12.epp > 10.0.2.9.nfs: Flags [P.], cksum 0xe9ed 
> (correct), seq 148:360, ack 93, win 1919, length 212: NFS request xid 
> 3777710790 208 getattr fh 0,1/53
>     09:55:01.612495 IP (tos 0x0, ttl 64, id 38337, offset 0, flags 
> [DF], proto TCP (6), length 240)
>         10.0.2.9.nfs > 10.1.0.12.epp: Flags [P.], cksum 0x16f8 
> (incorrect -> 0x417f), seq 93:293, ack 360, win 1432, length 200: NFS 
> reply xid 3777710790 reply ok 196 getattr NON 4 ids 0/47982174 sz 
> -1769090185
>     09:55:01.652270 IP (tos 0x0, ttl 64, id 15245, offset 0, flags 
> [DF], proto TCP (6), length 40)
>         10.1.0.12.epp > 10.0.2.9.nfs: Flags [.], cksum 0xef34 
> (correct), seq 360, ack 293, win 1941, length 0
>
> I have noticed there is this error 10016, that in nfs4.h translates to 
> NFS4ERR_WRONGSEC, suggesting that the server does not allow 'sys', but 
> I have checked again my /etc/exports file and contains
>
>     /home 10.0.0.0/8(rw,no_subtree_check,sec=sys:krb5:krb5i:krb5p)
>
> and also is reported by the operating system:
>
>     # cat /proc/fs/nfsd/exports
>     /export/home    
> 10.0.0.0/8(rw,root_squash,sync,wdelay,no_subtree_check,uuid=0743ce63:00c1185a:00000000:00000000,sec=1:390003:390004:390005)
>
> Any ideas?
>
> Thank you!
> Felix
>
>
> ---
> Felix Rubio
> "Don't believe what you're told. Double check."
>
> On 2020-01-22 19:30, Benjamin Coddington wrote:
>> On 22 Jan 2020, at 4:22, Felix Rubio wrote:
>>
>>> Hi everybody,
>>>
>>> I have a kerberized NFSv4 server that is exporting a mountpoint:
>>>
>>>     /home 10.0.0.0/8(rw,no_subtree_check,sec=krb5:krb5i:krb5p)
>>>
>>> if I mount that export with this command on the client, it works as 
>>> expected:
>>>
>>>     /sbin/mount.nfs4 NFS.domain:/home /network/home -o 
>>> _netdev,noatime,hard,sec=krb5
>>>
>>> However, if I modify the export to be
>>>
>>>     /home 10.0.0.0/8(rw,no_subtree_check,sec=sys:krb5:krb5i:krb5p)
>>>
>>> and I mount that export with sec=sys, as
>>>
>>>     /sbin/mount.nfs4 NFS.domain:/home /network/home -o 
>>> _netdev,noatime,hard,sec=sys
>>>
>>> I get the following error:
>>>
>>>     mount.nfs4: timeout set for Fri Jan 17 14:11:32 2020
>>>     mount.nfs4: trying text-based options 
>>> 'hard,sec=sys,vers=4.1,addr=10.2.2.9,clientaddr=10.2.0.12'
>>>     mount.nfs4: mount(2): Operation not permitted
>>>     mount.nfs4: Operation not permitted
>>>
>>> What might be the reason for this behavior?
>>
>> Hi Felix,
>>
>> I don't know.  Can you get more information?  Try again after 
>> `rpcdebug -m
>> nfs -s mount`.  That will turn up debugging for messages labeled for 
>> mount,
>> and the output will be in the kernel log.  There are other facilities 
>> there,
>> see rpcdebug(8).
>>
>> Another good option is getting a network capture of the mount attempt 
>> and
>> trying to figure out if the server is returning an error, or the 
>> client is
>> generating the error.
>>
>> There are also a lot of "nfs", "nfs4", and "rpc" tracepoints you can 
>> enable
>> to get more information.
>>
>> Ben


^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: kerberized NFSv4 client reporting operation not permitted when mounting with sec=sys
  2020-01-24 14:45     ` Benjamin Coddington
@ 2020-01-24 16:49       ` Felix Rubio
  2020-02-04 19:14         ` Benjamin Coddington
  0 siblings, 1 reply; 7+ messages in thread
From: Felix Rubio @ 2020-01-24 16:49 UTC (permalink / raw)
  To: Benjamin Coddington; +Cc: linux-nfs

Hi Benjamin,

     I have enabled the debug logging on nfsd by running

     When mounting from the client, this is what I get:

[629588.647849] nfsd_dispatch: vers 4 proc 1
[629588.655615] nfsv4 compound op #1/1: 53 (OP_SEQUENCE)
[629588.663926] __find_in_sessionid_hashtbl: 1579604994:2010353049:95:0
[629588.675361] nfsd4_sequence: slotid 0
[629588.679065] check_slot_seqid enter. seqid 644 slot_seqid 643
[629588.684589] nfsv4 compound op ffff882839705080 opcnt 1 #1: 53: 
status 0
[629588.691545] nfsv4 compound returned 0
[629588.695292] --> nfsd4_store_cache_entry slot ffff882806e83000
[629588.701933] renewing client (clientid 5e26dc02/77d38d99)
[629591.804857] nfsd_dispatch: vers 4 proc 1
[629591.809364] nfsv4 compound op #1/4: 53 (OP_SEQUENCE)
[629591.814944] __find_in_sessionid_hashtbl: 1579604994:2010353053:99:0
[629591.822163] nfsd4_sequence: slotid 0
[629591.826670] check_slot_seqid enter. seqid 155 slot_seqid 154
[629591.832771] nfsv4 compound op ffff882839705080 opcnt 4 #1: 53: 
status 0
[629591.839864] nfsv4 compound op #2/4: 24 (OP_PUTROOTFH)
[629591.845161] nfsd: fh_compose(exp 08:02/17468677 /export, 
ino=17468677)
[629591.851706] nfsv4 compound op ffff882839705080 opcnt 4 #2: 24: 
status 10016
[629591.859660] nfsv4 compound returned 10016
[629591.864797] --> nfsd4_store_cache_entry slot ffff882838b9e000
[629591.872968] renewing client (clientid 5e26dc02/77d38d9d)
[629591.889085] nfsd_dispatch: vers 4 proc 1
[629591.893713] nfsv4 compound op #1/4: 53 (OP_SEQUENCE)
[629591.899703] __find_in_sessionid_hashtbl: 1579604994:2010353053:99:0
[629591.906687] nfsd4_sequence: slotid 0
[629591.912695] check_slot_seqid enter. seqid 156 slot_seqid 155
[629591.918261] nfsv4 compound op ffff882839705080 opcnt 4 #1: 53: 
status 0
[629591.924866] nfsv4 compound op #2/4: 22 (OP_PUTFH)
[629591.931075] nfsd: fh_verify(32: 01060001 63ce4307 5a18c100 00000000 
00000000 1fba000a)
[629591.940556] nfsv4 compound op ffff882839705080 opcnt 4 #2: 22: 
status 0
[629591.948776] nfsv4 compound op #3/4: 3 (OP_ACCESS)
[629591.954607] nfsd: fh_verify(32: 01060001 63ce4307 5a18c100 00000000 
00000000 1fba000a)
[629591.967117] nfsv4 compound op ffff882839705080 opcnt 4 #3: 3: status 
0
[629591.975364] nfsv4 compound op #4/4: 9 (OP_GETATTR)
[629591.980854] nfsd: fh_verify(32: 01060001 63ce4307 5a18c100 00000000 
00000000 1fba000a)
[629591.990257] nfsv4 compound op ffff882839705080 opcnt 4 #4: 9: status 
0
[629591.996796] nfsv4 compound returned 0
[629592.001758] --> nfsd4_store_cache_entry slot ffff882838b9e000
[629592.008061] renewing client (clientid 5e26dc02/77d38d9d)

Using wireshark, this is the log of the packages from/to that ip 
address:

# tshark -i eth0 -p -w /tmp/nfs_mount.cap host 10.1.0.12 and port nfs
# tshark -r /tmp/nfs_mount.cap
   1 0.000000000    10.1.0.12 -> 10.0.2.9     NFS 202 V4 Call PUTROOTFH | 
GETATTR
   2 0.000058001     10.0.2.9 -> 10.1.0.12    TCP 54 nfs > rndc [ACK] 
Seq=1 Ack=149 Win=1432 Len=0
   3 0.074041118     10.0.2.9 -> 10.1.0.12    NFS 146 V4 Reply (Call In 
1) PUTROOTFH Status: NFS4ERR_WRONGSEC
   4 0.074927630    10.1.0.12 -> 10.0.2.9     TCP 54 rndc > nfs [ACK] 
Seq=149 Ack=93 Win=1476 Len=0
   5 0.084223658    10.1.0.12 -> 10.0.2.9     NFS 266 V4 Call ACCESS FH: 
0xea1b01ae, [Check: RD LU MD XT DL]
   6 0.084270458     10.0.2.9 -> 10.1.0.12    TCP 54 nfs > rndc [ACK] 
Seq=93 Ack=361 Win=1432 Len=0
   7 0.208635667     10.0.2.9 -> 10.1.0.12    NFS 254 V4 Reply (Call In 
5) ACCESS, [Access Denied: RD MD XT DL], [Allowed: LU]
   8 0.248855020    10.1.0.12 -> 10.0.2.9     TCP 54 rndc > nfs [ACK] 
Seq=361 Ack=293 Win=1498 Len=0

I think the frame of interest is #1, so this is its contents:
Frame 1: 202 bytes on wire (1616 bits), 202 bytes captured (1616 bits) 
on interface 0
     Interface id: 0
     Encapsulation type: Ethernet (1)
     Arrival Time: Jan 24, 2020 17:39:05.721360043 CET
     [Time shift for this packet: 0.000000000 seconds]
     Epoch Time: 1579883945.721360043 seconds
     [Time delta from previous captured frame: 0.000000000 seconds]
     [Time delta from previous displayed frame: 0.000000000 seconds]
     [Time since reference or first frame: 0.000000000 seconds]
     Frame Number: 1
     Frame Length: 202 bytes (1616 bits)
     Capture Length: 202 bytes (1616 bits)
     [Frame is marked: False]
     [Frame is ignored: False]
     [Protocols in frame: eth:ip:tcp:rpc]
Ethernet II, Src: 00:81:c4:c1:50:7f (00:81:c4:c1:50:7f), Dst: 
Microsof_44:24:d3 (00:0d:3a:44:24:d3)
     Destination: Microsof_44:24:d3 (00:0d:3a:44:24:d3)
         Address: Microsof_44:24:d3 (00:0d:3a:44:24:d3)
         .... ..0. .... .... .... .... = LG bit: Globally unique address 
(factory default)
         .... ...0 .... .... .... .... = IG bit: Individual address 
(unicast)
     Source: 00:81:c4:c1:50:7f (00:81:c4:c1:50:7f)
         Address: 00:81:c4:c1:50:7f (00:81:c4:c1:50:7f)
         .... ..0. .... .... .... .... = LG bit: Globally unique address 
(factory default)
         .... ...0 .... .... .... .... = IG bit: Individual address 
(unicast)
     Type: IP (0x0800)
Internet Protocol Version 4, Src: 10.1.0.12 (10.1.0.12), Dst: 10.0.2.9 
(10.0.2.9)
     Version: 4
     Header length: 20 bytes
     Differentiated Services Field: 0x00 (DSCP 0x00: Default; ECN: 0x00: 
Not-ECT (Not ECN-Capable Transport))
         0000 00.. = Differentiated Services Codepoint: Default (0x00)
         .... ..00 = Explicit Congestion Notification: Not-ECT (Not 
ECN-Capable Transport) (0x00)
     Total Length: 188
     Identification: 0xa3e0 (41952)
     Flags: 0x02 (Don't Fragment)
         0... .... = Reserved bit: Not set
         .1.. .... = Don't fragment: Set
         ..0. .... = More fragments: Not set
     Fragment offset: 0
     Time to live: 64
     Protocol: TCP (6)
     Header checksum: 0x8046 [validation disabled]
         [Good: False]
         [Bad: False]
     Source: 10.1.0.12 (10.1.0.12)
     Destination: 10.0.2.9 (10.0.2.9)
Transmission Control Protocol, Src Port: rndc (953), Dst Port: nfs 
(2049), Seq: 1, Ack: 1, Len: 148
     Source port: rndc (953)
     Destination port: nfs (2049)
     [Stream index: 0]
     Sequence number: 1    (relative sequence number)
     [Next sequence number: 149    (relative sequence number)]
     Acknowledgment number: 1    (relative ack number)
     Header length: 20 bytes
     Flags: 0x018 (PSH, ACK)
         000. .... .... = Reserved: Not set
         ...0 .... .... = Nonce: Not set
         .... 0... .... = Congestion Window Reduced (CWR): Not set
         .... .0.. .... = ECN-Echo: Not set
         .... ..0. .... = Urgent: Not set
         .... ...1 .... = Acknowledgment: Set
         .... .... 1... = Push: Set
         .... .... .0.. = Reset: Not set
         .... .... ..0. = Syn: Not set
         .... .... ...0 = Fin: Not set
     Window size value: 1476
     [Calculated window size: 1476]
     [Window size scaling factor: -1 (unknown)]
     Checksum: 0x4455 [validation disabled]
         [Good Checksum: False]
         [Bad Checksum: False]
     [SEQ/ACK analysis]
         [Bytes in flight: 148]
Remote Procedure Call, Type:Call XID:0xd17c6210
     Fragment header: Last fragment, 144 bytes
         1... .... .... .... .... .... .... .... = Last Fragment: Yes
         .000 0000 0000 0000 0000 0000 1001 0000 = Fragment Length: 144
     XID: 0xd17c6210 (3514589712)
     Message Type: Call (0)
     RPC Version: 2
     Program: NFS (100003)
     Program Version: 4
     Procedure: COMPOUND (1)
     Credentials
         Flavor: AUTH_UNIX (1)
         Length: 32
         Stamp: 0x00418ae8
         Machine Name: worker01
             length: 8
             contents: worker01
         UID: 0
         GID: 0
         Auxiliary GIDs (1) [0]
             GID: 0
     Verifier
         Flavor: AUTH_NULL (0)
         Length: 0
Network File System, Ops(4): SEQUENCE, PUTROOTFH, GETFH, GETATTR
     [Program Version: 4]
     [V4 Procedure: COMPOUND (1)]
     Tag: <EMPTY>
         length: 0
         contents: <EMPTY>
     minorversion: 1
     Operations (count: 4): SEQUENCE, PUTROOTFH, GETFH, GETATTR
         Opcode: SEQUENCE (53)
             sessionid: 02dc265e9d8dd3776300000000000000
             seqid: 0x0000009b
             slot id: 0
             high slot id: 0
             cache this?: No
         Opcode: PUTROOTFH (24)
         Opcode: GETFH (10)
         Opcode: GETATTR (9)
             Attr mask[0]: 0x0010011a (TYPE, CHANGE, SIZE, FSID, FILEID)
                 reqd_attr: TYPE (1)
                 reqd_attr: CHANGE (3)
                 reqd_attr: SIZE (4)
                 reqd_attr: FSID (8)
                 reco_attr: FILEID (20)
             Attr mask[1]: 0x00b0a23a (MODE, NUMLINKS, OWNER, 
OWNER_GROUP, RAWDEV, SPACE_USED, TIME_ACCESS, TIME_METADATA, 
TIME_MODIFY, MOUNTED_ON_FILEID)
                 reco_attr: MODE (33)
                 reco_attr: NUMLINKS (35)
                 reco_attr: OWNER (36)
                 reco_attr: OWNER_GROUP (37)
                 reco_attr: RAWDEV (41)
                 reco_attr: SPACE_USED (45)
                 reco_attr: TIME_ACCESS (47)
                 reco_attr: TIME_METADATA (52)
                 reco_attr: TIME_MODIFY (53)
                 reco_attr: MOUNTED_ON_FILEID (55)
     [Main Opcode: PUTROOTFH (24)]
     [Main Opcode: GETATTR (9)]

Just in case, this is the answer of the server:
Frame 3: 146 bytes on wire (1168 bits), 146 bytes captured (1168 bits) 
on interface 0
     Interface id: 0
     Encapsulation type: Ethernet (1)
     Arrival Time: Jan 24, 2020 17:39:05.795401161 CET
     [Time shift for this packet: 0.000000000 seconds]
     Epoch Time: 1579883945.795401161 seconds
     [Time delta from previous captured frame: 0.073983117 seconds]
     [Time delta from previous displayed frame: 0.000000000 seconds]
     [Time since reference or first frame: 0.074041118 seconds]
     Frame Number: 3
     Frame Length: 146 bytes (1168 bits)
     Capture Length: 146 bytes (1168 bits)
     [Frame is marked: False]
     [Frame is ignored: False]
     [Protocols in frame: eth:ip:tcp:rpc]
Ethernet II, Src: Microsof_44:24:d3 (00:0d:3a:44:24:d3), Dst: 
12:34:56:78:9a:bc (12:34:56:78:9a:bc)
     Destination: 12:34:56:78:9a:bc (12:34:56:78:9a:bc)
         Address: 12:34:56:78:9a:bc (12:34:56:78:9a:bc)
         .... ..1. .... .... .... .... = LG bit: Locally administered 
address (this is NOT the factory default)
         .... ...0 .... .... .... .... = IG bit: Individual address 
(unicast)
     Source: Microsof_44:24:d3 (00:0d:3a:44:24:d3)
         Address: Microsof_44:24:d3 (00:0d:3a:44:24:d3)
         .... ..0. .... .... .... .... = LG bit: Globally unique address 
(factory default)
         .... ...0 .... .... .... .... = IG bit: Individual address 
(unicast)
     Type: IP (0x0800)
Internet Protocol Version 4, Src: 10.0.2.9 (10.0.2.9), Dst: 10.1.0.12 
(10.1.0.12)
     Version: 4
     Header length: 20 bytes
     Differentiated Services Field: 0x00 (DSCP 0x00: Default; ECN: 0x00: 
Not-ECT (Not ECN-Capable Transport))
         0000 00.. = Differentiated Services Codepoint: Default (0x00)
         .... ..00 = Explicit Congestion Notification: Not-ECT (Not 
ECN-Capable Transport) (0x00)
     Total Length: 132
     Identification: 0x794c (31052)
     Flags: 0x02 (Don't Fragment)
         0... .... = Reserved bit: Not set
         .1.. .... = Don't fragment: Set
         ..0. .... = More fragments: Not set
     Fragment offset: 0
     Time to live: 64
     Protocol: TCP (6)
     Header checksum: 0xab12 [validation disabled]
         [Good: False]
         [Bad: False]
     Source: 10.0.2.9 (10.0.2.9)
     Destination: 10.1.0.12 (10.1.0.12)
Transmission Control Protocol, Src Port: nfs (2049), Dst Port: rndc 
(953), Seq: 1, Ack: 149, Len: 92
     Source port: nfs (2049)
     Destination port: rndc (953)
     [Stream index: 0]
     Sequence number: 1    (relative sequence number)
     [Next sequence number: 93    (relative sequence number)]
     Acknowledgment number: 149    (relative ack number)
     Header length: 20 bytes
     Flags: 0x018 (PSH, ACK)
         000. .... .... = Reserved: Not set
         ...0 .... .... = Nonce: Not set
         .... 0... .... = Congestion Window Reduced (CWR): Not set
         .... .0.. .... = ECN-Echo: Not set
         .... ..0. .... = Urgent: Not set
         .... ...1 .... = Acknowledgment: Set
         .... .... 1... = Push: Set
         .... .... .0.. = Reset: Not set
         .... .... ..0. = Syn: Not set
         .... .... ...0 = Fin: Not set
     Window size value: 1432
     [Calculated window size: 1432]
     [Window size scaling factor: -1 (unknown)]
     Checksum: 0x168c [validation disabled]
         [Good Checksum: False]
         [Bad Checksum: False]
     [SEQ/ACK analysis]
         [Bytes in flight: 92]
Remote Procedure Call, Type:Reply XID:0xd17c6210
     Fragment header: Last fragment, 88 bytes
         1... .... .... .... .... .... .... .... = Last Fragment: Yes
         .000 0000 0000 0000 0000 0000 0101 1000 = Fragment Length: 88
     XID: 0xd17c6210 (3514589712)
     Message Type: Reply (1)
     [Program: NFS (100003)]
     [Program Version: 4]
     [Procedure: COMPOUND (1)]
     Reply State: accepted (0)
     [This is a reply to a request in frame 1]
     [Time from request: 0.074041118 seconds]
     Verifier
         Flavor: AUTH_NULL (0)
         Length: 0
     Accept State: RPC executed successfully (0)
Network File System, Ops(2): SEQUENCE PUTROOTFH(NFS4ERR_WRONGSEC)
     [Program Version: 4]
     [V4 Procedure: COMPOUND (1)]
     Status: NFS4ERR_WRONGSEC (10016)
     Tag: <EMPTY>
         length: 0
         contents: <EMPTY>
     Operations (count: 2)
         Opcode: SEQUENCE (53)
             Status: NFS4_OK (0)
             sessionid: 02dc265e9d8dd3776300000000000000
             seqid: 0x0000009b
             slot id: 0
             high slot id: 9
             target high slot id: 9
             status flags: 0x00000000
                 .... .... .... .... .... .... .... ...0 = 
SEQ4_STATUS_CB_PATH_DOWN: Not set
                 .... .... .... .... .... .... .... ..0. = 
SEQ4_STATUS_CB_GSS_CONTEXTS_EXPIRING: Not set
                 .... .... .... .... .... .... .... .0.. = 
SEQ4_STATUS_CB_GSS_CONTEXTS_EXPIRED: Not set
                 .... .... .... .... .... .... .... 0... = 
SEQ4_STATUS_EXPIRED_ALL_STATE_REVOKED: Not set
                 .... .... .... .... .... .... ...0 .... = 
SEQ4_STATUS_EXPIRED_SOME_STATE_REVOKED: Not set
                 .... .... .... .... .... .... ..0. .... = 
SEQ4_STATUS_ADMIN_STATE_REVOKED: Not set
                 .... .... .... .... .... .... .0.. .... = 
SEQ4_STATUS_RECALLABLE_STATE_REVOKED: Not set
                 .... .... .... .... .... .... 0... .... = 
SEQ4_STATUS_LEASE_MOVED: Not set
                 .... .... .... .... .... ...0 .... .... = 
SEQ4_STATUS_RESTART_RECLAIM_NEEDED: Not set
                 .... .... .... .... .... ..0. .... .... = 
SEQ4_STATUS_CB_PATH_DOWN_SESSION: Not set
                 .... .... .... .... .... .0.. .... .... = 
SEQ4_STATUS_BACKCHANNEL_FAULT: Not set
                 .... .... .... .... .... 0... .... .... = 
SEQ4_STATUS_DEVID_CHANGED: Not set
                 .... .... .... .... ...0 .... .... .... = 
SEQ4_STATUS_DEVID_DELETED: Not set
         Opcode: PUTROOTFH (24)
             Status: NFS4ERR_WRONGSEC (10016)
     [Main Opcode: PUTROOTFH (24)]

Does this provide any light?

Thank you very much for your help!

Felix


---
Felix Rubio
"Don't believe what you're told. Double check."

^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: kerberized NFSv4 client reporting operation not permitted when mounting with sec=sys
  2020-01-24 16:49       ` Felix Rubio
@ 2020-02-04 19:14         ` Benjamin Coddington
  2020-02-05 11:09           ` Felix Rubio
  0 siblings, 1 reply; 7+ messages in thread
From: Benjamin Coddington @ 2020-02-04 19:14 UTC (permalink / raw)
  To: Felix Rubio; +Cc: linux-nfs



On 24 Jan 2020, at 11:49, Felix Rubio wrote:

> Hi Benjamin,
>
>     I have enabled the debug logging on nfsd by running
>
>     When mounting from the client, this is what I get:
>
> [629588.647849] nfsd_dispatch: vers 4 proc 1
> [629588.655615] nfsv4 compound op #1/1: 53 (OP_SEQUENCE)
> [629588.663926] __find_in_sessionid_hashtbl: 
> 1579604994:2010353049:95:0
> [629588.675361] nfsd4_sequence: slotid 0
> [629588.679065] check_slot_seqid enter. seqid 644 slot_seqid 643
> [629588.684589] nfsv4 compound op ffff882839705080 opcnt 1 #1: 53: 
> status 0
> [629588.691545] nfsv4 compound returned 0
> [629588.695292] --> nfsd4_store_cache_entry slot ffff882806e83000
> [629588.701933] renewing client (clientid 5e26dc02/77d38d99)
> [629591.804857] nfsd_dispatch: vers 4 proc 1
> [629591.809364] nfsv4 compound op #1/4: 53 (OP_SEQUENCE)
> [629591.814944] __find_in_sessionid_hashtbl: 
> 1579604994:2010353053:99:0
> [629591.822163] nfsd4_sequence: slotid 0
> [629591.826670] check_slot_seqid enter. seqid 155 slot_seqid 154
> [629591.832771] nfsv4 compound op ffff882839705080 opcnt 4 #1: 53: 
> status 0
> [629591.839864] nfsv4 compound op #2/4: 24 (OP_PUTROOTFH)
> [629591.845161] nfsd: fh_compose(exp 08:02/17468677 /export, 
> ino=17468677)
> [629591.851706] nfsv4 compound op ffff882839705080 opcnt 4 #2: 24: 
> status 10016
> [629591.859660] nfsv4 compound returned 10016

So this is definitely the server returning NFS4ERR_WRONGSEC..

> [629591.864797] --> nfsd4_store_cache_entry slot ffff882838b9e000
> [629591.872968] renewing client (clientid 5e26dc02/77d38d9d)
> [629591.889085] nfsd_dispatch: vers 4 proc 1
> [629591.893713] nfsv4 compound op #1/4: 53 (OP_SEQUENCE)
> [629591.899703] __find_in_sessionid_hashtbl: 
> 1579604994:2010353053:99:0
> [629591.906687] nfsd4_sequence: slotid 0
> [629591.912695] check_slot_seqid enter. seqid 156 slot_seqid 155
> [629591.918261] nfsv4 compound op ffff882839705080 opcnt 4 #1: 53: 
> status 0
> [629591.924866] nfsv4 compound op #2/4: 22 (OP_PUTFH)
> [629591.931075] nfsd: fh_verify(32: 01060001 63ce4307 5a18c100 
> 00000000 00000000 1fba000a)
> [629591.940556] nfsv4 compound op ffff882839705080 opcnt 4 #2: 22: 
> status 0
> [629591.948776] nfsv4 compound op #3/4: 3 (OP_ACCESS)
> [629591.954607] nfsd: fh_verify(32: 01060001 63ce4307 5a18c100 
> 00000000 00000000 1fba000a)
> [629591.967117] nfsv4 compound op ffff882839705080 opcnt 4 #3: 3: 
> status 0
> [629591.975364] nfsv4 compound op #4/4: 9 (OP_GETATTR)
> [629591.980854] nfsd: fh_verify(32: 01060001 63ce4307 5a18c100 
> 00000000 00000000 1fba000a)
> [629591.990257] nfsv4 compound op ffff882839705080 opcnt 4 #4: 9: 
> status 0
> [629591.996796] nfsv4 compound returned 0
> [629592.001758] --> nfsd4_store_cache_entry slot ffff882838b9e000
> [629592.008061] renewing client (clientid 5e26dc02/77d38d9d)
>
> Using wireshark, this is the log of the packages from/to that ip 
> address:
>
> # tshark -i eth0 -p -w /tmp/nfs_mount.cap host 10.1.0.12 and port nfs
> # tshark -r /tmp/nfs_mount.cap
>   1 0.000000000    10.1.0.12 -> 10.0.2.9     NFS 202 V4 Call PUTROOTFH 
> | GETATTR

..to this call ^^ ..

>   2 0.000058001     10.0.2.9 -> 10.1.0.12    TCP 54 nfs > rndc [ACK] 
> Seq=1 Ack=149 Win=1432 Len=0
>   3 0.074041118     10.0.2.9 -> 10.1.0.12    NFS 146 V4 Reply (Call In 
> 1) PUTROOTFH Status: NFS4ERR_WRONGSEC
>   4 0.074927630    10.1.0.12 -> 10.0.2.9     TCP 54 rndc > nfs [ACK] 
> Seq=149 Ack=93 Win=1476 Len=0
>   5 0.084223658    10.1.0.12 -> 10.0.2.9     NFS 266 V4 Call ACCESS 
> FH: 0xea1b01ae, [Check: RD LU MD XT DL]
>   6 0.084270458     10.0.2.9 -> 10.1.0.12    TCP 54 nfs > rndc [ACK] 
> Seq=93 Ack=361 Win=1432 Len=0
>   7 0.208635667     10.0.2.9 -> 10.1.0.12    NFS 254 V4 Reply (Call In 
> 5) ACCESS, [Access Denied: RD MD XT DL], [Allowed: LU]
>   8 0.248855020    10.1.0.12 -> 10.0.2.9     TCP 54 rndc > nfs [ACK] 
> Seq=361 Ack=293 Win=1498 Len=0
>
> I think the frame of interest is #1, so this is its contents:
> Frame 1: 202 bytes on wire (1616 bits), 202 bytes captured (1616 bits) 
> on interface 0
>     Interface id: 0
>     Encapsulation type: Ethernet (1)
>     Arrival Time: Jan 24, 2020 17:39:05.721360043 CET
>     [Time shift for this packet: 0.000000000 seconds]
>     Epoch Time: 1579883945.721360043 seconds
>     [Time delta from previous captured frame: 0.000000000 seconds]
>     [Time delta from previous displayed frame: 0.000000000 seconds]
>     [Time since reference or first frame: 0.000000000 seconds]
>     Frame Number: 1
>     Frame Length: 202 bytes (1616 bits)
>     Capture Length: 202 bytes (1616 bits)
>     [Frame is marked: False]
>     [Frame is ignored: False]
>     [Protocols in frame: eth:ip:tcp:rpc]
> Ethernet II, Src: 00:81:c4:c1:50:7f (00:81:c4:c1:50:7f), Dst: 
> Microsof_44:24:d3 (00:0d:3a:44:24:d3)
>     Destination: Microsof_44:24:d3 (00:0d:3a:44:24:d3)
>         Address: Microsof_44:24:d3 (00:0d:3a:44:24:d3)
>         .... ..0. .... .... .... .... = LG bit: Globally unique 
> address (factory default)
>         .... ...0 .... .... .... .... = IG bit: Individual address 
> (unicast)
>     Source: 00:81:c4:c1:50:7f (00:81:c4:c1:50:7f)
>         Address: 00:81:c4:c1:50:7f (00:81:c4:c1:50:7f)
>         .... ..0. .... .... .... .... = LG bit: Globally unique 
> address (factory default)
>         .... ...0 .... .... .... .... = IG bit: Individual address 
> (unicast)
>     Type: IP (0x0800)
> Internet Protocol Version 4, Src: 10.1.0.12 (10.1.0.12), Dst: 10.0.2.9 
> (10.0.2.9)
>     Version: 4
>     Header length: 20 bytes
>     Differentiated Services Field: 0x00 (DSCP 0x00: Default; ECN: 
> 0x00: Not-ECT (Not ECN-Capable Transport))
>         0000 00.. = Differentiated Services Codepoint: Default (0x00)
>         .... ..00 = Explicit Congestion Notification: Not-ECT (Not 
> ECN-Capable Transport) (0x00)
>     Total Length: 188
>     Identification: 0xa3e0 (41952)
>     Flags: 0x02 (Don't Fragment)
>         0... .... = Reserved bit: Not set
>         .1.. .... = Don't fragment: Set
>         ..0. .... = More fragments: Not set
>     Fragment offset: 0
>     Time to live: 64
>     Protocol: TCP (6)
>     Header checksum: 0x8046 [validation disabled]
>         [Good: False]
>         [Bad: False]
>     Source: 10.1.0.12 (10.1.0.12)
>     Destination: 10.0.2.9 (10.0.2.9)
> Transmission Control Protocol, Src Port: rndc (953), Dst Port: nfs 
> (2049), Seq: 1, Ack: 1, Len: 148
>     Source port: rndc (953)
>     Destination port: nfs (2049)
>     [Stream index: 0]
>     Sequence number: 1    (relative sequence number)
>     [Next sequence number: 149    (relative sequence number)]
>     Acknowledgment number: 1    (relative ack number)
>     Header length: 20 bytes
>     Flags: 0x018 (PSH, ACK)
>         000. .... .... = Reserved: Not set
>         ...0 .... .... = Nonce: Not set
>         .... 0... .... = Congestion Window Reduced (CWR): Not set
>         .... .0.. .... = ECN-Echo: Not set
>         .... ..0. .... = Urgent: Not set
>         .... ...1 .... = Acknowledgment: Set
>         .... .... 1... = Push: Set
>         .... .... .0.. = Reset: Not set
>         .... .... ..0. = Syn: Not set
>         .... .... ...0 = Fin: Not set
>     Window size value: 1476
>     [Calculated window size: 1476]
>     [Window size scaling factor: -1 (unknown)]
>     Checksum: 0x4455 [validation disabled]
>         [Good Checksum: False]
>         [Bad Checksum: False]
>     [SEQ/ACK analysis]
>         [Bytes in flight: 148]
> Remote Procedure Call, Type:Call XID:0xd17c6210
>     Fragment header: Last fragment, 144 bytes
>         1... .... .... .... .... .... .... .... = Last Fragment: Yes
>         .000 0000 0000 0000 0000 0000 1001 0000 = Fragment Length: 144
>     XID: 0xd17c6210 (3514589712)
>     Message Type: Call (0)
>     RPC Version: 2
>     Program: NFS (100003)
>     Program Version: 4
>     Procedure: COMPOUND (1)
>     Credentials
>         Flavor: AUTH_UNIX (1)

.. and the client is using AUTH_UNIX, or sec=sys.  Seems your server 
isn't
picking up the change to the export for the root for some reason.

How are you modifying the export?  What does `exportfs -v` say?

Ben


^ permalink raw reply	[flat|nested] 7+ messages in thread

* Re: kerberized NFSv4 client reporting operation not permitted when mounting with sec=sys
  2020-02-04 19:14         ` Benjamin Coddington
@ 2020-02-05 11:09           ` Felix Rubio
  0 siblings, 0 replies; 7+ messages in thread
From: Felix Rubio @ 2020-02-05 11:09 UTC (permalink / raw)
  To: Benjamin Coddington; +Cc: linux-nfs

Hi Ben,

exportfs -v returns the following output:

/export/home    
10.0.0.0/8(sync,wdelay,hide,no_subtree_check,sec=sys:krb5:krb5i:krb5p,rw,secure,root_squash,no_all_squash)

Maybe helps to know that I am using a CentOS 7.7.1908, SELinux enabled, 
kernel (provided by CentOS) 3.10.0-1062.9.1.el7.x86_64.

Thank you for your help!
Felix

---
Felix Rubio
"Don't believe what you're told. Double check."

On 2020-02-04 20:14, Benjamin Coddington wrote:
> On 24 Jan 2020, at 11:49, Felix Rubio wrote:
> 
>> Hi Benjamin,
>> 
>>     I have enabled the debug logging on nfsd by running
>> 
>>     When mounting from the client, this is what I get:
>> 
>> [629588.647849] nfsd_dispatch: vers 4 proc 1
>> [629588.655615] nfsv4 compound op #1/1: 53 (OP_SEQUENCE)
>> [629588.663926] __find_in_sessionid_hashtbl: 
>> 1579604994:2010353049:95:0
>> [629588.675361] nfsd4_sequence: slotid 0
>> [629588.679065] check_slot_seqid enter. seqid 644 slot_seqid 643
>> [629588.684589] nfsv4 compound op ffff882839705080 opcnt 1 #1: 53: 
>> status 0
>> [629588.691545] nfsv4 compound returned 0
>> [629588.695292] --> nfsd4_store_cache_entry slot ffff882806e83000
>> [629588.701933] renewing client (clientid 5e26dc02/77d38d99)
>> [629591.804857] nfsd_dispatch: vers 4 proc 1
>> [629591.809364] nfsv4 compound op #1/4: 53 (OP_SEQUENCE)
>> [629591.814944] __find_in_sessionid_hashtbl: 
>> 1579604994:2010353053:99:0
>> [629591.822163] nfsd4_sequence: slotid 0
>> [629591.826670] check_slot_seqid enter. seqid 155 slot_seqid 154
>> [629591.832771] nfsv4 compound op ffff882839705080 opcnt 4 #1: 53: 
>> status 0
>> [629591.839864] nfsv4 compound op #2/4: 24 (OP_PUTROOTFH)
>> [629591.845161] nfsd: fh_compose(exp 08:02/17468677 /export, 
>> ino=17468677)
>> [629591.851706] nfsv4 compound op ffff882839705080 opcnt 4 #2: 24: 
>> status 10016
>> [629591.859660] nfsv4 compound returned 10016
> 
> So this is definitely the server returning NFS4ERR_WRONGSEC..
> 
>> [629591.864797] --> nfsd4_store_cache_entry slot ffff882838b9e000
>> [629591.872968] renewing client (clientid 5e26dc02/77d38d9d)
>> [629591.889085] nfsd_dispatch: vers 4 proc 1
>> [629591.893713] nfsv4 compound op #1/4: 53 (OP_SEQUENCE)
>> [629591.899703] __find_in_sessionid_hashtbl: 
>> 1579604994:2010353053:99:0
>> [629591.906687] nfsd4_sequence: slotid 0
>> [629591.912695] check_slot_seqid enter. seqid 156 slot_seqid 155
>> [629591.918261] nfsv4 compound op ffff882839705080 opcnt 4 #1: 53: 
>> status 0
>> [629591.924866] nfsv4 compound op #2/4: 22 (OP_PUTFH)
>> [629591.931075] nfsd: fh_verify(32: 01060001 63ce4307 5a18c100 
>> 00000000 00000000 1fba000a)
>> [629591.940556] nfsv4 compound op ffff882839705080 opcnt 4 #2: 22: 
>> status 0
>> [629591.948776] nfsv4 compound op #3/4: 3 (OP_ACCESS)
>> [629591.954607] nfsd: fh_verify(32: 01060001 63ce4307 5a18c100 
>> 00000000 00000000 1fba000a)
>> [629591.967117] nfsv4 compound op ffff882839705080 opcnt 4 #3: 3: 
>> status 0
>> [629591.975364] nfsv4 compound op #4/4: 9 (OP_GETATTR)
>> [629591.980854] nfsd: fh_verify(32: 01060001 63ce4307 5a18c100 
>> 00000000 00000000 1fba000a)
>> [629591.990257] nfsv4 compound op ffff882839705080 opcnt 4 #4: 9: 
>> status 0
>> [629591.996796] nfsv4 compound returned 0
>> [629592.001758] --> nfsd4_store_cache_entry slot ffff882838b9e000
>> [629592.008061] renewing client (clientid 5e26dc02/77d38d9d)
>> 
>> Using wireshark, this is the log of the packages from/to that ip 
>> address:
>> 
>> # tshark -i eth0 -p -w /tmp/nfs_mount.cap host 10.1.0.12 and port nfs
>> # tshark -r /tmp/nfs_mount.cap
>>   1 0.000000000    10.1.0.12 -> 10.0.2.9     NFS 202 V4 Call PUTROOTFH 
>> | GETATTR
> 
> ..to this call ^^ ..
> 
>>   2 0.000058001     10.0.2.9 -> 10.1.0.12    TCP 54 nfs > rndc [ACK] 
>> Seq=1 Ack=149 Win=1432 Len=0
>>   3 0.074041118     10.0.2.9 -> 10.1.0.12    NFS 146 V4 Reply (Call In 
>> 1) PUTROOTFH Status: NFS4ERR_WRONGSEC
>>   4 0.074927630    10.1.0.12 -> 10.0.2.9     TCP 54 rndc > nfs [ACK] 
>> Seq=149 Ack=93 Win=1476 Len=0
>>   5 0.084223658    10.1.0.12 -> 10.0.2.9     NFS 266 V4 Call ACCESS 
>> FH: 0xea1b01ae, [Check: RD LU MD XT DL]
>>   6 0.084270458     10.0.2.9 -> 10.1.0.12    TCP 54 nfs > rndc [ACK] 
>> Seq=93 Ack=361 Win=1432 Len=0
>>   7 0.208635667     10.0.2.9 -> 10.1.0.12    NFS 254 V4 Reply (Call In 
>> 5) ACCESS, [Access Denied: RD MD XT DL], [Allowed: LU]
>>   8 0.248855020    10.1.0.12 -> 10.0.2.9     TCP 54 rndc > nfs [ACK] 
>> Seq=361 Ack=293 Win=1498 Len=0
>> 
>> I think the frame of interest is #1, so this is its contents:
>> Frame 1: 202 bytes on wire (1616 bits), 202 bytes captured (1616 bits) 
>> on interface 0
>>     Interface id: 0
>>     Encapsulation type: Ethernet (1)
>>     Arrival Time: Jan 24, 2020 17:39:05.721360043 CET
>>     [Time shift for this packet: 0.000000000 seconds]
>>     Epoch Time: 1579883945.721360043 seconds
>>     [Time delta from previous captured frame: 0.000000000 seconds]
>>     [Time delta from previous displayed frame: 0.000000000 seconds]
>>     [Time since reference or first frame: 0.000000000 seconds]
>>     Frame Number: 1
>>     Frame Length: 202 bytes (1616 bits)
>>     Capture Length: 202 bytes (1616 bits)
>>     [Frame is marked: False]
>>     [Frame is ignored: False]
>>     [Protocols in frame: eth:ip:tcp:rpc]
>> Ethernet II, Src: 00:81:c4:c1:50:7f (00:81:c4:c1:50:7f), Dst: 
>> Microsof_44:24:d3 (00:0d:3a:44:24:d3)
>>     Destination: Microsof_44:24:d3 (00:0d:3a:44:24:d3)
>>         Address: Microsof_44:24:d3 (00:0d:3a:44:24:d3)
>>         .... ..0. .... .... .... .... = LG bit: Globally unique 
>> address (factory default)
>>         .... ...0 .... .... .... .... = IG bit: Individual address 
>> (unicast)
>>     Source: 00:81:c4:c1:50:7f (00:81:c4:c1:50:7f)
>>         Address: 00:81:c4:c1:50:7f (00:81:c4:c1:50:7f)
>>         .... ..0. .... .... .... .... = LG bit: Globally unique 
>> address (factory default)
>>         .... ...0 .... .... .... .... = IG bit: Individual address 
>> (unicast)
>>     Type: IP (0x0800)
>> Internet Protocol Version 4, Src: 10.1.0.12 (10.1.0.12), Dst: 10.0.2.9 
>> (10.0.2.9)
>>     Version: 4
>>     Header length: 20 bytes
>>     Differentiated Services Field: 0x00 (DSCP 0x00: Default; ECN: 
>> 0x00: Not-ECT (Not ECN-Capable Transport))
>>         0000 00.. = Differentiated Services Codepoint: Default (0x00)
>>         .... ..00 = Explicit Congestion Notification: Not-ECT (Not 
>> ECN-Capable Transport) (0x00)
>>     Total Length: 188
>>     Identification: 0xa3e0 (41952)
>>     Flags: 0x02 (Don't Fragment)
>>         0... .... = Reserved bit: Not set
>>         .1.. .... = Don't fragment: Set
>>         ..0. .... = More fragments: Not set
>>     Fragment offset: 0
>>     Time to live: 64
>>     Protocol: TCP (6)
>>     Header checksum: 0x8046 [validation disabled]
>>         [Good: False]
>>         [Bad: False]
>>     Source: 10.1.0.12 (10.1.0.12)
>>     Destination: 10.0.2.9 (10.0.2.9)
>> Transmission Control Protocol, Src Port: rndc (953), Dst Port: nfs 
>> (2049), Seq: 1, Ack: 1, Len: 148
>>     Source port: rndc (953)
>>     Destination port: nfs (2049)
>>     [Stream index: 0]
>>     Sequence number: 1    (relative sequence number)
>>     [Next sequence number: 149    (relative sequence number)]
>>     Acknowledgment number: 1    (relative ack number)
>>     Header length: 20 bytes
>>     Flags: 0x018 (PSH, ACK)
>>         000. .... .... = Reserved: Not set
>>         ...0 .... .... = Nonce: Not set
>>         .... 0... .... = Congestion Window Reduced (CWR): Not set
>>         .... .0.. .... = ECN-Echo: Not set
>>         .... ..0. .... = Urgent: Not set
>>         .... ...1 .... = Acknowledgment: Set
>>         .... .... 1... = Push: Set
>>         .... .... .0.. = Reset: Not set
>>         .... .... ..0. = Syn: Not set
>>         .... .... ...0 = Fin: Not set
>>     Window size value: 1476
>>     [Calculated window size: 1476]
>>     [Window size scaling factor: -1 (unknown)]
>>     Checksum: 0x4455 [validation disabled]
>>         [Good Checksum: False]
>>         [Bad Checksum: False]
>>     [SEQ/ACK analysis]
>>         [Bytes in flight: 148]
>> Remote Procedure Call, Type:Call XID:0xd17c6210
>>     Fragment header: Last fragment, 144 bytes
>>         1... .... .... .... .... .... .... .... = Last Fragment: Yes
>>         .000 0000 0000 0000 0000 0000 1001 0000 = Fragment Length: 144
>>     XID: 0xd17c6210 (3514589712)
>>     Message Type: Call (0)
>>     RPC Version: 2
>>     Program: NFS (100003)
>>     Program Version: 4
>>     Procedure: COMPOUND (1)
>>     Credentials
>>         Flavor: AUTH_UNIX (1)
> 
> .. and the client is using AUTH_UNIX, or sec=sys.  Seems your server 
> isn't
> picking up the change to the export for the root for some reason.
> 
> How are you modifying the export?  What does `exportfs -v` say?
> 
> Ben

^ permalink raw reply	[flat|nested] 7+ messages in thread

end of thread, back to index

Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-01-22  9:22 kerberized NFSv4 client reporting operation not permitted when mounting with sec=sys Felix Rubio
2020-01-22 18:30 ` Benjamin Coddington
2020-01-23  9:03   ` Felix Rubio
2020-01-24 14:45     ` Benjamin Coddington
2020-01-24 16:49       ` Felix Rubio
2020-02-04 19:14         ` Benjamin Coddington
2020-02-05 11:09           ` Felix Rubio

Linux-NFS Archive on lore.kernel.org

Archives are clonable:
	git clone --mirror https://lore.kernel.org/linux-nfs/0 linux-nfs/git/0.git

	# If you have public-inbox 1.1+ installed, you may
	# initialize and index your mirror using the following commands:
	public-inbox-init -V2 linux-nfs linux-nfs/ https://lore.kernel.org/linux-nfs \
		linux-nfs@vger.kernel.org
	public-inbox-index linux-nfs

Example config snippet for mirrors

Newsgroup available over NNTP:
	nntp://nntp.lore.kernel.org/org.kernel.vger.linux-nfs


AGPL code for this site: git clone https://public-inbox.org/public-inbox.git