Arch Linux

Please read this before reporting a bug:
https://wiki.archlinux.org/title/Bug_reporting_guidelines

Do NOT report bugs when a package is just outdated, or it is in the AUR. Use the 'flag out of date' link on the package page, or the Mailing List.

REPEAT: Do NOT report bugs for outdated packages!
Tasklist

FS#42546 - [systemd] Unable to Open systemd --user Session: pam_systemd connection times out repeatedly

Attached to Project: Arch Linux
Opened by Alexander Stein (ajstein) - Saturday, 25 October 2014, 10:07 GMT
Last edited by Dave Reisner (falconindy) - Sunday, 22 March 2015, 15:11 GMT
Task Type Bug Report
Category Packages: Core
Status Closed
Assigned To Thomas Bächler (brain0)
Dave Reisner (falconindy)
Tom Gundersen (tomegun)
Architecture All
Severity Low
Priority Normal
Reported Version
Due in Version Undecided
Due Date Undecided
Percent Complete 100%
Votes 0
Private No

Details

Description:

It appears after running a series of updates on 22 October 2014 (see attached pacman log), I am no longer able to get a functional systemd --user session. Foolishly or not, I have continued to check pacman and make sure I am up to date. Nonetheless, after login on tty1 (my default) there is a long delay. Checking the journal, I always see the following.

Oct 22 18:28:34 mbp62 login[894]: pam_systemd(login:session): pam-systemd initializing
Oct 22 18:28:34 mbp62 login[894]: pam_systemd(login:session): Asking logind to create session: uid=1000 pid=894 service=login type=tty class=user desktop= seat= vtnr=0 tty=tty1 display= remote=no remote_user= remote_host=
Oct 22 18:28:34 mbp62 systemd[1059]: pam_systemd(systemd-user:session): pam-systemd initializing
Oct 22 18:28:59 mbp62 login[894]: pam_systemd(login:session): Failed to create session: Connection timed out

I have tried adding debug flags to /etc/pam.d/ after reading the man pages, but I cannot get further information. I am not sure how to troubleshoot further. I have read only a few BBS postings and one bug report where you recommended cleaning the system. I am not sure if it is the same issue or not yet.

Additional info:
* package version(s)

http://dl.il5.in/pacman.log

* config and/or log files etc.

The last month or two of /usr/bin/login messages showing this pattern crop up starting 22 October.

http://dl.il5.in/journal.login.failures.log

My full journal from systemd for this boot.

http://dl.il5.in/journal.this.boot.log

Steps to reproduce:

1 - Boot computer
2 - Unlock dmcrypt/luks disks
3 - Wait for boot to complete
4 - Login with non-root user on tty1 (my default)
5 - Switch to tty12 and watch journal log on this terminal (per my settings)
6 - Notice error
7 - Observe my terminal sessions report IPC/Dbus errors because last bashrc command systemctl --user import-environment fail.

NOTE: I inquired about this on BBS (https://bbs.archlinux.org/viewtopic.php?pid=1468535#p1468535) and IRC and no one seemed able to help me with this. I apologize in advance if this is a foolish configuration error.
This task depends upon

Closed by  Dave Reisner (falconindy)
Sunday, 22 March 2015, 15:11 GMT
Reason for closing:  No response
Additional comments about closing:  Not likely to be a packaging problem. The user manager still has some warts until kdbus is available.
Comment by Alexander Stein (ajstein) - Saturday, 25 October 2014, 10:22 GMT
Please excuse the sloppy ticket, but I forgot to add /etc/systemd/ and ~/.config/systemd configuration, if that will help.

http://dl.il5.in/etc.systemd.tar.xz

http://dl.il5.in/systemd.user.configs.xz

I have tried with and without loginctl enable-linger username and disable-linger. I was using enable-linger as this bug happened, and then I turned it off as part of testing and this did not impact the remaining timeout problem.
Comment by Dave Reisner (falconindy) - Saturday, 25 October 2014, 15:40 GMT
Seems like logind isn't responding (or not running). You'll need to debug why that is. You can install debug symbols from my repository:

[falconindy]
Server = http://repo.falconindy.com/$repo/os/$arch

And then attach to it with gdb and get a backtrace.
Comment by Alexander Stein (ajstein) - Saturday, 25 October 2014, 16:42 GMT
Ok. Will do. I just installed falconindy/systemd-debug. I have used gdb sparingly over the years. So I attached gdb to logind (PID 537 on that boot) and just ran backtrace (or bt rather), and what I got is quite short.

(gdb) bt
#0 0x00007f843083a9d3 in __epoll_wait_nocancel () from /usr/lib/libc.so.6
#1 0x00007f843138833d in sd_event_run (e=0x7f8432c7f240, timeout=<optimized out>) at src/libsystemd/sd-event/sd-event.c:2262
#2 0x00007f8431352c32 in manager_run (m=0x7f8432c7e010) at src/login/logind.c:1162
#3 main (argc=<optimized out>, argv=<optimized out>) at src/login/logind.c:1223


How do I get the full backtrace, and log it to a file to send to you better yet?
Comment by Alexander Stein (ajstein) - Saturday, 25 October 2014, 16:45 GMT
So also I noticed this popping up in the journal around the time I test login: a weird mention of evdev revocation not being supported by my kernel (current linux, I don't recall seeing it with linux-lts, also current).

Oct 25 19:36:24 mbp62 systemd-logind[2235]: New seat seat0.
Oct 25 19:36:24 mbp62 systemd-logind[2235]: New session c3 of user al.
Oct 25 19:36:24 mbp62 systemd-logind[2235]: New session c1 of user al.
Oct 25 19:39:19 mbp62 systemd-logind[2235]: Removed session c3.
Oct 25 19:39:36 mbp62 systemd-logind[2235]: New session c2 of user al.
Oct 25 19:41:09 mbp62 systemd-logind[2235]: kernel does not support evdev-revocation

Should I be worried about this?
Comment by Dave Reisner (falconindy) - Saturday, 25 October 2014, 16:56 GMT
No, seems harmless. Your backtrace isn't really useful either, it just shows userspace blocking on an epoll call. Did you get the backtrace during a time when your session was hanging, waiting to be created? Or was just sampled at some random time?

If you want more debugging information from systemd itself, I'd suggest:

# systemd-analyze set-log-level debug
Comment by Alexander Stein (ajstein) - Saturday, 25 October 2014, 17:00 GMT
It was at some random time, after my first login on tty1 hang for a bit then opened up X11 with my StumpWM instance. Then I went to tty2, went to tmux and ran gdb. I had a feeling it would not get you any useful information. I tried googling about gdb, but did not find much too useful.

So I guess I should reboot, log in as root, attach to logind with gdb, and then login with the user with the bad sysd --user sessions? How do I get a running full backtrace logged to a file?

Will post back shortly after I see systemd-analyze set-log-level debug. Expect a response back in the next 15-20 minutes.
Comment by Alexander Stein (ajstein) - Saturday, 25 October 2014, 20:22 GMT
So, for the record, I am not so good with gdb. I have tried running systemd-logind with gdb and when I continue I can never recover the gdb session. When I log in and out with my session running gdb and I ask for backtrace full, I get memory errors. I did run systemd with full debug via kernel parameters and dumped dmesg with all of that stuff.

http://dl.il5.in/dmesg.log

http://dl.il5.in/gdb-systemd-logind-533.log
Comment by Dave Reisner (falconindy) - Sunday, 15 March 2015, 14:14 GMT
Is this still a problem with systemd 219?

Loading...