Bug 1314521

Summary: autofs+cifs+kerberos fails to mount cifs-shares with error 5 - IO-Error
Product: [Fedora] Fedora Reporter: Thomas Schweikle <tschweikle>
Component: autofsAssignee: Ian Kent <ikent>
Status: CLOSED EOL QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 23CC: ikent, tschweikle
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-12-20 19:13:29 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Thomas Schweikle 2016-03-03 20:09:31 UTC
Description of problem:
Setup:
/etc/auto.home - exec-map:
-- snip
#!/bin/sh

function lgl() {
  printf '%s: %s\n' "$( date '+%Y%m%d%H%M%S' )" "$@" >> /var/log/mkhomedir.log
}

                                     lgl "------------------------------------------------------------------------------"
                                     lgl "Running as: $( id )"
uid=$1;                              lgl "User: $uid"
gid=$( id -gn $uid );                lgl "Group: $gid"
k5t=$uid;                            lgl "KRB5: $k5t"

hdr=$(ldapsearch -x "(uid=$uid)" sambaHomePath | awk '{ if ($0 ~ /^sambaHomePath/) { gsub(/ /, "\\ "); gsub(/\\/, "/"); gsub(/\$/,"\\$"); print $2 } }')
                                     lgl "Found samba home: $hdr"

lho="/local/home/$uid";              lgl "Local home: $lho"
if [ ! -d "$lho" ]; then
  mkdir -p "$lho";                   lgl "Local home created: $lho"
  cp -rT /etc/skel "$lho";           lgl "Copied /etc/skel to $lho"
  chown -R $uid:$gid "$lho";         lgl "Fixed user.group: $lho"
fi

case "${hdr:0:2}" in
  //)
    printf -- '-rsize=8192,wsize=8192 \\\n'
    printf -- '  / :%s \\\n'                                                                                                                $lho
    printf -- '  /%s -fstype=cifs,sec=krb5,user=%s,cruid=%s,uid=%s,gid=%s,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino :%s \\\n'    $uid $uid $k5t $uid $gid $hdr
    printf -- '  /SW2 -fstype=cifs,sec=krb5,user=%s,cruid=%s,uid=%s,gid=%s,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino :%s \\\n'   $uid $k5t $uid $gid '//<server>/sw2'
    printf -- '  /ALLG -fstype=cifs,sec=krb5,user=%s,cruid=%s,uid=%s,gid=%s,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino :%s\n'     $uid $k5t $uid $gid '//<server>/Allg'
    ;;

  [A-Z]\:)
    hdr=//netapp2-muc.bfs.de/$uid
    printf -- '-rsize=8192,wsize=8192 \\\n'
    printf -- '  / :%s \\\n'                                                                                                                $lho
    printf -- '  /%s -fstype=cifs,sec=krb5,user=%s,cruid=%s,uid=%s,gid=%s,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino :%s \\\n'    $uid $uid $k5t $uid $gid $hdr
    printf -- '  /SW2 -fstype=cifs,sec=krb5,user=%s,cruid=%s,uid=%s,gid=%s,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino :%s \\\n'   $uid $k5t $uid $gid '//<server>/sw2'
    printf -- '  /ALLG -fstype=cifs,sec=krb5,user=%s,cruid=%s,uid=%s,gid=%s,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino :%s\n'     $uid $k5t $uid $gid '//<server>/Allg'
    ;;

  "*")
    :
    ;;
esac
-- snap

This script is executed while a user logs in. It exausts:
-- snip
-rsize=8192,wsize=8192 \
  / :/local/home/<user> \
  /<user> -fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://netapp2-muc.bfs.de/<user> \
  /SW2 -fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://<server>/sw2 \
  /ALLG -fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://<server>/Allg
-- snap
This is a legal multi map which ist expected to mount:
/home/<user> -> /local/home/<user>
/home/<user>/<user> -> //<server>/<user>
/home/<user>/ALLG -> //<server>/ALLG
/home/<user>/SW2 -> //<server>/SW2


