[systemd-devel] pam_systemd.so and su

[Mike Kazantsev]

It's probably my fault that MUAs try to answer to me directly, since
I'm reading list from gmane but posting thru mail, but please be sure
tocheck the "To:" line next time, otherwise I might be the only one to
read the message.


On Mon, 19 Mar 2012 02:40:24 -0600
Canek Peláez Valdés <caneko at gmail.com> wrote:

> On Mon, Mar 19, 2012 at 2:20 AM, Mike Kazantsev <mk.fraggod at gmail.com> wrote:
> > On Sun, 18 Mar 2012 18:26:53 -0600
> > Canek Peláez Valdés <caneko at gmail.com> wrote:
> >
> >> On Sun, Mar 18, 2012 at 5:43 PM, Kok, Auke-jan H
> >> <auke-jan.h.kok at intel.com> wrote:
> >> > On Sun, Mar 18, 2012 at 3:08 PM, Canek Peláez Valdés <caneko at gmail.com> wrote:
> >> >>
> >> >> When I use su to become root, after logout the following message appears:
> >> >>
> >> >> ...killed.
> >> >>
> >
> > I can't recall ever facing that "message", so maybe you can explain
> > what does it mean?
> > Are the long-running processes you've started from "su" get killed?
> > ...along with su itself, which produces that message?
> 
> No, my su session works flawlessly, but when I logout the su session,
> the console gets unresponsive for two or three minutes, and then the
> "...killed." message appears.
> 

Hm, ok, if I'm reading that right, shell that invokes su gets killed
along with the su itself.


> > Also, maybe that is similar to the past logind issue?
> > http://thread.gmane.org/gmane.comp.sysutils.systemd.devel/4370/
> 
> It sounds similar to the second to last message in the thread.
> 

Maybe it'd be a good idea to join discussion there.
Judging by the number of posts, there's probably a bug opened
somewhere, and maybe even some patches floating around.


> >> >> So, two questions:
> >> >>
> >> >> 1. Why is my session being killed at logout time?
> >> >>
> >> >> 2. The pam_systemd.so is really necessary? The "...killed." message
> >> >> appears after two or three seconds, and it's slightly annoying.
> >> >
> >> > please read `man pam_systemd`...
> >>
> >> OK, done. Still doesn't understand. The kill-session-processes option
> >> is not set, so it should default to "no", right? Also, my
> >> /etc/systemd/systemd-logind.conf has no options set, in particular
> >> KillOnlyUsers is not set, and therefore is should default to "no",
> >> right? So, again, if both options are no, what is killing my session
> >> at logout time?
> >>
> >
> > I can suggest to check what exactly kills the processes by connecting
> > strace to:
> >
> >  a) systemd itself ("strace -s65535 -f -p 1 2>&1 | grep kill")
> >  b) systemd-logind
> >  c) su process (*after* it was started)
> >
> > I'm suggesting this because systemd can kill leftover pids when
> > cleaning up controller hierarchies, logind can kill the session,
> > pam_systemd seem to have a kill-parameter and probably can do it by
> > itself as well.
> >
> > When debugging somewhat similar issue in the past, I've wasted a lot of
> > time mistakingly assuming that it's either logind or pam_systemd that
> > does the killing, while in fact it was totally unrelated to
> > kill-switches in both of them (more details can be found here:
> > http://goo.gl/S5ZLO).
> 
> I did a "su -", and run strace on the pid of the su process. Then I
> logged out from the su session, and this got printed:
> 
> # strace -p5207
> Process 5207 attached - interrupt to quit
> wait4(-1, [{WIFEXITED(s) && WEXITSTATUS(s) == 0}], WSTOPPED, NULL) = 5208
> getuid()                                = 0
> time([1332145846])                      = 1332145846
> socket(PF_FILE, SOCK_DGRAM|SOCK_CLOEXEC, 0) = 3
> connect(3, {sa_family=AF_FILE, path="/dev/log"}, 110) = 0
> sendto(3, "<86>Mar 19 02:30:46 su[5207]: pa"..., 80, MSG_NOSIGNAL, NULL, 0) = 80

Is it some error printed to syslog?
"-s65535" strace flag suggested above would've shown the full message.


> close(6)                                = 0
> munmap(0x7f078e6ac000, 2101296)         = 0
> --- {si_signo=SIGTERM, si_code=SI_USER, si_pid=124, si_uid=0,
> si_value={int=238059712, ptr=0xe3080c0}} (Terminated) ---

That's the pid of su receiving SIGTERM, so obviously something else
(systemd or systemd-logind) sends it, so I suggest you trace these.


> rt_sigreturn(0xf)                       = 0
> munmap(0x7f078e4a9000, 2105456)         = 0
> munmap(0x7f078e2a5000, 2109640)         = 0
> munmap(0x7f078e08d000, 2192064)         = 0
> munmap(0x7f078de56000, 2318784)         = 0
> munmap(0x7f078dc54000, 2101296)         = 0
> munmap(0x7f078da4f000, 2113840)         = 0
> munmap(0x7f078d843000, 2144968)         = 0
> munmap(0x7f078d63e000, 2114088)         = 0
> munmap(0x7f078d43b000, 2105528)         = 0
> munmap(0x7f078d201000, 2333032)         = 0
> munmap(0x7f078cbd7000, 2113872)         = 0
> munmap(0x7f078c9d2000, 2114008)         = 0
> munmap(0x7f078c7d0000, 2101280)         = 0
> rt_sigprocmask(SIG_BLOCK, [CHLD], ~[KILL ALRM TERM STOP RTMIN RT_1], 8) = 0
> nanosleep({2, 0}, 0x7fff1a115aa0)       = 0
> kill(5208, SIGKILL)                     = -1 ESRCH (No such process)

You can probably check what that pid is, but I bet it's the shell that
su runs (especially since it's pid is su+1), so that's su terminating
whatever runs under it, but you've already logged out, hence "No such
process".


> write(2, " ...killed.\n", 12)           = 12

Probably su telling that something has terminated it and it killed
whatever command you ran there.


> exit_group(-1)                          = ?
> Process 5207 detached
> 
> That's the message all right, the "...killed.\n" one. I don't know how
> to read strace's output. Any light shed on this will be really
> appreciated.
> 
> Regards.

I'd say it looks consistent with what's discussed in
http://thread.gmane.org/gmane.comp.sysutils.systemd.devel/4370/ thread,
but to be extra sure, I'd suggest confirming that it's logind that
kills su (same strace tool should help) and iirc the fact that stuff
like sudo closed pam session too early turned out to be a bug in sudo
itself, so maybe there are fixed versions or bugs opened for su as well.

Also, if logind tries to kill session leader process when session ends,
and that turns out to be the origin of that SIGTERM, maybe there's some
way to disable that behavior as a workaround?


-- 
Mike Kazantsev // fraggod.net
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 198 bytes
Desc: not available
URL: <http://lists.freedesktop.org/archives/systemd-devel/attachments/20120319/34da7440/attachment-0001.pgp>