Bug 612179 - Errors from underlying mount program: crypt_activate_by_passphrase: File exists
Errors from underlying mount program: crypt_activate_by_passphrase: File exists
Status: CLOSED WONTFIX
Product: Fedora
Classification: Fedora
Component: pam_mount (Show other bugs)
15
All Linux
low Severity medium
: ---
: ---
Assigned To: Till Maas
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2010-07-07 09:49 EDT by Jan Pazdziora
Modified: 2012-08-07 15:38 EDT (History)
6 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2012-08-07 15:38:22 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:


Attachments (Terms of Use)
Running the pam_mount thdebug enabled, I get AVC denials (5.06 KB, text/plain)
2010-07-18 17:15 EDT, Jan Pazdziora
no flags Details

  None (edit)
Description Jan Pazdziora 2010-07-07 09:49:43 EDT
Description of problem:

When mounting home directory with pam_mount, error is shown, even if home is mounted just fine.

Version-Release number of selected component (if applicable):

# rpm -qa pam_mount cryptsetup* | sort
cryptsetup-luks-1.1.3-1.fc13.i686
cryptsetup-luks-libs-1.1.3-1.fc13.i686
pam_mount-2.4-2.fc13.i686

How reproducible:

Deterministic.

Steps to Reproduce:
1. Install F13 GA. In my case, 188 packages were installed with the Minimal install.
2. Upgrade to latest package versions, run yum upgrade. You will end up with about 191 packages.
3. Create LV to be used for encrypted home:
[root@vmware175 ~]# vgs
  VG   #PV #LV #SN Attr   VSize VFree
  vg0    1   2   0 wz--n- 7.88g 3.47g
[root@vmware175 ~]# lvs
  LV   VG   Attr   LSize   Origin Snap%  Move Log Copy%  Convert
  root vg0  -wi-ao   3.91g                                      
  swap vg0  -wi-ao 512.00m                                      
[root@vmware175 ~]# lvcreate -L 100M -n home-encrypted vg0
  Rounding up size to full physical extent 128.00 MiB
  Logical volume "home-encrypted" created
[root@vmware175 ~]# 

4. Setup LUKS:
[root@vmware175 ~]# cryptsetup luksFormat /dev/vg0/home-encrypted 

WARNING!
========
This will overwrite data on /dev/vg0/home-encrypted irrevocably.

Are you sure? (Type uppercase yes): YES
Enter LUKS passphrase: 
Verify passphrase: 
[root@vmware175 ~]# 

5. Set the password for the user test the same as you've setup the passphrase above:
[root@vmware175 home]# passwd test
Changing password for user test.
New password: 
BAD PASSWORD: it is too short
BAD PASSWORD: is too simple
Retype new password: 
passwd: all authentication tokens updated successfully.
[root@vmware175 home]# 

6. Create filesystem on that encrypted partition:
[root@vmware175 ~]# cryptsetup luksOpen /dev/vg0/home-encrypted home
Enter passphrase for /dev/vg0/home-encrypted: 
Key slot 0 unlocked.
[root@vmware175 ~]# mkfs -t ext4 /dev/mapper/home 
mke2fs 1.41.10 (10-Feb-2009)
Filesystem label=
OS type: Linux
Block size=1024 (log=0)
Fragment size=1024 (log=0)
Stride=0 blocks, Stripe width=0 blocks
32512 inodes, 130044 blocks
6502 blocks (5.00%) reserved for the super user
First data block=1
Maximum filesystem blocks=67371008
16 block groups
8192 blocks per group, 8192 fragments per group
2032 inodes per group
Superblock backups stored on blocks: 
	8193, 24577, 40961, 57345, 73729

Writing inode tables: done                            
Creating journal (4096 blocks): done
Writing superblocks and filesystem accounting information: done

This filesystem will be automatically checked every 24 mounts or
180 days, whichever comes first.  Use tune2fs -c or -i to override.
[root@vmware175 ~]# cryptsetup luksClose /dev/vg0/home-encrypted 
[root@vmware175 ~]# 