Version-Release number of selected component (if applicable):
apr-util-ldap-1.3.9-3.el6_0.1.x86_64
docbook-style-dsssl-1.79-10.el6.noarch
krb5-libs-1.10.3-42.el6.x86_64
krb5-workstation-1.10.3-42.el6.x86_64
libsss_idmap-1.12.4-47.el6_7.7.x86_64
nagios-plugins-ldap-2.0.3-3.el6.x86_64
nfs4-acl-tools-0.3.3-7.el6.x86_64
nfs-utils-1.2.3-64.el6.x86_64
nfs-utils-lib-1.1.5-11.el6.x86_64
nss-pam-ldapd-0.7.5-20.el6_6.3.x86_64
openldap-2.4.40-7.el6_7.x86_64
openldap-clients-2.4.40-7.el6_7.x86_64
pam_krb5-2.3.11-9.el6.x86_64
pam_ldap-185-11.el6.x86_64
python-krbV-1.0.90-3.el6.x86_64
python-ldap-2.3.10-1.el6.x86_64
python-sssdconfig-1.12.4-47.el6_7.7.noarch
sssd-1.12.4-47.el6_7.7.x86_64
sssd-ad-1.12.4-47.el6_7.7.x86_64
sssd-client-1.12.4-47.el6_7.7.x86_64
sssd-common-1.12.4-47.el6_7.7.x86_64
sssd-common-pac-1.12.4-47.el6_7.7.x86_64
sssd-ipa-1.12.4-47.el6_7.7.x86_64
sssd-krb5-1.12.4-47.el6_7.7.x86_64
sssd-krb5-common-1.12.4-47.el6_7.7.x86_64
sssd-ldap-1.12.4-47.el6_7.7.x86_64
sssd-proxy-1.12.4-47.el6_7.7.x86_64


How reproducible:
Always. Same Problem with:
- CentOS 6.7, 7.2
- RHEL 6.7
- OracleLinux 6.7, 7.2
- Fedora 22, 23, 24

Steps to Reproduce:
1. Install OS
2. Configure cifs-server (Windows 2008-Server will do)
3. Configure ldap, kerberos, autofs
4. make sure connections are OK
   - ldap
   - kerberos
5. make sure your users can request krb-tgt.

Actual results:
Mounting /home/<user> is OK, all cifs mounts fail with error 5.

Expected results:
Mounting all servers given in the multi map as far as the user has access and is allowed to mount.

Additional info:
This worked for about 6 months, now it is impossible to make it work again!


