All of lore.kernel.org
 help / color / mirror / Atom feed
* issue -- cifs automounts stopped working
@ 2020-07-17 14:04 Michael Keane, K1MK
       [not found] ` <CAH2r5msj3KMMonyhjDeyAweHEBezOHFkJwCUXpJ4Gv59Q=S9bQ@mail.gmail.com>
  0 siblings, 1 reply; 7+ messages in thread
From: Michael Keane, K1MK @ 2020-07-17 14:04 UTC (permalink / raw)
  To: linux-cifs

CIFS automounts to local NAS devices have stopped working recently

Fedora 32

kernel 5.7.8-200.fc32.x86_64

mount.cifs version: 6.9

auto.misc: it-share 
-fstype=cifs,multiuser,cruid=${UID},rw,vers=default,sec=krb5 
://filer5/IT_Share

dmesg:

    [ 3428.883661] fs/cifs/cifsfs.c: Devname:
    //filer5.arrlhq.org/IT_Share flags: 0
    [ 3428.883702] fs/cifs/connect.c: Username: root
    [ 3428.883706] fs/cifs/connect.c: file mode: 0755  dir mode: 0755
    [ 3428.883709] fs/cifs/connect.c: CIFS VFS: in mount_get_conns as
    Xid: 12 with uid: 0
    [ 3428.883710] fs/cifs/connect.c: UNC: \\filer5.arrlhq.org\IT_Share
    [ 3428.883721] fs/cifs/connect.c: Socket created
    [ 3428.883723] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072
    rcvtimeo 0x1b58
    [ 3428.884126] fs/cifs/fscache.c: cifs_fscache_get_client_cookie:
    (0x000000006d2b3226/0x0000000090edec3a)
    [ 3428.884130] fs/cifs/connect.c: CIFS VFS: in cifs_get_smb_ses as
    Xid: 13 with uid: 0
    [ 3428.884131] fs/cifs/connect.c: Existing smb sess not found
    [ 3428.884135] fs/cifs/smb2pdu.c: Negotiate protocol
    [ 3428.884141] fs/cifs/connect.c: Demultiplex PID: 5778
    [ 3428.884156] fs/cifs/transport.c: Sending smb: smb_len=252
    [ 3429.010818] fs/cifs/connect.c: RFC1002 header 0x11c
    [ 3429.010830] fs/cifs/smb2misc.c: SMB2 data length 96 offset 128
    [ 3429.010832] fs/cifs/smb2misc.c: SMB2 len 224
    [ 3429.010835] fs/cifs/smb2misc.c: length of negcontexts 60 pad 0
    [ 3429.010871] fs/cifs/transport.c: cifs_sync_mid_result: cmd=0
    mid=0 state=4
    [ 3429.010885] fs/cifs/misc.c: Null buffer passed to
    cifs_small_buf_release
    [ 3429.010891] fs/cifs/smb2pdu.c: mode 0x1
    [ 3429.010893] fs/cifs/smb2pdu.c: negotiated smb3.1.1 dialect
    [ 3429.010903] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0xbb92
    [ 3429.010907] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2 0x348 0x1bb92
    [ 3429.010910] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3 0x6 0x1
    [ 3429.010912] fs/cifs/smb2pdu.c: decoding 2 negotiate contexts
    [ 3429.010914] fs/cifs/smb2pdu.c: decode SMB3.11 encryption neg
    context of len 4
    [ 3429.010916] fs/cifs/smb2pdu.c: SMB311 cipher type:1
    [ 3429.010921] fs/cifs/connect.c: Security Mode: 0x1 Capabilities:
    0x300046 TimeAdjust: 0
    [ 3429.010923] fs/cifs/smb2pdu.c: Session Setup
    [ 3429.010926] fs/cifs/smb2pdu.c: sess setup type 5
    [ 3429.010949] fs/cifs/cifs_spnego.c: key description =
    ver=0x2;host=filer5.arrlhq.org;ip4=10.1.123.38;sec=krb5;uid=0x0;creduid=0x3e8;user=root;pid=0x1690
    [ 3429.025053] CIFS VFS: \\filer5.arrlhq.org Send error in SessSetup
    = -126
    [ 3429.025056] fs/cifs/connect.c: CIFS VFS: leaving cifs_get_smb_ses
    (xid = 13) rc = -126
    [ 3429.025059] fs/cifs/connect.c: build_unc_path_to_root:
    full_path=\\filer5.arrlhq.org\IT_Share
    [ 3429.025059] fs/cifs/connect.c: build_unc_path_to_root:
    full_path=\\filer5.arrlhq.org\IT_Share
    [ 3429.025060] fs/cifs/connect.c: build_unc_path_to_root:
    full_path=\\filer5.arrlhq.org\IT_Share
    [ 3429.025062] fs/cifs/dfs_cache.c: __dfs_cache_find: search path:
    \filer5.arrlhq.org\IT_Share
    [ 3429.025063] fs/cifs/dfs_cache.c: get_dfs_referral: get an DFS
    referral for \filer5.arrlhq.org\IT_Share
    [ 3429.025065] fs/cifs/dfs_cache.c: dfs_cache_noreq_find: path:
    \filer5.arrlhq.org\IT_Share
    [ 3429.025071] fs/cifs/fscache.c:
    cifs_fscache_release_client_cookie:
    (0x000000006d2b3226/0x0000000090edec3a)
    [ 3429.025076] fs/cifs/connect.c: CIFS VFS: leaving mount_put_conns
    (xid = 12) rc = 0
    [ 3429.025077] CIFS VFS: cifs_mount failed w/return code = -2

journalctl:

    Jul 17 09:43:13 mkZ230.ARRLHQ.ORG cifs.upcall[5779]: key
    description:
    cifs.spnego;0;0;39010000;ver=0x2;host=filer5.arrlhq.org;ip4=10.1.123.38;sec=krb5;uid=0x0;creduid=0x3e8;user=root;pid=0x1690
    Jul 17 09:43:13 mkZ230.ARRLHQ.ORG cifs.upcall[5779]: ver=2
    Jul 17 09:43:13 mkZ230.ARRLHQ.ORG cifs.upcall[5779]:
    host=filer5.arrlhq.org
    Jul 17 09:43:13 mkZ230.ARRLHQ.ORG cifs.upcall[5779]: ip=10.1.123.38
    Jul 17 09:43:13 mkZ230.ARRLHQ.ORG cifs.upcall[5779]: sec=1
    Jul 17 09:43:13 mkZ230.ARRLHQ.ORG cifs.upcall[5779]: uid=0
    Jul 17 09:43:13 mkZ230.ARRLHQ.ORG cifs.upcall[5779]: creduid=1000
    Jul 17 09:43:13 mkZ230.ARRLHQ.ORG cifs.upcall[5779]: user=root
    Jul 17 09:43:13 mkZ230.ARRLHQ.ORG cifs.upcall[5779]: pid=5776
    Jul 17 09:43:13 mkZ230.ARRLHQ.ORG cifs.upcall[5779]:
    get_cachename_from_process_env: pathname=/proc/5776/environ
    Jul 17 09:43:13 mkZ230.ARRLHQ.ORG cifs.upcall[5779]:
    get_existing_cc: default ccache is KEYRING:persistent:1000:1000
    Jul 17 09:43:13 mkZ230.ARRLHQ.ORG cifs.upcall[5779]:
    handle_krb5_mech: getting service ticket for filer5.arrlhq.org
    Jul 17 09:43:13 mkZ230.ARRLHQ.ORG cifs.upcall[5779]:
    cifs_krb5_get_req: unable to get credentials for filer5.arrlhq.org
    Jul 17 09:43:13 mkZ230.ARRLHQ.ORG cifs.upcall[5779]:
    handle_krb5_mech: failed to obtain service ticket (-1765328370)
    Jul 17 09:43:13 mkZ230.ARRLHQ.ORG cifs.upcall[5779]: Unable to
    obtain service ticket
    Jul 17 09:43:13 mkZ230.ARRLHQ.ORG cifs.upcall[5779]: Exit status
    -1765328370

$ klist
Ticket cache: KEYRING:persistent:1000:1000
Default principal: mkeane@ARRLHQ.ORG

Valid starting       Expires              Service principal
07/17/2020 09:43:06  07/17/2020 19:43:06 krbtgt/ARRLHQ.ORG@ARRLHQ.ORG
         renew until 07/24/2020 09:42:57

Filer5 is a QNAP TS-870U-RP Version 4.3.6.1070 (2019/09/10) NAS device 
but having this issue with other NAS device on LAN

-- 
Michael Keane, K1MK
IT Manager
ARRL, The National Association for Amateur Radio™
225 Main Street, Newington, CT 06111-1494 USA
Telephone: (860) 594-0285
email: mkeane@arrl.org


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

* Re: issue -- cifs automounts stopped working
       [not found]     ` <CAH2r5muNtwm3V-0GpaRBXmrptGDO9w1vDSWN9Wrf_eebuevg6A@mail.gmail.com>
@ 2020-07-21 19:52       ` Michael Keane, K1MK
  2020-07-21 19:59         ` Steve French
  0 siblings, 1 reply; 7+ messages in thread
From: Michael Keane, K1MK @ 2020-07-21 19:52 UTC (permalink / raw)
  To: Steve French; +Cc: Shyam Prasad N, CIFS

KRB5_CCNAME is not set in the environment of the user for whom the 
automount is failing.

In /etc/krb5.conf the default is set to:

    default_ccache_name = KEYRING:persistent:%{uid}

The calls to keyctl()  in the strace for cifs.upcall  indicate that it's 
successfully locating the user's keyring in the kernel and that it is 
able to read key data from that keying

I haven't gone through and tried unpacking and decoding the contents of 
those reads, but the reads aren't failing outright like it couldn't find 
the credentials cache or the contents that it's looking for


