Subject: Re: pam-mount: samba shares not unmounted after logout with message "$USER seems to have other remaining open sessions"

Paul Leiber (HE12026-03-01):

What I noticed in the pam-mount logs was a line saying that "user A seems to have other remaining open sessions".

I would suggest to check:

- if the user still has processes running after they logged out;

- the ?session started? / ?session ended? (stopped?) in the systemd
logs.

Regards,

--
Nicolas George

--- PyGate Linux v1.5.12
* Origin: Dragon's Lair, PyGate NNTP<>Fido Gate (3:633/10)

Subject: Re: pam-mount: samba shares not unmounted after logout with message "$USER seems to have other remaining open sessions"

Am 01.03.26 um 21:28 schrieb Nicolas George:

Paul Leiber (HE12026-03-01):

What I noticed in the pam-mount logs was a line saying that "user A seems to >> have other remaining open sessions".

I would suggest to check:

- if the user still has processes running after they logged out;

There are no open processes of the user after logout. (The line <logout wait="2000" hup="0" term="1" kill="1"/> should have taken care of that
anyway, if I am not mistaken.)

- the ?session started? / ?session ended? (stopped?) in the systemd
logs.

There are log entries indicating start of session and temination of
session for the user, but nothing that seems incorrect.

I still think that the problem lies with pmvarrun not being called to
decrease the entry for a user at logout. I found a bug report [1] where pmvarrun is called twice at login, but only once at logout, resulting in
too high values in /var/run/pam_mount/username. However, the root cause
seems to be different than in my case, where the number is correct after login, but incorrect after logout.

Here is an excerpt of my journal:

Login:
M„r 02 10:22:40 computer login[13770]: pam_krb5(login:auth): user xxx authenticated as xxx@xxx
M„r 02 10:22:40 computer login[13770]: pam_winbind(login:account): user
'xxx' granted access
M„r 02 10:22:40 computer login[13770]: pam_unix(login:session): session
opened for user xxx(uid=xxx) by xxx(uid=0)
M„r 02 10:22:40 computer login[13770]: (pam_mount.c:568): pam_mount
2.20: entering session stage
M„r 02 10:22:44 computer login[13770]: (mount.c:264): Mount info:
globalconf, user=xxx <volume fstype="cifs" server="server" path="scans" mountpoint="/home/xxx/Scans" cipher="(null)" fskeypath="(null)" fskeycipher="(null)" fskeyhash="(null)" header="(n>
M„r 02 10:22:44 computer login[13770]: (mount.c:636): scans already
seems to be mounted at /home/xxx/Scans, skipping
M„r 02 10:22:44 computer login[13770]: command: '/usr/sbin/pmvarrun'
'-u' 'xxx'
M„r 02 10:22:44 computer login[13770]: (pam_mount.c:441): pmvarrun says
login count is 17
M„r 02 10:22:44 computer login[13770]: (pam_mount.c:660): done opening
session (ret=0)


Logout:
M„r 02 10:22:44 computer login[14845]: (pam_mount.c:133): clean system authtok=0x557a08b07140 (1073741824)
M„r 02 10:22:44 computer login[14845]: (pam_mount.c:116): Clean global
config (1073741824)
M„r 02 10:22:47 computer login[13770]: pam_unix(login:session): session
closed for user xxx
M„r 02 10:22:47 computer login[13770]: (pam_mount.c:706): received order
to close things
M„r 02 10:22:47 computer login[13770]: command: '/usr/sbin/pmvarrun'
'-u' 'xxx'
M„r 02 10:22:47 computer login[13770]: (pam_mount.c:441): pmvarrun says
login count is 18
M„r 02 10:22:47 computer login[13770]: (pam_mount.c:734): xxx seems to
have other remaining open sessions
M„r 02 10:22:47 computer login[13770]: (pam_mount.c:743): pam_mount
execution complete
M„r 02 10:22:47 computer login[13770]: (pam_mount.c:133): clean system authtok=0x557a08b07140 (0)
M„r 02 10:22:47 computer login[13770]: (pam_mount.c:116): Clean global
config (0)

After some trials, the login count is already at 18. Also, the volumes
are already had been mounted, hence pam_mount is skipping the mount.


[1] https://bugs.freedesktop.org/show_bug.cgi?__goaway_challenge=meta-refresh&__goaway_id=d92d5d6bfe867e15e4f47d4f0f2253b2&__goaway_referer=https%3A%2F%2Fwww.google.com%2F&id=70214

