[systemd-bugs] [Bug 70214] "/usr/lib/systemd/systemd --user" process remains after logout and affects pam_mount

Fri Jan 10 04:24:25 PST 2014

https://bugs.freedesktop.org/show_bug.cgi?id=70214

Max <khaberev at gmail.com> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|RESOLVED                    |REOPENED
         Resolution|FIXED                       |---

--- Comment #6 from Max <khaberev at gmail.com> ---
Retested on Archlinux systemd-208-3
Test flow: "tst" user logs in via ssh and logs out.

No user prosesses remains after logout but the volume is still mounted.

pam_mount debug=1
Journald logs:

<login>

Jan 10 15:36:30 n102805 sshd[32375]: (pam_mount.c:365): pam_mount 2.14:
entering auth stage
Jan 10 15:36:30 n102805 sshd[32375]: Accepted password for tst from 127.0.0.1
port 43475 ssh2
Jan 10 15:36:30 n102805 sshd[32375]: (pam_mount.c:568): pam_mount 2.14:
entering session stage
Jan 10 15:36:30 n102805 sshd[32375]: (mount.c:263): Mount info: globalconf,
user=tst <volume fstyp...sh=0
Jan 10 15:36:30 n102805 sshd[32375]: (mount.c:660): Password will be sent to
helper as-is.
Jan 10 15:36:30 n102805 sshd[32375]: command: 'mount' '-p0'
'-osize=256M,uid=tst' '-ttmpfs' 'tmpfs...che'
Jan 10 15:36:30 n102805 sshd[32375]: (mount.c:68): Messages from underlying
mount program:
Jan 10 15:36:30 n102805 sshd[32375]: (mount.c:72): mount: --pass-fd is no
longer supported

***

Jan 10 15:36:30 n102805 sshd[32375]: command: 'pmvarrun' '-u' 'tst' '-o' '1'
Jan 10 15:36:30 n102805 sshd[32375]: (pam_mount.c:441): pmvarrun says login
count is 1
Jan 10 15:36:30 n102805 sshd[32375]: (pam_mount.c:660): done opening session
(ret=0)
Jan 10 15:36:30 n102805 sshd[32375]: pam_unix(sshd:session): session opened for
user tst by (uid=0)
Jan 10 15:36:30 n102805 systemd[1]: Starting user-1001.slice.
Jan 10 15:36:30 n102805 systemd[1]: Created slice user-1001.slice.
Jan 10 15:36:30 n102805 systemd[1]: Starting User Manager for 1001...
Jan 10 15:36:30 n102805 systemd[1]: Starting Session 74 of user tst.
Jan 10 15:36:30 n102805 systemd-logind[355]: New session 74 of user tst.
Jan 10 15:36:30 n102805 systemd[1]: Started Session 74 of user tst.
Jan 10 15:36:30 n102805 systemd[32402]: (pam_mount.c:568): pam_mount 2.14:
entering session stage
Jan 10 15:36:30 n102805 systemd[32402]: (pam_mount.c:173): conv->conv(...):
Conversation error
Jan 10 15:36:30 n102805 systemd[32402]: (pam_mount.c:477): warning: could not
obtain password interactively either
Jan 10 15:36:30 n102805 systemd[32402]: (mount.c:263): Mount info: globalconf,
user=tst <volume fstype="tmpfs" server="(null)" path="tmpfs"
mountpoint="/home/tst/.cache" cipher="(null)" fskeypath="(null)" fskeyc
Jan 10 15:36:30 n102805 systemd[32402]: (mount.c:624): tmpfs already seems to
be mounted at /home/tst/.cache, skipping
Jan 10 15:36:30 n102805 systemd[32402]: (pam_mount.c:173): conv->conv(...):
Conversation error
Jan 10 15:36:30 n102805 systemd[32402]: (pam_mount.c:477): warning: could not
obtain password interactively either
Jan 10 15:36:30 n102805 systemd[32402]: command: 'pmvarrun' '-u' 'tst' '-o' '1'
Jan 10 15:36:30 n102805 systemd[32402]: (pam_mount.c:568): pam_mount 2.14:
entering session stage
Jan 10 15:36:30 n102805 systemd[32402]: (pam_mount.c:173): conv->conv(...):
Conversation error
Jan 10 15:36:30 n102805 systemd[32402]: (pam_mount.c:477): warning: could not
obtain password interactively either
Jan 10 15:36:30 n102805 systemd[32402]: (mount.c:263): Mount info: globalconf,
user=tst <volume fstype="tmpfs" server="(null)" path="tmpfs"
mountpoint="/home/tst/.cache" cipher="(null)" fskeypath="(null)" fskeyc
Jan 10 15:36:30 n102805 systemd[32402]: (mount.c:624): tmpfs already seems to
be mounted at /home/tst/.cache, skipping
Jan 10 15:36:30 n102805 systemd[32402]: (pam_mount.c:173): conv->conv(...):
Conversation error
Jan 10 15:36:30 n102805 systemd[32402]: (pam_mount.c:477): warning: could not
obtain password interactively either
Jan 10 15:36:30 n102805 systemd[32402]: command: 'pmvarrun' '-u' 'tst' '-o' '1'
Jan 10 15:36:30 n102805 systemd[32402]: (pmvarrun.c:254): parsed count value 1
Jan 10 15:36:30 n102805 systemd[32402]: (pam_mount.c:441): pmvarrun says login
count is 2
Jan 10 15:36:30 n102805 systemd[32402]: (pam_mount.c:660): done opening session
(ret=0)
Jan 10 15:36:30 n102805 systemd[32402]: pam_unix(systemd-user:session): session
opened for user tst by (uid=0)
Jan 10 15:36:30 n102805 systemd[32402]: (pam_mount.c:441): pmvarrun says login
count is 2
Jan 10 15:36:30 n102805 systemd[32402]: (pam_mount.c:660): done opening session
(ret=0)
Jan 10 15:36:30 n102805 systemd[32402]: Failed to open private bus connection:
Failed to connect to socket /run/user/1001/dbus/user_bus_socket: No such file
or directory
Jan 10 15:36:30 n102805 systemd[32402]: Mounted /sys/kernel/config.
Jan 10 15:36:30 n102805 systemd[32402]: Mounted /sys/fs/fuse/connections.
Jan 10 15:36:30 n102805 systemd[32402]: Stopped target Sound Card.
Jan 10 15:36:30 n102805 systemd[32402]: Starting Default.
Jan 10 15:36:30 n102805 systemd[32402]: Reached target Default.
Jan 10 15:36:30 n102805 systemd[32402]: Startup finished in 11ms.
Jan 10 15:36:30 n102805 systemd[1]: Started User Manager for 1001.