On 07/21/2020 1:36 PM, Steve French wrote:
> That is plausible but I also wonder about other whether other parts of 
> krb5 configuration are changed/broken eg KRB5_CCNAME environment variable
>
> See https://web.mit.edu/kerberos/krb5-1.12/doc/basic/ccache_def.html
>
> On Tue, Jul 21, 2020, 12:24 Michael Keane, K1MK <mkeane@arrl.org 
> <mailto:mkeane@arrl.org>> wrote:
>
>     Thanks
>
>     In trying to further debug this problem, I've stood up a separate
>     Fedora 31 instance for testing with the result that the same
>     configuration that is failing on Fedora 32 is working under Fedora 31
>
>     Using strace it would appear the deviation occurs at the point of
>     "handle_krb5_mech" where the Fedora 31 instance proceeds though
>     several keyctl() calls to a successful return while the Fedora 32
>     instance goes through a similar sequence of keyctl() calls but
>     rather than finishing up with a final call to keyctl() to
>     instantiate the key it appears that the krb5 library and/or sssd
>     is going through a series of steps to locate the KDC (and failing)
>     even though the KDCs have always been explicitly configured in
>     /etc/krb5.conf
>
>     So the root cause of this issue may not be anything in cifs.upcall
>     but rather something in the sssd or kerberos that got changed as a
>     result of moving from Fedora 31 to Fedora 32
>
>     On 07/18/2020 8:40 PM, Steve French wrote:
>>     Looks like error obtaining the key (either keyutils package not
>>     installed or no Kerberos ticket found).
>>
>>     This page has debug instructions for cifs.upcall. see of that
>>     information is helpful.
>>
>>     http://sprabhu.blogspot.com/2014/12/debugging-calls-to-cifsupcall.html?m=1
>>
>>     Also try kinit as a local user and then mount with cruid mount
>>     option pointing to their uid to see if that helps.
>>
>>     On Fri, Jul 17, 2020, 09:04 Michael Keane, K1MK <mkeane@arrl.org
>>     <mailto:mkeane@arrl.org>> wrote:
>>
>>         CIFS automounts to local NAS devices have stopped working
>>         recently
>>
>>         Fedora 32
>>
>>         kernel 5.7.8-200.fc32.x86_64
>>
>>         mount.cifs version: 6.9
>>
>>         auto.misc: it-share
>>         -fstype=cifs,multiuser,cruid=${UID},rw,vers=default,sec=krb5
>>         ://filer5/IT_Share
>>
>>         dmesg:
>>
>>             [ 3428.883661] fs/cifs/cifsfs.c: Devname:
>>             //filer5.arrlhq.org/IT_Share
>>         <http://filer5.arrlhq.org/IT_Share> flags: 0
>>             [ 3428.883702] fs/cifs/connect.c: Username: root
>>             [ 3428.883706] fs/cifs/connect.c: file mode: 0755 dir
>>         mode: 0755
>>             [ 3428.883709] fs/cifs/connect.c: CIFS VFS: in
>>         mount_get_conns as
>>             Xid: 12 with uid: 0
>>             [ 3428.883710] fs/cifs/connect.c: UNC:
>>         \\filer5.arrlhq.org <http://filer5.arrlhq.org>\IT_Share
>>             [ 3428.883721] fs/cifs/connect.c: Socket created
>>             [ 3428.883723] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072
>>             rcvtimeo 0x1b58
>>             [ 3428.884126] fs/cifs/fscache.c:
>>         cifs_fscache_get_client_cookie:
>>             (0x000000006d2b3226/0x0000000090edec3a)
>>             [ 3428.884130] fs/cifs/connect.c: CIFS VFS: in
>>         cifs_get_smb_ses as
>>             Xid: 13 with uid: 0
>>             [ 3428.884131] fs/cifs/connect.c: Existing smb sess not found
>>             [ 3428.884135] fs/cifs/smb2pdu.c: Negotiate protocol
>>             [ 3428.884141] fs/cifs/connect.c: Demultiplex PID: 5778
>>             [ 3428.884156] fs/cifs/transport.c: Sending smb: smb_len=252
>>             [ 3429.010818] fs/cifs/connect.c: RFC1002 header 0x11c
>>             [ 3429.010830] fs/cifs/smb2misc.c: SMB2 data length 96
>>         offset 128
>>             [ 3429.010832] fs/cifs/smb2misc.c: SMB2 len 224
>>             [ 3429.010835] fs/cifs/smb2misc.c: length of negcontexts
>>         60 pad 0
>>             [ 3429.010871] fs/cifs/transport.c: cifs_sync_mid_result:
>>         cmd=0
>>             mid=0 state=4
>>             [ 3429.010885] fs/cifs/misc.c: Null buffer passed to
>>             cifs_small_buf_release
>>             [ 3429.010891] fs/cifs/smb2pdu.c: mode 0x1
>>             [ 3429.010893] fs/cifs/smb2pdu.c: negotiated smb3.1.1 dialect
>>             [ 3429.010903] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2
>>         0x348 0xbb92
>>             [ 3429.010907] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2
>>         0x348 0x1bb92
>>             [ 3429.010910] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3
>>         0x6 0x1
>>             [ 3429.010912] fs/cifs/smb2pdu.c: decoding 2 negotiate
>>         contexts
>>             [ 3429.010914] fs/cifs/smb2pdu.c: decode SMB3.11
>>         encryption neg
>>             context of len 4
>>             [ 3429.010916] fs/cifs/smb2pdu.c: SMB311 cipher type:1
>>             [ 3429.010921] fs/cifs/connect.c: Security Mode: 0x1
>>         Capabilities:
>>             0x300046 TimeAdjust: 0
>>             [ 3429.010923] fs/cifs/smb2pdu.c: Session Setup
>>             [ 3429.010926] fs/cifs/smb2pdu.c: sess setup type 5
>>             [ 3429.010949] fs/cifs/cifs_spnego.c: key description =
>>             ver=0x2;host=filer5.arrlhq.org
>>         <http://filer5.arrlhq.org>;ip4=10.1.123.38;sec=krb5;uid=0x0;creduid=0x3e8;user=root;pid=0x1690
>>             [ 3429.025053] CIFS VFS: \\filer5.arrlhq.org
>>         <http://filer5.arrlhq.org> Send error in SessSetup
>>             = -126
>>             [ 3429.025056] fs/cifs/connect.c: CIFS VFS: leaving
>>         cifs_get_smb_ses
>>             (xid = 13) rc = -126
>>             [ 3429.025059] fs/cifs/connect.c: build_unc_path_to_root:
>>             full_path=\\filer5.arrlhq.org
>>         <http://filer5.arrlhq.org>\IT_Share
>>             [ 3429.025059] fs/cifs/connect.c: build_unc_path_to_root:
>>             full_path=\\filer5.arrlhq.org
>>         <http://filer5.arrlhq.org>\IT_Share
>>             [ 3429.025060] fs/cifs/connect.c: build_unc_path_to_root:
>>             full_path=\\filer5.arrlhq.org
>>         <http://filer5.arrlhq.org>\IT_Share
>>             [ 3429.025062] fs/cifs/dfs_cache.c: __dfs_cache_find:
>>         search path:
>>             \filer5.arrlhq.org <http://filer5.arrlhq.org>\IT_Share
>>             [ 3429.025063] fs/cifs/dfs_cache.c: get_dfs_referral: get
>>         an DFS
>>             referral for \filer5.arrlhq.org
>>         <http://filer5.arrlhq.org>\IT_Share
>>             [ 3429.025065] fs/cifs/dfs_cache.c: dfs_cache_noreq_find:
>>         path:
>>             \filer5.arrlhq.org <http://filer5.arrlhq.org>\IT_Share
>>             [ 3429.025071] fs/cifs/fscache.c:
>>             cifs_fscache_release_client_cookie:
>>             (0x000000006d2b3226/0x0000000090edec3a)
>>             [ 3429.025076] fs/cifs/connect.c: CIFS VFS: leaving
>>         mount_put_conns
>>             (xid = 12) rc = 0
>>             [ 3429.025077] CIFS VFS: cifs_mount failed w/return code = -2
>>
>>         journalctl:
>>
>>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: key
>>             description:
>>             cifs.spnego;0;0;39010000;ver=0x2;host=filer5.arrlhq.org
>>         <http://filer5.arrlhq.org>;ip4=10.1.123.38;sec=krb5;uid=0x0;creduid=0x3e8;user=root;pid=0x1690
>>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: ver=2
>>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
>>             host=filer5.arrlhq.org <http://filer5.arrlhq.org>
>>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: ip=10.1.123.38
>>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: sec=1
>>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: uid=0
>>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: creduid=1000
>>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: user=root
>>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: pid=5776
>>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
>>             get_cachename_from_process_env: pathname=/proc/5776/environ
>>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
>>             get_existing_cc: default ccache is
>>         KEYRING:persistent:1000:1000
>>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
>>             handle_krb5_mech: getting service ticket for
>>         filer5.arrlhq.org <http://filer5.arrlhq.org>
>>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
>>             cifs_krb5_get_req: unable to get credentials for
>>         filer5.arrlhq.org <http://filer5.arrlhq.org>
>>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
>>             handle_krb5_mech: failed to obtain service ticket
>>         (-1765328370)
>>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: Unable to
>>             obtain service ticket
>>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: Exit status
>>             -1765328370
>>
>>         $ klist
>>         Ticket cache: KEYRING:persistent:1000:1000
>>         Default principal: mkeane@ARRLHQ.ORG <mailto:mkeane@ARRLHQ.ORG>
>>
>>         Valid starting       Expires              Service principal
>>         07/17/2020 09:43:06  07/17/2020 19:43:06
>>         krbtgt/ARRLHQ.ORG@ARRLHQ.ORG <mailto:ARRLHQ.ORG@ARRLHQ.ORG>
>>                  renew until 07/24/2020 09:42:57
>>
>>         Filer5 is a QNAP TS-870U-RP Version 4.3.6.1070 (2019/09/10)
>>         NAS device
>>         but having this issue with other NAS device on LAN
>>
>>         -- 
>>         Michael Keane, K1MK
>>         IT Manager
>>         ARRL, The National Association for Amateur Radio™
>>         225 Main Street, Newington, CT 06111-1494 USA
>>         Telephone: (860) 594-0285
>>         email: mkeane@arrl.org <mailto:mkeane@arrl.org>
>>
>
>     -- 
>     Michael Keane, K1MK
>     IT Manager
>     ARRL, The National Association for Amateur Radio™
>     225 Main Street, Newington, CT 06111-1494 USA
>     Telephone: (860) 594-0285
>     email:mkeane@arrl.org  <mailto:mkeane@arrl.org>
>

-- 
Michael Keane, K1MK
IT Manager
ARRL, The National Association for Amateur Radio™
225 Main Street, Newington, CT 06111-1494 USA
Telephone: (860) 594-0285
email: mkeane@arrl.org


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

