Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

X session logon fails with pamusb: "Could not get properties: Unknown object '/org/freedesktop/login1/user/self'." #262

Open
GameLostException opened this issue Jan 6, 2025 · 9 comments
Labels
bug Something isn't working
Milestone

Comments

@GameLostException
Copy link

Which version of pam_usb are you running?

0.8.5

Which distribution are you using?

Arch

Which login manager and desktop environment are you using?

Xfce 4.18

What happened?

I initially made this one change in the pam.d dir to activate pamusb as the first way to authenticate, as instructed on the Arch Wiki: added auth sufficient pam_usb.so into /etc/pam.d/system-auth:

#%PAM-1.0

auth       required                    pam_faillock.so      preauth
# Optionally use requisite above if you do not want to prompt for the password
# on locked accounts.
auth sufficient	pam_usb.so
-auth      [success=2 default=ignore]  pam_systemd_home.so
auth       [success=1 default=bad]     pam_unix.so          try_first_pass nullok
auth       [default=die]               pam_faillock.so      authfail
auth       optional                    pam_permit.so
auth       required                    pam_env.so
auth       required                    pam_faillock.so      authsucc
# If you drop the above call to pam_faillock.so the lock will be done also
# on non-consecutive authentication failures.

-account   [success=1 default=ignore]  pam_systemd_home.so
account    required                    pam_unix.so
account    optional                    pam_permit.so
account    required                    pam_time.so

-password  [success=1 default=ignore]  pam_systemd_home.so
password   required                    pam_unix.so          try_first_pass nullok shadow
password   optional                    pam_permit.so

-session   optional                    pam_systemd_home.so
session    required                    pam_limits.so
session    required                    pam_unix.so
session    optional                    pam_permit.so

It was working fine until a system update a couple months ago, since then, all my logons attempts before X is started fail consistently for all the users enabled within the pamusb config. The following error pops for a second or so and get me back to the login prompt:

Arch Linux 6.6.51-1-1ts (tty2)

boris-st login: boris
* Authentication request for user "boris" (login)
Could not get properties: Unknown object '/org/freedesktop/login1/user/self'.
Could not get properties: Unknown object '/org/freedesktop/login1/user/self'.
* Searching for "BKey" in the hardware database...
* Authentication device "BKey" is connected.
* Performing one time pad verification...
* Access granted.

The error is specifically Could not get properties: Unknown object '/org/freedesktop/login1/user/self'. but journalctl does not show anything out of the ordinary.

That being said, if I revert my /etc/pam.d/system-auth file to its original contents, X logon is possible again. Then once in X, if I re-enable the pamusb changes, all the pamusb authentication work fine with the USB key (screensaver dialogs, sudo/auth CLI prompts, etc.), until the next logout/logon when I get the issue shown above again.

Output of "pamusb-check --debug whoami"

* Authentication request for user "boris" (pamusb-check)
[src/local.c:281] Checking whether the caller (pamusb-check) is local or not...
[src/local.c:298] 	Checking pid 338161 (pamusb-check)...
[src/local.c:298] 	Checking pid 336163 (/usr/bin/zsh)...
[src/local.c:298] 	Checking pid 336155 (kitty)...
[src/local.c:298] 	Checking pid      1 (/sbin/init)...
[src/local.c:339] 	Using DISPLAY :0.0 for utmp search
[src/local.c:344] 	DISPLAY contains screen, truncating...
[src/local.c:053] 	No utmp entry found for tty ":0"
[src/local.c:353] 	Trying to get tty from display server
[src/local.c:358] 	Retrying with tty /dev/tty1, obtained from display server, for utmp search
[src/local.c:056] 		utmp entry for tty "tty1" found
[src/local.c:057] 			utmp->ut_pid: 1002
[src/local.c:058] 			utmp->ut_user: boris
[src/local.c:073] 	utmp check successful, request originates from a local source!
[src/local.c:441] No remote access detected, seems to be local request - allowing.
* Searching for "BKey" in the hardware database...
* Authentication device "BKey" is connected.
* Performing one time pad verification...
[src/volume.c:105] Searching for volume with uuid 47D8-DA1A.
[src/volume.c:130] Found mount points: (null)
[src/volume.c:145] Found volume 47D8-DA1A.
[src/volume.c:044] Attempting to mount device /dev/sdb1.
[src/volume.c:058] Mounted device /dev/sdb1 to /run/media/boris/47D8-DA1A.
[src/pad.c:317] Loading device pad...
[src/pad.c:327] Loading system pad...
[src/pad.c:343] Pad match.
[src/pad.c:176] Checking whether pads are expired or not...
[src/pad.c:204] Pads were generated 6 seconds ago, not updating.
[src/volume.c:196] Attempting to unmount /dev/sdb1 from /run/media/boris/47D8-DA1A.
[src/volume.c:209] Unmount succeeded.
* Access granted.

