mkmountpoint fails with long path names.

[Frédéric Nass]

Binary package hint: libpam-mount

Hi,

Upgrading from 10.04 LTS to 11.04 (libpam-mount from 1.3.2 to 2.8), I have few errors with the mounting of cifs shares.
More precisely in the creation of the mount point. It fails half the time. (Try1 fails, then Try2 succeeds, then Try3 fails, Try4 succeeds, Try 5 fails, etc, etc...)

auth.log relevant part when it fails on the first try is :

May 24 18:21:50 db-computer sshd[20079]: pam_mount(pam_mount.c:553): pam_mount 2.8: entering session stage
May 24 18:21:50 db-computer sshd[20079]: pam_mount(misc.c:38): Session open: (ruid/rgid=0/0, e=0/0)
May 24 18:21:50 db-computer sshd[20079]: pam_mount(mount.c:619): Could not get realpath of /home/department/group/testlogin: No such file or directory
May 24 18:21:50 db-computer sshd[20079]: pam_mount(mount.c:217): Mount department: globalconf, user=testlogin <volume fstype="cifs" server="zeus" path="testlogin" mountpoint="/home/department/group/testlogin" cipher="(null)" fskeypath="(null)" fske
ycipher="(null)" fskeyhash="(null)" options="rw,auto,iocharset=utf8,noserverino" /> fstab=0 ssh=0
May 24 18:21:50 db-computer sshd[20079]: pam_mount(mount.c:253): mkmountpoint: checking /home
May 24 18:21:50 db-computer sshd[20079]: pam_mount(mount.c:253): mkmountpoint: checking /home/department
May 24 18:21:50 db-computer sshd[20079]: pam_mount(mount.c:293): mkdir[0] /home/department
May 24 18:21:50 db-computer sshd[20079]: pam_mount(mount.c:300): chown /home/department -> 3654:206158431264
May 24 18:21:50 db-computer sshd[20079]: pam_mount(mount.c:253): mkmountpoint: checking /home/department
May 24 18:21:50 db-computer sshd[20079]: pam_mount(mount.c:253): mkmountpoint: checking /home/department
May 24 18:21:50 db-computer sshd[20079]: command: 'mount' '-t' 'cifs' '//zeus/testlogin' '/home/department/group/testlogin' '-o' 'user=testlogin,uid=3654,gid=1056,rw,auto,iocharset=utf8,noserverino'
May 24 18:21:50 db-computer sshd[20081]: pam_mount(misc.c:38): set_myuid<pre>: (ruid/rgid=0/0, e=0/1056)
May 24 18:21:50 db-computer sshd[20081]: pam_mount(misc.c:38): set_myuid<post>: (ruid/rgid=0/0, e=0/1056)
May 24 18:21:50 db-computer sshd[20079]: pam_mount(mount.c:68): Messages from underlying mount program:
May 24 18:21:50 db-computer sshd[20079]: pam_mount(mount.c:72): Couldn't chdir to /home/department/group/testlogin: No such file or directory
May 24 18:21:50 db-computer sshd[20079]: pam_mount(mount.c:573): could not remove /home/department/group/testlogin again: No such file or directory
May 24 18:21:50 db-computer sshd[20079]: pam_mount(pam_mount.c:521): mount of testlogin failed

auth.log relevant part when it succeeds on the next try is :

May 24 18:22:15 db-computer sshd[20240]: pam_mount(pam_mount.c:553): pam_mount 2.8: entering session stage
May 24 18:22:15 db-computer sshd[20240]: pam_mount(misc.c:38): Session open: (ruid/rgid=0/0, e=0/0)
May 24 18:22:15 db-computer sshd[20240]: pam_mount(mount.c:619): Could not get realpath of /home/department/group/testlogin: No such file or directory
May 24 18:22:15 db-computer sshd[20240]: pam_mount(mount.c:217): Mount department: globalconf, user=testlogin <volume fstype="cifs" server="zeus" path="testlogin" mountpoint="/home/department/group/testlogin" cipher="(null)" fskeypath="(null)" fskeycipher="(null)" fskeyhash="(null)" options="rw,auto,iocharset=utf8,noserverino" /> fstab=0 ssh=0
May 24 18:22:15 db-computer sshd[20240]: pam_mount(mount.c:253): mkmountpoint: checking /home
May 24 18:22:15 db-computer sshd[20240]: pam_mount(mount.c:253): mkmountpoint: checking /home/department
May 24 18:22:15 db-computer sshd[20240]: pam_mount(mount.c:253): mkmountpoint: checking /home/department/group
May 24 18:22:15 db-computer sshd[20240]: pam_mount(mount.c:278): mkdir[3654] /home/department/group
May 24 18:22:15 db-computer sshd[20240]: pam_mount(mount.c:253): mkmountpoint: checking /home/department/group/testlogin
May 24 18:22:15 db-computer sshd[20240]: pam_mount(mount.c:278): mkdir[3654] /home/department/group/testlogin
May 24 18:22:15 db-computer sshd[20240]: command: 'mount' '-t' 'cifs' '//zeus/testlogin' '/home/department/group/testlogin' '-o' 'user=testlogin,uid=3654,gid=1056,rw,auto,iocharset=utf8,noserverino'
May 24 18:22:15 db-computer sshd[20242]: pam_mount(misc.c:38): set_myuid<pre>: (ruid/rgid=0/0, e=0/1056)
May 24 18:22:15 db-computer sshd[20242]: pam_mount(misc.c:38): set_myuid<post>: (ruid/rgid=0/0, e=0/1056)

