mcdope/pam_usb

xscreensaver unlock failed

Closed this issue · 10 comments

aptx4869 commented

Which version of pam_usb are you running?

master

Which distribution are you using?

debian bullseye

Which login manager and desktop environment are you using?

lxdm + fvwm-crystal

What happened?

Related pam_usb.conf

<user id="aptx4869">
	<device>Om Mani Padme Hum</device>
        <!-- <option name="quiet">true</option> -->
        <option name="debug">true</option>
        <agent event="lock">
            <cmd>xscreensaver-command -lock</cmd>
            <env>DISPLAY=:0</env>
            <env>DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus</env>
            <env>XAUTHORITY=/home/aptx4869/.Xauthority</env>
        </agent>
        <agent event="unlock">
            <cmd>xscreensaver-command -deactivate</cmd>
            <env>DISPLAY=:0</env>
            <env>DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus</env>
            <env>XAUTHORITY=/home/aptx4869/.Xauthority</env>
        </agent>
</user>

It locked the screen when I remove the device but unlock failed. It used to work with pam_usb v0.8.1.

xscreensaver debug message:

[src/local.c:227] Checking whether the caller (xscreensaver) is local I or not...
[src/local.c:238] Checking pid 6608 (xscreensaver)... 
[src/local.c:238] Checking pid 4575 (fvwm).s 
[src/local.c:238] Checking pid 4533 (/usr/lib/1xdm/1xdm-session). 
[src/local.c:238] Checking pid 2006 (/usr/sbin/lxdm-binary)... 
[src/local.c:238] Checking pid 1(/sbin/init)... 
[src/local.c:297] Using DISPLAY :0 for utmp search 
[src/local.c:050] No utmp entry found for tty ":0" 
[src/local.c:313] Trying to get tty from display server 
[src/local.c:121] Determining tty by display server failed (running 'pamusb-check' a....
[src/local.c:323] Failed no result while trying to get TTY from display server 
[src/local.c:328] Trying to get tty by DISPLAY 
[src/local.c:336] Failed, no result while searching utmp for display :0 owned by user.... 
[src/local.c:345] Trying to get tty by loginctl 
[src/local.c:203] Got tty: tty7 
[src/local.c:351] Retrying with tty tty7, obtained by loginctl, for utmp search 
[src/local.c:050] No utmp entry found for tty "tty?" 
[src/local.c:379] Couldn't confirm login tty to be neither local or remote- denying.

Output of "pamusb-check --debug whoami"

* Authentication request for user "aptx4869" (pamusb-check)
[src/local.c:227] Checking whether the caller (pamusb-check) is local or not...
[src/local.c:238]       Checking pid 140409 (pamusb-check)...
[src/local.c:238]       Checking pid  31643 (-zsh)...
[src/local.c:238]       Checking pid  31641 (tmux)...
[src/local.c:242]               Setting pid 31643 as fallback for tmux check
[src/local.c:278]       Checking for remote clients attached to tmux before getting client tty...
[src/tmux.c:102]                Checking for IPv4 connections...
[src/tmux.c:102]                Checking for IPv6 connections...
[src/tmux.c:044]                Got tmux_client_id: 0
[src/tmux.c:047]                Got tmux_socket_path: /tmp//tmux-1000/default
[src/tmux.c:051]                Built get_tmux_session_details_cmd: tmux -S "/tmp//tmux-1000/default" list-clients -t "\$0"
[src/tmux.c:066]                Got tmux_client_tty: pts/0
[src/local.c:053]               utmp entry for tty "pts/0" found
[src/local.c:054]                       utmp->ut_pid: 31639
[src/local.c:055]                       utmp->ut_user: aptx4869
[src/local.c:071]               Checking utmp->ut_addr_v6[0]
[src/local.c:071]               Checking utmp->ut_addr_v6[1]
[src/local.c:071]               Checking utmp->ut_addr_v6[2]
[src/local.c:071]               Checking utmp->ut_addr_v6[3]
[src/local.c:075]       utmp check successful, request originates from a local source!
[src/local.c:375] No remote access detected, seems to be local request - allowing.
[src/device.c:038] Searching for "Om Mani Padme Hum" in the hardware database...
* Authentication device "Om Mani Padme Hum" is connected.
* Performing one time pad verification...
[src/volume.c:098] Searching for volume with uuid A814F8D214F8A50A.
[src/volume.c:123] Found mount points: (null)
[src/volume.c:138] Found volume A814F8D214F8A50A.
[src/volume.c:044] Attempting to mount device /dev/sdd1.
[src/volume.c:058] Mounted device /dev/sdd1 to /media/aptx4869/ESD-USB.
[src/pad.c:326] Loading device pad...
[src/pad.c:336] Loading system pad...
[src/pad.c:352] Pad match.
[src/pad.c:187] Checking whether pads are expired or not...
[src/pad.c:215] Pads were generated 3599 seconds ago, not updating.
[src/volume.c:189] Attempting to unmount /dev/sdd1 from /media/aptx4869/ESD-USB.
[src/volume.c:202] Unmount succeeded.
* Access granted.

Output of "w"

11:30:29 up 37 min,  8 users,  load average: 0.84, 0.55, 0.56
USER     TTY      来自           LOGIN@   IDLE   JCPU   PCPU WHAT
aptx4869 pts/0    :0               10:58    3.00s  0.00s  0.00s tmux -2 attach-session -d
aptx4869 pts/1    tmux(31641).%0   10:58   44.00s  4.05s  1.82s vim /etc/security/pam_env.conf
aptx4869 pts/2    tmux(31641).%1   10:58   31:56   1.65s  1.65s vim
aptx4869 pts/3    tmux(31641).%2   10:58   31:56   1.44s  1.44s slurm -L -i enp3s0
aptx4869 pts/4    tmux(31641).%3   10:58   31:56  37.48s 37.48s htop
aptx4869 pts/5    tmux(31641).%4   10:58   26:36   0.14s  0.14s mutt
aptx4869 pts/6    tmux(31641).%5   10:58   17:33   1.40s  1.40s mutt -F .mutt/gmail.muttrc
aptx4869 pts/7    tmux(31641).%6   10:58    3.00s  2.25s  0.01s w

Output of "loginctl"

SESSION  UID USER     SEAT  TTY
      2 1000 aptx4869 seat0 tty7

1 sessions listed.
mcdope commented

Reminds me yet again I should finally put out a new release... :D Can you please try the nighly build? It includes some fixes and more importantly some logging for the agent in your auth.log

aptx4869 commented

Do you mean nightly? But libpam-usb_0.8.3-1_amd64.deb make with make deb at ef5f774 is the current master and it is not fixed yet...

I tried git bisect
8675a26 is good:
pamusb2

auth.log:

Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: Authentication request for user "aptx4869" (xscreensaver)
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: Checking whether the caller (xscreensaver) is local or not...
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011Checking pid 2435393 (xscreensaver)...  
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011Checking pid   4575 (fvwm)...                                  
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011Checking pid   4533 (/usr/lib/lxdm/lxdm-session)...
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011Checking pid   2006 (/usr/sbin/lxdm-binary)...                                                                                                                                                               
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011Checking pid      1 (/sbin/init)...                            
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011Using DISPLAY :0 for utmp search             
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011No utmp entry found for tty ":0"                                 
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011Trying to get tty from display server                 
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011#011Failed, no result while trying to get TTY from display server
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011Trying to get tty by DISPLAY                                   
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011Retrying with tty pts/0, obtained by DISPLAY, for utmp search         
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011#011utmp entry for tty "pts/0" found                                  
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011#011#011utmp->ut_pid: 31639                  
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011#011#011utmp->ut_user: aptx4869                  
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011#011Checking utmp->ut_addr_v6[0]                                      
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011#011Checking utmp->ut_addr_v6[1]                 
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011#011Checking utmp->ut_addr_v6[2]                 
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011#011Checking utmp->ut_addr_v6[3]
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: #011utmp check successful, request originates from a local source!
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: No remote access detected, seems to be local request - allowing.
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: Searching for "Om Mani Padme Hum" in the hardware database...
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: Authentication device "Om Mani Padme Hum" is connected.
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: Performing one time pad verification...
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: Searching for volume with uuid A814F8D214F8A50A.
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: Found mount points: (null)
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: Found volume A814F8D214F8A50A.
Feb 18 09:50:52 KIC8462852 pam_usb[2435393]: Attempting to mount device /dev/sdd1.
Feb 18 09:50:53 KIC8462852 pam_usb[2435393]: Mounted device /dev/sdd1 to /media/aptx4869/ESD-USB.
Feb 18 09:50:53 KIC8462852 pam_usb[2435393]: Loading device pad...
Feb 18 09:50:53 KIC8462852 pam_usb[2435393]: Loading system pad...
Feb 18 09:50:53 KIC8462852 pam_usb[2435393]: Pad match.
Feb 18 09:50:53 KIC8462852 pam_usb[2435393]: Checking whether pads are expired or not...
Feb 18 09:50:53 KIC8462852 pam_usb[2435393]: Pads were generated 1741 seconds ago, not updating.
Feb 18 09:50:53 KIC8462852 pam_usb[2435393]: Attempting to unmount /dev/sdd1 from /media/aptx4869/ESD-USB.
Feb 18 09:50:53 KIC8462852 pam_usb[2435393]: Unmount succeeded. 
Feb 18 09:50:53 KIC8462852 pam_usb[2435393]: Access granted.

98e61ce is the first bad commit

libpam

auth.log

Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: Authentication request for user "aptx4869" (xscreensaver)                                                                                                                                                        
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: Checking whether the caller (xscreensaver) is local or not...
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: #011Checking pid 2435393 (xscreensaver)...
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: #011Checking pid   4575 (fvwm)...
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: #011Checking pid   4533 (/usr/lib/lxdm/lxdm-session)...
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: #011Checking pid   2006 (/usr/sbin/lxdm-binary)...
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: #011Checking pid      1 (/sbin/init)...
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: #011Using DISPLAY :0 for utmp search
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: #011No utmp entry found for tty ":0"
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: #011Trying to get tty from display server
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: #011#011Failed, no result while trying to get TTY from display server
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: #011Trying to get tty by DISPLAY
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: #011#011Failed, no result while searching utmp for display :0 owned by user aptx4869
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: #011Trying to get tty by loginctl
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: #011#011'loginctl' returned nothing.'
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: #011#011Failed, no result while searching utmp for tty (null)
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: Couldn't retrieve login tty, assuming remote
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: Couldn't confirm login tty to be neither local or remote - denying.
Feb 18 09:51:55 KIC8462852 pam_usb[2435393]: Access denied.

BTW, everything is fine if I launch xscreensaver in a terminal but when it is launched by fvwm from lxdm, access denied.

mcdope commented
mcdope commented

Actually, this seems to be a general thingy with lxdm. Seems it doesn't properly register the session in utmp. I can reproduce the same logs with just pamusb-check and in GNOME when started via lxdm.

grafik

When it works for you, it is because of tmux - when tmux is detected its data is checked to determine if the session has remote clients, if not: its considered local.

Think I will have to whitelist lxdm like xdm, and some other stuff. But still investigating.

mcdope commented

Please try again after compiling from branch issue-189-lxdm

aptx4869 commented

Please try again after compiling from branch issue-189-lxdm

It works

  • 👍1
mcdope commented

Thanks, gonna merge then.

mcdope commented

@aptx4869 Would you mind testing this build too? It should fix your issue also, just in better way (that also solves a bazillion similar problems).
grafik

https://www.dropbox.com/sh/008urzj2wpr7ir8/AADESu6gDcTEkLCpb5FFqReYa?dl=0

aptx4869 commented

@mcdope I can not access dropbox because of connection problem... Do you mean test on branch issue-196-improve-loginctl-handling? I build from that and it looks good.

mcdope commented