Output of "w"

17:07:46 up 1 day,  8:23,  2 users,  load average: 2.05, 2.20, 2.51
USER     TTY       LOGIN@   IDLE   JCPU   PCPU  WHAT
boris              Thu08   13:28   0.00s  0.37s /usr/lib/systemd/systemd --user
boris    tty1      Thu08   32:23m  2:05m  0.03s xinit /etc/xdg/xfce4/xinitrc -- /etc/X11/xinit/xserverrc vt1

Output of "loginctl"

SESSION  UID USER  SEAT  LEADER CLASS   TTY  IDLE SINCE
      1 1000 boris seat0 1002   user    tty1 yes  -
      2 1000 boris -     1198   manager -    no   -    

2 sessions listed.
@GameLostException GameLostException changed the title X session logon fail with pamusb: "Could not get properties: Unknown object '/org/freedesktop/login1/user/self'." X session logon fails with pamusb: "Could not get properties: Unknown object '/org/freedesktop/login1/user/self'." Jan 6, 2025
@mcdope
Copy link
Owner

mcdope commented Jan 7, 2025 via email

@GameLostException
Copy link
Author

Thanks for your prompt reply, I've added debug to all the .so module, it gives:

# Added "auth sufficient pam_usb.so" in system-auth, user boris is configured in pamusb

Jan 08 08:43:16 boris-st pam_usb[789934]: Authentication request for user "boris" (login)
Jan 08 08:43:16 boris-st pam_usb[789934]: Searching for "BKey" in the hardware database...
Jan 08 08:43:16 boris-st pam_usb[789934]: None of the configured authentication devices is connected.
Jan 08 08:43:16 boris-st pam_usb[789934]: Access denied.
Jan 08 08:43:16 boris-st login[789934]: pam_systemd_home(login:auth): pam-systemd-homed authenticating
Jan 08 08:43:16 boris-st login[789934]: pam_systemd_home(login:auth): New sd-bus connection (system-bus-pam-systemd-home-789934) opened.
Jan 08 08:43:16 boris-st login[789934]: pam_systemd_home(login:auth): systemd-homed is not available: Could not activate remote peer 'org.freedesktop.home1': activation request failed: unknown unit
Jan 08 08:43:16 boris-st login[789934]: pam_unix(login:auth): username [boris] obtained
Jan 08 08:43:26 boris-st login[789934]: pam_unix(login:session): session opened for user boris(uid=1000) by boris(uid=0)
Jan 08 08:43:26 boris-st login[789934]: pam_unix(login:session): session closed for user boris

# Using a dummy user, foo, to login, this one is not configured to go through pamusb auth

Jan 08 08:43:28 boris-st pam_usb[789977]: No authentication device(s) configured for user "foo".
Jan 08 08:43:28 boris-st login[789977]: pam_systemd_home(login:auth): pam-systemd-homed authenticating
Jan 08 08:43:28 boris-st login[789977]: pam_systemd_home(login:auth): New sd-bus connection (system-bus-pam-systemd-home-789977) opened.
Jan 08 08:43:28 boris-st login[789977]: pam_systemd_home(login:auth): systemd-homed is not available: Could not activate remote peer 'org.freedesktop.home1': activation request failed: unknown unit
Jan 08 08:43:28 boris-st login[789977]: pam_unix(login:auth): username [foo] obtained
Jan 08 08:43:30 boris-st login[789977]: pam_unix(login:session): session opened for user foo(uid=1003) by foo(uid=0)
Jan 08 08:43:30 boris-st (systemd)[789987]: pam_warn(systemd-user:setcred): function=[pam_sm_setcred] flags=0x8002 service=[systemd-user] terminal=[] user=[foo] ruser=[<unknown>] rhost=[<unknown>]
Jan 08 08:43:30 boris-st (systemd)[789987]: pam_unix(systemd-user:session): session opened for user foo(uid=1003) by foo(uid=0)

