maximbaz / yubikey-touch-detector

A tool to detect when your YubiKey is waiting for a touch (to send notification or display a visual indicator on the screen)
ISC License
415 stars 31 forks source link

[Feature]: Support new `keyboxd` gpg pubring format #54

Open shumvgolove opened 8 months ago

shumvgolove commented 8 months ago

Hey 👋

New gpg installations doesn't use pubring.kbx format since 2.4.1, and instead use keyboxd (aka sqlite db) with the $HOME/.gnupg/public-keys.d/pubring.db path.

Would be really awesome if yubikey-touch-detector gained support for keyboxd format, since newer installations are stuck without gpg detection 🥲

Thanks!

maximbaz commented 8 months ago

Many thanks for letting me know!

I'll try to get to this soon, but if you are eager to try something, I suspect and hope that simply adjusting the path here to the new file will do the trick.

https://github.com/maximbaz/yubikey-touch-detector/blob/3b3aaaf91c5e145093b0e9a38f68816a86671d48/main.go#L81

And if this works, we can update that part of the code to initialize gpgPubringPath with the new path (if it exists on the system) or with the old path as the fallback.

shumvgolove commented 8 months ago

Yeah, unfortunately this doesn't work :^(

Firstly, I've tried just to symlink the pubring.db to pubring.kbx with:

ln -s ~/.gnupg/public-keys.d/pubring.db ~/.gnupg/pubring.kbx

And executing the yubikey-touch-detector gives:

❯ yubikey-touch-detector -v
DEBU[2024-03-13T19:31:11Z] Starting YubiKey touch detector              
DEBU[2024-03-13T19:31:11Z] HMAC watcher on '/dev' is successfully established 
DEBU[2024-03-13T19:31:11Z] U2F watcher on '/dev' is successfully established 
DEBU[2024-03-13T19:31:11Z] GPG watcher is successfully established      
DEBU[2024-03-13T19:31:11Z] SSH watcher is successfully established 

However, signing/encrypting test string with:

echo test | gpg -se -u "$KEYID" -r "$KEYID" | gpg -

sadly doesn't output anything :(

With your suggestion, I've adjusted main.go like so:

diff --git a/main.go b/main.go
index 3b2d0c4..d697169 100644
--- a/main.go
+++ b/main.go
@@ -78,7 +78,7 @@ func main() {
        } else if ctx.SetProtocol(gpgme.ProtocolAssuan) != nil {
                log.Debugf("Cannot initialize Assuan IPC: %v. Disabling GPG and SSH watchers.", err)
        } else {
-               gpgPubringPath := path.Join(gpgme.GetDirInfo("homedir"), "pubring.kbx")
+               gpgPubringPath := path.Join(gpgme.GetDirInfo("homedir"), "public-keys.d/pubring.db")
                if _, err := os.Stat(gpgPubringPath); err == nil {

                        requestGPGCheck := make(chan bool)

And recompiled binary with go build. Executing modified yubikey-touch-detector and above gpg test also doesn't register any gpg touch events. I guess there's something different with new format: gpg docs mention keyboxd daemon that indeed running in my current user session:

❯ ps | grep keybox
 5845  sh         │       0.0 0.0 00:00:00 │ keyboxd --homedir /home/sh/.gnupg --daemon
shumvgolove commented 8 months ago

I've tried to kill all gpg related processes with:

pkill -9 gpg-agent; pkill -9 scdaemon; pkill -9 keyboxd

Then, I've executed yubikey-touch-detector and tested with:

echo test | gpg -se -u "$KEYID" -r "$KEYID" | gpg -

And finally events are being printed:

DEBU[2024-03-13T19:45:42Z] Starting YubiKey touch detector              
DEBU[2024-03-13T19:45:42Z] U2F watcher on '/dev' is successfully established 
DEBU[2024-03-13T19:45:42Z] HMAC watcher on '/dev' is successfully established 
DEBU[2024-03-13T19:45:42Z] SSH watcher is successfully established      
DEBU[2024-03-13T19:45:42Z] GPG watcher is successfully established      
DEBU[2024-03-13T19:45:45Z] [notifiers/debug] GPG_1                      
DEBU[2024-03-13T19:45:49Z] AssuanSend/status: PROGRESS, learncard k 0 0 
DEBU[2024-03-13T19:45:49Z] AssuanSend/status: PROGRESS, learncard k 0 0 
DEBU[2024-03-13T19:45:49Z] AssuanSend/status: PROGRESS, learncard k 0 0 
DEBU[2024-03-13T19:45:49Z] [notifiers/debug] GPG_0 

But that worked only once. After that, encrypting/signing test string doesn't produce any event in yubikey-touch-dector. Weird 🤔

maximbaz commented 8 months ago

I see... Thanks for your experiments!

While I don't have the setup yet to reproduce this, I can speculate based on your findings.

I think you would appreciate to know these details first: the way gpg detection works does not actually "depend" on the format of pubring.kbx file, we don't even open that file! Simplifying slightly, we have a computationally-expensive way to "ask" gpg whether it's waiting on a touch, and in order to not to burn your battery we only want to ask gpg when we think there might be an ongoing gpg operation. And I noticed back in the day, that whenever any gpg operation was executed, gpg itself would open pubring.kbx for its own purposes. So all yubikey-touch-detector does, is it listens on "open" event on that file, and if that file was opened, it is assumed that now is a good time to ask gpg whether it in fact waits for a touch or not.

Based on your latest log, it looks like gpg was optimized not to open the new file every single time, but probably once on the first usage. So that is probably why the detection worked once, and never again, because yubikey-touch-detector doesn't have this signal anymore.

We'll need to think how to handle this :thinking: It was clear from the beginning that this whole logic is based on a dirty hack, and that one day gpg might change how it internally works with regards to opening keyring file. Today is that day, it seems :grin:

cc @mochaaP you might find this thread curious, since you contributed recently to improving gpg detection.

mochaaP commented 8 months ago

A few questions:

If the lock could be detected in our process, we could use that If that didn't work, another option might be hooking into the GPG daemon, but that will be platform specific (and also not very safe)

Zempashi commented 7 months ago

Here is a gpg-agent trace:

pselect6(7, [3 4 5 6], NULL, NULL, {tv_sec=4, tv_nsec=109284}, {sigmask=[], sigsetsize=8}) = 0 (Timeout)
newfstatat(AT_FDCWD, "/home/user/.gnupg", {st_mode=S_IFDIR|0700, st_size=372, ...}, 0) = 0
pselect6(7, [3 4 5 6], NULL, NULL, {tv_sec=4, tv_nsec=107341}, {sigmask=[], sigsetsize=8}) = 0 (Timeout)
newfstatat(AT_FDCWD, "/home/user/.gnupg", {st_mode=S_IFDIR|0700, st_size=372, ...}, 0) = 0
pselect6(7, [3 4 5 6], NULL, NULL, {tv_sec=4, tv_nsec=113532}, {sigmask=[], sigsetsize=8}) = 0 (Timeout)
newfstatat(AT_FDCWD, "/home/user/.gnupg", {st_mode=S_IFDIR|0700, st_size=372, ...}, 0) = 0
pselect6(7, [3 4 5 6], NULL, NULL, {tv_sec=4, tv_nsec=110907}, {sigmask=[], sigsetsize=8}) = 0 (Timeout)
newfstatat(AT_FDCWD, "/home/user/.gnupg", {st_mode=S_IFDIR|0700, st_size=372, ...}, 0) = 0
#### make access to gpg
pselect6(7, [3 4 5 6], NULL, NULL, {tv_sec=4, tv_nsec=97653}, {sigmask=[], sigsetsize=8}) = 1 (in [3], left {tv_sec=3, tv_nsec=722223909})
accept(3, {sa_family=AF_UNIX}, [110 => 2]) = 7
rt_sigprocmask(SIG_BLOCK, ~[], [HUP INT USR1 USR2 TERM], 8) = 0
clone3({flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, child_tid=0x7fb00ea00990, parent_tid=0x7fb00ea00990, exit_signal=0, stack=0x7fb00e200000, stack_size=0x7fff80, tls=0x7fb00ea006c0} => {parent_tid=[12037]}, 88) = 12037
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], NULL, 8) = 0
futex(0x7fb00fc7e060, FUTEX_WAKE_PRIVATE, 1) = 1
pselect6(7, [3 4 5 6], NULL, NULL, {tv_sec=3, tv_nsec=721822197}, {sigmask=[], sigsetsize=8}) = 0 (Timeout)
newfstatat(AT_FDCWD, "/home/user/.gnupg", {st_mode=S_IFDIR|0700, st_size=372, ...}, 0) = 0
pselect6(7, [3 4 5 6], NULL, NULL, {tv_sec=4, tv_nsec=114795}, {sigmask=[], sigsetsize=8}) = 0 (Timeout)
rt_sigprocmask(SIG_BLOCK, ~[], [HUP INT USR1 USR2 TERM], 8) = 0
clone3({flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, child_tid=0x7fb00d600990, parent_tid=0x7fb00d600990, exit_signal=0, stack=0x7fb00ce00000, stack_size=0x7fff80, tls=0x7fb00d6006c0} => {parent_tid=[12039]}, 88) = 12039
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], NULL, 8) = 0
newfstatat(AT_FDCWD, "/home/user/.gnupg", {st_mode=S_IFDIR|0700, st_size=372, ...}, 0) = 0
futex(0x7fb00fc7e060, FUTEX_WAKE_PRIVATE, 1) = 1
pselect6(7, [3 4 5 6], NULL, NULL, {tv_sec=4, tv_nsec=339646}, {sigmask=[], sigsetsize=8}) = 1 (in [3], left {tv_sec=4, tv_nsec=299400})
accept(3, {sa_family=AF_UNIX}, [110 => 2]) = 10
rt_sigprocmask(SIG_BLOCK, ~[], [HUP INT USR1 USR2 TERM], 8) = 0
clone3({flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, child_tid=0x7fb00e000990, parent_tid=0x7fb00e000990, exit_signal=0, stack=0x7fb00d800000, stack_size=0x7fff80, tls=0x7fb00e0006c0} => {parent_tid=[12040]}, 88) = 12040
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], NULL, 8) = 0
futex(0x7fb00fc7e060, FUTEX_WAKE_PRIVATE, 1) = 1
pselect6(7, [3 4 5 6], NULL, NULL, {tv_sec=3, tv_nsec=999706340}, {sigmask=[], sigsetsize=8}) = 0 (Timeout)
newfstatat(AT_FDCWD, "/home/user/.gnupg", {st_mode=S_IFDIR|0700, st_size=372, ...}, 0) = 0
pselect6(7, [3 4 5 6], NULL, NULL, {tv_sec=4, tv_nsec=111468}, {sigmask=[], sigsetsize=8}) = 0 (Timeout)
newfstatat(AT_FDCWD, "/home/user/.gnupg", {st_mode=S_IFDIR|0700, st_size=372, ...}, 0) = 0
pselect6(7, [3 4 5 6], NULL, NULL, {tv_sec=4, tv_nsec=108423}, {sigmask=[], sigsetsize=8} <detached ...>

here is a strace from keyboxd:

pselect6(6, [3 4 5], NULL, NULL, {tv_sec=1, tv_nsec=156218382}, {sigmask=[], sigsetsize=8}) = 0 (Timeout)
pselect6(6, [3 4 5], NULL, NULL, {tv_sec=4, tv_nsec=361}, {sigmask=[], sigsetsize=8}) = 0 (Timeout)
pselect6(6, [3 4 5], NULL, NULL, {tv_sec=4, tv_nsec=280}, {sigmask=[], sigsetsize=8}) = 0 (Timeout)
pselect6(6, [3 4 5], NULL, NULL, {tv_sec=4, tv_nsec=390}, {sigmask=[], sigsetsize=8}) = 1 (in [3], left {tv_sec=1, tv_nsec=548978755})
accept(3, {sa_family=AF_UNIX}, [110 => 2]) = 6
rt_sigprocmask(SIG_BLOCK, ~[], [HUP INT USR1 USR2 TERM], 8) = 0
clone3({flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, child_tid=0x7f629be00990, parent_tid=0x7f629be00990, exit_signal=0, stack=0x7f629b600000, stack_size=0x7fff80, tls=0x7f629be006c0} => {parent_tid=[12456]}, 88) = 12456
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], NULL, 8) = 0
futex(0x7f62a2689060, FUTEX_WAKE_PRIVATE, 1) = 1
pselect6(6, [3 4 5], NULL, NULL, {tv_sec=1, tv_nsec=548581642}, {sigmask=[], sigsetsize=8}) = 0 (Timeout)
pselect6(6, [3 4 5], NULL, NULL, {tv_sec=4, tv_nsec=531}, {sigmask=[], sigsetsize=8}) = 0 (Timeout)
pselect6(6, [3 4 5], NULL, NULL, {tv_sec=4, tv_nsec=301}, {sigmask=[], sigsetsize=8}) = 1 (in [3], left {tv_sec=0, tv_nsec=191218874})
accept(3, {sa_family=AF_UNIX}, [110 => 2]) = 8
rt_sigprocmask(SIG_BLOCK, ~[], [HUP INT USR1 USR2 TERM], 8) = 0
clone3({flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, child_tid=0x7f62a1c00990, parent_tid=0x7f62a1c00990, exit_signal=0, stack=0x7f62a1400000, stack_size=0x7fff80, tls=0x7f62a1c006c0} => {parent_tid=[12460]}, 88) = 12460
rt_sigprocmask(SIG_SETMASK, [HUP INT USR1 USR2 TERM], NULL, 8) = 0
futex(0x7f62a2689060, FUTEX_WAKE_PRIVATE, 1) = 1
pselect6(6, [3 4 5], NULL, NULL, {tv_sec=0, tv_nsec=190621570}, {sigmask=[], sigsetsize=8}) = 0 (Timeout)
pselect6(6, [3 4 5], NULL, NULL, {tv_sec=4, tv_nsec=420}, {sigmask=[], sigsetsize=8}) = 0 (Timeout)
pselect6(6, [3 4 5], NULL, NULL, {tv_sec=4, tv_nsec=501}, {sigmask=[], sigsetsize=8} <detached ...

Here is a test about db lock:

❯ echo 'BEGIN EXCLUSIVE; COMMIT;' | sqlite3  ~/.gnupg/public-keys.d/pubring.db
~
❯ echo 'BEGIN EXCLUSIVE; COMMIT;' | sqlite3  ~/.gnupg/public-keys.d/pubring.db                                                                                                                         
~ ## Make access to gpg
❯ echo 'BEGIN EXCLUSIVE; COMMIT;' | sqlite3  ~/.gnupg/public-keys.d/pubring.db                                                                                                                         
Runtime error near line 1: database is locked (5) 
~
❯ echo 'BEGIN EXCLUSIVE; COMMIT;' | sqlite3  ~/.gnupg/public-keys.d/pubring.db
Runtime error near line 1: database is locked (5) 
~
❯ echo 'BEGIN EXCLUSIVE; COMMIT;' | sqlite3  ~/.gnupg/public-keys.d/pubring.db
Runtime error near line 1: database is locked (5) 
~
❯ echo 'BEGIN EXCLUSIVE; COMMIT;' | sqlite3  ~/.gnupg/public-keys.d/pubring.db
Runtime error near line 1: database is locked (5) 
~
❯ echo 'BEGIN EXCLUSIVE; COMMIT;' | sqlite3  ~/.gnupg/public-keys.d/pubring.db
Runtime error near line 1: database is locked (5) 
~
❯ echo 'BEGIN EXCLUSIVE; COMMIT;' | sqlite3  ~/.gnupg/public-keys.d/pubring.db
Runtime error near line 1: database is locked (5) 
~ ## touching yubikey
❯ echo 'BEGIN EXCLUSIVE; COMMIT;' | sqlite3  ~/.gnupg/public-keys.d/pubring.db
~                          
❯ echo 'BEGIN EXCLUSIVE; COMMIT;' | sqlite3  ~/.gnupg/public-keys.d/pubring.db
mochaaP commented 7 months ago

seems great, will try to implement this after I finish my work on some Win32 drivers :sweat_smile:

mochaaP commented 7 months ago

done that. will look at it later this weekend

shumvgolove commented 7 months ago

Sorry for the delay!

I guess it's a little bit late to include debug logs since @Zempashi provided them, but just in case, I've got similar results with pubring.db locking.

Thanks for working on it @mochaaP and congrats with win drivers 🙂

mochaaP commented 7 months ago

seems this is quite trivial: we just need to poll fcntl(2) to detect the lock. or we could link to sqlite3, but that might be overkill just for this task.

maximbaz commented 7 months ago

By linking to sqlite3, would we be able to be "notified" about the lock, instead of constantly polling?

mochaaP commented 7 months ago

to my knowledge, no. the underlying syscall is the same after all.

mochaaP commented 7 months ago

But it would be easier to find the offset to lock instead of reading the database ourselves

maximbaz commented 7 months ago

I'd really love us to first explore some other ways which can be event-based, instead of poll-based... For example, although inotify's open event does not trigger every time anymore, perhaps read or access events do. If yes, it would be great to know how often they get triggered when yubikey does not wait for a touch. If we have an event, that doesn't have too much of false positives, then we can additionally filter those out either by using the lock check, or straight with the existing CheckGPGOnRequest, depending on the amount of false-positives... :thinking:

It looks like if we simply back up our .gnupg folder and remove it, it will be recreated in the new format, and so it should be easier to test this for us, and yet have a fallback :grin:

mochaaP commented 7 months ago

I already poked around using inotify, unfortunately, with no avail. 😿

strboul commented 3 months ago

Hello everyone! My system also suffers from this issue.

I'm not quite sure if it's very relevant but I see the following info when I call gpg:

gpg-agent[189318]: DBG: handle_pincache_put: caching '0/openpgp/2'->'XXXX88F6B437CEDCFXXXXXCBF383DCDF9781025FE79EF5XXXX'

Could handle_pincache_put be the event we look for? I use ykman openpgp keys set-touch enc cached setup on my Yubikey though (haven't tested it if it appears without it).

maximbaz commented 3 months ago

Could some of you try a build from https://github.com/maximbaz/yubikey-touch-detector/tree/gpg-alt branch? Run with -v flag for verbose output, see if it detects touch when it is supposed to detect, and that you don't get GPG operation detected! "too much" when there isn't a touch needed.

This is basically the same approach we already use for ssh, I am reasonably sure I tried this for normal gpg in the past and experienced some issues, but I dont remember what, and I just tried again (still on the old pubring format) and it seems to work...