gpg-agent for ssh does not respond anymore since libassuan update

npreining · 2024-03-27 23:50:31

After today's update, gpg-agent listening on the ssh agent socket does not respond anymore.
Debugging with ssh -v -v -v shows that it hangs on communication with the agent (which is running).

Today's update brought in libassuan 2.5.7 which is responsible for IPC communication, so my guess is that this is the culprit.

Despite rebooting etc, gpg agent for ssh is not working now.

seth · 2024-03-28 08:44:31

Have you verified by downgraing assuan to see whether that restores functionality?

npreining · 2024-03-28 09:30:39

I have now checked, and it seems independent of libassuan, but scdaemon hangs. I have set up logs (log-level guru) for gpg-agent and scdaemon, and it fails to do anything useful.
I have my GPG key on a Yubikey, but independent of the key being plugged in or not, scdaemon just does not work.

When doing some gpg command, or eg ssh-add -L, the commands hang indefinitely. When I kill -9 scdaemon, that very instant gpg continues and I get an answer.

npreining · 2024-03-28 11:05:34

Here a typical example, yubikey plugged in, calling

gpg --edit-card

I get scdaemon hangig:

gpg-agent.log

2024-03-28 20:01:20 gpg-agent[4884] first connection to daemon /usr/lib/gnupg/scdaemon established
2024-03-28 20:01:20 gpg-agent[4884] DBG: chan_11 -> GETINFO socket_name
2024-03-28 20:01:20 gpg-agent[4884] DBG: chan_11 <- D /run/user/1000/gnupg/S.scdaemon
2024-03-28 20:01:20 gpg-agent[4884] DBG: chan_11 <- OK
2024-03-28 20:01:20 gpg-agent[4884] DBG: additional connections at '/run/user/1000/gnupg/S.scdaemon'
2024-03-28 20:01:20 gpg-agent[4884] DBG: chan_11 -> OPTION event-signal=12
2024-03-28 20:01:20 gpg-agent[4884] DBG: chan_11 <- OK
2024-03-28 20:01:20 gpg-agent[4884] DBG: chan_11 -> GETINFO version
2024-03-28 20:01:20 gpg-agent[4884] DBG: chan_11 <- D 2.4.5
2024-03-28 20:01:20 gpg-agent[4884] DBG: chan_11 <- OK
2024-03-28 20:01:20 gpg-agent[4884] DBG: chan_10 -> D 2.4.5
2024-03-28 20:01:20 gpg-agent[4884] DBG: chan_10 -> OK
2024-03-28 20:01:20 gpg-agent[4884] DBG: chan_10 <- SCD SERIALNO
2024-03-28 20:01:20 gpg-agent[4884] DBG: chan_11 -> SERIALNO

scdaemon.log

2024-03-28 20:01:20 scdaemon[4886] listening on socket '/run/user/1000/gnupg/S.scdaemon'
2024-03-28 20:01:20 scdaemon[4886] handler for fd -1 started
2024-03-28 20:01:20 scdaemon[4886] DBG: chan_7 -> OK GNU Privacy Guard's Smartcard server ready
2024-03-28 20:01:20 scdaemon[4886] DBG: chan_7 <- GETINFO socket_name
2024-03-28 20:01:20 scdaemon[4886] DBG: chan_7 -> D /run/user/1000/gnupg/S.scdaemon
2024-03-28 20:01:20 scdaemon[4886] DBG: chan_7 -> OK
2024-03-28 20:01:20 scdaemon[4886] DBG: chan_7 <- OPTION event-signal=12
2024-03-28 20:01:20 scdaemon[4886] DBG: chan_7 -> OK
2024-03-28 20:01:20 scdaemon[4886] DBG: chan_7 <- GETINFO version
2024-03-28 20:01:20 scdaemon[4886] DBG: chan_7 -> D 2.4.5
2024-03-28 20:01:20 scdaemon[4886] DBG: chan_7 -> OK
2024-03-28 20:01:20 scdaemon[4886] DBG: chan_7 <- SERIALNO

and there it hangs forever.

Last edited by npreining (2024-03-28 14:22:24)

seth · 2024-03-28 14:01:09

Please use [code][/code] tags. Edit your post in this regard.

Upstream report: https://dev.gnupg.org/T7066
https://dev.gnupg.org/T7044 actually looks somewhat related (windows or not) for "thread 7208.4: SERIALNO --all (and wait for write lock for card_top)"

When I kill -9 scdaemon, that very instant gpg continues and I get an answer.

So is it a regression of an https://archlinux.org/packages/core/x86_64/gnupg/ update?

mikezackles · 2024-04-01 15:24:34

In case it's related -- just chiming in to say that gpg --decrypt was hanging for me, and downgrading libassuan did indeed fix the problem.

seth · 2024-04-01 22:40:58

https://dev.gnupg.org/T7066#184601 suggest this to be a kernel related issue - three things that have shown up itr are
* bluetooth
* nouveau
*zswap

Anything in the dmesg/system journal?
(nouveau and zswap issues will typically show up there and zswap can also justbe disabled via kernel parameter)

theswitchy · 2024-04-03 10:45:16

I can confirm that a kernel downgrade from 6.8.2 back to 6.8.1 worked for me. Indeed, there were a couple of issues that showed up in the journal on 6.8.2 that were maybe symptomatic of this:

Apr 03 20:55:16 hostname kernel: usb usb1-port14: disabled by hub (EMI?), re-enabling...
Apr 03 20:55:16 hostname kernel: usb 1-14: USB disconnect, device number 3
Apr 03 20:55:16 hostname kernel: Bluetooth: hci0: Failed to send firmware data (-19)
Apr 03 20:55:16 hostname kernel: Bluetooth: hci0: FW download error recovery failed (-108)
Apr 03 20:55:16 hostname kernel: Bluetooth: hci0: sending frame failed (-19)
Apr 03 20:55:16 hostname kernel: Bluetooth: hci0: sending frame failed (-19)
Apr 03 20:55:16 hostname kernel: BUG: kernel NULL pointer dereference, address: 0000000000000070
Apr 03 20:55:16 hostname kernel: #PF: supervisor read access in kernel mode
Apr 03 20:55:16 hostname kernel: #PF: error_code(0x0000) - not-present page

This was followed by a kernel oops, related to the bluetooth failure:

Apr 03 20:55:16 hostname kernel: Oops: 0000 [#1] PREEMPT SMP PTI
Apr 03 20:55:16 hostname kernel: CPU: 7 PID: 426 Comm: kworker/u17:1 Tainted: G           OE      6.8.2-arch2-1 #1 a430fb92f7ba43092b62bbe6bac995458d3d442d
Apr 03 20:55:16 hostname kernel: Hardware name: Dell Inc. Latitude 5401/0D2RTT, BIOS 1.10.1 08/03/2020
Apr 03 20:55:16 hostname kernel: Workqueue: hci0 hci_power_on [bluetooth]
Apr 03 20:55:16 hostname kernel: RIP: 0010:btintel_read_debug_features+0x4d/0xf0 [btintel]
Apr 03 20:55:16 hostname kernel: Code: 65 48 8b 04 25 28 00 00 00 48 89 44 24 08 31 c0 48 8d 4c 24 07 c6 44 24 07 01 e8 de c9 12 00 48 89 c3 48 3d 00 f0 ff ff 77 49 <83> 78 70 13 75 67 48 8b 80 d0 00 00 00 be 02 00 00 00 48 89 df 48
Apr 03 20:55:16 hostname kernel: RSP: 0018:ffffaab48100bcc0 EFLAGS: 00010207
Apr 03 20:55:16 hostname kernel: RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffff9e1a8b76cab0
Apr 03 20:55:16 hostname kernel: RDX: 0000000000000000 RSI: 0000000000000202 RDI: ffff9e1a8b76caa8
Apr 03 20:55:16 hostname kernel: RBP: ffffaab48100bcf0 R08: ffff9e1a8b76cab0 R09: 0000000000000000
Apr 03 20:55:16 hostname kernel: R10: 0000000000000001 R11: 0000000000000100 R12: ffff9e1a8b76c000
Apr 03 20:55:16 hostname kernel: R13: ffff9e1a811ff100 R14: ffff9e1a89f7da05 R15: ffff9e1a8b76c6d0
Apr 03 20:55:16 hostname kernel: FS:  0000000000000000(0000) GS:ffff9e1dee5c0000(0000) knlGS:0000000000000000
Apr 03 20:55:16 hostname kernel: CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Apr 03 20:55:16 hostname kernel: CR2: 0000000000000070 CR3: 00000002dee20002 CR4: 00000000003706f0
Apr 03 20:55:16 hostname kernel: Call Trace:
Apr 03 20:55:16 hostname kernel:  <TASK>
Apr 03 20:55:16 hostname kernel:  ? __die+0x23/0x70
Apr 03 20:55:16 hostname kernel:  ? page_fault_oops+0x171/0x4e0
Apr 03 20:55:16 hostname kernel:  ? __timer_delete_sync+0x7d/0xe0
Apr 03 20:55:16 hostname kernel:  ? exc_page_fault+0x7f/0x180
Apr 03 20:55:16 hostname kernel:  ? asm_exc_page_fault+0x26/0x30
Apr 03 20:55:16 hostname kernel:  ? btintel_read_debug_features+0x4d/0xf0 [btintel 6735e787c9ed982ceaa471c7ab364a390a1acb37]
Apr 03 20:55:16 hostname kernel:  btintel_register_devcoredump_support.isra.0+0x3e/0x110 [btintel 6735e787c9ed982ceaa471c7ab364a390a1acb37]
Apr 03 20:55:16 hostname kernel:  btintel_setup_combined+0x2ab/0x790 [btintel 6735e787c9ed982ceaa471c7ab364a390a1acb37]
Apr 03 20:55:16 hostname kernel:  hci_dev_open_sync+0x102/0xc20 [bluetooth 81a2e5f6c3a85f38dade670bfe91d861a9119613]
Apr 03 20:55:16 hostname kernel:  ? __schedule+0x3ee/0x1520
Apr 03 20:55:16 hostname kernel:  hci_dev_do_open+0x23/0x60 [bluetooth 81a2e5f6c3a85f38dade670bfe91d861a9119613]
Apr 03 20:55:16 hostname kernel:  hci_power_on+0x51/0x260 [bluetooth 81a2e5f6c3a85f38dade670bfe91d861a9119613]
Apr 03 20:55:16 hostname kernel:  process_one_work+0x183/0x370
Apr 03 20:55:16 hostname kernel:  worker_thread+0x3ab/0x4f0
Apr 03 20:55:16 hostname kernel:  ? __pfx_worker_thread+0x10/0x10
Apr 03 20:55:16 hostname kernel:  kthread+0xe5/0x120
Apr 03 20:55:16 hostname kernel:  ? __pfx_kthread+0x10/0x10
Apr 03 20:55:16 hostname kernel:  ret_from_fork+0x31/0x50
Apr 03 20:55:16 hostname kernel:  ? __pfx_kthread+0x10/0x10
Apr 03 20:55:16 hostname kernel:  ret_from_fork_asm+0x1b/0x30
Apr 03 20:55:16 hostname kernel:  </TASK>

npreining · 2024-04-03 11:12:20

I am currently testing original 6.8.2 kernel (without Arch patches) and see whether this is a bug in the Arch patches or somewhere between 6.8.1 and 6.8.2 mainline. If necessary, I will bisect.

seth · 2024-04-03 12:53:40

The backtrace there is https://bbs.archlinux.org/viewtopic.php?id=294310

rca · 2024-04-03 18:13:30

I hit the same issue, scdaemon not responding to SCD SERIALNO command. I tried to downgrade libassuan, pinentry and gnupg, each time restarting gpg-agent, but to no avail.

I then downgraded my kernel from linux-lts-6.6.23-1 to linux-lts-6.6.11-1 and after a reboot gpg-agent works again.

Arch Linux

#1 2024-03-27 23:50:31

gpg-agent for ssh does not respond anymore since libassuan update

#2 2024-03-28 08:44:31

Re: gpg-agent for ssh does not respond anymore since libassuan update

#3 2024-03-28 09:30:39

Re: gpg-agent for ssh does not respond anymore since libassuan update

#4 2024-03-28 11:05:34

Re: gpg-agent for ssh does not respond anymore since libassuan update

#5 2024-03-28 14:01:09

Re: gpg-agent for ssh does not respond anymore since libassuan update

#6 2024-04-01 15:24:34

Re: gpg-agent for ssh does not respond anymore since libassuan update

#7 2024-04-01 22:40:58

Re: gpg-agent for ssh does not respond anymore since libassuan update

#8 2024-04-03 10:45:16

Re: gpg-agent for ssh does not respond anymore since libassuan update

#9 2024-04-03 11:12:20

Re: gpg-agent for ssh does not respond anymore since libassuan update

#10 2024-04-03 12:53:40

Re: gpg-agent for ssh does not respond anymore since libassuan update

#11 2024-04-03 18:13:30

Re: gpg-agent for ssh does not respond anymore since libassuan update

Board footer