# Using this dummy user to remove "auth sufficient pam_usb.so" from system-auth, I can logon again with user "Boris"

Jan 08 08:52:20 boris-st login[789977]: pam_unix(login:session): session closed for user foo
Jan 08 08:52:26 boris-st login[790291]: pam_unix(login:session): session opened for user boris(uid=1000) by boris(uid=0)
Jan 08 08:52:30 boris-st (sd-pam)[789989]: pam_unix(systemd-user:session): session closed for user foo

It looks like the pamusb module somehow doesn't "give" the pam_systemd_home.so one what it needs to mount the home dir, so I tried to keep pam_systemd_home.so first:

auth       required                    pam_faillock.so      preauth
# Optionally use requisite above if you do not want to prompt for the password                                                                                                                                       
# on locked accounts.                                                                                                                                                                                                
-auth      [success=3 default=ignore]  pam_systemd_home.so #incremented the lines skipping as I added one underneath
auth      sufficient                  pam_usb.so                                                                                                                                                                    
auth       [success=1 default=bad]     pam_unix.so          try_first_pass nullok
auth       [default=die]               pam_faillock.so      authfail
auth       optional                    pam_permit.so
auth       required                    pam_env.so
auth       required                    pam_faillock.so      authsucc

But the error stays the exact same :/

@mcdope
Copy link
Owner

mcdope commented Jan 8, 2025 via email

@mcdope
Copy link
Owner

mcdope commented Jan 8, 2025 via email

@GameLostException
Copy link
Author

GameLostException commented Jan 9, 2025

Thanks for the debug precision, here goes the journalctl with my comments. Note that I have removed the root user from the pamusb config (it was a mistake to add it in the first place anyway):

# Login as user boris which is configured to go through pamusb

Jan 09 07:59:42 boris-st pam_usb[158933]: Authentication request for user "boris" (login)
Jan 09 07:59:42 boris-st pam_usb[158933]: Checking whether the caller (login) is local or not...
Jan 09 07:59:42 boris-st pam_usb[158933]:         Checking pid 158933 (/bin/login)...
Jan 09 07:59:42 boris-st pam_usb[158933]:         Checking pid      1 (/sbin/init)...
Jan 09 07:59:42 boris-st pam_usb[158933]:         Trying to check for remote access by loginctl
Jan 09 07:59:42 boris-st pam_usb[158933]:                 'loginctl' returned nothing.
Jan 09 07:59:42 boris-st pam_usb[158933]:         Trying to get tty by loginctl
Jan 09 07:59:42 boris-st pam_usb[158933]:                 'loginctl' returned nothing.
Jan 09 07:59:42 boris-st pam_usb[158933]:                 Failed, could not obtain tty from loginctl - see line before this for reason.
Jan 09 07:59:42 boris-st pam_usb[158933]:         Fallback: Using TTY /dev/tty1 from ttyname() for search
Jan 09 07:59:42 boris-st pam_usb[158933]:                 utmp entry for tty "tty1" found
Jan 09 07:59:42 boris-st pam_usb[158933]:                         utmp->ut_pid: 158933
Jan 09 07:59:42 boris-st pam_usb[158933]:                         utmp->ut_user: LOGIN
Jan 09 07:59:42 boris-st pam_usb[158933]:         utmp check successful, request originates from a local source!
Jan 09 07:59:42 boris-st pam_usb[158933]: No remote access detected, seems to be local request - allowing.
Jan 09 07:59:42 boris-st pam_usb[158933]: Searching for "BKey" in the hardware database...
Jan 09 07:59:42 boris-st pam_usb[158933]: Authentication device "BKey" is connected.
Jan 09 07:59:42 boris-st pam_usb[158933]: Performing one time pad verification...
Jan 09 07:59:42 boris-st pam_usb[158933]: Searching for volume with uuid 47D8-DA1A.
Jan 09 07:59:42 boris-st pam_usb[158933]: Found mount points: (null)
Jan 09 07:59:42 boris-st pam_usb[158933]: Found volume 47D8-DA1A.
Jan 09 07:59:42 boris-st pam_usb[158933]: Attempting to mount device /dev/sda1.
Jan 09 07:59:42 boris-st pam_usb[158933]: Mounted device /dev/sda1 to /run/media/root/47D8-DA1A.
Jan 09 07:59:42 boris-st pam_usb[158933]: Loading device pad...
Jan 09 07:59:42 boris-st pam_usb[158933]: Loading system pad...
Jan 09 07:59:42 boris-st pam_usb[158933]: Pad match.
Jan 09 07:59:42 boris-st pam_usb[158933]: Checking whether pads are expired or not...
Jan 09 07:59:42 boris-st pam_usb[158933]: Pads were generated 1625 seconds ago, not updating.
Jan 09 07:59:42 boris-st pam_usb[158933]: Attempting to unmount /dev/sda1 from /run/media/root/47D8-DA1A.
Jan 09 07:59:42 boris-st pam_usb[158933]: Unmount succeeded.
Jan 09 07:59:42 boris-st pam_usb[158933]: Access granted.
Jan 09 07:59:42 boris-st login[158933]: pam_unix(login:session): session opened for user boris(uid=1000) by boris(uid=0)
Jan 09 07:59:42 boris-st login[158933]: pam_unix(login:session): session closed for user boris

