scdaemon: Sometimes a newly detected card is immediately considered removed
Open, NormalPublic
Actions

Assigned To

Authored By

	ikloecker
	Feb 26 2024, 1:44 PM

Description

When reloading the smart cards in Kleopatra after inserting a NetKey v3 card in the reader then about half of the time Kleopatra needs two attempts to load the new card. Logging (see below) shows that scdaemon seems to consider the card removed sometimes.

How to reproduce:

Have an empty GNUPGHOME.
Start Kleopatra.
Insert the card into the reader.
In Kleopatra switch to the Smart Card view and press Reload.

Expected:
After some time information about the smart card is displayed. (At first the list of certificates is empty while Kleopatra/gpgsm learns the card in the background.)

Observed:
About half of the time Kleopatra shows a tab for the smart card with incomplete or wrong information, e.g. showing the error message "NKS-VERSION failed: ERR Card removed <SCD>". Kleopatra immediately retries to load the smart card so that the information is updated to the correct information after a few seconds.

This is the scdaemon log (with debug ipc,cardio) of the failed attempt to read the card:

2024-02-26 11:50:12 scdaemon[20787] handler for fd 13 started
2024-02-26 11:50:12 scdaemon[20787] DBG: chan_13 -> OK GNU Privacy Guard's Smartcard server ready
2024-02-26 11:50:12 scdaemon[20787] DBG: chan_13 <- SERIALNO --all
2024-02-26 11:50:12 scdaemon[20787] ccid open error: skip
2024-02-26 11:50:13 scdaemon[20787] reader slot 0: using ccid driver
2024-02-26 11:50:13 scdaemon[20787] slot 0: ATR=3bbf96008131fe5d00640411030131c073f701d00090007d
2024-02-26 11:50:13 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=00 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:13 scdaemon[20787] DBG:  raw apdu: 00a4000c023f00
2024-02-26 11:50:13 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:13 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:13 scdaemon[20787] DBG:  raw apdu: 00a4020c022f02
2024-02-26 11:50:13 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:13 scdaemon[20787] DBG: send apdu: c=00 i=B0 p1=00 p2=00 lc=-1 le=0 em=0
2024-02-26 11:50:13 scdaemon[20787] DBG:  raw apdu: 00b0000000
2024-02-26 11:50:13 scdaemon[20787] DBG:  response: sw=9000  datalen=12
2024-02-26 11:50:13 scdaemon[20787] DBG:      dump: 5a0a89490173300026616520
2024-02-26 11:50:13 scdaemon[20787] DBG: send apdu: c=00 i=B0 p1=00 p2=0C lc=-1 le=0 em=0
2024-02-26 11:50:13 scdaemon[20787] DBG:  raw apdu: 00b0000c00
2024-02-26 11:50:13 scdaemon[20787] DBG:  response: sw=6B00  datalen=0
2024-02-26 11:50:13 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=04 p2=00 lc=6 le=-1 em=0
2024-02-26 11:50:13 scdaemon[20787] DBG:  raw apdu: 00a4040006d27600012401
2024-02-26 11:50:13 scdaemon[20787] DBG:  response: sw=6700  datalen=0
2024-02-26 11:50:13 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=04 p2=00 lc=9 le=256 em=0
2024-02-26 11:50:13 scdaemon[20787] DBG:  raw apdu: 00a4040009a0000003080000100000
2024-02-26 11:50:13 scdaemon[20787] DBG:  response: sw=6A82  datalen=0
2024-02-26 11:50:13 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=04 p2=0C lc=7 le=-1 em=0
2024-02-26 11:50:13 scdaemon[20787] DBG:  raw apdu: 00a4040c07d2760000030102
2024-02-26 11:50:14 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:14 scdaemon[20787] DBG:  raw apdu: 80aa060000
2024-02-26 11:50:14 scdaemon[20787] DBG:  response: sw=9000  datalen=16
2024-02-26 11:50:14 scdaemon[20787] DBG:       dump:  04110a15fa93318003030101010000009000
2024-02-26 11:50:14 scdaemon[20787] Detected NKS version: 3
2024-02-26 11:50:15 scdaemon[20787] ccid open error: skip
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_7 -> S DEVINFO_STATUS new
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_7 -> S DEVINFO_START
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_7 -> S DEVICE generic 89490173300026616520 nks
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_7 -> S DEVINFO_END
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 -> S SERIALNO 89490173300026616520
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 -> OK
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 <- GETINFO all_active_apps
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 -> S SERIALNO 89490173300026616520 nks
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 -> OK
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 <- SWITCHCARD 89490173300026616520
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 -> S SERIALNO 89490173300026616520
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 -> OK
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 <- SWITCHAPP nks
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 -> S SERIALNO 89490173300026616520 nks
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 -> OK
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 <- GETATTR $SIGNKEYID
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 -> S $SIGNKEYID NKS-NKS3.4531
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 -> OK
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_7 -> S DEVINFO_STATUS removal
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_7 -> S DEVINFO_START
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_7 -> S DEVINFO_END
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 <- GETATTR $ENCRKEYID
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 -> ERR 100663406 Card removed <SCD>
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 <- GETATTR NKS-VERSION
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 -> ERR 100663406 Card removed <SCD>
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 <- GETINFO all_active_apps
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 -> ERR 100663408 Card not present <SCD>
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 <- BYE
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 -> OK closing connection
2024-02-26 11:50:15 scdaemon[20787] handler for fd 13 terminated

And this is the scdaemon log of the immediately following (successful) attempt to read the card:

