[systemd-devel] systemd-logind bug in systemd v35

[Albert Strasheim]

Hello all

I think we've found a bug in systemd-logind with systemd v35
(specifically, systemd-35-1.fc16.x86_64.rpm).

After a few thousand ssh logins, we start seeing stuff like this in
/var/log/secure:

Oct  4 13:34:29 next-10-221-0-2 sshd[568]: pam_systemd(sshd:session):
Failed to create session: Did not receive a reply. Possible causes
include: the remote application did not send a reply, the message bus
security policy blocked the reply, the reply timeout expired, or the
network connection was broken.
Oct  4 13:34:29 next-10-221-0-2 sshd[568]: pam_unix(sshd:session):
session opened for user root by (uid=0)
Oct  4 13:34:30 next-10-221-0-2 sshd[621]: pam_systemd(sshd:session):
Failed to create session: Did not receive a reply. Possible causes
include: the remote application did not send a reply, the message bus
security policy blocked the reply, the reply timeout expired, or the
network connection was broken.
Oct  4 13:34:30 next-10-221-0-2 sshd[621]: pam_unix(sshd:session):
session opened for user root by (uid=0)
Oct  4 13:34:31 next-10-221-0-2 sshd[1451]: Accepted password for root
from 10.221.255.254 port 41899 ssh2

and strace on systemd-logind produces this:

stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
sendmsg(3, {msg_name(0)=NULL, msg_iov(5)=[{"<27>", 4}, {"Oct  4
13:37:35 ", 16}, {"systemd-logind", 14}, {"[2169]: ", 8}, {"Failed to
save user data for root: Too many open files", 54}], msg_controllen=0,
msg_flags=0}, MSG_NOSIGNAL) = 96
sendmsg(8, {msg_name(0)=NULL, msg_iov(2)=[{"l\4\1\1=\0\0\0?\333
\3h\0\0\0\1\1o\0\27\0\0\0/org/freedesktop/login1\0\2\1s\0\36\0\0\0org.freedesktop.login1.Manager\0\0\3\1s\0\n\0\0\0SessionNew\0\0\0\0\0\0\10\1g\0\2so\0",
120}, {"\10\0\0\0c6239507\0\0\0\0(\0\0\0/org/freedesktop/login1/session/c6239507\0",
61}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 181
sendmsg(8, {msg_name(0)=NULL, msg_iov(2)=[{"l\4\1\0019\0\0\0@\333
\3~\0\0\0\1\1o\0\36\0\0\0/org/freedesktop/login1/user/0\0\0\2\1s\0\37\0\0\0org.freedesktop.DBus.Properties\0\3\1s\0\21\0\0\0PropertiesChanged\0\0\0\0\0\0\0\10\1g\0\10sa{sv}as\0\0\0",
144}, {"\33\0\0\0org.freedesktop.login1.User\0\0\0\0\0\0\0\0\0\r\0\0\0\10\0\0\0Sessions\0",
57}], msg_controllen=0, msg_flags=0}, MSG_NOSIGNAL) = 201
fcntl(1023, F_DUPFD_CLOEXEC, 3)         = -1 EMFILE (Too many open files)
close(1023)                             = 0

Looks like systemd-logind isn't closing all its file descriptors under
some circumstances.

Regards

Albert