* Re: issue -- cifs automounts stopped working
  2020-07-21 19:52       ` Michael Keane, K1MK
@ 2020-07-21 19:59         ` Steve French
  2020-07-22  3:48           ` Michael Keane, K1MK
  0 siblings, 1 reply; 7+ messages in thread
From: Steve French @ 2020-07-21 19:59 UTC (permalink / raw)
  To: Michael Keane, K1MK; +Cc: Shyam Prasad N, CIFS

Would setting KRB5_CCNAME (as would be expected in the past) for that
process fix the issue?

On Tue, Jul 21, 2020 at 2:52 PM Michael Keane, K1MK <mkeane@arrl.org> wrote:
>
> KRB5_CCNAME is not set in the environment of the user for whom the
> automount is failing.
>
> In /etc/krb5.conf the default is set to:
>
>     default_ccache_name = KEYRING:persistent:%{uid}
>
> The calls to keyctl()  in the strace for cifs.upcall  indicate that it's
> successfully locating the user's keyring in the kernel and that it is
> able to read key data from that keying
>
> I haven't gone through and tried unpacking and decoding the contents of
> those reads, but the reads aren't failing outright like it couldn't find
> the credentials cache or the contents that it's looking for
>
>
> On 07/21/2020 1:36 PM, Steve French wrote:
> > That is plausible but I also wonder about other whether other parts of
> > krb5 configuration are changed/broken eg KRB5_CCNAME environment variable
> >
> > See https://web.mit.edu/kerberos/krb5-1.12/doc/basic/ccache_def.html
> >
> > On Tue, Jul 21, 2020, 12:24 Michael Keane, K1MK <mkeane@arrl.org
> > <mailto:mkeane@arrl.org>> wrote:
> >
> >     Thanks
> >
> >     In trying to further debug this problem, I've stood up a separate
> >     Fedora 31 instance for testing with the result that the same
> >     configuration that is failing on Fedora 32 is working under Fedora 31
> >
> >     Using strace it would appear the deviation occurs at the point of
> >     "handle_krb5_mech" where the Fedora 31 instance proceeds though
> >     several keyctl() calls to a successful return while the Fedora 32
> >     instance goes through a similar sequence of keyctl() calls but
> >     rather than finishing up with a final call to keyctl() to
> >     instantiate the key it appears that the krb5 library and/or sssd
> >     is going through a series of steps to locate the KDC (and failing)
> >     even though the KDCs have always been explicitly configured in
> >     /etc/krb5.conf
> >
> >     So the root cause of this issue may not be anything in cifs.upcall
> >     but rather something in the sssd or kerberos that got changed as a
> >     result of moving from Fedora 31 to Fedora 32
> >
> >     On 07/18/2020 8:40 PM, Steve French wrote:
> >>     Looks like error obtaining the key (either keyutils package not
> >>     installed or no Kerberos ticket found).
> >>
> >>     This page has debug instructions for cifs.upcall. see of that
> >>     information is helpful.
> >>
> >>     http://sprabhu.blogspot.com/2014/12/debugging-calls-to-cifsupcall.html?m=1
> >>
> >>     Also try kinit as a local user and then mount with cruid mount
> >>     option pointing to their uid to see if that helps.
> >>
> >>     On Fri, Jul 17, 2020, 09:04 Michael Keane, K1MK <mkeane@arrl.org
> >>     <mailto:mkeane@arrl.org>> wrote:
> >>
> >>         CIFS automounts to local NAS devices have stopped working
> >>         recently
> >>
> >>         Fedora 32
> >>
> >>         kernel 5.7.8-200.fc32.x86_64
> >>
> >>         mount.cifs version: 6.9
> >>
> >>         auto.misc: it-share
> >>         -fstype=cifs,multiuser,cruid=${UID},rw,vers=default,sec=krb5
> >>         ://filer5/IT_Share
> >>
> >>         dmesg:
> >>
> >>             [ 3428.883661] fs/cifs/cifsfs.c: Devname:
> >>             //filer5.arrlhq.org/IT_Share
> >>         <http://filer5.arrlhq.org/IT_Share> flags: 0
> >>             [ 3428.883702] fs/cifs/connect.c: Username: root
> >>             [ 3428.883706] fs/cifs/connect.c: file mode: 0755 dir
> >>         mode: 0755
> >>             [ 3428.883709] fs/cifs/connect.c: CIFS VFS: in
> >>         mount_get_conns as
> >>             Xid: 12 with uid: 0
> >>             [ 3428.883710] fs/cifs/connect.c: UNC:
> >>         \\filer5.arrlhq.org <http://filer5.arrlhq.org>\IT_Share
> >>             [ 3428.883721] fs/cifs/connect.c: Socket created
> >>             [ 3428.883723] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072
> >>             rcvtimeo 0x1b58
> >>             [ 3428.884126] fs/cifs/fscache.c:
> >>         cifs_fscache_get_client_cookie:
> >>             (0x000000006d2b3226/0x0000000090edec3a)
> >>             [ 3428.884130] fs/cifs/connect.c: CIFS VFS: in
> >>         cifs_get_smb_ses as
> >>             Xid: 13 with uid: 0
> >>             [ 3428.884131] fs/cifs/connect.c: Existing smb sess not found
> >>             [ 3428.884135] fs/cifs/smb2pdu.c: Negotiate protocol
> >>             [ 3428.884141] fs/cifs/connect.c: Demultiplex PID: 5778
> >>             [ 3428.884156] fs/cifs/transport.c: Sending smb: smb_len=252
> >>             [ 3429.010818] fs/cifs/connect.c: RFC1002 header 0x11c
> >>             [ 3429.010830] fs/cifs/smb2misc.c: SMB2 data length 96
> >>         offset 128
> >>             [ 3429.010832] fs/cifs/smb2misc.c: SMB2 len 224
> >>             [ 3429.010835] fs/cifs/smb2misc.c: length of negcontexts
> >>         60 pad 0
> >>             [ 3429.010871] fs/cifs/transport.c: cifs_sync_mid_result:
> >>         cmd=0
> >>             mid=0 state=4
> >>             [ 3429.010885] fs/cifs/misc.c: Null buffer passed to
> >>             cifs_small_buf_release
> >>             [ 3429.010891] fs/cifs/smb2pdu.c: mode 0x1
> >>             [ 3429.010893] fs/cifs/smb2pdu.c: negotiated smb3.1.1 dialect
> >>             [ 3429.010903] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2
> >>         0x348 0xbb92
> >>             [ 3429.010907] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2
> >>         0x348 0x1bb92
> >>             [ 3429.010910] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3
> >>         0x6 0x1
> >>             [ 3429.010912] fs/cifs/smb2pdu.c: decoding 2 negotiate
> >>         contexts
> >>             [ 3429.010914] fs/cifs/smb2pdu.c: decode SMB3.11
> >>         encryption neg
> >>             context of len 4
> >>             [ 3429.010916] fs/cifs/smb2pdu.c: SMB311 cipher type:1
> >>             [ 3429.010921] fs/cifs/connect.c: Security Mode: 0x1
> >>         Capabilities:
> >>             0x300046 TimeAdjust: 0
> >>             [ 3429.010923] fs/cifs/smb2pdu.c: Session Setup
> >>             [ 3429.010926] fs/cifs/smb2pdu.c: sess setup type 5
> >>             [ 3429.010949] fs/cifs/cifs_spnego.c: key description =
> >>             ver=0x2;host=filer5.arrlhq.org
> >>         <http://filer5.arrlhq.org>;ip4=10.1.123.38;sec=krb5;uid=0x0;creduid=0x3e8;user=root;pid=0x1690
> >>             [ 3429.025053] CIFS VFS: \\filer5.arrlhq.org
> >>         <http://filer5.arrlhq.org> Send error in SessSetup
> >>             = -126
> >>             [ 3429.025056] fs/cifs/connect.c: CIFS VFS: leaving
> >>         cifs_get_smb_ses
> >>             (xid = 13) rc = -126
> >>             [ 3429.025059] fs/cifs/connect.c: build_unc_path_to_root:
> >>             full_path=\\filer5.arrlhq.org
> >>         <http://filer5.arrlhq.org>\IT_Share
> >>             [ 3429.025059] fs/cifs/connect.c: build_unc_path_to_root:
> >>             full_path=\\filer5.arrlhq.org
> >>         <http://filer5.arrlhq.org>\IT_Share
> >>             [ 3429.025060] fs/cifs/connect.c: build_unc_path_to_root:
> >>             full_path=\\filer5.arrlhq.org
> >>         <http://filer5.arrlhq.org>\IT_Share
> >>             [ 3429.025062] fs/cifs/dfs_cache.c: __dfs_cache_find:
> >>         search path:
> >>             \filer5.arrlhq.org <http://filer5.arrlhq.org>\IT_Share
> >>             [ 3429.025063] fs/cifs/dfs_cache.c: get_dfs_referral: get
> >>         an DFS
> >>             referral for \filer5.arrlhq.org
> >>         <http://filer5.arrlhq.org>\IT_Share
> >>             [ 3429.025065] fs/cifs/dfs_cache.c: dfs_cache_noreq_find:
> >>         path:
> >>             \filer5.arrlhq.org <http://filer5.arrlhq.org>\IT_Share
> >>             [ 3429.025071] fs/cifs/fscache.c:
> >>             cifs_fscache_release_client_cookie:
> >>             (0x000000006d2b3226/0x0000000090edec3a)
> >>             [ 3429.025076] fs/cifs/connect.c: CIFS VFS: leaving
> >>         mount_put_conns
> >>             (xid = 12) rc = 0
> >>             [ 3429.025077] CIFS VFS: cifs_mount failed w/return code = -2
> >>
> >>         journalctl:
> >>
> >>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: key
> >>             description:
> >>             cifs.spnego;0;0;39010000;ver=0x2;host=filer5.arrlhq.org
> >>         <http://filer5.arrlhq.org>;ip4=10.1.123.38;sec=krb5;uid=0x0;creduid=0x3e8;user=root;pid=0x1690
> >>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: ver=2
> >>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> >>             host=filer5.arrlhq.org <http://filer5.arrlhq.org>
> >>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: ip=10.1.123.38
> >>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: sec=1
> >>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: uid=0
> >>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: creduid=1000
> >>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: user=root
> >>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: pid=5776
> >>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> >>             get_cachename_from_process_env: pathname=/proc/5776/environ
> >>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> >>             get_existing_cc: default ccache is
> >>         KEYRING:persistent:1000:1000
> >>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> >>             handle_krb5_mech: getting service ticket for
> >>         filer5.arrlhq.org <http://filer5.arrlhq.org>
> >>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> >>             cifs_krb5_get_req: unable to get credentials for
> >>         filer5.arrlhq.org <http://filer5.arrlhq.org>
> >>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> >>             handle_krb5_mech: failed to obtain service ticket
> >>         (-1765328370)
> >>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: Unable to
> >>             obtain service ticket
> >>             Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>         <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: Exit status
> >>             -1765328370
> >>
> >>         $ klist
> >>         Ticket cache: KEYRING:persistent:1000:1000
> >>         Default principal: mkeane@ARRLHQ.ORG <mailto:mkeane@ARRLHQ.ORG>
> >>
> >>         Valid starting       Expires              Service principal
> >>         07/17/2020 09:43:06  07/17/2020 19:43:06
> >>         krbtgt/ARRLHQ.ORG@ARRLHQ.ORG <mailto:ARRLHQ.ORG@ARRLHQ.ORG>
> >>                  renew until 07/24/2020 09:42:57
> >>
> >>         Filer5 is a QNAP TS-870U-RP Version 4.3.6.1070 (2019/09/10)
> >>         NAS device
> >>         but having this issue with other NAS device on LAN
> >>
> >>         --
> >>         Michael Keane, K1MK
> >>         IT Manager
> >>         ARRL, The National Association for Amateur Radio™
> >>         225 Main Street, Newington, CT 06111-1494 USA
> >>         Telephone: (860) 594-0285
> >>         email: mkeane@arrl.org <mailto:mkeane@arrl.org>
> >>
> >
> >     --
> >     Michael Keane, K1MK
> >     IT Manager
> >     ARRL, The National Association for Amateur Radio™
> >     225 Main Street, Newington, CT 06111-1494 USA
> >     Telephone: (860) 594-0285
> >     email:mkeane@arrl.org  <mailto:mkeane@arrl.org>
> >
>
> --
> Michael Keane, K1MK
> IT Manager
> ARRL, The National Association for Amateur Radio™
> 225 Main Street, Newington, CT 06111-1494 USA
> Telephone: (860) 594-0285
> email: mkeane@arrl.org
>


-- 
Thanks,

Steve

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

* Re: issue -- cifs automounts stopped working
  2020-07-21 19:59         ` Steve French