2024-02-26 11:50:15 scdaemon[20787] handler for fd 13 started
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 -> OK GNU Privacy Guard's Smartcard server ready
2024-02-26 11:50:15 scdaemon[20787] DBG: chan_13 <- SERIALNO --all
2024-02-26 11:50:15 scdaemon[20787] ccid open error: skip
2024-02-26 11:50:15 scdaemon[20787] reader slot 0: using ccid driver
2024-02-26 11:50:15 scdaemon[20787] slot 0: ATR=3bbf96008131fe5d00640411030131c073f701d00090007d
2024-02-26 11:50:15 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=00 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:15 scdaemon[20787] DBG:  raw apdu: 00a4000c023f00
2024-02-26 11:50:16 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:16 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:16 scdaemon[20787] DBG:  raw apdu: 00a4020c022f02
2024-02-26 11:50:16 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:16 scdaemon[20787] DBG: send apdu: c=00 i=B0 p1=00 p2=00 lc=-1 le=0 em=0
2024-02-26 11:50:16 scdaemon[20787] DBG:  raw apdu: 00b0000000
2024-02-26 11:50:16 scdaemon[20787] DBG:  response: sw=9000  datalen=12
2024-02-26 11:50:16 scdaemon[20787] DBG:      dump: 5a0a89490173300026616520
2024-02-26 11:50:16 scdaemon[20787] DBG: send apdu: c=00 i=B0 p1=00 p2=0C lc=-1 le=0 em=0
2024-02-26 11:50:16 scdaemon[20787] DBG:  raw apdu: 00b0000c00
2024-02-26 11:50:16 scdaemon[20787] DBG:  response: sw=6B00  datalen=0
2024-02-26 11:50:16 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=04 p2=00 lc=6 le=-1 em=0
2024-02-26 11:50:16 scdaemon[20787] DBG:  raw apdu: 00a4040006d27600012401
2024-02-26 11:50:16 scdaemon[20787] DBG:  response: sw=6700  datalen=0
2024-02-26 11:50:16 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=04 p2=00 lc=9 le=256 em=0
2024-02-26 11:50:16 scdaemon[20787] DBG:  raw apdu: 00a4040009a0000003080000100000
2024-02-26 11:50:16 scdaemon[20787] DBG:  response: sw=6A82  datalen=0
2024-02-26 11:50:16 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=04 p2=0C lc=7 le=-1 em=0
2024-02-26 11:50:16 scdaemon[20787] DBG:  raw apdu: 00a4040c07d2760000030102
2024-02-26 11:50:17 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:17 scdaemon[20787] DBG:  raw apdu: 80aa060000
2024-02-26 11:50:17 scdaemon[20787] DBG:  response: sw=9000  datalen=16
2024-02-26 11:50:17 scdaemon[20787] DBG:       dump:  04110a15fa93318003030101010000009000
2024-02-26 11:50:17 scdaemon[20787] Detected NKS version: 3
2024-02-26 11:50:17 scdaemon[20787] ccid open error: skip
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_7 -> S DEVINFO_STATUS new
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_7 -> S DEVINFO_START
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_7 -> S DEVICE generic 89490173300026616520 nks
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_7 -> S DEVINFO_END
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 -> S SERIALNO 89490173300026616520
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 -> OK
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 <- GETINFO all_active_apps
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 -> S SERIALNO 89490173300026616520 nks
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 -> OK
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 <- SWITCHCARD 89490173300026616520
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 -> S SERIALNO 89490173300026616520
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 -> OK
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 <- SWITCHAPP nks
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 -> S SERIALNO 89490173300026616520 nks
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 -> OK
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 <- GETATTR $SIGNKEYID
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 -> S $SIGNKEYID NKS-NKS3.4531
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 -> OK
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 <- GETATTR $ENCRKEYID
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 -> S $ENCRKEYID NKS-NKS3.45B1
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 -> OK
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 <- GETATTR NKS-VERSION
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 -> S NKS-VERSION 3
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 -> OK
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 <- GETATTR $DISPSERIALNO
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 -> S $DISPSERIALNO 8949017330002661652
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 -> OK
2024-02-26 11:50:17 scdaemon[20787] DBG: chan_13 <- GETATTR CHV-STATUS
2024-02-26 11:50:17 scdaemon[20787] DBG:  raw apdu: 00200000
2024-02-26 11:50:17 scdaemon[20787] DBG:  response: sw=63C3  datalen=0
2024-02-26 11:50:17 scdaemon[20787] DBG:  raw apdu: 00200001
2024-02-26 11:50:17 scdaemon[20787] DBG:  response: sw=63C0  datalen=0
2024-02-26 11:50:17 scdaemon[20787] nks: switching to SigG
2024-02-26 11:50:17 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=04 p2=0C lc=6 le=-1 em=0
2024-02-26 11:50:17 scdaemon[20787] DBG:  raw apdu: 00a4040c06d27600006601
2024-02-26 11:50:18 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:18 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:18 scdaemon[20787] DBG:  raw apdu: 00a4020c025349
2024-02-26 11:50:18 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:18 scdaemon[20787] DBG: send apdu: c=00 i=B2 p1=01 p2=04 lc=-1 le=0 em=0
2024-02-26 11:50:18 scdaemon[20787] DBG:  raw apdu: 00b2010400
2024-02-26 11:50:18 scdaemon[20787] DBG:  response: sw=9000  datalen=105
2024-02-26 11:50:18 scdaemon[20787] DBG:      dump: a04c830184941903008180200181802002818020038180200481802005082006 \
2024-02-26 11:50:18 scdaemon[20787] DBG:  8a0105a129910101ab1a87032a9e9aaf13a409950108830181830183b4069501 \
2024-02-26 11:50:18 scdaemon[20787] DBG:  30830175910102ab058401479700b6199501407b068001008901027a0c930200 \
2024-02-26 11:50:18 scdaemon[20787] DBG:  01a406830181830183
2024-02-26 11:50:18 scdaemon[20787] DBG:  raw apdu: 00200081
2024-02-26 11:50:18 scdaemon[20787] DBG:  response: sw=63C3  datalen=0
2024-02-26 11:50:18 scdaemon[20787] DBG:  raw apdu: 00200083
2024-02-26 11:50:18 scdaemon[20787] DBG:  response: sw=63C0  datalen=0
2024-02-26 11:50:18 scdaemon[20787] DBG: chan_13 -> S CHV-STATUS 3+0+3+0
2024-02-26 11:50:18 scdaemon[20787] DBG: chan_13 -> OK
2024-02-26 11:50:18 scdaemon[20787] DBG: chan_13 <- LEARN --force
2024-02-26 11:50:18 scdaemon[20787] DBG: chan_13 -> S READER 04E6:E003:51271834208013:0
2024-02-26 11:50:18 scdaemon[20787] DBG: chan_13 -> S SERIALNO 89490173300026616520
2024-02-26 11:50:18 scdaemon[20787] DBG: chan_13 -> S APPTYPE nks
2024-02-26 11:50:18 scdaemon[20787] DBG: chan_13 -> S APPVERSION 3
2024-02-26 11:50:18 scdaemon[20787] nks: switching to NKS
2024-02-26 11:50:18 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=04 p2=0C lc=7 le=-1 em=0
2024-02-26 11:50:18 scdaemon[20787] DBG:  raw apdu: 00a4040c07d2760000030102
2024-02-26 11:50:19 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:19 scdaemon[20787] DBG:  raw apdu: 00200000
2024-02-26 11:50:19 scdaemon[20787] DBG:  response: sw=63C3  datalen=0
2024-02-26 11:50:19 scdaemon[20787] DBG:  raw apdu: 00200001
2024-02-26 11:50:19 scdaemon[20787] DBG:  response: sw=63C0  datalen=0
2024-02-26 11:50:19 scdaemon[20787] nks: switching to SigG
2024-02-26 11:50:19 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=04 p2=0C lc=6 le=-1 em=0
2024-02-26 11:50:19 scdaemon[20787] DBG:  raw apdu: 00a4040c06d27600006601
2024-02-26 11:50:20 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:20 scdaemon[20787] DBG:  raw apdu: 00200081
2024-02-26 11:50:20 scdaemon[20787] DBG:  response: sw=63C3  datalen=0
2024-02-26 11:50:20 scdaemon[20787] DBG:  raw apdu: 00200083
2024-02-26 11:50:20 scdaemon[20787] DBG:  response: sw=63C0  datalen=0
2024-02-26 11:50:20 scdaemon[20787] DBG: chan_13 -> S CHV-STATUS 3+0+3+0
2024-02-26 11:50:20 scdaemon[20787] nks: switching to NKS
2024-02-26 11:50:20 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=04 p2=0C lc=7 le=-1 em=0
2024-02-26 11:50:20 scdaemon[20787] DBG:  raw apdu: 00a4040c07d2760000030102
2024-02-26 11:50:21 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:21 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:21 scdaemon[20787] DBG:  raw apdu: 00a4020c024531
2024-02-26 11:50:21 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:21 scdaemon[20787] DBG: send apdu: c=00 i=B2 p1=01 p2=04 lc=-1 le=0 em=0
2024-02-26 11:50:21 scdaemon[20787] DBG:  raw apdu: 00b2010400
2024-02-26 11:50:21 scdaemon[20787] DBG:  response: sw=9000  datalen=256
2024-02-26 11:50:21 scdaemon[20787] DBG:      dump: baab9d7dacd69afa1c0ba4b58981c0a9a2d2290dcaab55ba972bf518adaeac91 \
2024-02-26 11:50:21 scdaemon[20787] DBG:  3c470597b3186bec6db2ee6250d1b3452ddd0937befc97e98070056abbfd3c02 \
2024-02-26 11:50:21 scdaemon[20787] DBG:  81838f19947a3abf8e1643543fedf4446fdef3fd268200df90ca1c2fcebcb205 \
2024-02-26 11:50:21 scdaemon[20787] DBG:  3b799b15a481425cc260c5b8979cb2127142217a0f0696b6d589941b88a46524 \
2024-02-26 11:50:21 scdaemon[20787] DBG:  8b14e7c69200f453bf59c1b53657cac334d90a658a22843c51e5d6440410b3be \
2024-02-26 11:50:21 scdaemon[20787] DBG:  5c74ea2111f51e483777ea09eca8d096e11d4e226fc827b1c59a44c6908301da \
2024-02-26 11:50:21 scdaemon[20787] DBG:  82b09dee52cf84501ff054a3ba085a1be36a5c443cdc63dc251a878053485a2e \
2024-02-26 11:50:21 scdaemon[20787] DBG:  069d9bf15fee32d770dd3250f56be6464ebf1ec7356783a3ec7c6c156f8d5ecb
2024-02-26 11:50:21 scdaemon[20787] DBG: send apdu: c=00 i=B2 p1=02 p2=04 lc=-1 le=0 em=0
2024-02-26 11:50:21 scdaemon[20787] DBG:  raw apdu: 00b2020400
2024-02-26 11:50:21 scdaemon[20787] DBG:  response: sw=9000  datalen=8
2024-02-26 11:50:21 scdaemon[20787] DBG:      dump: 0000000040000081
2024-02-26 11:50:21 scdaemon[20787] DBG: chan_13 -> S KEYPAIRINFO 39400430E38BB96F105B740A7119FE113578B59D NKS-NKS3.4531 sa - rsa2048
2024-02-26 11:50:21 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:21 scdaemon[20787] DBG:  raw apdu: 00a4020c02c000
2024-02-26 11:50:21 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:21 scdaemon[20787] DBG: send apdu: c=00 i=B0 p1=00 p2=00 lc=-1 le=32 em=0
2024-02-26 11:50:21 scdaemon[20787] DBG:  raw apdu: 00b0000020
2024-02-26 11:50:21 scdaemon[20787] DBG:  response: sw=9000  datalen=32
2024-02-26 11:50:21 scdaemon[20787] DBG:      dump: 308203933082027ba003020102020412c5e380300d06092a864886f70d010105
2024-02-26 11:50:21 scdaemon[20787] DBG: chan_13 -> S CERTINFO 101 NKS-NKS3.C000
2024-02-26 11:50:21 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:21 scdaemon[20787] DBG:  raw apdu: 00a4020c024331
2024-02-26 11:50:22 scdaemon[20787] DBG:  response: sw=6A82  datalen=0
2024-02-26 11:50:22 scdaemon[20787] error selecting FID 0x4331: No such file or directory
2024-02-26 11:50:22 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:22 scdaemon[20787] DBG:  raw apdu: 00a4020c024332
2024-02-26 11:50:22 scdaemon[20787] DBG:  response: sw=6A82  datalen=0
2024-02-26 11:50:22 scdaemon[20787] error selecting FID 0x4332: No such file or directory
2024-02-26 11:50:22 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:22 scdaemon[20787] DBG:  raw apdu: 00a4020c02b000
2024-02-26 11:50:22 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:22 scdaemon[20787] DBG: send apdu: c=00 i=B0 p1=00 p2=00 lc=-1 le=32 em=0
2024-02-26 11:50:22 scdaemon[20787] DBG:  raw apdu: 00b0000020
2024-02-26 11:50:22 scdaemon[20787] DBG:  response: sw=9000  datalen=32
2024-02-26 11:50:22 scdaemon[20787] DBG:      dump: 318201b5308201b1308181310b3009060355040613024445311c301a06035504
2024-02-26 11:50:22 scdaemon[20787] DBG: chan_13 -> S CERTINFO 110 NKS-NKS3.B000
2024-02-26 11:50:22 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:22 scdaemon[20787] DBG:  raw apdu: 00a4020c0245b1
2024-02-26 11:50:22 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:22 scdaemon[20787] DBG: send apdu: c=00 i=B2 p1=01 p2=04 lc=-1 le=0 em=0
2024-02-26 11:50:22 scdaemon[20787] DBG:  raw apdu: 00b2010400
2024-02-26 11:50:22 scdaemon[20787] DBG:  response: sw=9000  datalen=256
2024-02-26 11:50:22 scdaemon[20787] DBG:      dump: 9e0bbe4afdeb12d55039c5ce3de79c553a0079d65cf072242590523b66980381 \
2024-02-26 11:50:22 scdaemon[20787] DBG:  d3a7f8107e67e97a8d9380678fbf69f29d2047c0662a7a730c1ebecc543c8b28 \
2024-02-26 11:50:22 scdaemon[20787] DBG:  d0a477ec83d1743ce13027e8752778b6152fd0e878657cf84505683f90a72a67 \
2024-02-26 11:50:22 scdaemon[20787] DBG:  744cf148c33f775c53e0b09ff1523af7e274dd8e0e245f91f4ec7ae82b805614 \
2024-02-26 11:50:22 scdaemon[20787] DBG:  4854758c8d69ca2192750203ac851274e12c129f3bde9d8e6474f69cc57799f0 \
2024-02-26 11:50:22 scdaemon[20787] DBG:  23c314d717517503dccffe615318d576ec660a83b7f721b7f2bac1b25ef493a9 \
2024-02-26 11:50:22 scdaemon[20787] DBG:  8c905097764fe52244f563140e485af3cd4c6c476f61d77169e66f322e86d266 \
2024-02-26 11:50:22 scdaemon[20787] DBG:  8237814a53cf88382e38761a50f4d3922201123ab9250a843ce4d95777f4d131
2024-02-26 11:50:22 scdaemon[20787] DBG: send apdu: c=00 i=B2 p1=02 p2=04 lc=-1 le=0 em=0
2024-02-26 11:50:22 scdaemon[20787] DBG:  raw apdu: 00b2020400
2024-02-26 11:50:22 scdaemon[20787] DBG:  response: sw=9000  datalen=8
2024-02-26 11:50:22 scdaemon[20787] DBG:      dump: 0000000040000081
2024-02-26 11:50:22 scdaemon[20787] DBG: chan_13 -> S KEYPAIRINFO 42C3CA6F9D7A725A59DDE06B16B61E88C62777C4 NKS-NKS3.45B1 e - rsa2048
2024-02-26 11:50:22 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:22 scdaemon[20787] DBG:  raw apdu: 00a4020c02c200
2024-02-26 11:50:22 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:22 scdaemon[20787] DBG: send apdu: c=00 i=B0 p1=00 p2=00 lc=-1 le=32 em=0
2024-02-26 11:50:22 scdaemon[20787] DBG:  raw apdu: 00b0000020
2024-02-26 11:50:22 scdaemon[20787] DBG:  response: sw=9000  datalen=32
2024-02-26 11:50:22 scdaemon[20787] DBG:      dump: 308203933082027ba003020102020429977672300d06092a864886f70d010105
2024-02-26 11:50:22 scdaemon[20787] DBG: chan_13 -> S CERTINFO 101 NKS-NKS3.C200
2024-02-26 11:50:22 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:22 scdaemon[20787] DBG:  raw apdu: 00a4020c0243b1
2024-02-26 11:50:22 scdaemon[20787] DBG:  response: sw=6A82  datalen=0
2024-02-26 11:50:22 scdaemon[20787] error selecting FID 0x43B1: No such file or directory
2024-02-26 11:50:22 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:22 scdaemon[20787] DBG:  raw apdu: 00a4020c0243b2
2024-02-26 11:50:22 scdaemon[20787] DBG:  response: sw=6A82  datalen=0
2024-02-26 11:50:22 scdaemon[20787] error selecting FID 0x43B2: No such file or directory
2024-02-26 11:50:22 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:22 scdaemon[20787] DBG:  raw apdu: 00a4020c0245b2
2024-02-26 11:50:22 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:22 scdaemon[20787] DBG: send apdu: c=00 i=B2 p1=01 p2=04 lc=-1 le=0 em=0
2024-02-26 11:50:22 scdaemon[20787] DBG:  raw apdu: 00b2010400
2024-02-26 11:50:22 scdaemon[20787] DBG:  response: sw=9000  datalen=128
2024-02-26 11:50:22 scdaemon[20787] DBG:      dump: 873dd0d151d4f6a860f97fcebc3ab373975ac63ab8bd1392aa07833ae6ddfe65 \
2024-02-26 11:50:22 scdaemon[20787] DBG:  6be26a90213b49a172fe23d9cb3576eac92fab78e85fb941cfefb6a94cdc110e \
2024-02-26 11:50:22 scdaemon[20787] DBG:  b88f69fdee1777408cd49b3e041515ddb1c676bb985a8807b118a6d421505cd5 \
2024-02-26 11:50:22 scdaemon[20787] DBG:  4c804d8eabe591d45711042b511ba6a0dcb9701b1dfed2f6ad6c8e43eb38e03b
2024-02-26 11:50:22 scdaemon[20787] DBG: send apdu: c=00 i=B2 p1=02 p2=04 lc=-1 le=0 em=0
2024-02-26 11:50:22 scdaemon[20787] DBG:  raw apdu: 00b2020400
2024-02-26 11:50:22 scdaemon[20787] DBG:  response: sw=9000  datalen=4
2024-02-26 11:50:22 scdaemon[20787] DBG:      dump: 40000081
2024-02-26 11:50:22 scdaemon[20787] DBG: chan_13 -> S KEYPAIRINFO 20E7CB1D5299669CABF29B103C692AB34CB03528 NKS-NKS3.45B2 e - rsa1024
2024-02-26 11:50:22 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:22 scdaemon[20787] DBG:  raw apdu: 00a4020c02c201
2024-02-26 11:50:22 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:22 scdaemon[20787] DBG: send apdu: c=00 i=B0 p1=00 p2=00 lc=-1 le=32 em=0
2024-02-26 11:50:22 scdaemon[20787] DBG:  raw apdu: 00b0000020
2024-02-26 11:50:22 scdaemon[20787] DBG:  response: sw=9000  datalen=32
2024-02-26 11:50:22 scdaemon[20787] DBG:      dump: 3082030f308201f7a003020102020431a037d4300d06092a864886f70d010105
2024-02-26 11:50:22 scdaemon[20787] DBG: chan_13 -> S CERTINFO 101 NKS-NKS3.C201
2024-02-26 11:50:22 scdaemon[20787] nks: switching to SigG
2024-02-26 11:50:22 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=04 p2=0C lc=6 le=-1 em=0
2024-02-26 11:50:22 scdaemon[20787] DBG:  raw apdu: 00a4040c06d27600006601
2024-02-26 11:50:23 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:23 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:23 scdaemon[20787] DBG:  raw apdu: 00a4020c024531
2024-02-26 11:50:23 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:23 scdaemon[20787] DBG: send apdu: c=00 i=B2 p1=01 p2=04 lc=-1 le=0 em=0
2024-02-26 11:50:23 scdaemon[20787] DBG:  raw apdu: 00b2010400
2024-02-26 11:50:23 scdaemon[20787] DBG:  response: sw=9000  datalen=256
2024-02-26 11:50:23 scdaemon[20787] DBG:      dump: 96bd9a93412ed10fabb039d7963caeb3c1acfabf3a8601db1747f1ee3710e399 \
2024-02-26 11:50:23 scdaemon[20787] DBG:  e6c91f1980946162fc498d81bd61aea016976077d0432ace8c06aa88ed384e9b \
2024-02-26 11:50:23 scdaemon[20787] DBG:  809127f5fceba50d58deb967f98655b0254bb38fad968a24d350d37a9a763faf \
2024-02-26 11:50:23 scdaemon[20787] DBG:  257213df2ee90d5b365a59b730508c97d72bc1788a058ff1dfeb8df83e55cbc6 \
2024-02-26 11:50:23 scdaemon[20787] DBG:  cfdd33284cf4649dea3251b852aee13ce7b22477a16065c9c91863f3e3c7abd5 \
2024-02-26 11:50:23 scdaemon[20787] DBG:  6d03404eec99603d648cff09f5db396a2860ea8c13e31ff14272d0a86756a620 \
2024-02-26 11:50:23 scdaemon[20787] DBG:  1fe8184c0b515c88053d058a31ead08d5823b134c7242715ceafb37c7402dcda \
2024-02-26 11:50:23 scdaemon[20787] DBG:  ae8fda22a7f5a9b04ce0d4ae4ae66305ea7ddaf8c95777ab167bcc384ca0d205
2024-02-26 11:50:23 scdaemon[20787] DBG: send apdu: c=00 i=B2 p1=02 p2=04 lc=-1 le=0 em=0
2024-02-26 11:50:23 scdaemon[20787] DBG:  raw apdu: 00b2020400
2024-02-26 11:50:23 scdaemon[20787] DBG:  response: sw=9000  datalen=8
2024-02-26 11:50:23 scdaemon[20787] DBG:      dump: 0000000040000081
2024-02-26 11:50:23 scdaemon[20787] DBG: chan_13 -> S KEYPAIRINFO A69B0D3796EE33E4426E5CE4B6BEEE5F1209FBA4 NKS-SIGG.4531 se - rsa2048
2024-02-26 11:50:23 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:23 scdaemon[20787] DBG:  raw apdu: 00a4020c02c000
2024-02-26 11:50:23 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:23 scdaemon[20787] DBG: send apdu: c=00 i=B0 p1=00 p2=00 lc=-1 le=32 em=0
2024-02-26 11:50:23 scdaemon[20787] DBG:  raw apdu: 00b0000020
2024-02-26 11:50:23 scdaemon[20787] DBG:  response: sw=9000  datalen=32
2024-02-26 11:50:23 scdaemon[20787] DBG:      dump: 308203633082024ba003020102020411f6cbff300d06092a864886f70d010105
2024-02-26 11:50:23 scdaemon[20787] DBG: chan_13 -> S CERTINFO 101 NKS-SIGG.C000
2024-02-26 11:50:23 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:23 scdaemon[20787] DBG:  raw apdu: 00a4020c02c008
2024-02-26 11:50:23 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:23 scdaemon[20787] DBG: send apdu: c=00 i=B0 p1=00 p2=00 lc=-1 le=32 em=0
2024-02-26 11:50:23 scdaemon[20787] DBG:  raw apdu: 00b0000020
2024-02-26 11:50:23 scdaemon[20787] DBG:  response: sw=9000  datalen=32
2024-02-26 11:50:23 scdaemon[20787] DBG:      dump: [all zero]
2024-02-26 11:50:23 scdaemon[20787] data at FID 0xC008 does not look like a certificate
2024-02-26 11:50:23 scdaemon[20787] DBG: send apdu: c=00 i=A4 p1=02 p2=0C lc=2 le=-1 em=0
2024-02-26 11:50:23 scdaemon[20787] DBG:  raw apdu: 00a4020c02c00e
2024-02-26 11:50:24 scdaemon[20787] DBG:  response: sw=9000  datalen=0
2024-02-26 11:50:24 scdaemon[20787] DBG: send apdu: c=00 i=B0 p1=00 p2=00 lc=-1 le=32 em=0
2024-02-26 11:50:24 scdaemon[20787] DBG:  raw apdu: 00b0000020
2024-02-26 11:50:24 scdaemon[20787] DBG:  response: sw=9000  datalen=32
2024-02-26 11:50:24 scdaemon[20787] DBG:      dump: [all zero]
2024-02-26 11:50:24 scdaemon[20787] data at FID 0xC00E does not look like a certificate
2024-02-26 11:50:24 scdaemon[20787] DBG: chan_13 -> OK
2024-02-26 11:50:24 scdaemon[20787] DBG: chan_13 <- GETATTR SERIALNO
2024-02-26 11:50:24 scdaemon[20787] DBG: chan_13 -> S SERIALNO 89490173300026616520
2024-02-26 11:50:24 scdaemon[20787] DBG: chan_13 -> OK
[...]

Event Timeline

ikloecker created this task.Feb 26 2024, 1:44 PM

At the failed attempt I notice a DEVINFO_STATUS removal soon after the SWITCHCARD. This is related to the reader status file and triggered by ccid_slot_status. --debug ipc.app,reader might be a better selection of debug flags here.

Here are logs with debug ipc,app,reader:

2024-02-29 15:12:07 scdaemon[20881] handler for fd 13 started
2024-02-29 15:12:07 scdaemon[20881] DBG: chan_13 -> OK GNU Privacy Guard's Smartcard server ready
2024-02-29 15:12:07 scdaemon[20881] DBG: chan_13 <- SERIALNO --all
2024-02-29 15:12:07 scdaemon[20881] DBG: apdu_open_reader: BAI=60900
2024-02-29 15:12:07 scdaemon[20881] DBG: apdu_open_reader: new device=60900
2024-02-29 15:12:07 scdaemon[20881] ccid open error: skip
2024-02-29 15:12:07 scdaemon[20881] DBG: apdu_open_reader: BAI=60a00
2024-02-29 15:12:07 scdaemon[20881] DBG: apdu_open_reader: new device=60a00
2024-02-29 15:12:08 scdaemon[20881] reader slot 0: using ccid driver
2024-02-29 15:12:08 scdaemon[20881] slot 0: ATR=3bbf96008131fe5d00640411030131c073f701d00090007d
2024-02-29 15:12:08 scdaemon[20881] DBG: enter: apdu_connect: slot=0
2024-02-29 15:12:08 scdaemon[20881] DBG: leave: apdu_connect => sw=0x0
2024-02-29 15:12:09 scdaemon[20881] Detected NKS version: 3
2024-02-29 15:12:09 scdaemon[20881] DBG: apdu_open_reader: BAI=40200
2024-02-29 15:12:09 scdaemon[20881] DBG: apdu_open_reader: new device=40200
2024-02-29 15:12:09 scdaemon[20881] ccid open error: skip
2024-02-29 15:12:09 scdaemon[20881] DBG: enter: apdu_get_status: slot=0 hang=0
2024-02-29 15:12:09 scdaemon[20881] DBG: leave: apdu_get_status => sw=0x0 status=7
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_7 -> S DEVINFO_STATUS new
2024-02-29 15:12:09 scdaemon[20881] DBG: enter: apdu_get_status: slot=0 hang=0
2024-02-29 15:12:09 scdaemon[20881] DBG: leave: apdu_get_status => sw=0x0 status=7
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_7 -> S DEVINFO_START
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_7 -> S DEVICE generic 89490173300026616520 nks
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_7 -> S DEVINFO_END
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> S SERIALNO 89490173300026616520
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> OK
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 <- GETINFO all_active_apps
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> S SERIALNO 89490173300026616520 nks
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> OK
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 <- SWITCHCARD 89490173300026616520
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> S SERIALNO 89490173300026616520
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> OK
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 <- SWITCHAPP nks
2024-02-29 15:12:09 scdaemon[20881] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> S SERIALNO 89490173300026616520 nks
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> OK
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 <- GETATTR $SIGNKEYID
2024-02-29 15:12:09 scdaemon[20881] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:12:09 scdaemon[20881] DBG: slot 0 app nks: calling getattr($SIGNKEYID)
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> S $SIGNKEYID NKS-NKS3.4531
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> OK
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 <- GETATTR $ENCRKEYID
2024-02-29 15:12:09 scdaemon[20881] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:12:09 scdaemon[20881] DBG: slot 0 app nks: calling getattr($ENCRKEYID)
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> S $ENCRKEYID NKS-NKS3.45B1
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> OK
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 <- GETATTR NKS-VERSION
2024-02-29 15:12:09 scdaemon[20881] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:12:09 scdaemon[20881] DBG: slot 0 app nks: calling getattr(NKS-VERSION)
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> S NKS-VERSION 3
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> OK
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 <- GETATTR $DISPSERIALNO
2024-02-29 15:12:09 scdaemon[20881] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:12:09 scdaemon[20881] DBG: slot 0 app nks: calling getattr($DISPSERIALNO)
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> S $DISPSERIALNO 8949017330002661652
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> OK
2024-02-29 15:12:09 scdaemon[20881] DBG: enter: apdu_get_status: slot=0 hang=0
2024-02-29 15:12:09 scdaemon[20881] DBG: leave: apdu_get_status => sw=0x1000c status=0
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_7 -> S DEVINFO_STATUS removal
2024-02-29 15:12:09 scdaemon[20881] DBG: Removal of a card: 0
2024-02-29 15:12:09 scdaemon[20881] DBG: enter: apdu_close_reader: slot=0
2024-02-29 15:12:09 scdaemon[20881] DBG: enter: apdu_disconnect: slot=0
2024-02-29 15:12:09 scdaemon[20881] DBG: leave: apdu_disconnect => sw=0x0
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 <- GETATTR CHV-STATUS
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> ERR 100663406 Card removed <SCD>
2024-02-29 15:12:09 scdaemon[20881] DBG: leave: apdu_close_reader => 0x0 (close_reader)
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_7 -> S DEVINFO_START
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_7 -> S DEVINFO_END
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 <- GETINFO all_active_apps
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> ERR 100663408 Card not present <SCD>
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 <- BYE
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_13 -> OK closing connection
2024-02-29 15:12:09 scdaemon[20881] handler for fd 13 terminated

For comparison, the logs when it doesn't fail:

2024-02-29 15:08:33 scdaemon[20536] handler for fd 13 started
2024-02-29 15:08:33 scdaemon[20536] DBG: chan_13 -> OK GNU Privacy Guard's Smartcard server ready
2024-02-29 15:08:33 scdaemon[20536] DBG: chan_13 <- SERIALNO --all
2024-02-29 15:08:33 scdaemon[20536] DBG: apdu_open_reader: BAI=60900
2024-02-29 15:08:33 scdaemon[20536] DBG: apdu_open_reader: new device=60900
2024-02-29 15:08:33 scdaemon[20536] ccid open error: skip
2024-02-29 15:08:33 scdaemon[20536] DBG: apdu_open_reader: BAI=60a00
2024-02-29 15:08:33 scdaemon[20536] DBG: apdu_open_reader: new device=60a00
2024-02-29 15:08:34 scdaemon[20536] reader slot 0: using ccid driver
2024-02-29 15:08:34 scdaemon[20536] slot 0: ATR=3bbf96008131fe5d00640411030131c073f701d00090007d
2024-02-29 15:08:34 scdaemon[20536] DBG: enter: apdu_connect: slot=0
2024-02-29 15:08:34 scdaemon[20536] DBG: leave: apdu_connect => sw=0x0
2024-02-29 15:08:36 scdaemon[20536] Detected NKS version: 3
2024-02-29 15:08:36 scdaemon[20536] DBG: apdu_open_reader: BAI=40200
2024-02-29 15:08:36 scdaemon[20536] DBG: apdu_open_reader: new device=40200
2024-02-29 15:08:36 scdaemon[20536] ccid open error: skip
2024-02-29 15:08:36 scdaemon[20536] DBG: enter: apdu_get_status: slot=0 hang=0
2024-02-29 15:08:36 scdaemon[20536] DBG: leave: apdu_get_status => sw=0x0 status=7
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_7 -> S DEVINFO_STATUS new
2024-02-29 15:08:36 scdaemon[20536] DBG: enter: apdu_get_status: slot=0 hang=0
2024-02-29 15:08:36 scdaemon[20536] DBG: leave: apdu_get_status => sw=0x0 status=7
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_7 -> S DEVINFO_START
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_7 -> S DEVICE generic 89490173300026616520 nks
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_7 -> S DEVINFO_END
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 -> S SERIALNO 89490173300026616520
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 <- GETINFO all_active_apps
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 -> S SERIALNO 89490173300026616520 nks
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 <- SWITCHCARD 89490173300026616520
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 -> S SERIALNO 89490173300026616520
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 <- SWITCHAPP nks
2024-02-29 15:08:36 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 -> S SERIALNO 89490173300026616520 nks
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 <- GETATTR $SIGNKEYID
2024-02-29 15:08:36 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:08:36 scdaemon[20536] DBG: slot 0 app nks: calling getattr($SIGNKEYID)
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 -> S $SIGNKEYID NKS-NKS3.4531
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 <- GETATTR $ENCRKEYID
2024-02-29 15:08:36 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:08:36 scdaemon[20536] DBG: slot 0 app nks: calling getattr($ENCRKEYID)
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 -> S $ENCRKEYID NKS-NKS3.45B1
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 <- GETATTR NKS-VERSION
2024-02-29 15:08:36 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:08:36 scdaemon[20536] DBG: slot 0 app nks: calling getattr(NKS-VERSION)
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 -> S NKS-VERSION 3
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 <- GETATTR $DISPSERIALNO
2024-02-29 15:08:36 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:08:36 scdaemon[20536] DBG: slot 0 app nks: calling getattr($DISPSERIALNO)
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 -> S $DISPSERIALNO 8949017330002661652
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:36 scdaemon[20536] DBG: chan_13 <- GETATTR CHV-STATUS
2024-02-29 15:08:36 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:08:36 scdaemon[20536] DBG: slot 0 app nks: calling getattr(CHV-STATUS)
2024-02-29 15:08:36 scdaemon[20536] nks: switching to SigG
2024-02-29 15:08:37 scdaemon[20536] DBG: chan_13 -> S CHV-STATUS 3+0+3+0
2024-02-29 15:08:37 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:37 scdaemon[20536] DBG: chan_13 <- LEARN --force
2024-02-29 15:08:37 scdaemon[20536] DBG: chan_13 -> S READER 04E6:E003:51271834208013:0
2024-02-29 15:08:37 scdaemon[20536] DBG: chan_13 -> S SERIALNO 89490173300026616520
2024-02-29 15:08:37 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:08:37 scdaemon[20536] DBG: chan_13 -> S APPTYPE nks
2024-02-29 15:08:37 scdaemon[20536] DBG: chan_13 -> S APPVERSION 3
2024-02-29 15:08:37 scdaemon[20536] nks: switching to NKS
2024-02-29 15:08:38 scdaemon[20536] nks: switching to SigG
2024-02-29 15:08:39 scdaemon[20536] DBG: chan_13 -> S CHV-STATUS 3+0+3+0
2024-02-29 15:08:39 scdaemon[20536] nks: switching to NKS
2024-02-29 15:08:40 scdaemon[20536] DBG: chan_13 -> S KEYPAIRINFO 39400430E38BB96F105B740A7119FE113578B59D NKS-NKS3.4531 sa - rsa2048
2024-02-29 15:08:40 scdaemon[20536] DBG: chan_13 -> S CERTINFO 101 NKS-NKS3.C000
2024-02-29 15:08:40 scdaemon[20536] error selecting FID 0x4331: No such file or directory
2024-02-29 15:08:40 scdaemon[20536] error selecting FID 0x4332: No such file or directory
2024-02-29 15:08:40 scdaemon[20536] DBG: chan_13 -> S CERTINFO 110 NKS-NKS3.B000
2024-02-29 15:08:41 scdaemon[20536] DBG: chan_13 -> S KEYPAIRINFO 42C3CA6F9D7A725A59DDE06B16B61E88C62777C4 NKS-NKS3.45B1 e - rsa2048
2024-02-29 15:08:41 scdaemon[20536] DBG: chan_13 -> S CERTINFO 101 NKS-NKS3.C200
2024-02-29 15:08:41 scdaemon[20536] error selecting FID 0x43B1: No such file or directory
2024-02-29 15:08:41 scdaemon[20536] error selecting FID 0x43B2: No such file or directory
2024-02-29 15:08:41 scdaemon[20536] DBG: chan_13 -> S KEYPAIRINFO 20E7CB1D5299669CABF29B103C692AB34CB03528 NKS-NKS3.45B2 e - rsa1024
2024-02-29 15:08:41 scdaemon[20536] DBG: chan_13 -> S CERTINFO 101 NKS-NKS3.C201
2024-02-29 15:08:41 scdaemon[20536] nks: switching to SigG
2024-02-29 15:08:42 scdaemon[20536] DBG: chan_13 -> S KEYPAIRINFO A69B0D3796EE33E4426E5CE4B6BEEE5F1209FBA4 NKS-SIGG.4531 se - rsa2048
2024-02-29 15:08:42 scdaemon[20536] DBG: chan_13 -> S CERTINFO 101 NKS-SIGG.C000
2024-02-29 15:08:42 scdaemon[20536] data at FID 0xC008 does not look like a certificate
2024-02-29 15:08:42 scdaemon[20536] data at FID 0xC00E does not look like a certificate
2024-02-29 15:08:42 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:42 scdaemon[20536] DBG: chan_13 <- GETATTR SERIALNO
2024-02-29 15:08:42 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:08:42 scdaemon[20536] DBG: chan_13 -> S SERIALNO 89490173300026616520
2024-02-29 15:08:42 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:42 scdaemon[20536] DBG: chan_13 <- READKEY -- NKS-NKS3.4531
2024-02-29 15:08:42 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=NKS-NKS3.4531
2024-02-29 15:08:42 scdaemon[20536] DBG: slot 0 app nks: calling readkey(NKS-NKS3.4531)
2024-02-29 15:08:42 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=NKS-NKS3.4531
2024-02-29 15:08:42 scdaemon[20536] DBG: slot 0 app nks: calling readcert(NKS-NKS3.4531)
2024-02-29 15:08:42 scdaemon[20536] nks: switching to NKS
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 -> [ 44 20 28 31 30 3a 70 75 62 6c 69 63 2d 6b 65 79 ...(291 byte(s) skipped) ]
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 <- GETATTR $DISPSERIALNO 39400430E38BB96F105B740A7119FE113578B59D
2024-02-29 15:08:44 scdaemon[20536] DBG: slot 0, app nks: calling with_keygrip(lookup)
2024-02-29 15:08:44 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:08:44 scdaemon[20536] DBG: slot 0 app nks: calling getattr($DISPSERIALNO)
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 -> S $DISPSERIALNO 8949017330002661652
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 <- GETATTR SERIALNO
2024-02-29 15:08:44 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 -> S SERIALNO 89490173300026616520
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 <- READKEY -- NKS-NKS3.45B1
2024-02-29 15:08:44 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=NKS-NKS3.45B1
2024-02-29 15:08:44 scdaemon[20536] DBG: slot 0 app nks: calling readkey(NKS-NKS3.45B1)
2024-02-29 15:08:44 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=NKS-NKS3.45B1
2024-02-29 15:08:44 scdaemon[20536] DBG: slot 0 app nks: calling readcert(NKS-NKS3.45B1)
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 -> [ 44 20 28 31 30 3a 70 75 62 6c 69 63 2d 6b 65 79 ...(293 byte(s) skipped) ]
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 <- GETATTR $DISPSERIALNO 42C3CA6F9D7A725A59DDE06B16B61E88C62777C4
2024-02-29 15:08:44 scdaemon[20536] DBG: slot 0, app nks: calling with_keygrip(lookup)
2024-02-29 15:08:44 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:08:44 scdaemon[20536] DBG: slot 0 app nks: calling getattr($DISPSERIALNO)
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 -> S $DISPSERIALNO 8949017330002661652
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 <- GETATTR SERIALNO
2024-02-29 15:08:44 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 -> S SERIALNO 89490173300026616520
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:44 scdaemon[20536] DBG: chan_13 <- READKEY -- NKS-NKS3.45B2
2024-02-29 15:08:44 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=NKS-NKS3.45B2
2024-02-29 15:08:44 scdaemon[20536] DBG: slot 0 app nks: calling readkey(NKS-NKS3.45B2)
2024-02-29 15:08:44 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=NKS-NKS3.45B2
2024-02-29 15:08:44 scdaemon[20536] DBG: slot 0 app nks: calling readcert(NKS-NKS3.45B2)
2024-02-29 15:08:45 scdaemon[20536] DBG: chan_13 -> [ 44 20 28 31 30 3a 70 75 62 6c 69 63 2d 6b 65 79 ...(157 byte(s) skipped) ]
2024-02-29 15:08:45 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:45 scdaemon[20536] DBG: chan_13 <- GETATTR $DISPSERIALNO 20E7CB1D5299669CABF29B103C692AB34CB03528
2024-02-29 15:08:45 scdaemon[20536] DBG: slot 0, app nks: calling with_keygrip(lookup)
2024-02-29 15:08:45 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:08:45 scdaemon[20536] DBG: slot 0 app nks: calling getattr($DISPSERIALNO)
2024-02-29 15:08:45 scdaemon[20536] DBG: chan_13 -> S $DISPSERIALNO 8949017330002661652
2024-02-29 15:08:45 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:45 scdaemon[20536] DBG: chan_13 <- GETATTR SERIALNO
2024-02-29 15:08:45 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:08:45 scdaemon[20536] DBG: chan_13 -> S SERIALNO 89490173300026616520
2024-02-29 15:08:45 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:45 scdaemon[20536] DBG: chan_13 <- READKEY -- NKS-SIGG.4531
2024-02-29 15:08:45 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=NKS-SIGG.4531
2024-02-29 15:08:45 scdaemon[20536] DBG: slot 0 app nks: calling readkey(NKS-SIGG.4531)
2024-02-29 15:08:45 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=NKS-SIGG.4531
2024-02-29 15:08:45 scdaemon[20536] DBG: slot 0 app nks: calling readcert(NKS-SIGG.4531)
2024-02-29 15:08:45 scdaemon[20536] nks: switching to SigG
2024-02-29 15:08:47 scdaemon[20536] DBG: chan_13 -> [ 44 20 28 31 30 3a 70 75 62 6c 69 63 2d 6b 65 79 ...(293 byte(s) skipped) ]
2024-02-29 15:08:47 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:47 scdaemon[20536] DBG: chan_13 <- GETATTR $DISPSERIALNO A69B0D3796EE33E4426E5CE4B6BEEE5F1209FBA4
2024-02-29 15:08:47 scdaemon[20536] DBG: slot 0, app nks: calling with_keygrip(lookup)
2024-02-29 15:08:47 scdaemon[20536] nks: switching to NKS
2024-02-29 15:08:48 scdaemon[20536] nks: switching to SigG
2024-02-29 15:08:49 scdaemon[20536] DBG: slot 0: have=nks want=nks keyref=[none]
2024-02-29 15:08:49 scdaemon[20536] DBG: slot 0 app nks: calling getattr($DISPSERIALNO)
2024-02-29 15:08:49 scdaemon[20536] nks: switching to NKS
2024-02-29 15:08:50 scdaemon[20536] DBG: chan_13 -> S $DISPSERIALNO 8949017330002661652
2024-02-29 15:08:50 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:50 scdaemon[20536] DBG: chan_13 <- GETINFO all_active_apps
2024-02-29 15:08:50 scdaemon[20536] DBG: chan_13 -> S SERIALNO 89490173300026616520 nks
2024-02-29 15:08:50 scdaemon[20536] DBG: chan_13 -> OK
2024-02-29 15:08:50 scdaemon[20536] DBG: chan_13 <- BYE
2024-02-29 15:08:50 scdaemon[20536] DBG: chan_13 -> OK closing connection
2024-02-29 15:08:50 scdaemon[20536] handler for fd 13 terminated

The logs of the failed run contain the following:

2024-02-29 15:12:09 scdaemon[20881] DBG: enter: apdu_get_status: slot=0 hang=0
2024-02-29 15:12:09 scdaemon[20881] DBG: leave: apdu_get_status => sw=0x1000c status=0
2024-02-29 15:12:09 scdaemon[20881] DBG: chan_7 -> S DEVINFO_STATUS removal
2024-02-29 15:12:09 scdaemon[20881] DBG: Removal of a card: 0
2024-02-29 15:12:09 scdaemon[20881] DBG: enter: apdu_close_reader: slot=0
2024-02-29 15:12:09 scdaemon[20881] DBG: enter: apdu_disconnect: slot=0
2024-02-29 15:12:09 scdaemon[20881] DBG: leave: apdu_disconnect => sw=0x0

It looks like hardware problem or card reader problem.
Please test with debug-ccid-driver line in scdaemon.conf to see lower-lever (driver debug) message.

Possible issue would be that USB interrupt transfer (watching card removal) may be unreliable with your card reader (we observed some cases in the past for SCM card reader).
If it is the case, a patch can stop using the USB interrupt transfer.

diff --git a/scd/ccid-driver.c b/scd/ccid-driver.c
index ad1e16a12..d7dbb93f4 100644
--- a/scd/ccid-driver.c
+++ b/scd/ccid-driver.c
@@ -1853,6 +1853,7 @@ ccid_open_reader (const char *spec_reader_name, int idx,
 int
 ccid_require_get_status (ccid_driver_t handle)
 {
+  return 1;
   /* When a card reader supports interrupt transfer to check the
      status of card, it is possible to submit only an interrupt
      transfer, and no check is required by application layer.  USB can

scdaemon: Sometimes a newly detected card is immediately considered removedOpen, NormalPublicActions

Description

Event Timeline

scdaemon: Sometimes a newly detected card is immediately considered removed
Open, NormalPublic
Actions