--- PyGate Linux v1.5.12
* Origin: Dragon's Lair, PyGate NNTP<>Fido Gate (3:633/10)

Subject: Re: pam-mount: samba shares not unmounted after logout with message "$USER seems to have other remaining open sessions"

Paul Leiber (HE12026-03-02):

There are no open processes of the user after logout. (The line <logout wait="2000" hup="0" term="1" kill="1"/> should have taken care of that anyway, if I am not mistaken.)

You might think that. But I have a slew of computers where KDE, and
GNOME before that, leaves process lingering long after the user has
logged out, keeping the session nominally open. And filling up /var
because we log running process regularly.

It is on Ubuntu 22, it does not seem to happen on Trixie, but I have not
yet deployed it.

I still think that the problem lies with pmvarrun not being called to decrease the entry for a user at logout.

I have slightly different diagnostic. See below.

Here is an excerpt of my journal:

Two pieces of advice about it:

- Avoid localizing the dates in your journal, especially if it causes
non-ASCII characters to be present. If you got that from journalctl,
then it was localized only when printing, so you need to worry about
it only when sharing excerpts like that.

As a general principle, localizing system messages means you can get
confusing information from the message itself or from its
localization, not just from the message itself.

- Avoid line-rewrapping on log messages. I had to
`%s/> M„r.*\zs\n> \ze[^M]/` multiple times to read it properly.

M„r 02 10:22:44 computer login[13770]: command: '/usr/sbin/pmvarrun' '-u' 'xxx'
M„r 02 10:22:44 computer login[13770]: (pam_mount.c:441): pmvarrun says login count is 17

M„r 02 10:22:47 computer login[13770]: command: '/usr/sbin/pmvarrun' '-u' 'xxx'
M„r 02 10:22:47 computer login[13770]: (pam_mount.c:441): pmvarrun says login count is 18

What I am seeing is pam called from login calling pmvarrun twice the
same way with options `-u xxx`.

But in the source code, I see:

modify_pm_count(&Config, Config.user, "1");

in pam_sm_open_session() and

if (modify_pm_count(&Config, Config.user, "-1") > 0)

in pam_sm_close_session(), and it connects to:

{CMD_PMVARRUN, NULL, {"pmvarrun", "-u", "%(USER)", "-o", "%(OPERATION)", NULL}},

So what we should be seeing is:

command: '/usr/sbin/pmvarrun' '-u' 'xxx' '-o' '1'
command: '/usr/sbin/pmvarrun' '-u' 'xxx' '-o' '-1'

If pam-mount forgets the -o option, then it defaults to 1, and it would
explain the mount count increasing each time.

But it needs to be confirmed, because it also could just be a bug /
misfeature of the code that logs the command. There is an easy way to do
it: just before you valid your password, from another terminal, run as
root:

strace -f -s 10000 -e execve -p $(pidof login | tr ' ' ,) -o /tmp/strace_login

Translation:
strace ? dump the system calls done by processes;
-f ? including subprocesses after a fork;
-s 10000 ? with a very high limit to truncate strings and lists
-e execve ? only the system call that starts a new process
-p ? ? trace these processes
$(pidof login ?) ? theses processes = the login process
| tr ' ' , ? replace spaces with commas in case there are several
-o ? save the output in that file

Then you look at the file to see how pmvarrun is invoked.

If you see it invoked with the -o option, then it is a false lead and
the issue is somewhere else.

If you see it invoked as shown in the logs, then we have surrounded the
issue, and somebody needs to debug the source code to see where the -o
option gets lost. (But we have reached the limit of the investigating
that I was willing to do.)

Regards,

--
Nicolas George

--- PyGate Linux v1.5.12
* Origin: Dragon's Lair, PyGate NNTP<>Fido Gate (3:633/10)

Subject: Re: pam-mount: samba shares not unmounted after logout with message "$USER seems to have other remaining open sessions"

Am 02.03.26 um 12:52 schrieb Nicolas George:

Paul Leiber (HE12026-03-02):

There are no open processes of the user after logout. (The line <logout
wait="2000" hup="0" term="1" kill="1"/> should have taken care of that
anyway, if I am not mistaken.)

You might think that. But I have a slew of computers where KDE, and
GNOME before that, leaves process lingering long after the user has
logged out, keeping the session nominally open. And filling up /var
because we log running process regularly.

I checked with ps -u username -U username after logging out, and it gave an empty result. Is there something else I could check?