# boris session failed to stay open, now using root to revert back my system-auth config and comment the pamusb bit

Jan 09 07:59:48 boris-st pam_usb[158977]: No authentication device(s) configured for user "root".
Jan 09 07:59:52 boris-st login[158977]: pam_unix(login:session): session opened for user root(uid=0) by root(uid=0)
Jan 09 07:59:52 boris-st (systemd)[158988]: pam_warn(systemd-user:setcred): function=[pam_sm_setcred] flags=0x8002 service=[systemd-user] terminal=[] user=[root] ruser=[<unknown>] rhost=[<unknown>]
Jan 09 07:59:52 boris-st (systemd)[158988]: pam_unix(systemd-user:session): session opened for user root(uid=0) by root(uid=0)
Jan 09 08:00:05 boris-st login[158977]: pam_unix(login:session): session closed for user root

# back to the boris user who can login now pamusb is disabled

Jan 09 08:00:11 boris-st login[159017]: pam_unix(login:session): session opened for user boris(uid=1000) by boris(uid=0)
Jan 09 08:00:16 boris-st (sd-pam)[158990]: pam_unix(systemd-user:session): session closed for user root
Jan 09 08:00:17 boris-st pkexec[159176]: pam_unix(polkit-1:session): session opened for user root(uid=0) by boris(uid=1000)
Jan 09 08:00:17 boris-st pamusb-agent[159195]: Process is already running.
Jan 09 08:03:00 boris-st sudo[163271]: pam_unix(sudo:session): session opened for user root(uid=0) by boris(uid=1000)

Additionally, here is the text I see on-screen when failing to logon before X is started:

Arch Linux 6.6.69-1-its (tty1)

