apognu / tuigreet

Graphical console greeter for greetd
GNU General Public License v3.0
858 stars 43 forks source link

tuigreet often freezes on login to swaywm with "Please wait" #129

Closed belugame closed 2 months ago

belugame commented 2 months ago

My system: Debian trixie/sid, kernel 6.6.9-1

This occurs to me sometimes and sometimes not. Seen it on the master commit but also already on the 0.7 release. And that is on two of my systems (the other on Debian stable). Tinkering with the greeter is still new to me so I may do something wrong but cannot figure it out.

I select user and enter the password but when I hit Enter it only shows "Please wait" and does no longer react to ESC or the F-keys. I can always get sway to start by switching to another terminal and login in there however.

Sometimes success rate is 100% for weeks and then it drops to 30% when I login usually once or twice a day. I have had sway start with "-d" to get a debug log but I could not see anything problematic. Any advice how to debug this further is appreciated.

My /etc/greetd/config.toml:

[terminal]
vt = 7

[default_session]
command = "/usr/sbin/tuigreet --user-menu -r --cmd /usr/local/bin/start-sway.sh"
user = "_greetd"

And start-sway.sh:

#! /bin/bash
export XDG_SESSION_DESKTOP=sway
export XDG_CURRENT_DESKTOP=sway
export MOZ_ENABLE_WAYLAND=1

exec sway
belugame commented 2 months ago

I am currently on a salvaged session where tuigreet got stuck and I can see tuigreet still running:

 ps aux | ag sway             
_greetd     1349  0.2  0.0 349004  7116 tty7     Sl+  09:28   0:04 /usr/sbin/tuigreet --user-menu -r --cmd /usr/local/bin/start-sway.sh
foo      2120  2.3  0.5 2433408 120004 tty3   Sl+  09:29   0:35 sway
foo      2202  0.0  0.0   8436  3328 ?        S    09:29   0:00 swayidle -w timeout 500 swaymsg "output * power off" resume swaymsg "output * power on"
foo      2206  0.0  0.1 501368 38812 ?        Sl   09:29   0:00 swaync

Not sure if this helps:

sudo strace -p1349 -s9999 -e write
strace: Process 1349 attached
write(1, "\33[39m\33[49m\33[0m\33[?25l", 20) = 20
write(1, "\33[39m\33[49m\33[0m\33[?25l", 20) = 20
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=25446, si_uid=126, si_status=1, si_utime=0, si_stime=0} ---
write(1, "\33[39m\33[49m\33[0m\33[?25l", 20) = 20
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=25627, si_uid=126, si_status=1, si_utime=0, si_stime=0} ---
...
apognu commented 2 months ago

Hey thanks for reporting this. When was the last time you tested from the tip of the master branch? If it has been some time, would you mind testing again? The packaged versions are now quite old and I would like to make sure it was not already fixed.

Other than that, I did push some sort of debug logging mechanism on the dev/debug-logging branch that, when enabled (with --debug), logs into /tmp/tuigreet.log. Would you mind running this for a bit and report log output if and when you encounter the issue again?

Note: I tried to be mindful of what exactly gets logged, but please review the output to make sure there is not any sensitive information before posting it.

From your output, sway seems to have been launched, you greetd has received the StartSession message, the only thing that could go wrong is if we do not get the response that the session has been started, or if we fail to exit.

belugame commented 2 months ago

@apognu Thank you very much for adding the debug feature. I just tried it out and got these log messages with an unsuccessful change from tuigreet to sway:

2024-04-28T19:52:55.788759Z  INFO tuigreet: 48: tuigreet started
2024-04-28T19:52:56.934629Z  INFO tuigreet::ipc: 36: sending request to greetd: CreateSession { username: "foo" }
2024-04-28T19:52:56.958522Z  INFO tuigreet::ipc: 72: received greetd message: AuthMessage { auth_message_type: Secret, auth_message: "Password: " }
2024-04-28T19:52:59.996453Z  INFO tuigreet::ipc: 36: sending request to greetd: PostAuthMessageResponse
apognu commented 2 months ago

That is weird, the logs stop when (presumably) your password is sent to greetd. We never register a response from it.

On paper, we should receive a message saying that authentication was successful, send a message asking greetd to start the sway session, and exit on greetd's acknowledgement.

Greetd has nothing interesting in its logs/output?

belugame commented 2 months ago

I found this segfault of greetd in my syslog at the login time (adjusted for my local timezone):

2024-04-28T21:52:59.623330+02:00 foo kernel: wlp1s0: authenticate with xxx
2024-04-28T21:53:00.043419+02:00 foo kernel: show_signal_msg: 22 callbacks suppressed
2024-04-28T21:53:00.043435+02:00 foo kernel: greetd[1514]: segfault at 7ffc871e3f98 ip 00007fd898a78ead sp 00007ffc871e3f40 error 6 in libc.so.6[7fd898a44000+155000] likely on CPU 0 (core 0, socket 0)
2024-04-28T21:53:00.043437+02:00 foo kernel: Code: 00 e8 b7 d5 0b 00 0f 1f 80 00 00 00 00 41 57 49 89 d7 41 56 49 89 f6 41 55 41 54 55 53 48 89 fb 4c 89 f7 48 81 ec e8 04 00 00 <48> 89 74 24 58 be 25 00 00 00 89 4c 24 3c 64 48 8b 04 25 28 00 00
2024-04-28T21:53:00.154898+02:00 foo wpa_supplicant[1107]: wlp1s0: Trying to associate with xxx (SSID='xxx' freq=5240 MHz)
2024-04-28T21:53:00.155429+02:00 foo kernel: wlp1s0: send auth to xxx (try 1/3) 
2024-04-28T21:53:00.155448+02:00 foo kernel: wlp1s0: authenticated

Hmm, from what I see greetd has no more verbose logging.

apognu commented 2 months ago

A segfault in greetd (or more likely in C-land that greetd invokes) might be outside of this project's scope, unfortunately.

I can see a few people reporting segfaults/coredumps on greetd's issue tracker over the years:

I do not think (but happy to be proven wrong) that tuigreet is the one triggering those through IPC, so I do not think there is much I can do here.

belugame commented 2 months ago

Thank you for your feedback, I will try to debug it further with greetd :)