Looks like pam_mount is not able to create the moint point in one step. Or maybe the chown command fails.
chown /home/department -> 3653:206158431263 looks weared, uh ?

Anyway, when falling back to libpam-mount 1.3.2 (on 11.04), it works just fine like before.

Any help ?

Frédéric Nass
IUT de Metz.

/etc/security/pam_mount.conf.xml :

<debug enable="1" />
<volume user="*" fstype="cifs" server="zeus" path="%(USER)" mountpoint="~" uid="1000-65535" options="rw,auto,iocharset=utf8,noserverino" />
<volume user="*" fstype="cifs" server="zeus" path="commun" mountpoint="/commun" uid="1000-65535" options="rw,auto,iocharset=utf8,noserverino" />
<logout wait="10000" hup="yes" term="yes" kill="yes" />
<mkmountpoint enable="1" remove="true" />

(Auth is LDAP with nslcd configured. But things work fine with libpam-mount 1.3.2)

[Frédéric Nass (nass)]

On the first try (when it fails) /home directory contains :

root@db-computer:/home# tree -p -d /home
/home
└── [drwx--x--x] department

Then on the second try (when it succeeds) /home directory contains :

root@db-computer:/home# tree -p -d /home
/home
└── [drwx--x--x] department
    └── [drwx--x--x] group
        └── [drwx-----x] testlogin

Frédéric.

[Frédéric Nass (nass)]

Showing ownership will be more useful...

first try (when it fails) :

root@db-computer:~# tree -pdug /home/
/home/
└── [drwx--x--x testlogin group] department

second try (when it succeeds) :

root@db-info-2012:~# tree -pdug /home/
/home/
└── [drwx--x--x testlogin group] department
    └── [drwx--x--x testlogin group] group
        └── [drwx-----x testlogin group] testlogin

Frédéric.

[Frédéric Nass (nass)]

Hi,

I made a test with a local account, mounting it's home directory over cifs when logging in (just to make sure neither the ldap indexing or nslcd cache was in cause) and same things happens :

May 25 09:07:17 db-computer sshd[26015]: pam_mount(mount.c:253): mkmountpoint: checking /home
May 25 09:07:17 db-computer sshd[26015]: pam_mount(mount.c:253): mkmountpoint: checking /home/department
May 25 09:07:17 db-computer sshd[26015]: pam_mount(mount.c:293): mkdir[0] /home/department
May 25 09:07:17 db-computer sshd[26015]: pam_mount(mount.c:300): chown /home/department -> 3654:206158431264
May 25 09:07:17 db-computer sshd[26015]: pam_mount(mount.c:253): mkmountpoint: checking /home/department
May 25 09:07:17 db-computer sshd[26015]: pam_mount(mount.c:253): mkmountpoint: checking /home/department

Tell me if you need any other useful information.

Frédéric.

[dev-zero (dev-zero)]

I can confirm this on oneiric. The problem is that the recursive mountpoint creation is broken in the case where pam_mount can't successfully seteuid/setgeuid. This bug is most probably still present in the current pam-mount-2.13 as well.
I've added an untested patch in the upstream bug report: https://sourceforge.net/tracker/?func=detail&aid=3531369&group_id=41452&atid=430593

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[dev-zero (dev-zero)]

Upstream recently accepted my patch and fixed it in Git HEAD. pam_mount-2.14 will most likely contain the fix.

[Frédéric Nass (nass)]

Hi dev-zero,

Thank you for your precious help.

Frédéric.