Lightdm login fails with fscrypt home folder

Everything about X, Gnome, KDE, ... and everything running on it

Lightdm login fails with fscrypt home folder

Postby J V » 2020-03-02 16:56

Edit 3: Apparently the version of fscrypt in sid is slightly out of date and doesn't support v2 policy keys, which fix this issue. I'll just have to wait

Edit 2: After a lot of digging I've found stderr from tee says:
tee: /home/j/.xsession-errors: Required key not available


So it looks like it has something to do with fscrypt and pam after all, though what I'm not sure

Edit: After further debugging I've found the login is dying at this line in /etc/X11/Xsession:
Code: Select all
exec >>"$ERRFILE" 2>&1


$ERRFILE in this case is "/home/j/.xsession-errors" so that doesn't help much, but I'm surprised exec could be called without a subcommand. Guess I'll have to read up on it

---

I recently made a new encrypted home folder with fscrypt, and copied all the files over. This worked fine, I can log into a TTY and startx and everything works great. Unfortunately, lightdm won't start the session for my user. It just goes back to lightdm after a brief black screen.

I sadly did a large dist-upgrade (I'm on sid) at the same time so that doesn't help narrow it down. Downgrading from sid to testing didn't fix it so that doesn't help either.

It's user-specific because if I make a test user it will log in fine, but it's not anything to do with the home folder because if I replace it with an empty folder it still won't work. I did the same with /etc/X11 to no avail.

Here's the lightdm.log for the login attempt:
Code: Select all
[+3.07s] DEBUG: Greeter start authentication for j
[+3.07s] DEBUG: Session pid=4871: Sending SIGTERM
[+3.07s] DEBUG: Session pid=4881: Started with service 'lightdm', username 'j'
[+3.07s] DEBUG: Session pid=4871: Terminated with signal 15
[+3.07s] DEBUG: Session: Failed during authentication
[+3.07s] DEBUG: Seat seat0: Session stopped
[+3.08s] DEBUG: Session pid=4881: Got 1 message(s) from PAM
[+3.08s] DEBUG: Prompt greeter with 1 message(s)
[+5.95s] DEBUG: Continue authentication
[+5.96s] DEBUG: Session pid=4881: Authentication complete with return value 0: Success
[+5.96s] DEBUG: Authenticate result for user j: Success
[+5.96s] DEBUG: User j authorized
[+6.00s] DEBUG: Greeter requests session lightdm-xsession
[+6.00s] DEBUG: Seat seat0: Stopping greeter; display server will be re-used for user session
[+6.00s] DEBUG: Terminating login1 session c7
[+6.00s] DEBUG: Session pid=4827: Sending SIGTERM
[+6.01s] DEBUG: Greeter closed communication channel
[+6.01s] DEBUG: Session pid=4827: Exited with return value 0
[+6.01s] DEBUG: Seat seat0: Session stopped
[+6.01s] DEBUG: Seat seat0: Greeter stopped, running session
[+6.01s] DEBUG: Registering session with bus path /org/freedesktop/DisplayManager/Session0
[+6.01s] DEBUG: posix_spawn avoided (fd close requested) (child_setup specified)
[+6.01s] DEBUG: Session pid=4881: Running command /etc/X11/Xsession default
[+6.01s] DEBUG: Creating shared data directory /var/lib/lightdm/data/j
[+6.01s] DEBUG: Session pid=4881: Logging to .xsession-errors
[+7.19s] DEBUG: Activating VT 7
[+7.19s] DEBUG: Activating login1 session 13
[+7.19s] DEBUG: Seat seat0 changes active session to
[+7.19s] DEBUG: Seat seat0 changes active session to 13
[+7.19s] DEBUG: Session 13 is already active
[+7.25s] DEBUG: Session pid=4881: Exited with return value 2
[+7.25s] DEBUG: Seat seat0: Session stopped
[+7.25s] DEBUG: Seat seat0: Stopping display server, no sessions require it
[+7.25s] DEBUG: Sending signal 15 to process 4754
[+7.27s] DEBUG: Seat seat0 changes active session to
[+7.72s] DEBUG: Process 4754 exited with return value 0
[+7.72s] DEBUG: XServer 0: X server stopped
[+7.72s] DEBUG: Releasing VT 7
[+7.72s] DEBUG: XServer 0: Removing X server authority /var/run/lightdm/root/:0
[+7.72s] DEBUG: Seat seat0: Display server stopped
[+7.72s] DEBUG: Seat seat0: Active display server stopped, starting greeter
[+7.72s] DEBUG: Seat seat0: Creating greeter session
[+7.72s] DEBUG: Seat seat0: Creating display server of type x
[+7.72s] DEBUG: Using VT 7
[+7.72s] DEBUG: Seat seat0: Starting local X display on VT 7
[+7.72s] DEBUG: XServer 0: Logging to /var/log/lightdm/x-0.log
[+7.72s] DEBUG: XServer 0: Writing X server authority to /var/run/lightdm/root/:0
[+7.72s] DEBUG: XServer 0: Launching X Server
[+7.72s] DEBUG: Launching process 4907: /usr/bin/X :0 -seat seat0 -auth /var/run/lightdm/root/:0 -nolisten tcp vt7 -novtswitch
[+7.72s] DEBUG: XServer 0: Waiting for ready signal from X server :0
[+8.33s] DEBUG: Got signal 10 from process 4907
[+8.33s] DEBUG: XServer 0: Got signal from X server :0
[+8.33s] DEBUG: XServer 0: Connecting to XServer :0
[+8.33s] DEBUG: posix_spawn avoided (fd close requested) (child_setup specified)
[+8.33s] DEBUG: Seat seat0: Display server ready, starting session authentication
[+8.33s] DEBUG: Session pid=4977: Started with service 'lightdm-greeter', username 'lightdm'
[+8.34s] DEBUG: Session pid=4977: Authentication complete with return value 0: Success
[+8.34s] DEBUG: Seat seat0: Session authenticated, running command
[+8.34s] DEBUG: Session pid=4977: Running command /usr/sbin/lightdm-gtk-greeter
[+8.34s] DEBUG: Creating shared data directory /var/lib/lightdm/data/lightdm
[+8.34s] DEBUG: Session pid=4977: Logging to /var/log/lightdm/seat0-greeter.log
[+8.36s] DEBUG: Activating VT 7
[+8.36s] DEBUG: Activating login1 session c8
[+8.36s] DEBUG: Seat seat0 changes active session to c8
[+8.36s] DEBUG: Session c8 is already active
[+8.45s] DEBUG: Greeter connected version=1.26.0 api=1 resettable=false
[+8.63s] DEBUG: Greeter start authentication
[+8.63s] DEBUG: Session pid=5020: Started with service 'lightdm', username '(null)'
[+8.64s] DEBUG: Session pid=5020: Got 1 message(s) from PAM
[+8.64s] DEBUG: Prompt greeter with 1 message(s)
[+10.85s] DEBUG: Seat seat0 changes active session to 7
[+12.47s] DEBUG: Seat seat0 changes active session to c8
[+12.47s] DEBUG: Session c8 is already active
[+18.17s] DEBUG: Seat seat0 changes active session to 7


The biggest difference between the logs of the working and non-working account is this section:
Code: Select all
[+1035.24s] DEBUG: Seat seat0 changes active session to
[+1035.24s] DEBUG: Seat seat0 changes active session to 33
[+1035.24s] DEBUG: Session 33 is already active
[+1035.30s] DEBUG: Session pid=12296: Exited with return value 2
[+1035.30s] DEBUG: Seat seat0: Session stopped
[+1035.30s] DEBUG: Seat seat0: Stopping display server, no sessions require it
[+1035.30s] DEBUG: Sending signal 15 to process 12113
[+1035.32s] DEBUG: Seat seat0 changes active session to
[+1035.74s] DEBUG: Process 12113 exited with return value 0


On the working account it goes like this:
Code: Select all
[+1005.27s] DEBUG: Seat seat0 changes active session to
[+1005.27s] DEBUG: Seat seat0 changes active session to 30
[+1005.27s] DEBUG: Session 30 is already active
[+1012.84s] DEBUG: Seat seat0 changes active session to 7
[+1018.10s] DEBUG: Seat seat0 changes active session to 30
[+1018.10s] DEBUG: Session 30 is already active
[+1018.19s] DEBUG: Process 11578 exited with return value 1


Unfortunately, the processes are already gone by the time I have access to the logs, so I don't know what process the return values are from...

Does anyone have any idea what's going on? How to find out what a killed process was? How to get more verbose logging from lightdm?
J V
 
Posts: 120
Joined: 2011-02-21 17:34

Return to Desktop & Multimedia

Who is online

Users browsing this forum: No registered users and 10 guests

fashionable