/var/log/messages:
-- snip
Mar  3 20:58:00 atmosrv3-fr automount[9373]: attempting to mount entry /home/<user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: lookup_mount: lookup(program): looking up <user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: lookup_mount: lookup(program): <user> -> -rsize=8192,wsize=8192    / :/local/home/<user>    /<user> -fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://netapp2-muc.bfs.de/<user>    /SW2 -fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://<server>/sw2    /ALLG -fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://netapp01-ber.bfs.de/Allg
Mar  3 20:58:00 atmosrv3-fr automount[9373]: parse_mount: parse(sun): expanded entry: -rsize=8192,wsize=8192    / :/local/home/<user>    /<user> -fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://netapp2-muc.bfs.de/<user>    /SW2 -fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://<server>/sw2    /ALLG -fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://netapp01-ber.bfs.de/Allg
Mar  3 20:58:00 atmosrv3-fr automount[9373]: parse_mount: parse(sun): gathered options: rsize=8192,wsize=8192
Mar  3 20:58:00 atmosrv3-fr automount[9373]: parse_mount: parse(sun): dequote("/") -> /
Mar  3 20:58:00 atmosrv3-fr automount[9373]: parse_mapent: parse(sun): gathered options: rsize=8192,wsize=8192
Mar  3 20:58:00 atmosrv3-fr automount[9373]: parse_mapent: parse(sun): dequote(":/local/home/<user>") -> :/local/home/<user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: update_offset_entry: parse(sun): updated multi-mount offset / -> -rsize=8192,wsize=8192 :/local/home/<user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: parse_mount: parse(sun): dequote("/<user>") -> /<user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: parse_mapent: parse(sun): gathered options: rsize=8192,wsize=8192,fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino
Mar  3 20:58:00 atmosrv3-fr automount[9373]: parse_mapent: parse(sun): dequote("://netapp2-muc.bfs.de/<user>") -> ://netapp2-muc.bfs.de/<user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: update_offset_entry: parse(sun): updated multi-mount offset /<user> -> -rsize=8192,wsize=8192,fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://netapp2-muc.bfs.de/<user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: parse_mount: parse(sun): dequote("/SW2") -> /SW2
Mar  3 20:58:00 atmosrv3-fr automount[9373]: parse_mapent: parse(sun): gathered options: rsize=8192,wsize=8192,fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino
Mar  3 20:58:00 atmosrv3-fr automount[9373]: parse_mapent: parse(sun): dequote("://<server>/sw2") -> ://<server>/sw2
Mar  3 20:58:00 atmosrv3-fr automount[9373]: update_offset_entry: parse(sun): updated multi-mount offset /SW2 -> -rsize=8192,wsize=8192,fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://<server>/sw2
Mar  3 20:58:00 atmosrv3-fr automount[9373]: parse_mount: parse(sun): dequote("/ALLG") -> /ALLG
Mar  3 20:58:00 atmosrv3-fr automount[9373]: parse_mapent: parse(sun): gathered options: rsize=8192,wsize=8192,fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino
Mar  3 20:58:00 atmosrv3-fr automount[9373]: parse_mapent: parse(sun): dequote("://netapp01-ber.bfs.de/Allg") -> ://netapp01-ber.bfs.de/Allg
Mar  3 20:58:00 atmosrv3-fr automount[9373]: update_offset_entry: parse(sun): updated multi-mount offset /ALLG -> -rsize=8192,wsize=8192,fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://netapp01-ber.bfs.de/Allg
Mar  3 20:58:00 atmosrv3-fr automount[9373]: parse_mapent: parse(sun): gathered options: rsize=8192,wsize=8192
Mar  3 20:58:00 atmosrv3-fr automount[9373]: parse_mapent: parse(sun): dequote(":/local/home/<user>") -> :/local/home/<user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: sun_mount: parse(sun): mounting root /home/<user>/, mountpoint <user>, what :/local/home/<user>, fstype nfs, options rsize=8192,wsize=8192
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mount_mount: mount(nfs): root=/home/<user>/ name=<user> what=:/local/home/<user>, fstype=nfs, options=rsize=8192,wsize=8192
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mount_mount: mount(nfs): nfs options="rsize=8192,wsize=8192", nobind=0, nosymlink=0, ro=0
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mount_mount: mount(nfs): calling mkdir_path /home/<user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mount_mount: mount(nfs): <user> is local, attempt bind mount
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mount_mount: mount(bind): calling mkdir_path /home/<user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mount_mount: mount(bind): calling mount --bind -s  -o defaults /local/home/<user> /home/<user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mount_mount: mount(bind): mounted /local/home/<user> type bind on /home/<user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: do_mount_autofs_offset: mount offset /home/<user>/ALLG at /home/<user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mount_autofs_offset: calling mount -t autofs -s  -o fd=7,pgrp=9373,minproto=5,maxproto=5,offset automount /home/<user>/ALLG
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mounted offset on /home/<user>/ALLG with timeout 300, freq 75 seconds
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mount_autofs_offset: mounted trigger /home/<user>/ALLG at /home/<user>/ALLG
Mar  3 20:58:00 atmosrv3-fr automount[9373]: do_mount_autofs_offset: mount offset /home/<user>/SW2 at /home/<user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mount_autofs_offset: calling mount -t autofs -s  -o fd=7,pgrp=9373,minproto=5,maxproto=5,offset automount /home/<user>/SW2
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mounted offset on /home/<user>/SW2 with timeout 300, freq 75 seconds
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mount_autofs_offset: mounted trigger /home/<user>/SW2 at /home/<user>/SW2
Mar  3 20:58:00 atmosrv3-fr automount[9373]: do_mount_autofs_offset: mount offset /home/<user>/<user> at /home/<user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mount_autofs_offset: calling mount -t autofs -s  -o fd=7,pgrp=9373,minproto=5,maxproto=5,offset automount /home/<user>/<user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mounted offset on /home/<user>/<user> with timeout 300, freq 75 seconds
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mount_autofs_offset: mounted trigger /home/<user>/<user> at /home/<user>/<user>
Mar  3 20:58:00 atmosrv3-fr automount[9373]: dev_ioctl_send_ready: token = 67
Mar  3 20:58:00 atmosrv3-fr automount[9373]: mounted /home/<user>
Mar  3 20:58:19 atmosrv3-fr automount[9373]: handle_packet: type = 5
Mar  3 20:58:19 atmosrv3-fr automount[9373]: handle_packet_missing_direct: token 68, name /home/<user>/ALLG, request pid 9442
Mar  3 20:58:19 atmosrv3-fr automount[9373]: attempting to mount entry /home/<user>/ALLG
Mar  3 20:58:19 atmosrv3-fr automount[9373]: lookup_mount: lookup(program): /home/<user>/ALLG -> -rsize=8192,wsize=8192,fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://netapp01-ber.bfs.de/Allg
Mar  3 20:58:19 atmosrv3-fr automount[9373]: parse_mount: parse(sun): expanded entry: -rsize=8192,wsize=8192,fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://netapp01-ber.bfs.de/Allg
Mar  3 20:58:19 atmosrv3-fr automount[9373]: parse_mount: parse(sun): gathered options: rsize=8192,wsize=8192,fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino
Mar  3 20:58:19 atmosrv3-fr automount[9373]: sun_mount: parse(sun): mounting root /home/<user>/ALLG, mountpoint /home/<user>/ALLG, what //netapp01-ber.bfs.de/Allg, fstype cifs, options rsize=8192,wsize=8192,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino
Mar  3 20:58:19 atmosrv3-fr automount[9373]: do_mount: //netapp01-ber.bfs.de/Allg /home/<user>/ALLG type cifs options rsize=8192,wsize=8192,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino using module generic
Mar  3 20:58:19 atmosrv3-fr automount[9373]: mount_mount: mount(generic): calling mkdir_path /home/<user>/ALLG
Mar  3 20:58:19 atmosrv3-fr automount[9373]: mount_mount: mount(generic): calling mount -t cifs -s -o rsize=8192,wsize=8192,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino //netapp01-ber.bfs.de/Allg /home/<user>/ALLG
Mar  3 20:58:19 atmosrv3-fr kernel: CIFS VFS: Send error in SessSetup = -5
Mar  3 20:58:19 atmosrv3-fr automount[9373]: >> mount error(5): Input/output error
Mar  3 20:58:19 atmosrv3-fr automount[9373]: >> Refer to the mount.cifs(8) manual page (e.g. man mount.cifs)
Mar  3 20:58:19 atmosrv3-fr automount[9373]: mount(generic): failed to mount //netapp01-ber.bfs.de/Allg (type cifs) on /home/<user>/ALLG
Mar  3 20:58:19 atmosrv3-fr automount[9373]: dev_ioctl_send_fail: token = 68
Mar  3 20:58:19 atmosrv3-fr automount[9373]: failed to mount /home/<user>/ALLG
Mar  3 20:58:19 atmosrv3-fr kernel: CIFS VFS: cifs_mount failed w/return code = -5
Mar  3 20:58:25 atmosrv3-fr automount[9373]: handle_packet: type = 5
Mar  3 20:58:25 atmosrv3-fr automount[9373]: handle_packet_missing_direct: token 69, name /home/<user>/<user>, request pid 9450
Mar  3 20:58:25 atmosrv3-fr automount[9373]: attempting to mount entry /home/<user>/<user>
Mar  3 20:58:25 atmosrv3-fr automount[9373]: lookup_mount: lookup(program): /home/<user>/<user> -> -rsize=8192,wsize=8192,fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://netapp2-muc.bfs.de/<user>
Mar  3 20:58:25 atmosrv3-fr automount[9373]: parse_mount: parse(sun): expanded entry: -rsize=8192,wsize=8192,fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://netapp2-muc.bfs.de/<user>
Mar  3 20:58:25 atmosrv3-fr automount[9373]: parse_mount: parse(sun): gathered options: rsize=8192,wsize=8192,fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino
Mar  3 20:58:25 atmosrv3-fr automount[9373]: sun_mount: parse(sun): mounting root /home/<user>/<user>, mountpoint /home/<user>/<user>, what //netapp2-muc.bfs.de/<user>, fstype cifs, options rsize=8192,wsize=8192,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino
Mar  3 20:58:25 atmosrv3-fr automount[9373]: do_mount: //netapp2-muc.bfs.de/<user> /home/<user>/<user> type cifs options rsize=8192,wsize=8192,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino using module generic
Mar  3 20:58:25 atmosrv3-fr automount[9373]: mount_mount: mount(generic): calling mkdir_path /home/<user>/<user>
Mar  3 20:58:25 atmosrv3-fr automount[9373]: mount_mount: mount(generic): calling mount -t cifs -s -o rsize=8192,wsize=8192,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino //netapp2-muc.bfs.de/<user> /home/<user>/<user>
Mar  3 20:58:25 atmosrv3-fr kernel: CIFS VFS: Send error in SessSetup = -5
Mar  3 20:58:25 atmosrv3-fr automount[9373]: >> mount error(5): Input/output error
Mar  3 20:58:25 atmosrv3-fr automount[9373]: >> Refer to the mount.cifs(8) manual page (e.g. man mount.cifs)
Mar  3 20:58:25 atmosrv3-fr automount[9373]: mount(generic): failed to mount //netapp2-muc.bfs.de/<user> (type cifs) on /home/<user>/<user>
Mar  3 20:58:25 atmosrv3-fr kernel: CIFS VFS: cifs_mount failed w/return code = -5
Mar  3 20:58:25 atmosrv3-fr automount[9373]: dev_ioctl_send_fail: token = 69
Mar  3 20:58:25 atmosrv3-fr automount[9373]: failed to mount /home/<user>/<user>
Mar  3 20:58:30 atmosrv3-fr automount[9373]: handle_packet: type = 5
Mar  3 20:58:30 atmosrv3-fr automount[9373]: handle_packet_missing_direct: token 70, name /home/<user>/SW2, request pid 9458
Mar  3 20:58:30 atmosrv3-fr automount[9373]: attempting to mount entry /home/<user>/SW2
Mar  3 20:58:30 atmosrv3-fr automount[9373]: lookup_mount: lookup(program): /home/<user>/SW2 -> -rsize=8192,wsize=8192,fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://<server>/sw2
Mar  3 20:58:30 atmosrv3-fr automount[9373]: parse_mount: parse(sun): expanded entry: -rsize=8192,wsize=8192,fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino ://<server>/sw2
Mar  3 20:58:30 atmosrv3-fr automount[9373]: parse_mount: parse(sun): gathered options: rsize=8192,wsize=8192,fstype=cifs,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino
Mar  3 20:58:30 atmosrv3-fr automount[9373]: sun_mount: parse(sun): mounting root /home/<user>/SW2, mountpoint /home/<user>/SW2, what //<server>/sw2, fstype cifs, options rsize=8192,wsize=8192,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino
Mar  3 20:58:30 atmosrv3-fr automount[9373]: do_mount: //<server>/sw2 /home/<user>/SW2 type cifs options rsize=8192,wsize=8192,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino using module generic
Mar  3 20:58:30 atmosrv3-fr automount[9373]: mount_mount: mount(generic): calling mkdir_path /home/<user>/SW2
Mar  3 20:58:30 atmosrv3-fr automount[9373]: mount_mount: mount(generic): calling mount -t cifs -s -o rsize=8192,wsize=8192,sec=krb5,user=<user>,cruid=<user>,uid=<user>,gid=AG-IT,dir_mode=0771,file_mode=0640,nosuid,nodev,noserverino //<server>/sw2 /home/<user>/SW2
Mar  3 20:58:30 atmosrv3-fr kernel: CIFS VFS: Send error in SessSetup = -5
Mar  3 20:58:30 atmosrv3-fr automount[9373]: >> mount error(5): Input/output error
Mar  3 20:58:30 atmosrv3-fr automount[9373]: >> Refer to the mount.cifs(8) manual page (e.g. man mount.cifs)
Mar  3 20:58:30 atmosrv3-fr automount[9373]: mount(generic): failed to mount //<server>/sw2 (type cifs) on /home/<user>/SW2
Mar  3 20:58:30 atmosrv3-fr automount[9373]: dev_ioctl_send_fail: token = 70
Mar  3 20:58:30 atmosrv3-fr automount[9373]: failed to mount /home/<user>/SW2
Mar  3 20:58:30 atmosrv3-fr kernel: CIFS VFS: cifs_mount failed w/return code = -5
Mar  3 20:58:46 atmosrv3-fr automount[9373]: st_expire: state 1 path /net
Mar  3 20:58:46 atmosrv3-fr automount[9373]: expire_proc: exp_proc = 140095339493120 path /net
Mar  3 20:58:46 atmosrv3-fr automount[9373]: expire_cleanup: got thid 140095339493120 path /net stat 0
Mar  3 20:58:46 atmosrv3-fr automount[9373]: expire_cleanup: sigchld: exp 140095339493120 finished, switching from 2 to 1
Mar  3 20:58:46 atmosrv3-fr automount[9373]: st_ready: st_ready(): state = 2 path /net
-- snap
The user only will see "ls: cannot access ALLG/: No such file or directory" for any of the cifs-mounts. The user does have a kerberos-ticket and is allowed to access any of the shares:
-- snip
Ticket cache: FILE:/tmp/krb5cc_10947_h4oeCY
Default principal: <user>@<realm>