@ 2020-07-22  3:48           ` Michael Keane, K1MK
  2020-07-22  4:03             ` Steve French
  2020-07-22  5:07             ` Isaac Boukris
  0 siblings, 2 replies; 7+ messages in thread
From: Michael Keane, K1MK @ 2020-07-22  3:48 UTC (permalink / raw)
  To: Steve French; +Cc: Shyam Prasad N, CIFS

Tried setting KRB5_CCNAME to KEYRING:persistent:1000 with no change 
(Also tried KRB5CCNAME  as well, as that's the environment variable 
which seems to work with kinit & klist)

Also tried setting default_ccahe_name in /etc/krb5.conf to a legacy 
value of

     default_ccache_name = /tmp/krb5_%{uid}

in order to force it to use the filesystem rather than the kernel space 
for the credentials cache. And it still fails in the same way. I think 
that tends to makes this more likely a regression in krb5 than the kernel.

I believe that I may have verified this by reverting from 
krb5-*/-/1.18.2-10 to krb5-*-1.17.1-5 which resolves the issue



On 07/21/2020 3:59 PM, Steve French wrote:
> Would setting KRB5_CCNAME (as would be expected in the past) for that
> process fix the issue?
>
> On Tue, Jul 21, 2020 at 2:52 PM Michael Keane, K1MK <mkeane@arrl.org> wrote:
>> KRB5_CCNAME is not set in the environment of the user for whom the
>> automount is failing.
>>
>> In /etc/krb5.conf the default is set to:
>>
>>      default_ccache_name = KEYRING:persistent:%{uid}
>>
>> The calls to keyctl()  in the strace for cifs.upcall  indicate that it's
>> successfully locating the user's keyring in the kernel and that it is
>> able to read key data from that keying
>>
>> I haven't gone through and tried unpacking and decoding the contents of
>> those reads, but the reads aren't failing outright like it couldn't find
>> the credentials cache or the contents that it's looking for
>>
>>
>> On 07/21/2020 1:36 PM, Steve French wrote:
>>> That is plausible but I also wonder about other whether other parts of
>>> krb5 configuration are changed/broken eg KRB5_CCNAME environment variable
>>>
>>> See https://web.mit.edu/kerberos/krb5-1.12/doc/basic/ccache_def.html
>>>
>>> On Tue, Jul 21, 2020, 12:24 Michael Keane, K1MK <mkeane@arrl.org
>>> <mailto:mkeane@arrl.org>> wrote:
>>>
>>>      Thanks
>>>
>>>      In trying to further debug this problem, I've stood up a separate
>>>      Fedora 31 instance for testing with the result that the same
>>>      configuration that is failing on Fedora 32 is working under Fedora 31
>>>
>>>      Using strace it would appear the deviation occurs at the point of
>>>      "handle_krb5_mech" where the Fedora 31 instance proceeds though
>>>      several keyctl() calls to a successful return while the Fedora 32
>>>      instance goes through a similar sequence of keyctl() calls but
>>>      rather than finishing up with a final call to keyctl() to
>>>      instantiate the key it appears that the krb5 library and/or sssd
>>>      is going through a series of steps to locate the KDC (and failing)
>>>      even though the KDCs have always been explicitly configured in
>>>      /etc/krb5.conf
>>>
>>>      So the root cause of this issue may not be anything in cifs.upcall
>>>      but rather something in the sssd or kerberos that got changed as a
>>>      result of moving from Fedora 31 to Fedora 32
>>>
>>>      On 07/18/2020 8:40 PM, Steve French wrote:
>>>>      Looks like error obtaining the key (either keyutils package not
>>>>      installed or no Kerberos ticket found).
>>>>
>>>>      This page has debug instructions for cifs.upcall. see of that
>>>>      information is helpful.
>>>>
>>>>      http://sprabhu.blogspot.com/2014/12/debugging-calls-to-cifsupcall.html?m=1
>>>>
>>>>      Also try kinit as a local user and then mount with cruid mount
>>>>      option pointing to their uid to see if that helps.
>>>>
>>>>      On Fri, Jul 17, 2020, 09:04 Michael Keane, K1MK <mkeane@arrl.org
>>>>      <mailto:mkeane@arrl.org>> wrote:
>>>>
>>>>          CIFS automounts to local NAS devices have stopped working
>>>>          recently
>>>>
>>>>          Fedora 32
>>>>
>>>>          kernel 5.7.8-200.fc32.x86_64
>>>>
>>>>          mount.cifs version: 6.9
>>>>
>>>>          auto.misc: it-share
>>>>          -fstype=cifs,multiuser,cruid=${UID},rw,vers=default,sec=krb5
>>>>          ://filer5/IT_Share
>>>>
>>>>          dmesg:
>>>>
>>>>              [ 3428.883661] fs/cifs/cifsfs.c: Devname:
>>>>              //filer5.arrlhq.org/IT_Share
>>>>          <http://filer5.arrlhq.org/IT_Share> flags: 0
>>>>              [ 3428.883702] fs/cifs/connect.c: Username: root
>>>>              [ 3428.883706] fs/cifs/connect.c: file mode: 0755 dir
>>>>          mode: 0755
>>>>              [ 3428.883709] fs/cifs/connect.c: CIFS VFS: in
>>>>          mount_get_conns as
>>>>              Xid: 12 with uid: 0
>>>>              [ 3428.883710] fs/cifs/connect.c: UNC:
>>>>          \\filer5.arrlhq.org <http://filer5.arrlhq.org>\IT_Share
>>>>              [ 3428.883721] fs/cifs/connect.c: Socket created
>>>>              [ 3428.883723] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072
>>>>              rcvtimeo 0x1b58
>>>>              [ 3428.884126] fs/cifs/fscache.c:
>>>>          cifs_fscache_get_client_cookie:
>>>>              (0x000000006d2b3226/0x0000000090edec3a)
>>>>              [ 3428.884130] fs/cifs/connect.c: CIFS VFS: in
>>>>          cifs_get_smb_ses as
>>>>              Xid: 13 with uid: 0
>>>>              [ 3428.884131] fs/cifs/connect.c: Existing smb sess not found
>>>>              [ 3428.884135] fs/cifs/smb2pdu.c: Negotiate protocol
>>>>              [ 3428.884141] fs/cifs/connect.c: Demultiplex PID: 5778
>>>>              [ 3428.884156] fs/cifs/transport.c: Sending smb: smb_len=252
>>>>              [ 3429.010818] fs/cifs/connect.c: RFC1002 header 0x11c
>>>>              [ 3429.010830] fs/cifs/smb2misc.c: SMB2 data length 96
>>>>          offset 128
>>>>              [ 3429.010832] fs/cifs/smb2misc.c: SMB2 len 224
>>>>              [ 3429.010835] fs/cifs/smb2misc.c: length of negcontexts
>>>>          60 pad 0
>>>>              [ 3429.010871] fs/cifs/transport.c: cifs_sync_mid_result:
>>>>          cmd=0
>>>>              mid=0 state=4
>>>>              [ 3429.010885] fs/cifs/misc.c: Null buffer passed to
>>>>              cifs_small_buf_release
>>>>              [ 3429.010891] fs/cifs/smb2pdu.c: mode 0x1
>>>>              [ 3429.010893] fs/cifs/smb2pdu.c: negotiated smb3.1.1 dialect
>>>>              [ 3429.010903] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2
>>>>          0x348 0xbb92
>>>>              [ 3429.010907] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2
>>>>          0x348 0x1bb92
>>>>              [ 3429.010910] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3
>>>>          0x6 0x1
>>>>              [ 3429.010912] fs/cifs/smb2pdu.c: decoding 2 negotiate
>>>>          contexts
>>>>              [ 3429.010914] fs/cifs/smb2pdu.c: decode SMB3.11
>>>>          encryption neg
>>>>              context of len 4
>>>>              [ 3429.010916] fs/cifs/smb2pdu.c: SMB311 cipher type:1
>>>>              [ 3429.010921] fs/cifs/connect.c: Security Mode: 0x1
>>>>          Capabilities:
>>>>              0x300046 TimeAdjust: 0
>>>>              [ 3429.010923] fs/cifs/smb2pdu.c: Session Setup
>>>>              [ 3429.010926] fs/cifs/smb2pdu.c: sess setup type 5
>>>>              [ 3429.010949] fs/cifs/cifs_spnego.c: key description =
>>>>              ver=0x2;host=filer5.arrlhq.org
>>>>          <http://filer5.arrlhq.org>;ip4=10.1.123.38;sec=krb5;uid=0x0;creduid=0x3e8;user=root;pid=0x1690
>>>>              [ 3429.025053] CIFS VFS: \\filer5.arrlhq.org
>>>>          <http://filer5.arrlhq.org> Send error in SessSetup
>>>>              = -126
>>>>              [ 3429.025056] fs/cifs/connect.c: CIFS VFS: leaving
>>>>          cifs_get_smb_ses
>>>>              (xid = 13) rc = -126
>>>>              [ 3429.025059] fs/cifs/connect.c: build_unc_path_to_root:
>>>>              full_path=\\filer5.arrlhq.org
>>>>          <http://filer5.arrlhq.org>\IT_Share
>>>>              [ 3429.025059] fs/cifs/connect.c: build_unc_path_to_root:
>>>>              full_path=\\filer5.arrlhq.org
>>>>          <http://filer5.arrlhq.org>\IT_Share
>>>>              [ 3429.025060] fs/cifs/connect.c: build_unc_path_to_root:
>>>>              full_path=\\filer5.arrlhq.org
>>>>          <http://filer5.arrlhq.org>\IT_Share
>>>>              [ 3429.025062] fs/cifs/dfs_cache.c: __dfs_cache_find:
>>>>          search path:
>>>>              \filer5.arrlhq.org <http://filer5.arrlhq.org>\IT_Share
>>>>              [ 3429.025063] fs/cifs/dfs_cache.c: get_dfs_referral: get
>>>>          an DFS
>>>>              referral for \filer5.arrlhq.org
>>>>          <http://filer5.arrlhq.org>\IT_Share
>>>>              [ 3429.025065] fs/cifs/dfs_cache.c: dfs_cache_noreq_find:
>>>>          path:
>>>>              \filer5.arrlhq.org <http://filer5.arrlhq.org>\IT_Share
>>>>              [ 3429.025071] fs/cifs/fscache.c:
>>>>              cifs_fscache_release_client_cookie:
>>>>              (0x000000006d2b3226/0x0000000090edec3a)
>>>>              [ 3429.025076] fs/cifs/connect.c: CIFS VFS: leaving
>>>>          mount_put_conns
>>>>              (xid = 12) rc = 0
>>>>              [ 3429.025077] CIFS VFS: cifs_mount failed w/return code = -2
>>>>
>>>>          journalctl:
>>>>
>>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: key
>>>>              description:
>>>>              cifs.spnego;0;0;39010000;ver=0x2;host=filer5.arrlhq.org
>>>>          <http://filer5.arrlhq.org>;ip4=10.1.123.38;sec=krb5;uid=0x0;creduid=0x3e8;user=root;pid=0x1690
>>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: ver=2
>>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
>>>>              host=filer5.arrlhq.org <http://filer5.arrlhq.org>
>>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: ip=10.1.123.38
>>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: sec=1
>>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: uid=0
>>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: creduid=1000
>>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: user=root
>>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: pid=5776
>>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
>>>>              get_cachename_from_process_env: pathname=/proc/5776/environ
>>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
>>>>              get_existing_cc: default ccache is
>>>>          KEYRING:persistent:1000:1000
>>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
>>>>              handle_krb5_mech: getting service ticket for
>>>>          filer5.arrlhq.org <http://filer5.arrlhq.org>
>>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
>>>>              cifs_krb5_get_req: unable to get credentials for
>>>>          filer5.arrlhq.org <http://filer5.arrlhq.org>
>>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
>>>>              handle_krb5_mech: failed to obtain service ticket
>>>>          (-1765328370)
>>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: Unable to
>>>>              obtain service ticket
>>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
>>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: Exit status
>>>>              -1765328370
>>>>
>>>>          $ klist
>>>>          Ticket cache: KEYRING:persistent:1000:1000
>>>>          Default principal: mkeane@ARRLHQ.ORG <mailto:mkeane@ARRLHQ.ORG>
>>>>
>>>>          Valid starting       Expires              Service principal
>>>>          07/17/2020 09:43:06  07/17/2020 19:43:06
>>>>          krbtgt/ARRLHQ.ORG@ARRLHQ.ORG <mailto:ARRLHQ.ORG@ARRLHQ.ORG>
>>>>                   renew until 07/24/2020 09:42:57
>>>>
>>>>          Filer5 is a QNAP TS-870U-RP Version 4.3.6.1070 (2019/09/10)
>>>>          NAS device
>>>>          but having this issue with other NAS device on LAN
>>>>
>>>>          --
>>>>          Michael Keane, K1MK
>>>>          IT Manager
>>>>          ARRL, The National Association for Amateur Radio™
>>>>          225 Main Street, Newington, CT 06111-1494 USA
>>>>          Telephone: (860) 594-0285
>>>>          email: mkeane@arrl.org <mailto:mkeane@arrl.org>
>>>>
>>>      --
>>>      Michael Keane, K1MK
>>>      IT Manager
>>>      ARRL, The National Association for Amateur Radio™
>>>      225 Main Street, Newington, CT 06111-1494 USA
>>>      Telephone: (860) 594-0285
>>>      email:mkeane@arrl.org  <mailto:mkeane@arrl.org>
>>>
>> --
>> Michael Keane, K1MK
>> IT Manager
>> ARRL, The National Association for Amateur Radio™
>> 225 Main Street, Newington, CT 06111-1494 USA
>> Telephone: (860) 594-0285
>> email: mkeane@arrl.org
>>
>

-- 
Michael Keane, K1MK
IT Manager
ARRL, The National Association for Amateur Radio™
225 Main Street, Newington, CT 06111-1494 USA
Telephone: (860) 594-0285
email: mkeane@arrl.org


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

* Re: issue -- cifs automounts stopped working
  2020-07-22  3:48           ` Michael Keane, K1MK