It is on Ubuntu 22, it does not seem to happen on Trixie, but I have not
yet deployed it.

I still think that the problem lies with pmvarrun not being called to
decrease the entry for a user at logout.

I have slightly different diagnostic. See below.

Here is an excerpt of my journal:

Two pieces of advice about it:

- Avoid localizing the dates in your journal, especially if it causes
non-ASCII characters to be present. If you got that from journalctl,
then it was localized only when printing, so you need to worry about
it only when sharing excerpts like that.

Thank you for the advice. I'll try to find a way to not localize the date in the future.

As a general principle, localizing system messages means you can get
confusing information from the message itself or from its
localization, not just from the message itself.
- Avoid line-rewrapping on log messages. I had to
`%s/> M„r.*\zs\n> \ze[^M]/` multiple times to read it properly.

I think this was Thunderbird, I think I have switched off line wrapping now.

M„r 02 10:22:44 computer login[13770]: command: '/usr/sbin/pmvarrun' '-u' 'xxx'
M„r 02 10:22:44 computer login[13770]: (pam_mount.c:441): pmvarrun says login count is 17
M„r 02 10:22:47 computer login[13770]: command: '/usr/sbin/pmvarrun' '-u' 'xxx'
M„r 02 10:22:47 computer login[13770]: (pam_mount.c:441): pmvarrun says login count is 18

What I am seeing is pam called from login calling pmvarrun twice the
same way with options `-u xxx`.

But in the source code, I see:

modify_pm_count(&Config, Config.user, "1");

in pam_sm_open_session() and

if (modify_pm_count(&Config, Config.user, "-1") > 0)

in pam_sm_close_session(), and it connects to:

{CMD_PMVARRUN, NULL, {"pmvarrun", "-u", "%(USER)", "-o", "%(OPERATION)", NULL}},

So what we should be seeing is:

command: '/usr/sbin/pmvarrun' '-u' 'xxx' '-o' '1'
command: '/usr/sbin/pmvarrun' '-u' 'xxx' '-o' '-1'

If pam-mount forgets the -o option, then it defaults to 1, and it would explain the mount count increasing each time.

But it needs to be confirmed, because it also could just be a bug / misfeature of the code that logs the command. There is an easy way to do
it: just before you valid your password, from another terminal, run as
root:

strace -f -s 10000 -e execve -p $(pidof login | tr ' ' ,) -o /tmp/strace_login

Translation:
strace ? dump the system calls done by processes;
-f ? including subprocesses after a fork;
-s 10000 ? with a very high limit to truncate strings and lists
-e execve ? only the system call that starts a new process
-p ? ? trace these processes
$(pidof login ?) ? theses processes = the login process
| tr ' ' , ? replace spaces with commas in case there are several
-o ? save the output in that file

Then you look at the file to see how pmvarrun is invoked.

For login:

9414ÿ execve("/usr/sbin/pmvarrun", ["/usr/sbin/pmvarrun", "-u", "xxx"], 0x55ec223822c0 /* 11 vars */) = 0

For logout:

9483ÿ execve("/usr/sbin/pmvarrun", ["/usr/sbin/pmvarrun", "-u", "xxx"], 0x55ec223822c0 /* 17 vars */) = 0

If you see it invoked with the -o option, then it is a false lead and
the issue is somewhere else.

If you see it invoked as shown in the logs, then we have surrounded the issue, and somebody needs to debug the source code to see where the -o
option gets lost. (But we have reached the limit of the investigating
that I was willing to do.)

The output matches the second description. I am not sure if I will be able to find the bug myself due to my limited knowledge, we'll see. In any case, would an appropriate next step be filing a bug report in the Debian bugtracker?

Thanks for your efforts, Nicolas, you helped me a lot!

Paul

--- PyGate Linux v1.5.12
* Origin: Dragon's Lair, PyGate NNTP<>Fido Gate (3:633/10)

Subject: Re: pam-mount: samba shares not unmounted after logout with message "$USER seems to have other remaining open sessions"

Am 02.03.26 um 14:03 schrieb Paul Leiber:

Am 02.03.26 um 12:52 schrieb Nicolas George:

Paul Leiber (HE12026-03-02):

There are no open processes of the user after logout. (The line <logout
wait="2000" hup="0" term="1" kill="1"/> should have taken care of that
anyway, if I am not mistaken.)

You might think that. But I have a slew of computers where KDE, and
GNOME before that, leaves process lingering long after the user has
logged out, keeping the session nominally open. And filling up /var
because we log running process regularly.