Valid starting     Expires            Service principal
03/03/16 20:58:00  03/04/16 06:58:00  krbtgt/<realm>@<realm>
        renew until 03/10/16 20:58:00
03/03/16 20:58:19  03/04/16 06:58:00  cifs/<server1>@<realm>
        renew until 03/10/16 20:58:00
03/03/16 20:58:25  03/04/16 06:58:00  cifs/<server2>@<realm>
        renew until 03/10/16 20:58:00
03/03/16 20:58:30  03/04/16 06:58:00  cifs/<server3>@<realm>
        renew until 03/10/16 20:58:00
-- snap

Logs where gathered from RHEL 6.7, latest fixes and patches applied.

Comment 1 Thomas Schweikle 2016-03-03 20:20:51 UTC
I've enabled debugging for autofs, setting "--debug" in /etc/sysconfig/autofs OPTIONS.

Here is what I see using smbclient to access one of the shares:
# kinit <user>
Password for <user>@<realm>:
Warning: Your password will expire in 16 days on Sun Mar 20 15:46:57 2016

# klist
Ticket cache: FILE:/tmp/krb5cc_10947_h4oeCY
Default principal: <user>@<realm>

Valid starting     Expires            Service principal
03/03/16 21:14:17  03/04/16 07:14:17  krbtgt/<realm>@<realm>
        renew until 03/10/16 21:14:12

