It takes 8-9 secs until pinentry asks for the PIN of the OpenPGP card

Hardware Librem 5
1

I’m using an OpenPGP card in my cellphone Puris L5 for GnuPG
actions (password-store, SSH, …). It mostly takes some 8-9 seconds until the PIN entry dialog pops up. I enabled debug log for the gpg-agent and the scdaemon, see below, and the time is consumed by the scdaemon waitinng for something. What does this mean?

/tmp/gpg-agent-debug.log:

2024-05-15 10:55:09 gpg-agent[2565] DBG: chan_11 -> BYE
2024-05-15 11:07:58 gpg-agent[2565] ssh handler 0xffffb17ff1e0 for fd 10 started
2024-05-15 11:07:58 gpg-agent[2565] ssh request handler for request_identities (11) started
2024-05-15 11:07:58 gpg-agent[2565] no running SCdaemon - starting it
2024-05-15 11:07:58 gpg-agent[2565] DBG: chan_11 <- OK GNU Privacy Guard's Smartcard server ready
2024-05-15 11:07:58 gpg-agent[2565] DBG: first connection to SCdaemon established
2024-05-15 11:07:58 gpg-agent[2565] DBG: chan_11 -> GETINFO socket_name
2024-05-15 11:07:58 gpg-agent[2565] DBG: chan_11 <- D /run/user/1000/gnupg/S.scdaemon
2024-05-15 11:07:58 gpg-agent[2565] DBG: chan_11 <- OK
2024-05-15 11:07:58 gpg-agent[2565] DBG: additional connections at '/run/user/1000/gnupg/S.scdaemon'
2024-05-15 11:07:58 gpg-agent[2565] DBG: chan_11 -> OPTION event-signal=12
2024-05-15 11:07:58 gpg-agent[2565] DBG: chan_11 <- OK
2024-05-15 11:07:58 gpg-agent[2565] DBG: chan_11 -> SERIALNO

it takes 8-9 secs to get the card's SERIALNO from the scdaemon

2024-05-15 11:08:07 gpg-agent[2565] DBG: chan_11 <- S SERIALNO D27600012401030400050000A6FE0000
...

/tmp/scdaemon-debug.log:

2024-05-15 11:07:58 scdaemon[16983] listening on socket '/run/user/1000/gnupg/S.scdaemon'
2024-05-15 11:07:58 scdaemon[16983] handler for fd -1 started
2024-05-15 11:07:58 scdaemon[16983] DBG: chan_7 -> OK GNU Privacy Guard's Smartcard server ready
2024-05-15 11:07:58 scdaemon[16983] DBG: chan_7 <- GETINFO socket_name
2024-05-15 11:07:58 scdaemon[16983] DBG: chan_7 -> D /run/user/1000/gnupg/S.scdaemon
2024-05-15 11:07:58 scdaemon[16983] DBG: chan_7 -> OK
2024-05-15 11:07:58 scdaemon[16983] DBG: chan_7 <- OPTION event-signal=12
2024-05-15 11:07:58 scdaemon[16983] DBG: chan_7 -> OK
2024-05-15 11:07:58 scdaemon[16983] DBG: chan_7 <- SERIALNO

It takes 8 secs until scdaemon detects the reader, waht does this maen?

2024-05-15 11:08:06 scdaemon[16983] detected reader 'L5 built-in SmartCard Reader 00 00'
2024-05-15 11:08:06 scdaemon[16983] detected reader 'L5 built-in SmartCard Reader 00 01'
2024-05-15 11:08:06 scdaemon[16983] reader slot 0: not connected
2024-05-15 11:08:06 scdaemon[16983] reader slot 0: active protocol: T1
2024-05-15 11:08:06 scdaemon[16983] slot 0: ATR=3B DA 18 FF 81 B1 FE 75 1F 03 00 31 F5 73 C0 01 60 00 90 00 1C
2024-05-15 11:08:06 scdaemon[16983] AID: D2 76 00 01 24 01 03 04 00 05 00 00 A6 FE 00 00
2024-05-15 11:08:06 scdaemon[16983] Historical Bytes: 00 31 F5 73 C0 01 60 05 90 00
2024-05-15 11:08:06 scdaemon[16983] Version-2+ .....: yes
2 Likes
2

To unlock the OpenPGP card among other processes the pcscd daemon is used. This is started when needed by a service:

purism@pureos:~$ systemctl status pcscd
● pcscd.service - PC/SC Smart Card Daemon
     Loaded: loaded (/lib/systemd/system/pcscd.service; indirect; vendor pres>
    Drop-In: /usr/lib/systemd/system/pcscd.service.d
             └─librem5.conf
     Active: inactive (dead)
TriggeredBy: ● pcscd.socket
       Docs: man:pcscd(8)

(here shown as inactive).
While looking around how I could instrument this for debugging, I found the following control file:

purism@pureos:~$ cat /usr/lib/systemd/system/pcscd.service.d/librem5.conf
[Service]
ExecStartPre=/bin/bash -c "echo 1 > /sys/class/leds/smc_en/brightness && sleep 5"
ExecStopPost=/bin/bash -c "echo 0 > /sys/class/leds/smc_en/brightness"

Why is there a sleep 5 ?
And, for what this echo 1 > ... is good for?

1 Like