@ 2020-07-22  4:03             ` Steve French
  2020-07-31  3:54               ` Xiaoli Feng
  2020-07-22  5:07             ` Isaac Boukris
  1 sibling, 1 reply; 7+ messages in thread
From: Steve French @ 2020-07-22  4:03 UTC (permalink / raw)
  To: Michael Keane, K1MK; +Cc: Shyam Prasad N, CIFS, samba-technical

There are two common Kerberos libraries, MIT and Heimdal (Heimdal is
also packaged as an optional part of Samba as an alternative to MIT
Kerberos) ... would be interesting if there is a way to work around
this by switching to Heimdal krb5 libraries.

Adding samba-technical as some of the developers on samba-technical
know the Kerberos maintainers and may have suggestions on how to track
down this possible regression in MIT kerberos.

On Tue, Jul 21, 2020 at 10:48 PM Michael Keane, K1MK <mkeane@arrl.org> wrote:
>
> Tried setting KRB5_CCNAME to KEYRING:persistent:1000 with no change
> (Also tried KRB5CCNAME  as well, as that's the environment variable
> which seems to work with kinit & klist)
>
> Also tried setting default_ccahe_name in /etc/krb5.conf to a legacy
> value of
>
>      default_ccache_name = /tmp/krb5_%{uid}
>
> in order to force it to use the filesystem rather than the kernel space
> for the credentials cache. And it still fails in the same way. I think
> that tends to makes this more likely a regression in krb5 than the kernel.
>
> I believe that I may have verified this by reverting from
> krb5-*/-/1.18.2-10 to krb5-*-1.17.1-5 which resolves the issue
>
>
>
> On 07/21/2020 3:59 PM, Steve French wrote:
> > Would setting KRB5_CCNAME (as would be expected in the past) for that
> > process fix the issue?
> >
> > On Tue, Jul 21, 2020 at 2:52 PM Michael Keane, K1MK <mkeane@arrl.org> wrote:
> >> KRB5_CCNAME is not set in the environment of the user for whom the
> >> automount is failing.
> >>
> >> In /etc/krb5.conf the default is set to:
> >>
> >>      default_ccache_name = KEYRING:persistent:%{uid}
> >>
> >> The calls to keyctl()  in the strace for cifs.upcall  indicate that it's
> >> successfully locating the user's keyring in the kernel and that it is
> >> able to read key data from that keying
> >>
> >> I haven't gone through and tried unpacking and decoding the contents of
> >> those reads, but the reads aren't failing outright like it couldn't find
> >> the credentials cache or the contents that it's looking for
> >>
> >>
> >> On 07/21/2020 1:36 PM, Steve French wrote:
> >>> That is plausible but I also wonder about other whether other parts of
> >>> krb5 configuration are changed/broken eg KRB5_CCNAME environment variable
> >>>
> >>> See https://web.mit.edu/kerberos/krb5-1.12/doc/basic/ccache_def.html
> >>>
> >>> On Tue, Jul 21, 2020, 12:24 Michael Keane, K1MK <mkeane@arrl.org
> >>> <mailto:mkeane@arrl.org>> wrote:
> >>>
> >>>      Thanks
> >>>
> >>>      In trying to further debug this problem, I've stood up a separate
> >>>      Fedora 31 instance for testing with the result that the same
> >>>      configuration that is failing on Fedora 32 is working under Fedora 31
> >>>
> >>>      Using strace it would appear the deviation occurs at the point of
> >>>      "handle_krb5_mech" where the Fedora 31 instance proceeds though
> >>>      several keyctl() calls to a successful return while the Fedora 32
> >>>      instance goes through a similar sequence of keyctl() calls but
> >>>      rather than finishing up with a final call to keyctl() to
> >>>      instantiate the key it appears that the krb5 library and/or sssd
> >>>      is going through a series of steps to locate the KDC (and failing)
> >>>      even though the KDCs have always been explicitly configured in
> >>>      /etc/krb5.conf
> >>>
> >>>      So the root cause of this issue may not be anything in cifs.upcall
> >>>      but rather something in the sssd or kerberos that got changed as a
> >>>      result of moving from Fedora 31 to Fedora 32
> >>>
> >>>      On 07/18/2020 8:40 PM, Steve French wrote:
> >>>>      Looks like error obtaining the key (either keyutils package not
> >>>>      installed or no Kerberos ticket found).
> >>>>
> >>>>      This page has debug instructions for cifs.upcall. see of that
> >>>>      information is helpful.
> >>>>
> >>>>      http://sprabhu.blogspot.com/2014/12/debugging-calls-to-cifsupcall.html?m=1
> >>>>
> >>>>      Also try kinit as a local user and then mount with cruid mount
> >>>>      option pointing to their uid to see if that helps.
> >>>>
> >>>>      On Fri, Jul 17, 2020, 09:04 Michael Keane, K1MK <mkeane@arrl.org
> >>>>      <mailto:mkeane@arrl.org>> wrote:
> >>>>
> >>>>          CIFS automounts to local NAS devices have stopped working
> >>>>          recently
> >>>>
> >>>>          Fedora 32
> >>>>
> >>>>          kernel 5.7.8-200.fc32.x86_64
> >>>>
> >>>>          mount.cifs version: 6.9
> >>>>
> >>>>          auto.misc: it-share
> >>>>          -fstype=cifs,multiuser,cruid=${UID},rw,vers=default,sec=krb5
> >>>>          ://filer5/IT_Share
> >>>>
> >>>>          dmesg:
> >>>>
> >>>>              [ 3428.883661] fs/cifs/cifsfs.c: Devname:
> >>>>              //filer5.arrlhq.org/IT_Share
> >>>>          <http://filer5.arrlhq.org/IT_Share> flags: 0
> >>>>              [ 3428.883702] fs/cifs/connect.c: Username: root
> >>>>              [ 3428.883706] fs/cifs/connect.c: file mode: 0755 dir
> >>>>          mode: 0755
> >>>>              [ 3428.883709] fs/cifs/connect.c: CIFS VFS: in
> >>>>          mount_get_conns as
> >>>>              Xid: 12 with uid: 0
> >>>>              [ 3428.883710] fs/cifs/connect.c: UNC:
> >>>>          \\filer5.arrlhq.org <http://filer5.arrlhq.org>\IT_Share
> >>>>              [ 3428.883721] fs/cifs/connect.c: Socket created
> >>>>              [ 3428.883723] fs/cifs/connect.c: sndbuf 16384 rcvbuf 131072
> >>>>              rcvtimeo 0x1b58
> >>>>              [ 3428.884126] fs/cifs/fscache.c:
> >>>>          cifs_fscache_get_client_cookie:
> >>>>              (0x000000006d2b3226/0x0000000090edec3a)
> >>>>              [ 3428.884130] fs/cifs/connect.c: CIFS VFS: in
> >>>>          cifs_get_smb_ses as
> >>>>              Xid: 13 with uid: 0
> >>>>              [ 3428.884131] fs/cifs/connect.c: Existing smb sess not found
> >>>>              [ 3428.884135] fs/cifs/smb2pdu.c: Negotiate protocol
> >>>>              [ 3428.884141] fs/cifs/connect.c: Demultiplex PID: 5778
> >>>>              [ 3428.884156] fs/cifs/transport.c: Sending smb: smb_len=252
> >>>>              [ 3429.010818] fs/cifs/connect.c: RFC1002 header 0x11c
> >>>>              [ 3429.010830] fs/cifs/smb2misc.c: SMB2 data length 96
> >>>>          offset 128
> >>>>              [ 3429.010832] fs/cifs/smb2misc.c: SMB2 len 224
> >>>>              [ 3429.010835] fs/cifs/smb2misc.c: length of negcontexts
> >>>>          60 pad 0
> >>>>              [ 3429.010871] fs/cifs/transport.c: cifs_sync_mid_result:
> >>>>          cmd=0
> >>>>              mid=0 state=4
> >>>>              [ 3429.010885] fs/cifs/misc.c: Null buffer passed to
> >>>>              cifs_small_buf_release
> >>>>              [ 3429.010891] fs/cifs/smb2pdu.c: mode 0x1
> >>>>              [ 3429.010893] fs/cifs/smb2pdu.c: negotiated smb3.1.1 dialect
> >>>>              [ 3429.010903] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2
> >>>>          0x348 0xbb92
> >>>>              [ 3429.010907] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2
> >>>>          0x348 0x1bb92
> >>>>              [ 3429.010910] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3
> >>>>          0x6 0x1
> >>>>              [ 3429.010912] fs/cifs/smb2pdu.c: decoding 2 negotiate
> >>>>          contexts
> >>>>              [ 3429.010914] fs/cifs/smb2pdu.c: decode SMB3.11
> >>>>          encryption neg
> >>>>              context of len 4
> >>>>              [ 3429.010916] fs/cifs/smb2pdu.c: SMB311 cipher type:1
> >>>>              [ 3429.010921] fs/cifs/connect.c: Security Mode: 0x1
> >>>>          Capabilities:
> >>>>              0x300046 TimeAdjust: 0
> >>>>              [ 3429.010923] fs/cifs/smb2pdu.c: Session Setup
> >>>>              [ 3429.010926] fs/cifs/smb2pdu.c: sess setup type 5
> >>>>              [ 3429.010949] fs/cifs/cifs_spnego.c: key description =
> >>>>              ver=0x2;host=filer5.arrlhq.org
> >>>>          <http://filer5.arrlhq.org>;ip4=10.1.123.38;sec=krb5;uid=0x0;creduid=0x3e8;user=root;pid=0x1690
> >>>>              [ 3429.025053] CIFS VFS: \\filer5.arrlhq.org
> >>>>          <http://filer5.arrlhq.org> Send error in SessSetup
> >>>>              = -126
> >>>>              [ 3429.025056] fs/cifs/connect.c: CIFS VFS: leaving
> >>>>          cifs_get_smb_ses
> >>>>              (xid = 13) rc = -126
> >>>>              [ 3429.025059] fs/cifs/connect.c: build_unc_path_to_root:
> >>>>              full_path=\\filer5.arrlhq.org
> >>>>          <http://filer5.arrlhq.org>\IT_Share
> >>>>              [ 3429.025059] fs/cifs/connect.c: build_unc_path_to_root:
> >>>>              full_path=\\filer5.arrlhq.org
> >>>>          <http://filer5.arrlhq.org>\IT_Share
> >>>>              [ 3429.025060] fs/cifs/connect.c: build_unc_path_to_root:
> >>>>              full_path=\\filer5.arrlhq.org
> >>>>          <http://filer5.arrlhq.org>\IT_Share
> >>>>              [ 3429.025062] fs/cifs/dfs_cache.c: __dfs_cache_find:
> >>>>          search path:
> >>>>              \filer5.arrlhq.org <http://filer5.arrlhq.org>\IT_Share
> >>>>              [ 3429.025063] fs/cifs/dfs_cache.c: get_dfs_referral: get
> >>>>          an DFS
> >>>>              referral for \filer5.arrlhq.org
> >>>>          <http://filer5.arrlhq.org>\IT_Share
> >>>>              [ 3429.025065] fs/cifs/dfs_cache.c: dfs_cache_noreq_find:
> >>>>          path:
> >>>>              \filer5.arrlhq.org <http://filer5.arrlhq.org>\IT_Share
> >>>>              [ 3429.025071] fs/cifs/fscache.c:
> >>>>              cifs_fscache_release_client_cookie:
> >>>>              (0x000000006d2b3226/0x0000000090edec3a)
> >>>>              [ 3429.025076] fs/cifs/connect.c: CIFS VFS: leaving
> >>>>          mount_put_conns
> >>>>              (xid = 12) rc = 0
> >>>>              [ 3429.025077] CIFS VFS: cifs_mount failed w/return code = -2
> >>>>
> >>>>          journalctl:
> >>>>
> >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: key
> >>>>              description:
> >>>>              cifs.spnego;0;0;39010000;ver=0x2;host=filer5.arrlhq.org
> >>>>          <http://filer5.arrlhq.org>;ip4=10.1.123.38;sec=krb5;uid=0x0;creduid=0x3e8;user=root;pid=0x1690
> >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: ver=2
> >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> >>>>              host=filer5.arrlhq.org <http://filer5.arrlhq.org>
> >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: ip=10.1.123.38
> >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: sec=1
> >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: uid=0
> >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: creduid=1000
> >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: user=root
> >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: pid=5776
> >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> >>>>              get_cachename_from_process_env: pathname=/proc/5776/environ
> >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> >>>>              get_existing_cc: default ccache is
> >>>>          KEYRING:persistent:1000:1000
> >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> >>>>              handle_krb5_mech: getting service ticket for
> >>>>          filer5.arrlhq.org <http://filer5.arrlhq.org>
> >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> >>>>              cifs_krb5_get_req: unable to get credentials for
> >>>>          filer5.arrlhq.org <http://filer5.arrlhq.org>
> >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> >>>>              handle_krb5_mech: failed to obtain service ticket
> >>>>          (-1765328370)
> >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: Unable to
> >>>>              obtain service ticket
> >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: Exit status
> >>>>              -1765328370
> >>>>
> >>>>          $ klist
> >>>>          Ticket cache: KEYRING:persistent:1000:1000
> >>>>          Default principal: mkeane@ARRLHQ.ORG <mailto:mkeane@ARRLHQ.ORG>
> >>>>
> >>>>          Valid starting       Expires              Service principal
> >>>>          07/17/2020 09:43:06  07/17/2020 19:43:06
> >>>>          krbtgt/ARRLHQ.ORG@ARRLHQ.ORG <mailto:ARRLHQ.ORG@ARRLHQ.ORG>
> >>>>                   renew until 07/24/2020 09:42:57
> >>>>
> >>>>          Filer5 is a QNAP TS-870U-RP Version 4.3.6.1070 (2019/09/10)
> >>>>          NAS device
> >>>>          but having this issue with other NAS device on LAN
> >>>>
> >>>>          --
> >>>>          Michael Keane, K1MK
> >>>>          IT Manager
> >>>>          ARRL, The National Association for Amateur Radio™
> >>>>          225 Main Street, Newington, CT 06111-1494 USA
> >>>>          Telephone: (860) 594-0285
> >>>>          email: mkeane@arrl.org <mailto:mkeane@arrl.org>
> >>>>
> >>>      --
> >>>      Michael Keane, K1MK
> >>>      IT Manager
> >>>      ARRL, The National Association for Amateur Radio™
> >>>      225 Main Street, Newington, CT 06111-1494 USA
> >>>      Telephone: (860) 594-0285
> >>>      email:mkeane@arrl.org  <mailto:mkeane@arrl.org>
> >>>
> >> --
> >> Michael Keane, K1MK
> >> IT Manager
> >> ARRL, The National Association for Amateur Radio™
> >> 225 Main Street, Newington, CT 06111-1494 USA
> >> Telephone: (860) 594-0285
> >> email: mkeane@arrl.org
> >>
> >
>
> --
> Michael Keane, K1MK
> IT Manager
> ARRL, The National Association for Amateur Radio™
> 225 Main Street, Newington, CT 06111-1494 USA
> Telephone: (860) 594-0285
> email: mkeane@arrl.org
>


-- 
Thanks,

Steve

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

* Re: issue -- cifs automounts stopped working
  2020-07-22  3:48           ` Michael Keane, K1MK
  2020-07-22  4:03             ` Steve French
@ 2020-07-22  5:07             ` Isaac Boukris
  1 sibling, 0 replies; 7+ messages in thread