# smbclient -k //<server>/Allg
session setup failed: NT_STATUS_MORE_PROCESSING_REQUIRED
did you forget to run kinit?

# klist
Ticket cache: FILE:/tmp/krb5cc_10947_h4oeCY
Default principal: <user>@<realm>

Valid starting     Expires            Service principal
03/03/16 21:14:17  03/04/16 07:14:17  krbtgt/<realm>@<realm>
        renew until 03/10/16 21:14:12
03/03/16 21:14:21  03/04/16 07:14:17  cifs/<server>@<realm>
        renew until 03/10/16 21:14:12

# echo $KRB5CCNAME
FILE:/tmp/krb5cc_10947_h4oeCY

Comment 2 Thomas Schweikle 2016-03-03 20:42:36 UTC
The same setup does work with:
- Debian stable, testing, unstable
- Ubuntu 14.04.4 LTS
- FreeBSD CURRENT (quite different in setup, because FreeBSD doesn't know about multimaps :-( ) -- but works too.

Here is what I see connecting to my server from Ubuntu 14.04.4 LTS:
-- snip
$ kinit <user>
Password for <user>@<realm>:
Warning: Your password will expire in 16 days on So 20 Mär 2016 15:46:57 CET

$ klist
Ticket cache: FILE:/tmp/krb5cc_10947
Default principal: <user>@<realm>

Valid starting       Expires              Service principal
03.03.2016 21:38:29  04.03.2016 07:38:29  krbtgt/<realm>@<realm>
        renew until 10.03.2016 21:38:14

$ smbclient -k //<server>/<user>
Domain=[BFS] OS=[Windows 5.0] Server=[Windows 2000 LAN Manager]
smb: \> ls
  desktop.ini                       AHS       80  Tue Nov 27 14:58:16 2012
  Documents                          DR        0  Wed Jan 20 16:19:38 2016
  Safes                               D        0  Tue Sep 10 16:54:58 2013
  upcp.sh                             A        0  Tue May 27 16:53:46 2014
[...]
                40960 blocks of size 262144. 40194 blocks available
smb: \> q

$ klist
Ticket cache: FILE:/tmp/krb5cc_10947
Default principal: <user>@<realm>

Valid starting       Expires              Service principal
03.03.2016 21:38:29  04.03.2016 07:38:29  krbtgt/<realm>@<realm>
        renew until 10.03.2016 21:38:14
03.03.2016 21:38:46  04.03.2016 07:38:29  cifs/<server>@<realm>
        renew until 10.03.2016 21:38:14
$ kdestroy
-- snap

Comment 3 Ian Kent 2016-03-08 11:31:22 UTC
(In reply to Thomas Schweikle from comment #1)
> I've enabled debugging for autofs, setting "--debug" in
> /etc/sysconfig/autofs OPTIONS.
> 
> Here is what I see using smbclient to access one of the shares:
> # kinit <user>
> Password for <user>@<realm>:
> Warning: Your password will expire in 16 days on Sun Mar 20 15:46:57 2016
> 
> # klist
> Ticket cache: FILE:/tmp/krb5cc_10947_h4oeCY
> Default principal: <user>@<realm>
> 
> Valid starting     Expires            Service principal
> 03/03/16 21:14:17  03/04/16 07:14:17  krbtgt/<realm>@<realm>
>         renew until 03/10/16 21:14:12
> 
> # smbclient -k //<server>/Allg
> session setup failed: NT_STATUS_MORE_PROCESSING_REQUIRED
> did you forget to run kinit?

I think these in the log of comment #0:
Mar  3 20:58:25 atmosrv3-fr kernel: CIFS VFS: Send error in SessSetup = -5
Mar  3 20:58:25 atmosrv3-fr automount[9373]: >> mount error(5): Input/output error
Mar  3 20:58:25 atmosrv3-fr automount[9373]: >> Refer to the mount.cifs(8) manual page (e.g. man mount.cifs)

and the above from smbclient is fairly clear evidence the CIFS
client is the problem with your setup.

But I suspect the CIFS maintainer will be equally mystified as
I am as to why.

I have a similar report against autofs but for authentication
to a Windows server for accessing autofs maps.

It's the same more precessing type message as you see here with
smbclient.

I know with some other (apparently unrelated) problems it was
apparent some of the underlying libraries have changed away
from using OpenSSL and I think this has affected openldap
for one, which autofs uses, and those same libraries may be
used by the CIFS kernel callback program and smbclient.

I don't know what libraries the CIFS executables use so I
don't know if the problem is related.

Are you ok to change the component to cifs-utils to get
input for the CIFS maintainer?

Ian

Comment 4 Thomas Schweikle 2016-05-03 12:55:34 UTC
Had to do other work with higher priority in between ... back to this now.
I've found various bug reports about this problem related to the kernel on launchpad (https://bugs.launchpad.net/ubuntu/+source/linux/+bug/1373473). I've tried newer and older kernel to verify against.

Kernel from elrepo -- with an up to date system:
- 4.5.2-1.el6.elrepo.x86_64: mount error - IO-Error.
- 3.10.101-1.el6.elrepo.x86_64: mount error - IO-Error.
- 3.8.13-118.4.2.el6uek.x86_64: mount error - IO-Error.
- 3.8.13-118.4.1.el6uek.x86_64: mount error - IO-Error.
- 3.8.13-118.3.2.el6uek.x86_64: mount error - IO-Error.
- 2.6.32-573.22.1.el6.x86_64: mount error - IO-Error.
- 2.6.32-573.18.1.el6.x86_64: mount error - IO-Error.
- 2.6.32-573.12.1.el6.x86_64: mount error - IO-Error.

From the last DVD for CentOS 6:
- it is working. Upgrading only kernels breaks it.
  Going back to an older one makes it work again.
- Updating libraries used by cifs breaks it too.
  Going pack to older ones makes it work again.

Think it is something all over together: cifs-utils, libraries, and final the kernel which changed. all together break cifs-mounts. But I am clueless what exactly could be the case why it is broken at now.
I've even tried to recompile all of them -- whithout success. Same error.

Comment 5 Thomas Schweikle 2016-05-03 13:01:15 UTC
Found it broken with:
- Redhat 6, 7
- CentOS 6, 7
- Oracle Linux 6, 7
- Fedora (all supported versions)
- Ubuntu 14.04, 15.10, 16.04, (upcoming) 16.10

All up to date.

Found it working:
- Redhat 6, 7 (original DVD install image or media)
- Centos 6, 7 (original DVD install image or media)

Comment 6 Fedora End Of Life 2016-11-24 15:54:48 UTC
This message is a reminder that Fedora 23 is nearing its end of life.
Approximately 4 (four) weeks from now Fedora will stop maintaining
and issuing updates for Fedora 23. It is Fedora's policy to close all
bug reports from releases that are no longer maintained. At that time
this bug will be closed as EOL if it remains open with a Fedora  'version'
of '23'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version.

Thank you for reporting this issue and we are sorry that we were not 
able to fix it before Fedora 23 is end of life. If you would still like 
to see this bug fixed and are able to reproduce it against a later version 
of Fedora, you are encouraged  change the 'version' to a later Fedora 
version prior this bug is closed as described in the policy above.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events. Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

Comment 7 Fedora End Of Life 2016-12-20 19:13:29 UTC
Fedora 23 changed to end-of-life (EOL) status on 2016-12-20. Fedora 23 is
no longer maintained, which means that it will not receive any further
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of
Fedora please feel free to reopen this bug against that version. If you
are unable to reopen this bug, please file a new report against the
current release. If you experience problems, please add a comment to this
bug.

Thank you for reporting this bug and we are sorry it could not be fixed.