7. Install pam_mount:
[root@vmware175 ~]# yum install pam_mount
Setting up Install Process
Resolving Dependencies
--> Running transaction check
---> Package pam_mount.i686 0:1.32-1.fc12 set to be updated
--> Processing Dependency: libHX >= 3.1 for package: pam_mount-1.32-1.fc12.i686
--> Processing Dependency: libHX.so.22 for package: pam_mount-1.32-1.fc12.i686
--> Running transaction check
---> Package libHX.i686 0:3.1-1.fc12 set to be updated
--> Finished Dependency Resolution

Dependencies Resolved

================================================================================
 Package            Arch          Version                 Repository       Size
================================================================================
Installing:
 pam_mount          i686          1.32-1.fc12             fedora          111 k
Installing for dependencies:
 libHX              i686          3.1-1.fc12              fedora           47 k

Transaction Summary
================================================================================
Install       2 Package(s)
Upgrade       0 Package(s)

Total download size: 158 k
Installed size: 409 k
Is this ok [y/N]: y
Downloading Packages:
(1/2): libHX-3.1-1.fc12.i686.rpm                         |  47 kB     00:00     
(2/2): pam_mount-1.32-1.fc12.i686.rpm                    | 111 kB     00:00     
--------------------------------------------------------------------------------
Total                                           571 kB/s | 158 kB     00:00     
Running rpm_check_debug
Running Transaction Test
Transaction Test Succeeded
Running Transaction
  Installing     : libHX-3.1-1.fc12.i686                                    1/2 
  Installing     : pam_mount-1.32-1.fc12.i686                               2/2 

Installed:
  pam_mount.i686 0:1.32-1.fc12                                                  

Dependency Installed:
  libHX.i686 0:3.1-1.fc12                                                       

Complete!
[root@vmware175 ~]# 

8. Enable pam_mount in pam (changes in password-auth and system-auth are not shown as they are the same as in the *-ac versions, being symlinks to those *-ac files):
[root@vmware175 ~]# diff -u /etc/pam.d{.orig,}
diff -u /etc/pam.d.orig/login /etc/pam.d/login
--- /etc/pam.d.orig/login	2010-05-19 13:50:15.000000000 +0200
+++ /etc/pam.d/login	2010-07-07 16:10:54.466931926 +0200
@@ -8,6 +8,7 @@
 session    required     pam_selinux.so close
 session    required     pam_loginuid.so
 session    optional     pam_console.so
+session    optional     pam_mount.so
 # pam_selinux.so open should only be followed by sessions to be executed in the user context
 session    required     pam_selinux.so open
 session    required     pam_namespace.so
diff -u /etc/pam.d.orig/password-auth-ac /etc/pam.d/password-auth-ac
--- /etc/pam.d.orig/password-auth-ac	2010-07-07 15:36:42.000000000 +0200
+++ /etc/pam.d/password-auth-ac	2010-07-07 16:12:10.650193025 +0200
@@ -2,6 +2,7 @@
 # This file is auto-generated.
 # User changes will be destroyed the next time authconfig is run.
 auth        required      pam_env.so
+auth        optional      pam_mount.so
 auth        sufficient    pam_unix.so nullok try_first_pass
 auth        requisite     pam_succeed_if.so uid >= 500 quiet
 auth        required      pam_deny.so
@@ -19,3 +20,4 @@
 session     required      pam_limits.so
 session     [success=1 default=ignore] pam_succeed_if.so service in crond quiet use_uid
 session     required      pam_unix.so
+session     optional      pam_mount.so
diff -u /etc/pam.d.orig/system-auth-ac /etc/pam.d/system-auth-ac
--- /etc/pam.d.orig/system-auth-ac	2010-07-07 15:36:42.000000000 +0200
+++ /etc/pam.d/system-auth-ac	2010-07-07 16:12:33.959928330 +0200
@@ -2,6 +2,7 @@
 # This file is auto-generated.
 # User changes will be destroyed the next time authconfig is run.
 auth        required      pam_env.so
+auth        optional      pam_mount.so
 auth        sufficient    pam_fprintd.so
 auth        sufficient    pam_unix.so nullok try_first_pass
 auth        requisite     pam_succeed_if.so uid >= 500 quiet
@@ -20,3 +21,4 @@
 session     required      pam_limits.so
 session     [success=1 default=ignore] pam_succeed_if.so service in crond quiet use_uid
 session     required      pam_unix.so
+session     optional      pam_mount.so
[root@vmware175 ~]# 