I checked with ps -u username -U username after logging out, and it gave an empty result. Is there something else I could check?

It is on Ubuntu 22, it does not seem to happen on Trixie, but I have not
yet deployed it.

I still think that the problem lies with pmvarrun not being called to
decrease the entry for a user at logout.

I have slightly different diagnostic. See below.

Here is an excerpt of my journal:

Two pieces of advice about it:

- Avoid localizing the dates in your journal, especially if it causes
ÿÿ non-ASCII characters to be present. If you got that from journalctl,
ÿÿ then it was localized only when printing, so you need to worry about
ÿÿ it only when sharing excerpts like that.

Thank you for the advice. I'll try to find a way to not localize the date in the future.

ÿÿ As a general principle, localizing system messages means you can get
ÿÿ confusing information from the message itself or from its
ÿÿ localization, not just from the message itself.
- Avoid line-rewrapping on log messages. I had to
ÿÿ `%s/> M„r.*\zs\n> \ze[^M]/` multiple times to read it properly.

I think this was Thunderbird, I think I have switched off line wrapping now.

M„r 02 10:22:44 computer login[13770]: command: '/usr/sbin/pmvarrun' '-u' 'xxx'
M„r 02 10:22:44 computer login[13770]: (pam_mount.c:441): pmvarrun says login count is 17
M„r 02 10:22:47 computer login[13770]: command: '/usr/sbin/pmvarrun' '-u' 'xxx'
M„r 02 10:22:47 computer login[13770]: (pam_mount.c:441): pmvarrun says login count is 18

What I am seeing is pam called from login calling pmvarrun twice the
same way with options `-u xxx`.

But in the source code, I see:

ÿÿÿÿmodify_pm_count(&Config, Config.user, "1");

in pam_sm_open_session() and

ÿÿÿÿif (modify_pm_count(&Config, Config.user, "-1") > 0)

in pam_sm_close_session(), and it connects to:

ÿÿÿÿÿÿÿÿ {CMD_PMVARRUN,ÿÿ NULL,ÿÿÿÿ {"pmvarrun", "-u", "%(USER)", "-o", "%(OPERATION)", NULL}},

So what we should be seeing is:

ÿÿÿÿcommand: '/usr/sbin/pmvarrun' '-u' 'xxx' '-o' '1'
ÿÿÿÿcommand: '/usr/sbin/pmvarrun' '-u' 'xxx' '-o' '-1'

If pam-mount forgets the -o option, then it defaults to 1, and it would
explain the mount count increasing each time.

But it needs to be confirmed, because it also could just be a bug /
misfeature of the code that logs the command. There is an easy way to do
it: just before you valid your password, from another terminal, run as
root:

strace -f -s 10000 -e execve -p $(pidof login | tr ' ' ,) -o /tmp/strace_login

Translation:
strace ? dump the system calls done by processes;
-f ? including subprocesses after a fork;
-s 10000 ? with a very high limit to truncate strings and lists
-e execve ? only the system call that starts a new process
-p ? ? trace these processes
$(pidof login ?) ? theses processes = the login process
| tr ' ' , ? replace spaces with commas in case there are several
-o ? save the output in that file

Then you look at the file to see how pmvarrun is invoked.

For login:

9414ÿ execve("/usr/sbin/pmvarrun", ["/usr/sbin/pmvarrun", "-u", "xxx"], 0x55ec223822c0 /* 11 vars */) = 0

For logout:

9483ÿ execve("/usr/sbin/pmvarrun", ["/usr/sbin/pmvarrun", "-u", "xxx"], 0x55ec223822c0 /* 17 vars */) = 0

If you see it invoked with the -o option, then it is a false lead and
the issue is somewhere else.

If you see it invoked as shown in the logs, then we have surrounded the
issue, and somebody needs to debug the source code to see where the -o
option gets lost. (But we have reached the limit of the investigating
that I was willing to do.)

The output matches the second description. I am not sure if I will be able to find the bug myself due to my limited knowledge, we'll see. In any case, would an appropriate next step be filing a bug report in the Debian bugtracker?

Thanks for your efforts, Nicolas, you helped me a lot!

Paul

For future reference, here is the bug report:

https://bugs.debian.org/cgi-bin/bugreport.cgi?bug=1129584

--- PyGate Linux v1.5.12
* Origin: Dragon's Lair, PyGate NNTP<>Fido Gate (3:633/10)