<logout>

Jan 10 15:38:13 n102805 sshd[32404]: Received disconnect from 127.0.0.1: 11:
disconnected by user
Jan 10 15:38:13 n102805 sshd[32375]: (pam_mount.c:706): received order to close
things
Jan 10 15:38:13 n102805 sshd[32375]: command: 'pmvarrun' '-u' 'tst' '-o' '-1'
Jan 10 15:38:13 n102805 sshd[32375]: (pam_mount.c:441): pmvarrun says login
count is 1
Jan 10 15:38:13 n102805 sshd[32375]: (pam_mount.c:735): tst seems to have other
remaining open sessions
Jan 10 15:38:13 n102805 sshd[32375]: (pam_mount.c:743): pam_mount execution
complete
Jan 10 15:38:13 n102805 sshd[32375]: pam_unix(sshd:session): session closed for
user tst
Jan 10 15:38:13 n102805 sshd[32375]: (pam_mount.c:116): Clean global config (0)
Jan 10 15:38:13 n102805 sshd[32375]: (pam_mount.c:133): clean system
authtok=0x1cc1a90 (0)
Jan 10 15:38:13 n102805 systemd-logind[355]: Removed session 74.
Jan 10 15:38:13 n102805 systemd[1]: Stopping User Manager for 1001...
Jan 10 15:38:13 n102805 systemd[32408]: (pam_mount.c:116): Clean global config
(1073741824)
Jan 10 15:38:13 n102805 systemd[32402]: (pam_mount.c:116): Clean global config
(1073741824)
Jan 10 15:38:13 n102805 systemd[32402]: Stopping Default.
Jan 10 15:38:13 n102805 systemd[32402]: Stopped target Default.
Jan 10 15:38:13 n102805 systemd[32402]: Starting Shutdown.
Jan 10 15:38:13 n102805 systemd[32402]: Reached target Shutdown.
Jan 10 15:38:13 n102805 systemd[32402]: Starting Exit the Session...
Jan 10 15:38:13 n102805 systemd[1]: Stopped User Manager for 1001.
Jan 10 15:38:13 n102805 systemd[1]: Stopping user-1001.slice.
Jan 10 15:38:13 n102805 systemd[1]: Removed slice user-1001.slice.

On login:
The sshd mounts the volume and increases /var/run/pam_mount/tst by '1'.
The systemd makes the same things. Volume is mounted already and
/var/run/pam_mount/tst is increased by '1' again. Now it is equal to '2'.
(Duplicated logs from systemd/pam_mount. Is it a problem?)

On logout:
The sshd closes session. The pam_sm_close_session() (pam_mount.c) function is
called. It decreases /var/run/pam_mount/tst by '-1'. But the value is still
positive ('1') and no unmounting is performed.
The systemd closes session but the pam_sm_close_session() function is not
called and the volume remains mounted.

-- 
You are receiving this mail because:
You are the QA Contact for the bug.
You are the assignee for the bug.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freedesktop.org/archives/systemd-bugs/attachments/20140110/32ce3ea1/attachment.html>