9. Configure the volume to be used for test's home:
[root@vmware175 ~]# diff -u /etc/security/pam_mount.conf.xml.orig /etc/security/pam_mount.conf.xml
--- /etc/security/pam_mount.conf.xml.orig	2009-09-24 02:33:20.000000000 +0200
+++ /etc/security/pam_mount.conf.xml	2010-07-07 15:59:29.841149462 +0200
@@ -40,5 +40,10 @@
 
 <mkmountpoint enable="1" remove="true" />
 
+<volume user="test"
+	fstype="crypt"
+	path="/dev/vg0/home-encrypted"
+	mountpoint="/home/test"
+	options="fstype=ext4" />
 
 </pam_mount>
[root@vmware175 ~]#

10. Disable SELinux. This is needed because of bug 599609.
[root@vmware175 ~]# setenforce 0
[root@vmware175 ~]# 

11. Create file in existing (unencrypted) home:
[root@vmware175 ~]# touch /home/test/x
[root@vmware175 ~]# 

12. Log in on the console and check that we've mounted that fresh (encrypted) filesystem -- the file x is not there:
vmware175 login: test
pam_mount password:
pam_mount(mount.c:64): Errors from underlying mount program:
pam_mount(mount.c:68): Device _dev_dm_2 already exists.
pam_mount(pam_mount.c:492): mount of /dev/vg0/home-encrypted failed
Las login: Wed Jul  7 16:15:26 on tty 1
-bash-4.1$ ls x
ls: cannot access x: No such file or directory

13. Logout from that test account.

14. Upgrade to the latest pam_mount from testing:
[root@vmware175 ~]# yum --enablerepo=updates-testing update pam_mount
Setting up Update Process
Resolving Dependencies
--> Running transaction check
---> Package pam_mount.i686 0:2.4-2.fc13 set to be updated
--> Processing Dependency: cryptsetup-luks-libs >= 1.1.2 for package: pam_mount-2.4-2.fc13.i686
--> Processing Dependency: libHX >= 3.4 for package: pam_mount-2.4-2.fc13.i686
--> Running transaction check
--> Processing Dependency: cryptsetup-luks-libs = 1.1.0-1.fc13 for package: cryptsetup-luks-1.1.0-1.fc13.i686
---> Package cryptsetup-luks-libs.i686 0:1.1.3-1.fc13 set to be updated
---> Package libHX.i686 0:3.4-1.fc13 set to be updated
--> Running transaction check
---> Package cryptsetup-luks.i686 0:1.1.3-1.fc13 set to be updated
--> Finished Dependency Resolution

Dependencies Resolved

================================================================================
 Package            Arch          Version                 Repository       Size
================================================================================
Updating:
 pam_mount          i686          2.4-2.fc13              updates-testing  120 k
Updating for dependencies:
 cryptsetup-luks    i686          1.1.3-1.fc13            updates-testing  70 k
 cryptsetup-luks-libs i686        1.1.3-1.fc13            updates-testing  47 k
 libHX              i686          3.4-1.fc13              updates-testing  52 k

Transaction Summary
================================================================================
Install       0 Package(s)
Upgrade       4 Package(s)

Total download size: 289 k
Is this ok [y/N]: y
Downloading Packages:
(1/4): cryptsetup-luks-1.1.3-1.fc13.i686.rpm             |  70 kB     00:00     
(2/4): cryptsetup-luks-libs-1.1.3-1.fc13.i686.rpm        |  47 kB     00:00     
(3/4): libHX-3.4-1.fc13.i686.rpm                         |  52 kB     00:00     
(4/4): pam_mount-2.4-2.fc13.i686.rpm                     | 120 kB     00:01     
--------------------------------------------------------------------------------
Total                                            79 kB/s | 289 kB     00:03     
Running rpm_check_debug
Running Transaction Test
Transaction Test Succeeded
Running Transaction
  Updating       : cryptsetup-luks-libs-1.1.3-1.fc13.i686                   1/8 
  Updating       : libHX-3.4-1.fc13.i686                                    2/8 
  Updating       : pam_mount-2.4-2.fc13.i686                                3/8 
  Updating       : cryptsetup-luks-1.1.3-1.fc13.i686                        4/8 
  Cleanup        : pam_mount-1.32-1.fc12.i686                               5/8 
  Cleanup        : cryptsetup-luks-1.1.0-1.fc13.i686                        6/8 
  Cleanup        : cryptsetup-luks-libs-1.1.0-1.fc13.i686                   7/8 
  Cleanup        : libHX-3.1-1.fc12.i686                                    8/8 

Updated:
  pam_mount.i686 0:2.4-2.fc13                                                  

Dependency Updated:
  cryptsetup-luks.i686 0:1.1.3-1.fc13 cryptsetup-luks-libs.i686 0:1.1.3-1.fc13 libHX.i686 0:3.4-1.fc13

Complete!
[root@vmware175 ~]# 

15. Log in as test again:
vmware175 login: test
pam_mount password:
pam_mount(mount.c:64): Errors from underlying mount program:
pam_mount(mount.c:68): crypt_activate_by_passphrase: File exists
pam_mount(pam_mount.c:521): mount of /dev/vg0/home-encrypted failed
Last login: Wed Jul  7 16:37:28 on tty1
-bash-4.1$

Actual results:

Error is shown on the console, and there are the same errors in /var/log/messages:
Jul  7 16:50:53 vmware175 kernel: EXT4-fs (dm-4): mounted filesystem with ordered data mode
Jul  7 16:50:53 vmware175 login: pam_mount(mount.c:64): Errors from underlying mount program:
Jul  7 16:50:53 vmware175 login: pam_mount(mount.c:68): crypt_activate_by_passphrase: File exists
Jul  7 16:50:53 vmware175 login: pam_mount(pam_mount.c:521): mount of /dev/vg0/home-encrypted failed

Expected results:

No errors, especially as the filesystem is mounted just fine.

Additional info:
Comment 1 Jan Pazdziora 2010-07-07 09:51:30 EDT
Note that from the 1.32 version of pam_mount to 2.4, the error message has changed from

pam_mount(mount.c:68): Device _dev_dm_2 already exists.

to

pam_mount(mount.c:68): crypt_activate_by_passphrase: File exists

But I believe that it's still talking about /dev/mapper/_dev_dm_2.
Comment 2 Till Maas 2010-07-07 10:32:28 EDT
Jan Engelhardt, do you know what might be wrong here?
Comment 3 Jan Engelhardt 2010-07-07 13:02:30 EDT
Enable <debug enable="1"> in pmt.conf.xml. It will dump the command to run mount.crypt. mount.crypt can then be run independently of the pam module to close in on the problem.
Comment 5 Jan Pazdziora 2010-07-18 17:09:16 EDT
Running the command shown in the debug output 

mount -t crypt -ofstype=ext4 ome/user

yields no errors and the exit status is 0.
Comment 6 Jan Pazdziora 2010-07-18 17:15:03 EDT
Created attachment 432735 [details]
Running the pam_mount thdebug enabled, I get AVC denials
Comment 7 Jan Engelhardt 2010-07-27 18:14:22 EDT
It probably makes sense to first get the AVC stuff resolved.
Comment 8 Bug Zapper 2011-06-01 10:31:54 EDT
This message is a reminder that Fedora 13 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 13.  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 WONTFIX if it remains open with a Fedora 
'version' of '13'.

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 prior to Fedora 13's end of life.

Bug Reporter: Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 13 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 please change the 'version' of this 
bug to the applicable version.  If you are unable to change the version, 
please add a comment here and someone will do it for you.

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.

The process we are following is described here: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping
Comment 9 Jan Pazdziora 2011-06-02 09:26:04 EDT
On Fedora 15 with

# rpm -q pam_mount
pam_mount-2.5-2.fc15.i686

the error is

pam_mount(mount.c:64): Errors from underlying mount program:
pam_mount(mount.c:68): crypt_activate_by_passphrase: Device or resource busy
pam_mount(pam_mount.c:521): mount of /dev/vg_vmware171/home-encrypted failed

on both login and su - login attempt, and the encrypted home is *not* mounted.
Comment 10 Jisakiel 2011-09-07 18:35:25 EDT
Not really sure if related, but I am experiencing similar issues... device gets created but not mounted. 


I believe I might have some more information on the AVC denials... On the first mount (first GDM login) it gets denied (crypt_activate_by_passphrase: Operation not permitted , yet the /dev/mapper/_dev_sdaX is created). Afterwards, the device is never closed (perhaps related to #718309 ) and therefore next manual attempts fail with "File exists". 

audit2allow shows: 

#============= local_login_t ==============
allow local_login_t var_run_t:file { read write };

#============= xdm_t ==============
allow xdm_t var_run_t:file { read write };


and the selinux troubleshooter tells me about pmvarrun trying to access my username file (I assume in /var/run/pam_mount/USER), which apparently has the policy suggested context (var_run_t). 


So it *seems* to me (selinux newbie) that pmvarrun might be running under those context (when logging as a console user and gdm user respectively) and so it would not have permission to touch /var/run/pam_mount files...  


Yet manual mounts do work, as well as console logins (even with the AVC) when I luksClose the device beforehand... :S
Comment 11 kevin.t.bowen 2011-09-27 15:46:48 EDT
I can replicate this problem as of Fedora 16 Beta RC2. Output is identical to OP's description in replication steps 14+
Comment 12 Kevin R. Page 2011-12-19 16:22:35 EST
Also on Fedora 16. Is this cosmetic for everyone else here?

Because I'm finding this is genuinely preventing a mount occuring, even if I then type the mount command as taken from pam_mount debug:


# mount -v -t auto -p0 /dev/delamare_vg0/delamare_lv_backup_cryptmount /opt/backup
mount: you didn't specify a filesystem type for /dev/mapper/delamare_vg0-delamare_lv_backup_cryptmount
       I will try type crypto_LUKS
command: 'readlink' '-fn' '/dev/mapper/delamare_vg0-delamare_lv_backup_cryptmount' 
command: 'readlink' '-fn' '/opt/backup' 
Password: 
mount.crypto_LUKS(mtcrypt.c:435): keysize=8 trunc_keysize=32
mount.crypto_LUKS(crypto-dmc.c:142): Using _dev_dm_3 as dmdevice name
crypt_activate_by_passphrase: File exists


... where /dev/mapper/_dev_dm_3 does indeed already exist. This mostly causes a problem with shared encrypted mounts (i.e. the same device mounted for multiple users sequentially or concurrently). I'm suspicious about user/mount count tracking going awry, I also see some errors about pmvarrun being unable to start /var/run/pam_mount (related to bug #656656 perhaps?)
Comment 13 Jan Engelhardt 2011-12-19 16:59:48 EST
>same device mounted for multiple users

Ah now that finally puts some sense to the "File exists" error people see.. There is no mount tracking in mount.crypt (only in pam_mount.so), though there probably should be.

Pondering on how to determine if a cryptodev has already been established.
Comment 14 Kevin R. Page 2011-12-19 18:27:58 EST
(In reply to comment #13)
> >same device mounted for multiple users
> 
> Ah now that finally puts some sense to the "File exists" error people see..
> There is no mount tracking in mount.crypt (only in pam_mount.so), though there
> probably should be.
> 
> Pondering on how to determine if a cryptodev has already been established.

Although note that, in my case, all users (apart from root, which doesn't mount any encrypted devices) have logged out. But the /dev/mapper/_dm* remain, and the mount of the shared device fails on the second log in.

But yeah, the underlying mount command seems to be unhappy at the /dev/mapper/_dm* already being there.
Comment 15 Till Maas 2012-06-20 15:40:03 EDT
Can you please test pam_mount-2.13-1.fc17 if you are already using F17? The package is in updates-testing.
Comment 16 Fedora End Of Life 2012-08-07 15:38:24 EDT
This message is a notice that Fedora 15 is now at end of life. Fedora
has stopped maintaining and issuing updates for Fedora 15. It is
Fedora's policy to close all bug reports from releases that are no
longer maintained. At this time, all open bugs with a Fedora 'version'
of '15' have been closed as WONTFIX.

(Please note: Our normal process is to give advanced warning of this
occurring, but we forgot to do that. A thousand apologies.)

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

Bug Reporter: Thank you for reporting this issue and we are sorry that
we were unable to fix it before Fedora 15 reached 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 to click on
"Clone This Bug" (top right of this page) and open it against that
version of Fedora.

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.

The process we are following is described here:
http://fedoraproject.org/wiki/BugZappers/HouseKeeping

Note You need to log in before you can comment on or make changes to this bug.