I want to mount a samba share with autofs.
srv.xxxxxxx.net is the samba server (proxmox container, Debian 10)
ldap2.xxxxxxx.net is the openldap (proxmox container, Debian 10)
gui.xxxxxxx.net is the client (proxmox vm, Ubuntu 18.04)
Samba runs in standalone mode (no active directory)
The share is /srv/test
ls -l /srv/
drwxrwxrwx 2 test05 Domain Users 4096 Feb 8 11:41 test
The autofs configuration is saved in openldap
dn: cn=test,ou=auto.mnt,ou=automount,ou=services,dc=lan,dc=xxxxxxx,dc=net
cn: test
objectClass: automount
objectClass: top
description: /srv/test on Samba
automountInformation: -fstype=cifs,multiuser,user=${USER},cruid=test05,sec=krb5 ://srv.xxxxxxx.net/test
/etc/autofs_ldap_auth.conf
<?xml version="1.0" ?>
<autofs_ldap_sasl_conf
usetls="no"
tlsrequired="no"
authrequired="yes"
authtype="GSSAPI"
clientprinc="host/gui.xxxxxxx.net"
/>
When the service autofs is started the mountpoints are created
ls -lisa /mnt
insgesamt 4
22776 0 drwxr-xr-x 4 root root 0 mars 2 15:25 .
2 4 drwxr-xr-x 25 root root 4096 mars 2 10:02 ..
22778 0 dr-xr-xr-x 2 root root 0 mars 2 15:25 exchange
22777 0 dr-xr-xr-x 2 root root 0 mars 2 15:25 test <---- created by autofs
But when the user tries to cd into the test directory he gets an error
test05@gui:/mnt$ cd test
bash: cd: test: File or directory not found (translated from german)
In the automount log I found this message
cifs.upcall: get_tgt_time: unable to get principal
I think that this is my problem but I don't know how to fix it.
When I compare my log with others I found with google then I see a difference in the ccache type.
In my log
cifs.upcall: get_cachename_from_process_env: pathname=/proc/2239/environ
cifs.upcall: get_cachename_from_process_env: cachename = MEMORY:_autofstkt
cifs.upcall: get_existing_cc: default ccache is MEMORY:_autofstkt
In all other logs I found something like
cifs.upcall: get_cachename_from_process_env: pathname=/proc/1234/environ
cifs.upcall: get_existing_cc: default ccache is FILE:/tmp/krb5cc_12345678
Is this an error in my configuration?
NSS and kerberos authentication seems to work:
klist
Ticket cache: FILE:/tmp/krb5cc_10105_YxoDWF
Default principal: test05@XXXXXXX.NET
id test05
uid=10105(test05) gid=512(Domain Admins) Gruppen=512(Domain Admins)
ldapwhoami
SASL/GSSAPI authentication started
SASL username: test05@XXXXXXX.NET
SASL SSF: 56
SASL data security layer installed.
dn:uid=test05,ou=users,dc=lan,dc=xxxxxxx,dc=net
automount log
Mar 2 16:01:28 gui automount[808]: handle_packet: type = 3
Mar 2 16:01:28 gui automount[808]: handle_packet_missing_indirect: token 9, name test, request pid 1753
Mar 2 16:01:28 gui automount[808]: attempting to mount entry /mnt/test
Mar 2 16:01:28 gui automount[808]: parse_mount: parse(sun): expanded entry: -fstype=cifs,multiuser,user=test05,cruid=test05,sec=krb5 ://srv.xxxxxxx.net/test
Mar 2 16:01:28 gui automount[808]: parse_mount: parse(sun): gathered options: fstype=cifs,multiuser,user=test05,cruid=test05,sec=krb5
Mar 2 16:01:28 gui automount[808]: parse_mount: parse(sun): dequote("://srv.xxxxxxx.net/test") -> ://srv.xxxxxxx.net/test
Mar 2 16:01:28 gui automount[808]: parse_mount: parse(sun): core of entry: options=fstype=cifs,multiuser,user=test05,cruid=test05,sec=krb5, loc=://srv.xxxxxxx.net/test
Mar 2 16:01:28 gui automount[808]: sun_mount: parse(sun): mounting root /mnt, mountpoint test, what //srv.xxxxxxx.net/test, fstype cifs, options multiuser,user=test05,cruid=test05,sec=krb5
Mar 2 16:01:28 gui automount[808]: do_mount: //srv.xxxxxxx.net/test /mnt/test type cifs options multiuser,user=test05,cruid=test05,sec=krb5 using module generic
Mar 2 16:01:28 gui automount[808]: mount_mount: mount(generic): calling mkdir_path /mnt/test
Mar 2 16:01:28 gui automount[808]: mount_mount: mount(generic): calling mount -t cifs -o multiuser,user=test05,cruid=test05,sec=krb5 //srv.xxxxxxx.net/test /mnt/test
Mar 2 16:01:28 gui kernel: [ 2177.233113] CIFS: Attempting to mount //srv.xxxxxxx.net/test
Mar 2 16:01:28 gui kernel: [ 2177.233133] No dialect specified on mount. Default has changed to a more secure dialect, SMB2.1 or later (e.g. SMB3), from CIFS (SMB1). To use the less secure SMB1 dialect to access old servers which do not support SMB3 (or SMB2.1) specify vers=1.0 on mount.
Mar 2 16:01:28 gui cifs.upcall: key description: cifs.spnego;0;0;39010000;ver=0x2;host=srv.xxxxxxx.net;ip4=192.168.1.121;sec=krb5;uid=0x0;creduid=0x2779;user=test05;pid=0x8bf
Mar 2 16:01:28 gui cifs.upcall: ver=2
Mar 2 16:01:28 gui cifs.upcall: host=srv.xxxxxxx.net
Mar 2 16:01:28 gui cifs.upcall: ip=192.168.1.121
Mar 2 16:01:28 gui cifs.upcall: sec=1
Mar 2 16:01:28 gui cifs.upcall: uid=0
Mar 2 16:01:28 gui cifs.upcall: creduid=10105
Mar 2 16:01:28 gui cifs.upcall: user=test05
Mar 2 16:01:28 gui cifs.upcall: pid=2239
Mar 2 16:01:28 gui cifs.upcall: get_cachename_from_process_env: pathname=/proc/2239/environ
Mar 2 16:01:28 gui cifs.upcall: get_cachename_from_process_env: cachename = MEMORY:_autofstkt
Mar 2 16:01:28 gui cifs.upcall: get_existing_cc: default ccache is MEMORY:_autofstkt
Mar 2 16:01:28 gui kernel: [ 2177.243918] CIFS VFS: Send error in SessSetup = -126
Mar 2 16:01:28 gui kernel: [ 2177.243931] CIFS VFS: cifs_mount failed w/return code = -2
Mar 2 16:01:28 gui cifs.upcall: get_tgt_time: unable to get principal
Mar 2 16:01:28 gui cifs.upcall: krb5_get_init_creds_keytab: -1765328174
Mar 2 16:01:28 gui cifs.upcall: Exit status 1
Mar 2 16:01:28 gui automount[808]: >> mount error(2): No such file or directory
Mar 2 16:01:28 gui automount[808]: >> Refer to the mount.cifs(8) manual page (e.g. man mount.cifs)
Mar 2 16:01:28 gui automount[808]: mount(generic): failed to mount //srv.xxxxxxx.net/test (type cifs) on /mnt/test
Mar 2 16:01:28 gui automount[808]: dev_ioctl_send_fail: token = 9
Mar 2 16:01:28 gui automount[808]: failed to mount /mnt/test
Mar 2 16:01:28 gui automount[808]: handle_packet: type = 3
Mar 2 16:01:28 gui automount[808]: handle_packet_missing_indirect: token 10, name test, request pid 1753
Mar 2 16:01:28 gui automount[808]: dev_ioctl_send_fail: token = 10
sssd log
==> /var/log/sssd/sssd_nss.log <==
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [accept_fd_handler] (0x0400): Client connected!
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [sss_cmd_get_version] (0x0200): Received client version [1].
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [sss_cmd_get_version] (0x0200): Offered version [1].
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [nss_getby_id] (0x0400): Input ID: 10105
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_send] (0x0400): CR #257: New request 'User by ID'
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #257: Performing a multi-domain search
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #257: Search will check the cache and check the data provider
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #257: Using domain [xxxxxxx.net]
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_search_send] (0x0400): CR #257: Looking up UID:10105@xxxxxxx.net
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #257: Checking negative cache for [UID:10105@xxxxxxx.net]
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #257: [UID:10105@xxxxxxx.net] is not present in negative cache
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #257: Looking up [UID:10105@xxxxxxx.net] in cache
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_search_send] (0x0400): CR #257: Returning [UID:10105@xxxxxxx.net] from cache
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_search_ncache_filter] (0x0400): CR #257: Filtering out results by negative cache
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_create_and_add_result] (0x0400): CR #257: Found 1 entries in domain xxxxxxx.net
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_done] (0x0400): CR #257: Finished: Success
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [nss_getby_id] (0x0400): Input ID: 512
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_send] (0x0400): CR #258: New request 'Group by ID'
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_select_domains] (0x0400): CR #258: Performing a multi-domain search
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_search_domains] (0x0400): CR #258: Search will check the cache and check the data provider
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_set_domain] (0x0400): CR #258: Using domain [xxxxxxx.net]
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_search_send] (0x0400): CR #258: Looking up GID:512@xxxxxxx.net
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #258: Checking negative cache for [GID:512@xxxxxxx.net]
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_search_ncache] (0x0400): CR #258: [GID:512@xxxxxxx.net] is not present in negative cache
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_search_cache] (0x0400): CR #258: Looking up [GID:512@xxxxxxx.net] in cache
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [sysdb_get_user_members_recursively] (0x0400): No such entry
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_search_send] (0x0400): CR #258: Object found, but needs to be refreshed.
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_search_dp] (0x0400): CR #258: Performing midpoint cache update of [GID:512@xxxxxxx.net]
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [sss_dp_issue_request] (0x0400): Issuing request for [0x558d3052be70:2:512@xxxxxxx.net]
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [sss_dp_get_account_msg] (0x0400): Creating request for [xxxxxxx.net][0x2][BE_REQ_GROUP][idnumber=512:-]
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [sss_dp_internal_get_send] (0x0400): Entering request [0x558d3052be70:2:512@xxxxxxx.net]
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_search_ncache_filter] (0x0400): CR #258: Filtering out results by negative cache
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_create_and_add_result] (0x0400): CR #258: Found 1 entries in domain xxxxxxx.net
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [cache_req_done] (0x0400): CR #258: Finished: Success
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [nss_protocol_fill_members] (0x0400): Group [Domain Admins] member [root@xxxxxxx.net] filtered out! (negative cache)
==> /var/log/sssd/sssd_xxxxxxx.net.log <==
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [dp_get_account_info_handler] (0x0200): Got request for [0x2][BE_REQ_GROUP][idnumber=512]
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [dp_attach_req] (0x0400): DP Request [Account #34]: New request. Flags [0x0001].
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [dp_attach_req] (0x0400): Number of active DP request: 1
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [sdap_get_groups_next_base] (0x0400): Searching for groups with base [dc=lan,dc=xxxxxxx,dc=net]
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with [(&(gidNumber=512)(objectClass=posixGroup)(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][dc=lan,dc=xxxxxxx,dc=net].
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no errmsg set
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [sdap_get_groups_process] (0x0400): Search for groups, returned 1 results.
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [sysdb_search_by_name] (0x0400): No such entry
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [sdap_process_missing_member_2307] (0x0400): Adding a ghost entry
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [sdap_get_primary_name] (0x0400): Processing object Domain Admins
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [sdap_save_group] (0x0400): Processing group Domain Admins@xxxxxxx.net
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [sdap_process_ghost_members] (0x0400): Group has 1 members
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [sdap_save_group] (0x0400): Storing info for group Domain Admins@xxxxxxx.net
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [dp_req_done] (0x0400): DP Request [Account #34]: Request handler finished [0]: Erfolg
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [_dp_req_recv] (0x0400): DP Request [Account #34]: Receiving request data.
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [dp_req_reply_list_success] (0x0400): DP Request [Account #34]: Finished. Success.
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [dp_table_value_destructor] (0x0400): Removing [0:1:0x0001:2::xxxxxxx.net:idnumber=512] from reply table
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [dp_req_destructor] (0x0400): DP Request [Account #34]: Request removed.
(Mon Mar 2 16:01:28 2020) [sssd[be[xxxxxxx.net]]] [dp_req_destructor] (0x0400): Number of active DP request: 0
==> /var/log/sssd/sssd_nss.log <==
(Mon Mar 2 16:01:28 2020) [sssd[nss]] [sss_dp_req_destructor] (0x0400): Deleting request: [0x558d3052be70:2:512@xxxxxxx.net]
ldap log
Mar 2 15:01:28 ldap2 slapd[359]: conn=1234 op=9 SRCH base="dc=lan,dc=xxxxxxx,dc=net" scope=2 deref=0 filter="(&(gidNumber=512)(objectClass=posixGroup)(cn=*)(&(gidNumber=*)(!(gidNumber=0))))"
Mar 2 15:01:28 ldap2 slapd[359]: conn=1234 op=9 SRCH attr=objectClass cn userPassword gidNumber memberuid modifyTimestamp modifyTimestamp
Mar 2 15:01:28 ldap2 slapd[359]: conn=1234 op=9 SEARCH RESULT tag=101 err=0 nentries=1 text=
Mar 2 15:01:28 ldap2 slapd[359]: conn=1237 fd=25 ACCEPT from IP=192.168.1.130:48108 (IP=0.0.0.0:389)
Mar 2 15:01:28 ldap2 slapd[359]: conn=1237 op=0 BIND dn="" method=163
Mar 2 15:01:28 ldap2 slapd[359]: conn=1237 op=0 RESULT tag=97 err=14 text=SASL(0): successful result:
Mar 2 15:01:28 ldap2 slapd[359]: conn=1237 op=1 BIND dn="" method=163
Mar 2 15:01:28 ldap2 slapd[359]: conn=1237 op=1 RESULT tag=97 err=14 text=SASL(0): successful result:
Mar 2 15:01:28 ldap2 slapd[359]: conn=1237 op=2 BIND dn="" method=163
Mar 2 15:01:28 ldap2 slapd[359]: conn=1237 op=2 BIND authcid="host/gui.xxxxxxx.net@XXXXXXX.NET" authzid="host/gui.xxxxxxx.net@XXXXXXX.NET"
Mar 2 15:01:28 ldap2 slapd[359]: conn=1237 op=2 BIND dn="cn=gui,ou=hosts,ou=sssd,ou=services,dc=lan,dc=xxxxxxx,dc=net" mech=GSSAPI sasl_ssf=0 ssf=0
Mar 2 15:01:28 ldap2 slapd[359]: conn=1237 op=2 RESULT tag=97 err=0 text=
Mar 2 15:01:28 ldap2 slapd[359]: conn=1237 op=3 SRCH base="ou=auto.mnt,ou=automount,ou=services,dc=lan,dc=xxxxxxx,dc=net" scope=2 deref=0 filter="(&(objectClass=automount)(|(cn=test)(cn=/)(cn=\2A)))"
Mar 2 15:01:28 ldap2 slapd[359]: conn=1237 op=3 SRCH attr=cn automountInformation
Mar 2 15:01:28 ldap2 slapd[359]: conn=1237 op=3 SEARCH RESULT tag=101 err=0 nentries=1 text=
Mar 2 15:01:28 ldap2 slapd[359]: conn=1237 op=4 UNBIND
Mar 2 15:01:28 ldap2 slapd[359]: conn=1237 fd=25 closed
Mar 2 15:01:28 ldap2 slapd[359]: conn=1141 op=640 SRCH base="cn=XXXXXXX.NET,cn=krb5,ou=services,dc=lan,dc=xxxxxxx,dc=net" scope=2 deref=0 filter="(&(|(objectClass=krbPrincipalAux)(objectClass=krbPrincipal))(krbPrincipalName=test05@XXXXXXX.NET))"
Mar 2 15:01:28 ldap2 slapd[359]: conn=1141 op=640 SRCH attr=krbprincipalname krbcanonicalname objectclass krbprincipalkey krbmaxrenewableage krbmaxticketlife krbticketflags krbprincipalexpiration krbticketpolicyreference krbUpEnabled krbpwdpolicyreference krbpasswordexpiration krbLastFailedAuth krbLoginFailedCount krbLastSuccessfulAuth krbLastPwdChange krbLastAdminUnlock krbPrincipalAuthInd krbExtraData krbObjectReferences krbAllowedToDelegateTo krbPwdHistory
Mar 2 15:01:28 ldap2 slapd[359]: conn=1141 op=640 SEARCH RESULT tag=101 err=0 nentries=1 text=
Mar 2 15:01:28 ldap2 slapd[359]: conn=1141 op=641 SRCH base="cn=XXXXXXX.NET,cn=krb5,ou=services,dc=lan,dc=xxxxxxx,dc=net" scope=2 deref=0 filter="(&(|(objectClass=krbPrincipalAux)(objectClass=krbPrincipal))(krbPrincipalName=krbtgt/XXXXXXX.NET@XXXXXXX.NET))"
Mar 2 15:01:28 ldap2 slapd[359]: conn=1141 op=641 SRCH attr=krbprincipalname krbcanonicalname objectclass krbprincipalkey krbmaxrenewableage krbmaxticketlife krbticketflags krbprincipalexpiration krbticketpolicyreference krbUpEnabled krbpwdpolicyreference krbpasswordexpiration krbLastFailedAuth krbLoginFailedCount krbLastSuccessfulAuth krbLastPwdChange krbLastAdminUnlock krbPrincipalAuthInd krbExtraData krbObjectReferences krbAllowedToDelegateTo krbPwdHistory
Mar 2 15:01:28 ldap2 slapd[359]: conn=1141 op=641 SEARCH RESULT tag=101 err=0 nentries=1 text=
Mar 2 15:01:28 ldap2 slapd[359]: conn=1141 op=642 SRCH base="cn=user,cn=XXXXXXX.NET,cn=krb5,ou=services,dc=lan,dc=xxxxxxx,dc=net" scope=0 deref=0 filter="(objectClass=krbPwdPolicy)"
Mar 2 15:01:28 ldap2 slapd[359]: conn=1141 op=642 SRCH attr=cn krbmaxpwdlife krbminpwdlife krbpwdmindiffchars krbpwdminlength krbpwdhistorylength krbpwdmaxfailure krbpwdfailurecountinterval krbpwdlockoutduration krbpwdattributes krbpwdmaxlife krbpwdmaxrenewablelife krbpwdallowedkeysalts
Mar 2 15:01:28 ldap2 slapd[359]: conn=1141 op=642 SEARCH RESULT tag=101 err=0 nentries=1 text=
Thanks for your time looking at my problem
Edit:
/etc/krb5.conf (same on every host)
[libdefaults]
default_realm = XXXXXXX.NET
kdc_timesync = 1
ccache_type = 4
forwardable = true
proxiable = true
[realms]
XXXXXXX.NET = {
kdc = kerb.xxxxxxx.net
admin_server = kerb.xxxxxxx.net
}
[domain_realm]
.xxxxxxx.net = XXXXXXX.NET
xxxxxxx.net = XXXXXXX.NET
[logging]
default = FILE:/var/log/krb5.log
Best Answer
I found the problem.
On srv.xxxxxxx.net I had to install the package keyutils.
But now I have an other strange behaviour when I try to mount the samba share. I'll open a new question for that.
Strange behaviour when mounting a samba share with autofs