boris-st login: boris
Authentication request for user "boris" (login)
/src/local.c:281 Checking whether the caller (login) is local or not...
/src/local.c:298 Checking pid 158879 (/bin/login)...
/src/local.c:298 Checking pid 1 (/sbin/init)...
/src/local.c:332 Trying to check for remote access by loginctl
Could not get properties: Unknown object '/org/freedesktop/login1/user/self'
/src/local.c:268 'loginctl' returned nothing.
/src/local.c:373 Trying to get tty by loginctl
Could not get properties: Unknown object '/org/freedesktop/login1/user/self'
/src/local.c:224 'loginctl' returned nothing.
/src/local.c:418 Failed, could not obtain tty from loginctl - see log
/src/local.c:434 Fallback: Using TTY /dev/tty1 from ttyname() for search
/src/local.c:356 utmp entry for tty 'tty1' found
/src/local.c:357 utmp->ut_pid: 158879
/src/local.c:358 utmp->ut_user: LOGIN
/src/local.c:373 utmp check successful, request originates from a local source
/src/local.c:411 No remote access detected, seems to be local request - allowing.
Searching for "BKey" in the hardware database...
Authentication device "BKey" is connected.
Performing one time pad verification...
/src/volume.c:165 Searching for volume with uuid 4708-DA1A.
/src/volume.c:198 Found mount points: (null)
/src/volume.c:145 Found volume 4708-DA1A.
/src/volume.c:644 Attempting to mount device /dev/sda1.
/src/volume.c:658 Mounted device /dev/sda1 to /run/media/root/4708-DA1A.
/src/pad.c:317 Loading device pad...
/src/pad.c:327 Loading system pad...
/src/pad.c:349 Pad match.
/src/pad.c:376 Checking whether pads are expired or not...
/src/pad.c:384 Pads were generated 1685 seconds ago, not updating.
/src/volume.c:196 Attempting to unmount /dev/sda1 from /run/media/root/4708-DA1A.
/src/volume.c:289 Unmount succeeded.
Access granted.
Last login: Thu Jan 9 07:56:23 on tty1

About your latest comment Jan 08 08:43:16 boris-st pam_usb[789934]: None of the configured authentication devices is connected., this was not an error, I just had the USB key disconnected at this moment but that doesn't change the issue at hand.

@mcdope
Copy link
Owner

mcdope commented Jan 11, 2025

Thanks, so we have actually have two issues - even if likely related.

Let's focus on your last log for now. For your last log: So the messages really come from loginctl. Seems it's not ready on your system before X is started. Never seen behaviour like this but it can be ignored anyway since the fallback to "ttyname" worked and access was granted. What exactly happens afters, does it prompt for password (read: falls back to pam_unix) or does it "log you out" and throw you back to the login?

If it throws you back to login: this was an issue earlier, but assumed to be fixed. Maybe you find some hints or rubberducking in that issue: #199

@GameLostException
Copy link
Author

What exactly happens afters, does it prompt for password (read: falls back to pam_unix) or does it "log you out" and throw you back to the login?

Right after showing this (shortening the logs using the non-debug ones):

Arch Linux 6.6.51-1-1ts (tty2)

boris-st login: boris
* Authentication request for user "boris" (login)
Could not get properties: Unknown object '/org/freedesktop/login1/user/self'.
Could not get properties: Unknown object '/org/freedesktop/login1/user/self'.
* Searching for "BKey" in the hardware database...
* Authentication device "BKey" is connected.
* Performing one time pad verification...
* Access granted.

it goes back to the login prompt, in a loop:

Arch Linux 6.6.51-1-1ts (tty2)

boris-st login: 

Thanks for the reference to the other issue, I had a quick look but will need more time to start diving into the code (my C is so rusty it won't be the easiest task but hey).
Will keep you posted on my finding, thanks again for your support.

@mcdope
Copy link
Owner

mcdope commented Jan 11, 2025

Damn, so it is basically #199. To be honest, I don't even know where to look for reasons - all things I've expected to be the cause are fixed. I almost expected that one to be not truly solved, but I never was able to reproduce it again.

Most likely this is SOME memory thingy in SOME place...

This is most likely asked way to much, but would you be willing to create an DD image of your system so I can throw it into a VM for reproducing and testing? Obv. remove all your personal data before (or after) if you want, or create a test user and delete your whole user for that or like that. But I'm well aware how much hassle that would be so I don't expect you to do it 😆

But if you wanna do, I could provide the necessary upload storage.

@mcdope mcdope added the bug Something isn't working label Jan 11, 2025
@mcdope mcdope added this to the 1.0.0 milestone Jan 11, 2025
@mcdope mcdope modified the milestones: 1.0.0, 0.9.0 Jan 11, 2025
@mcdope
Copy link
Owner

mcdope commented Jan 11, 2025

back then it could be avoided by either: a) disabling deny_remote globally (bad idea) or b) disabling deny_remote for login (better idea, but still a bad idea in VERY exotic setups)

You could try that and see if it helps.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants