Smart card reader is not accessiable

[develtech1]

Hi,
I am facing an issue while using SmartCard-HSM on a Linux machine. I am using smartcard with strongswan for VPN based on certificates. I am trying to check the presence of smart card by using command "pkcs15-tool -D" in bash/perl script and included in crontab but it fails after some time.

after 30 sec i got following messages in the logs.
first it gave "PKCS#15 binding failed:"

Using reader with a card: Gemalto GemPC Twin 00 00
PKCS#15 binding failed: Transmit failed

After another 30 sec the command output was "Failed to connect to card:"
Using reader with a card: Gemalto GemPC Twin 00 00
Failed to connect to card: Generic reader error

Other partial logs information is following, detail logs are attached;
A Part from OPENSC log, during this test i did not unplugged smart cards

0x77b5b210 10:28:40.440 [pkcs15-tool] reader-pcsc.c:376:refresh_attributes: card absent

A Part from PCSCD log

05000157 ccid_usb.c:638:WriteUSB() write failed (3/8): -7 Success

Another part from PCSCD log

00000012 ifdhandler.c:1292:IFDHTransmitToICC() usb:08e6/3437:libusb-1.0:3:8:0 (lun: 0)
00000008 openct/proto-t1.c:170:t1_transceive() T=1 state machine is DEAD. Reset the card first.
00000005 ifdwrapper.c:520:IFDTransmit() Card not transacted: 612
00000005 winscard.c:1564:SCardTransmit() Card not transacted: 0x80100016

I have already posted the same issue on OPENSC list. The details of the problem, logs and packages are given on following OPENSC link;

https://github.com/OpenSC/OpenSC/issues/976

OPENSC final comments were following;

It is not clear what is going on. PCSC reporting 0x80100016 SCARD_E_NOT_TRANSACTED
starting at 10:24:19.810 in the logs implies there is a problem with the card, reader or USB.

On your blog https://ludovicrousseau.blogspot.com/2010/05/how-to-know-pin-sizes-supported-by.html I found following;

The application has no way to know why the command failed. Someone has to look at the very low level logs to discover that the probelm is with wPINMaxExtraDigit.

Can we get information about the cause of the problem after looking on the PCSCD logs, can you suggest the solution after having detail look on PCSCD logs attached, please.

Packages details are following;

kernel 3.10
strongswan 5.3
libusb 1.0.8-1
pcsc-lite 1.8.1-1
ccid 1.4.5
opensc 0.15.0-1
libtool 2.4.2
smart cards Cardomatic HSM
Gemalto SC reader

Link to detail logs logs.tar.gz

[frankmorgner]

I think @CardContact should look at this if you're using the USB variant of the token.

[CardContact]

Based on the information above, this seems to be a problem with the Gemalto GemPC Twin 00 00 reader.

[LudovicRousseau]

From your pcscd log the first error is:

00000007 ifdhandler.c:1292:IFDHTransmitToICC() usb:08e6/3437:libusb-1.0:3:8:0 (lun: 0)
02542640 ccid_usb.c:677:ReadUSB() read failed (3/8): -7 Success
00000026 openct/proto-t1.c:214:t1_transceive() fatal: transmit/receive failed

-7 is LIBUSB_ERROR_TIMEOUT

I do not have enough details in the log. Please follow http:https://pcsclite.alioth.debian.org/ccid.html#support to generate a correct pcscd log.

You are using a locally build libccid (/usr/local/lib/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libcci). Maybe you can upgrade the driver. I do not expect the upgrade to fix your issue.

[develtech1]

Hi,
Thanks for response.
PCSCD logs are attached after using following command;

sudo LIBCCID_ifdLogLevel=0x000F pcscd --foreground --debug --apdu --color | tee log.txt

As per observation, I am getting error because of using pkcs15-tool -D /pkcs11-tool -T commands and currently strongswan or any other process is not using the smart cards. (all scripts and application are stopped)

log.tar.gz

[LudovicRousseau]

00000010 APDU: 00 B1 00 00 04 54 02 00 00 01 
00000005 ifdhandler.c:1292:IFDHTransmitToICC() usb:08e6/3437:libusb-1.0:3:2:0 (lun: 0)
00000006 commands.c:2035:CmdXfrBlockTPDU_T1() T=1: 10 and 258 bytes
00000006 openct/proto-t1.c:571:t1_build() more bit: 0
00000011 sending: 00 00 0A 00 B1 00 00 04 54 02 00 00 01 E8 
00000018 -> 000000 6F 0E 00 00 00 00 42 00 00 00 00 00 0A 00 B1 00 00 04 54 02 00 00 01 E8 
02542534 ccid_usb.c:677:ReadUSB() read failed (3/2): -7 Success
00000023 openct/proto-t1.c:214:t1_transceive() fatal: transmit/receive failed
00000007 SW: 

The problem occurs with the APDU 00 B1 00 00 04 54 02 00 00 01 with INS=0xB1 used in https://github.com/OpenSC/OpenSC/blob/master/src/libopensc/card-sc-hsm.c#L246

The same APDU is used 60 times before the error with no problem.

Can you generate a new pcscd trace to check if the problem occurs always at the same point?

[develtech1]

Sir, 3 more pcsc log files are attached.

Problem occurred on following commands, pcscd logs against each command are in a separate file as below;

log1-14-3-17.txt     9:26 - 9:33 		pkcs15-tool -D
		   	
log2-14-3-17.txt    10:06 - 10:39 	        pkcs15-tool -D

log3-14-3-17.txt      11:36 - 12:22 	        pkcs11-tool --module=/usr/local/lib/opensc-pkcs11.so -T

Uploading pcscd-logs.tar.gz…

[LudovicRousseau]

I can't download the logs. I think you failed to upload them.

[develtech1]

Hi,
I have attached it again . Please check
logs-pcscd.tar.gz

[LudovicRousseau]

Maybe the read timeout is too short.
Edit the CCID driver and apply this patch:

--- /var/folders/jb/2mvc64nx74b76qjg_5yk8zs00000gn/T//5DqKla_ifdhandler.c   2017-03-15 10:08:36.000000000 +0100
+++ src/ifdhandler.c    2017-03-15 10:08:35.000000000 +0100
@@ -1007,7 +1007,7 @@ EXTERNAL RESPONSECODE IFDHSetProtocolPar
        /* compute communication timeout */
        (void)ATR_GetParameter(&atr, ATR_PARAMETER_F, &f);
        (void)ATR_GetParameter(&atr, ATR_PARAMETER_D, &d);
-       ccid_desc->readTimeout = T1_card_timeout(f, d, param[2],
+       ccid_desc->readTimeout = 10 * T1_card_timeout(f, d, param[2],
            (param[3] & 0xF0) >> 4 /* BWI */, param[3] & 0x0F /* CWI */,
            ccid_desc->dwDefaultClock);

The line to change is https://github.com/LudovicRousseau/CCID/blob/master/src/ifdhandler.c#L1010

[develtech1]

After applying the patch "10 * T1_card_timeout" i have used the same command "pkcs15-tool -D" but it still fails after some time its log "log-patched.txt" file attached. I have added a print "Timeout-patch" which will be shown in the logs.

Additional when i use command "opensc-tool -l" it never cause any error, for comparison its logs "log-working-opensc-cmd.txt" file is also attached.

logs-pcscd-16-3-17.tar.gz

[LudovicRousseau]

The problem is not always with the same APDU. This time it is:

00000022 winscard.c:1539:SCardTransmit() Send Protocol: T=1
00000012 APDU: 00 B1 00 00 00 00 04 54 02 00 00 04 E7 
00000006 ifdhandler.c:1294:IFDHTransmitToICC() usb:08e6/3437:libusb-1.0:3:4:0 (lun: 0)
00000005 commands.c:2035:CmdXfrBlockTPDU_T1() T=1: 13 and 1257 bytes
00000006 openct/proto-t1.c:571:t1_build() more bit: 0
00000013 sending: 00 40 0D 00 B1 00 00 00 00 04 54 02 00 00 04 E7 4D 
00000019 -> 000000 6F 11 00 00 00 00 CB 00 00 00 00 40 0D 00 B1 00 00 00 00 04 54 02 00 00 04 E7 4D 
00042675 <- 000000 80 02 01 00 00 00 CB 00 00 00 00 20 FE 30 82 04 E3 30 82 02 CB A0 03 02 01 02 02 01 01 30 0D 06 09 2A 86 48 86 F7 0D 01 01 05 05 00 30 13 31 11 30 0F 06 03 55 04 03 13 08 4E 45 58 55 53 20 43 41 30 1E 17 0D 31 37 30 32 30 38 30 38 30 34 34 34 5A 17 0D 33 37 30 32 30 33 30 38 30 34 34 34 5A 30 13 31 11 30 0F 06 03 55 04 03 13 08 4E 45 58 55 53 20 43 41 30 82 02 22 30 0D 06 09 2A 86 48 86 F7 0D 01 01 01 05 00 03 82 02 0F 00 30 82 02 0A 02 82 02 01 00 C6 91 92 34 AF 98 67 44 0A 4A E7 73 AD AD 40 E9 F9 A7 54 BD E0 B5 9B D9 4B C3 68 7F 0A 38 1A 61 D6 34 47 A9 92 69 9D 10 1F F6 4A 4F A9 3C 98 AE F4 C7 48 CA E1 BF D5 EB 07 27 71 C8 5D F7 4A 0B D9 A6 8A F1 12 2D A4 46 9A 00 A5 B4 16 DA E0 75 F5 35 60 E2 79 80 1F 0D 2D 87 F6 B4 15 56 28 1E 3D 08 AA 0E FA F9 53 44 54 65 E9 8A 7B 2F 44 45 06 7A 96 C8 B3 
00000153 received: 00 20 FE 30 82 04 E3 30 82 02 CB A0 03 02 01 02 02 01 01 30 0D 06 09 2A 86 48 86 F7 0D 01 01 05 05 00 30 13 31 11 30 0F 06 03 55 04 03 13 08 4E 45 58 55 53 20 43 41 30 1E 17 0D 31 37 30 32 30 38 30 38 30 34 34 34 5A 17 0D 33 37 30 32 30 33 30 38 30 34 34 34 5A 30 13 31 11 30 0F 06 03 55 04 03 13 08 4E 45 58 55 53 20 43 41 30 82 02 22 30 0D 06 09 2A 86 48 86 F7 0D 01 01 01 05 00 03 82 02 0F 00 30 82 02 0A 02 82 02 01 00 C6 91 92 34 AF 98 67 44 0A 4A E7 73 AD AD 40 E9 F9 A7 54 BD E0 B5 9B D9 4B C3 68 7F 0A 38 1A 61 D6 34 47 A9 92 69 9D 10 1F F6 4A 4F A9 3C 98 AE F4 C7 48 CA E1 BF D5 EB 07 27 71 C8 5D F7 4A 0B D9 A6 8A F1 12 2D A4 46 9A 00 A5 B4 16 DA E0 75 F5 35 60 E2 79 80 1F 0D 2D 87 F6 B4 15 56 28 1E 3D 08 AA 0E FA F9 53 44 54 65 E9 8A 7B 2F 44 45 06 7A 96 C8 B3 
00000010 openct/proto-t1.c:351:t1_transceive() 
00000007 sending: 00 90 00 90 
00000015 -> 000000 6F 04 00 00 00 00 CC 00 00 00 00 90 00 90 
00031804 <- 000000 80 02 01 00 00 00 CC 00 00 00 00 60 FE 03 18 48 81 E0 61 D8 1F AF 4D 90 9B 72 5B 79 5A 6A 76 E0 F2 56 B6 9C F8 CE 05 32 28 61 62 85 C5 C9 95 07 C5 83 7D D4 90 A6 C7 78 75 DE BD 85 9C EE E1 50 D7 E2 06 8F D7 87 D0 A5 83 80 E5 64 3F 10 FE FD 74 02 8C 3B 29 E5 94 23 F9 57 BA F6 AC 8F 53 33 95 1F 7C F7 B4 74 E8 28 21 23 46 60 36 09 CB 3C 34 22 D4 93 E2 CE 81 12 43 59 D9 E5 95 EF 91 5B 4B 8D 70 11 54 33 FF BA E2 B5 46 C1 4D 6E F1 27 7E 1B C1 1E 29 E6 C6 AE C3 A7 35 91 B7 A6 6C D7 96 3A AB 59 19 EF 01 8A 26 53 B3 F5 D7 1B 6C 3A B3 E8 9A 8A 18 64 C9 BE 55 69 17 2A F1 C6 B2 BD E3 7E 5A AF 59 4E 7E E4 B0 EA 8F 10 AB 74 17 90 54 31 89 A1 AD E9 C1 13 27 46 6C E9 9F 75 D6 BE CE 6B 58 79 C3 77 0D A8 82 7C 54 5C 32 CF AF CD 8A 22 86 34 ED 53 96 6B DB 97 24 59 AA CC FD 39 FD 40 D5 66 81 C9 48 0C 5B 4A 8F 6E 
00000146 received: 00 60 FE 03 18 48 81 E0 61 D8 1F AF 4D 90 9B 72 5B 79 5A 6A 76 E0 F2 56 B6 9C F8 CE 05 32 28 61 62 85 C5 C9 95 07 C5 83 7D D4 90 A6 C7 78 75 DE BD 85 9C EE E1 50 D7 E2 06 8F D7 87 D0 A5 83 80 E5 64 3F 10 FE FD 74 02 8C 3B 29 E5 94 23 F9 57 BA F6 AC 8F 53 33 95 1F 7C F7 B4 74 E8 28 21 23 46 60 36 09 CB 3C 34 22 D4 93 E2 CE 81 12 43 59 D9 E5 95 EF 91 5B 4B 8D 70 11 54 33 FF BA E2 B5 46 C1 4D 6E F1 27 7E 1B C1 1E 29 E6 C6 AE C3 A7 35 91 B7 A6 6C D7 96 3A AB 59 19 EF 01 8A 26 53 B3 F5 D7 1B 6C 3A B3 E8 9A 8A 18 64 C9 BE 55 69 17 2A F1 C6 B2 BD E3 7E 5A AF 59 4E 7E E4 B0 EA 8F 10 AB 74 17 90 54 31 89 A1 AD E9 C1 13 27 46 6C E9 9F 75 D6 BE CE 6B 58 79 C3 77 0D A8 82 7C 54 5C 32 CF AF CD 8A 22 86 34 ED 53 96 6B DB 97 24 59 AA CC FD 39 FD 40 D5 66 81 C9 48 0C 5B 4A 8F 6E 
00000011 sending: 00 80 00 80 
00000012 -> 000000 6F 04 00 00 00 00 CD 00 00 00 00 80 00 80 
25420807 ccid_usb.c:677:ReadUSB() read failed (3/4): -7 Success
00000025 openct/proto-t1.c:214:t1_transceive() fatal: transmit/receive failed
00000008 SW: 

Can you try with:

• same reader but with another Smartcard-HSM card
• same card but with another smart card reader

[develtech1]

Hi,
Sir, after changing reader and smart card, i was getting same error.
However, after that i have changed the libusb and ccid drivers version. and now error is fixed. It is perfectly working for pkcs15-tool -D or -c command.

[LudovicRousseau]

OK. I guess the problem was in libusb.

[lnksz]

Hi @develtech1,
I know this is an old thread, but we are facing a very similar issue. Could you maybe post from what version you upgraded to what version of your dependencies?