From: Isaac Boukris @ 2020-07-22  5:07 UTC (permalink / raw)
  To: Michael Keane, K1MK
  Cc: Steve French, Shyam Prasad N, CIFS,
	Upstream Samba Technical Mailing list

On Wed, Jul 22, 2020 at 5:48 AM Michael Keane, K1MK <mkeane@arrl.org> wrote:
>
> Tried setting KRB5_CCNAME to KEYRING:persistent:1000 with no change
> (Also tried KRB5CCNAME  as well, as that's the environment variable

Indeed KRB5CCNAME is the right variable name, you can also run the
upcall with KRB5_TRACE=/logfile to get more insights what the krb5
libs are doing.

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

* Re: issue -- cifs automounts stopped working
  2020-07-22  4:03             ` Steve French
@ 2020-07-31  3:54               ` Xiaoli Feng
  0 siblings, 0 replies; 7+ messages in thread
From: Xiaoli Feng @ 2020-07-31  3:54 UTC (permalink / raw)
  To: Michael Keane, K1MK; +Cc: Shyam Prasad N, CIFS, samba-technical, Steve French

Hello,

I'm not sure if your problem is like this. But I know there is
a bug for selinux. It will prevent to mount cifs with krb5 when 
krb5 upgrade from 1.17 to 1.18 in RHEL8. Disabled selinux or 
executing "setsebool samba_export_all_rw=1" will fix this issue. 
  https://bugzilla.redhat.com/show_bug.cgi?id=1847221

Thanks.

----- Original Message -----
> From: "Steve French via samba-technical" <samba-technical@lists.samba.org>
> To: "Michael Keane, K1MK" <mkeane@arrl.org>
> Cc: "Shyam Prasad N" <nspmangalore@gmail.com>, "CIFS" <linux-cifs@vger.kernel.org>, "samba-technical"
> <samba-technical@lists.samba.org>
> Sent: Wednesday, July 22, 2020 12:03:10 PM
> Subject: Re: issue -- cifs automounts stopped working
> 
> There are two common Kerberos libraries, MIT and Heimdal (Heimdal is
> also packaged as an optional part of Samba as an alternative to MIT
> Kerberos) ... would be interesting if there is a way to work around
> this by switching to Heimdal krb5 libraries.
> 
> Adding samba-technical as some of the developers on samba-technical
> know the Kerberos maintainers and may have suggestions on how to track
> down this possible regression in MIT kerberos.
> 
> On Tue, Jul 21, 2020 at 10:48 PM Michael Keane, K1MK <mkeane@arrl.org> wrote:
> >
> > Tried setting KRB5_CCNAME to KEYRING:persistent:1000 with no change
> > (Also tried KRB5CCNAME  as well, as that's the environment variable
> > which seems to work with kinit & klist)
> >
> > Also tried setting default_ccahe_name in /etc/krb5.conf to a legacy
> > value of
> >
> >      default_ccache_name = /tmp/krb5_%{uid}
> >
> > in order to force it to use the filesystem rather than the kernel space
> > for the credentials cache. And it still fails in the same way. I think
> > that tends to makes this more likely a regression in krb5 than the kernel.
> >
> > I believe that I may have verified this by reverting from
> > krb5-*/-/1.18.2-10 to krb5-*-1.17.1-5 which resolves the issue
> >
> >
> >
> > On 07/21/2020 3:59 PM, Steve French wrote:
> > > Would setting KRB5_CCNAME (as would be expected in the past) for that
> > > process fix the issue?
> > >
> > > On Tue, Jul 21, 2020 at 2:52 PM Michael Keane, K1MK <mkeane@arrl.org>
> > > wrote:
> > >> KRB5_CCNAME is not set in the environment of the user for whom the
> > >> automount is failing.
> > >>
> > >> In /etc/krb5.conf the default is set to:
> > >>
> > >>      default_ccache_name = KEYRING:persistent:%{uid}
> > >>
> > >> The calls to keyctl()  in the strace for cifs.upcall  indicate that it's
> > >> successfully locating the user's keyring in the kernel and that it is
> > >> able to read key data from that keying
> > >>
> > >> I haven't gone through and tried unpacking and decoding the contents of
> > >> those reads, but the reads aren't failing outright like it couldn't find
> > >> the credentials cache or the contents that it's looking for
> > >>
> > >>
> > >> On 07/21/2020 1:36 PM, Steve French wrote:
> > >>> That is plausible but I also wonder about other whether other parts of
> > >>> krb5 configuration are changed/broken eg KRB5_CCNAME environment
> > >>> variable
> > >>>
> > >>> See https://web.mit.edu/kerberos/krb5-1.12/doc/basic/ccache_def.html
> > >>>
> > >>> On Tue, Jul 21, 2020, 12:24 Michael Keane, K1MK <mkeane@arrl.org
> > >>> <mailto:mkeane@arrl.org>> wrote:
> > >>>
> > >>>      Thanks
> > >>>
> > >>>      In trying to further debug this problem, I've stood up a separate
> > >>>      Fedora 31 instance for testing with the result that the same
> > >>>      configuration that is failing on Fedora 32 is working under Fedora
> > >>>      31
> > >>>
> > >>>      Using strace it would appear the deviation occurs at the point of
> > >>>      "handle_krb5_mech" where the Fedora 31 instance proceeds though
> > >>>      several keyctl() calls to a successful return while the Fedora 32
> > >>>      instance goes through a similar sequence of keyctl() calls but
> > >>>      rather than finishing up with a final call to keyctl() to
> > >>>      instantiate the key it appears that the krb5 library and/or sssd
> > >>>      is going through a series of steps to locate the KDC (and failing)
> > >>>      even though the KDCs have always been explicitly configured in
> > >>>      /etc/krb5.conf
> > >>>
> > >>>      So the root cause of this issue may not be anything in cifs.upcall
> > >>>      but rather something in the sssd or kerberos that got changed as a
> > >>>      result of moving from Fedora 31 to Fedora 32
> > >>>
> > >>>      On 07/18/2020 8:40 PM, Steve French wrote:
> > >>>>      Looks like error obtaining the key (either keyutils package not
> > >>>>      installed or no Kerberos ticket found).
> > >>>>
> > >>>>      This page has debug instructions for cifs.upcall. see of that
> > >>>>      information is helpful.
> > >>>>
> > >>>>      http://sprabhu.blogspot.com/2014/12/debugging-calls-to-cifsupcall.html?m=1
> > >>>>
> > >>>>      Also try kinit as a local user and then mount with cruid mount
> > >>>>      option pointing to their uid to see if that helps.
> > >>>>
> > >>>>      On Fri, Jul 17, 2020, 09:04 Michael Keane, K1MK <mkeane@arrl.org
> > >>>>      <mailto:mkeane@arrl.org>> wrote:
> > >>>>
> > >>>>          CIFS automounts to local NAS devices have stopped working
> > >>>>          recently
> > >>>>
> > >>>>          Fedora 32
> > >>>>
> > >>>>          kernel 5.7.8-200.fc32.x86_64
> > >>>>
> > >>>>          mount.cifs version: 6.9
> > >>>>
> > >>>>          auto.misc: it-share
> > >>>>          -fstype=cifs,multiuser,cruid=${UID},rw,vers=default,sec=krb5
> > >>>>          ://filer5/IT_Share
> > >>>>
> > >>>>          dmesg:
> > >>>>
> > >>>>              [ 3428.883661] fs/cifs/cifsfs.c: Devname:
> > >>>>              //filer5.arrlhq.org/IT_Share
> > >>>>          <http://filer5.arrlhq.org/IT_Share> flags: 0
> > >>>>              [ 3428.883702] fs/cifs/connect.c: Username: root
> > >>>>              [ 3428.883706] fs/cifs/connect.c: file mode: 0755 dir
> > >>>>          mode: 0755
> > >>>>              [ 3428.883709] fs/cifs/connect.c: CIFS VFS: in
> > >>>>          mount_get_conns as
> > >>>>              Xid: 12 with uid: 0
> > >>>>              [ 3428.883710] fs/cifs/connect.c: UNC:
> > >>>>          \\filer5.arrlhq.org <http://filer5.arrlhq.org>\IT_Share
> > >>>>              [ 3428.883721] fs/cifs/connect.c: Socket created
> > >>>>              [ 3428.883723] fs/cifs/connect.c: sndbuf 16384 rcvbuf
> > >>>>              131072
> > >>>>              rcvtimeo 0x1b58
> > >>>>              [ 3428.884126] fs/cifs/fscache.c:
> > >>>>          cifs_fscache_get_client_cookie:
> > >>>>              (0x000000006d2b3226/0x0000000090edec3a)
> > >>>>              [ 3428.884130] fs/cifs/connect.c: CIFS VFS: in
> > >>>>          cifs_get_smb_ses as
> > >>>>              Xid: 13 with uid: 0
> > >>>>              [ 3428.884131] fs/cifs/connect.c: Existing smb sess not
> > >>>>              found
> > >>>>              [ 3428.884135] fs/cifs/smb2pdu.c: Negotiate protocol
> > >>>>              [ 3428.884141] fs/cifs/connect.c: Demultiplex PID: 5778
> > >>>>              [ 3428.884156] fs/cifs/transport.c: Sending smb:
> > >>>>              smb_len=252
> > >>>>              [ 3429.010818] fs/cifs/connect.c: RFC1002 header 0x11c
> > >>>>              [ 3429.010830] fs/cifs/smb2misc.c: SMB2 data length 96
> > >>>>          offset 128
> > >>>>              [ 3429.010832] fs/cifs/smb2misc.c: SMB2 len 224
> > >>>>              [ 3429.010835] fs/cifs/smb2misc.c: length of negcontexts
> > >>>>          60 pad 0
> > >>>>              [ 3429.010871] fs/cifs/transport.c: cifs_sync_mid_result:
> > >>>>          cmd=0
> > >>>>              mid=0 state=4
> > >>>>              [ 3429.010885] fs/cifs/misc.c: Null buffer passed to
> > >>>>              cifs_small_buf_release
> > >>>>              [ 3429.010891] fs/cifs/smb2pdu.c: mode 0x1
> > >>>>              [ 3429.010893] fs/cifs/smb2pdu.c: negotiated smb3.1.1
> > >>>>              dialect
> > >>>>              [ 3429.010903] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2
> > >>>>          0x348 0xbb92
> > >>>>              [ 3429.010907] fs/cifs/asn1.c: OID len = 7 oid = 0x1 0x2
> > >>>>          0x348 0x1bb92
> > >>>>              [ 3429.010910] fs/cifs/asn1.c: OID len = 10 oid = 0x1 0x3
> > >>>>          0x6 0x1
> > >>>>              [ 3429.010912] fs/cifs/smb2pdu.c: decoding 2 negotiate
> > >>>>          contexts
> > >>>>              [ 3429.010914] fs/cifs/smb2pdu.c: decode SMB3.11
> > >>>>          encryption neg
> > >>>>              context of len 4
> > >>>>              [ 3429.010916] fs/cifs/smb2pdu.c: SMB311 cipher type:1
> > >>>>              [ 3429.010921] fs/cifs/connect.c: Security Mode: 0x1
> > >>>>          Capabilities:
> > >>>>              0x300046 TimeAdjust: 0
> > >>>>              [ 3429.010923] fs/cifs/smb2pdu.c: Session Setup
> > >>>>              [ 3429.010926] fs/cifs/smb2pdu.c: sess setup type 5
> > >>>>              [ 3429.010949] fs/cifs/cifs_spnego.c: key description =
> > >>>>              ver=0x2;host=filer5.arrlhq.org
> > >>>>          <http://filer5.arrlhq.org>;ip4=10.1.123.38;sec=krb5;uid=0x0;creduid=0x3e8;user=root;pid=0x1690
> > >>>>              [ 3429.025053] CIFS VFS: \\filer5.arrlhq.org
> > >>>>          <http://filer5.arrlhq.org> Send error in SessSetup
> > >>>>              = -126
> > >>>>              [ 3429.025056] fs/cifs/connect.c: CIFS VFS: leaving
> > >>>>          cifs_get_smb_ses
> > >>>>              (xid = 13) rc = -126
> > >>>>              [ 3429.025059] fs/cifs/connect.c: build_unc_path_to_root:
> > >>>>              full_path=\\filer5.arrlhq.org
> > >>>>          <http://filer5.arrlhq.org>\IT_Share
> > >>>>              [ 3429.025059] fs/cifs/connect.c: build_unc_path_to_root:
> > >>>>              full_path=\\filer5.arrlhq.org
> > >>>>          <http://filer5.arrlhq.org>\IT_Share
> > >>>>              [ 3429.025060] fs/cifs/connect.c: build_unc_path_to_root:
> > >>>>              full_path=\\filer5.arrlhq.org
> > >>>>          <http://filer5.arrlhq.org>\IT_Share
> > >>>>              [ 3429.025062] fs/cifs/dfs_cache.c: __dfs_cache_find:
> > >>>>          search path:
> > >>>>              \filer5.arrlhq.org <http://filer5.arrlhq.org>\IT_Share
> > >>>>              [ 3429.025063] fs/cifs/dfs_cache.c: get_dfs_referral: get
> > >>>>          an DFS
> > >>>>              referral for \filer5.arrlhq.org
> > >>>>          <http://filer5.arrlhq.org>\IT_Share
> > >>>>              [ 3429.025065] fs/cifs/dfs_cache.c: dfs_cache_noreq_find:
> > >>>>          path:
> > >>>>              \filer5.arrlhq.org <http://filer5.arrlhq.org>\IT_Share
> > >>>>              [ 3429.025071] fs/cifs/fscache.c:
> > >>>>              cifs_fscache_release_client_cookie:
> > >>>>              (0x000000006d2b3226/0x0000000090edec3a)
> > >>>>              [ 3429.025076] fs/cifs/connect.c: CIFS VFS: leaving
> > >>>>          mount_put_conns
> > >>>>              (xid = 12) rc = 0
> > >>>>              [ 3429.025077] CIFS VFS: cifs_mount failed w/return code
> > >>>>              = -2
> > >>>>
> > >>>>          journalctl:
> > >>>>
> > >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> > >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: key
> > >>>>              description:
> > >>>>              cifs.spnego;0;0;39010000;ver=0x2;host=filer5.arrlhq.org
> > >>>>          <http://filer5.arrlhq.org>;ip4=10.1.123.38;sec=krb5;uid=0x0;creduid=0x3e8;user=root;pid=0x1690
> > >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> > >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: ver=2
> > >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> > >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> > >>>>              host=filer5.arrlhq.org <http://filer5.arrlhq.org>
> > >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> > >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: ip=10.1.123.38
> > >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> > >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: sec=1
> > >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> > >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: uid=0
> > >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> > >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: creduid=1000
> > >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> > >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: user=root
> > >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> > >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: pid=5776
> > >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> > >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> > >>>>              get_cachename_from_process_env:
> > >>>>              pathname=/proc/5776/environ
> > >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> > >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> > >>>>              get_existing_cc: default ccache is
> > >>>>          KEYRING:persistent:1000:1000
> > >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> > >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> > >>>>              handle_krb5_mech: getting service ticket for
> > >>>>          filer5.arrlhq.org <http://filer5.arrlhq.org>
> > >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> > >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> > >>>>              cifs_krb5_get_req: unable to get credentials for
> > >>>>          filer5.arrlhq.org <http://filer5.arrlhq.org>
> > >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> > >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]:
> > >>>>              handle_krb5_mech: failed to obtain service ticket
> > >>>>          (-1765328370)
> > >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> > >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: Unable to
> > >>>>              obtain service ticket
> > >>>>              Jul 17 09:43:13 mkZ230.ARRLHQ.ORG
> > >>>>          <http://mkZ230.ARRLHQ.ORG> cifs.upcall[5779]: Exit status
> > >>>>              -1765328370
> > >>>>
> > >>>>          $ klist
> > >>>>          Ticket cache: KEYRING:persistent:1000:1000
> > >>>>          Default principal: mkeane@ARRLHQ.ORG
> > >>>>          <mailto:mkeane@ARRLHQ.ORG>
> > >>>>
> > >>>>          Valid starting       Expires              Service principal
> > >>>>          07/17/2020 09:43:06  07/17/2020 19:43:06
> > >>>>          krbtgt/ARRLHQ.ORG@ARRLHQ.ORG <mailto:ARRLHQ.ORG@ARRLHQ.ORG>
> > >>>>                   renew until 07/24/2020 09:42:57
> > >>>>
> > >>>>          Filer5 is a QNAP TS-870U-RP Version 4.3.6.1070 (2019/09/10)
> > >>>>          NAS device
> > >>>>          but having this issue with other NAS device on LAN
> > >>>>
> > >>>>          --
> > >>>>          Michael Keane, K1MK
> > >>>>          IT Manager
> > >>>>          ARRL, The National Association for Amateur Radio™
> > >>>>          225 Main Street, Newington, CT 06111-1494 USA
> > >>>>          Telephone: (860) 594-0285
> > >>>>          email: mkeane@arrl.org <mailto:mkeane@arrl.org>
> > >>>>
> > >>>      --
> > >>>      Michael Keane, K1MK
> > >>>      IT Manager
> > >>>      ARRL, The National Association for Amateur Radio™
> > >>>      225 Main Street, Newington, CT 06111-1494 USA
> > >>>      Telephone: (860) 594-0285
> > >>>      email:mkeane@arrl.org  <mailto:mkeane@arrl.org>
> > >>>
> > >> --
> > >> Michael Keane, K1MK
> > >> IT Manager
> > >> ARRL, The National Association for Amateur Radio™
> > >> 225 Main Street, Newington, CT 06111-1494 USA
> > >> Telephone: (860) 594-0285
> > >> email: mkeane@arrl.org
> > >>
> > >
> >
> > --
> > Michael Keane, K1MK
> > IT Manager
> > ARRL, The National Association for Amateur Radio™
> > 225 Main Street, Newington, CT 06111-1494 USA
> > Telephone: (860) 594-0285
> > email: mkeane@arrl.org
> >
> 
> 
> --
> Thanks,
> 
> Steve
> 
> 


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

end of thread, other threads:[~2020-07-31  3:55 UTC | newest]

Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2020-07-17 14:04 issue -- cifs automounts stopped working Michael Keane, K1MK
     [not found] ` <CAH2r5msj3KMMonyhjDeyAweHEBezOHFkJwCUXpJ4Gv59Q=S9bQ@mail.gmail.com>
     [not found]   ` <752d5d05-7b91-b119-b5a6-7fcdeb1f0ced@arrl.org>
     [not found]     ` <CAH2r5muNtwm3V-0GpaRBXmrptGDO9w1vDSWN9Wrf_eebuevg6A@mail.gmail.com>
2020-07-21 19:52       ` Michael Keane, K1MK
2020-07-21 19:59         ` Steve French
2020-07-22  3:48           ` Michael Keane, K1MK
2020-07-22  4:03             ` Steve French
2020-07-31  3:54               ` Xiaoli Feng
2020-07-22  5:07             ` Isaac Boukris

This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.