Bug 673448 - ccid 1.4.x has a problem in processing the waittime extension request.
Summary: ccid 1.4.x has a problem in processing the waittime extension request.
Keywords:
Status: CLOSED WONTFIX
Alias: None
Product: Fedora
Classification: Fedora
Component: ccid
Version: 14
Hardware: i686
OS: Linux
unspecified
urgent
Target Milestone: ---
Assignee: Bob Relyea
QA Contact: Fedora Extras Quality Assurance
URL: http://lists.gnupg.org/pipermail/gnup...
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2011-01-28 09:21 UTC by Sandro Bonazzola
Modified: 2012-08-16 15:23 UTC (History)
3 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2012-08-16 15:22:56 UTC
Type: ---


Attachments (Terms of Use)

Description Sandro Bonazzola 2011-01-28 09:21:37 UTC
Description of problem:

Trying to generate a key on a OpenPGP 1.1 Smart Card using gpg --card-edit , admin, generate. The key generation fails with a pcsc error.
Googling around I found this message: 
http://lists.gnupg.org/pipermail/gnupg-users/2006-October/029525.html

stopped pcscd daemon, running gpg as root users, gpg uses internal ccid driver without pcscd, the key is successfully generated.
So it really seems an error caused by pcscd.

root access seems to be needed for this test because the internal ccid driver need to access the usb device.

I've seen there are newer version of pcsc-lite and ccid released upstream, so I've opened bug #673444 and bug #673445 asking for an update in Fedora 14, hoping they solve this issue.

The Smart card reader is a SCM Microsystem SCR335.

Version-Release number of selected component (if applicable):
pcsc-lite-1.6.4-3.fc14.i686
ccid-1.4.0-2.fc14.i686
gnupg-1.4.11-2.fc14.i686
gnupg2-2.0.16-3.fc14.1.i686
openct-0.6.19-3.fc14.i686
pcsc-lite-openct-0.6.19-3.fc14.i686

How reproducible:

Always reproducible.

Steps to Reproduce:
1. gpg --card-edit
2. admin
3. generate
  
Actual results:

key not generated, with the following logging (tested a lot of times):

Jan 28 09:12:54 Ssandro pcscd: ccid_usb.c:652:ReadUSB() read failed (5/2): -7 Success
Jan 28 09:12:54 Ssandro pcscd: ccid_usb.c:652:ReadUSB() read failed (5/2): -7 Success
Jan 28 09:18:58 Ssandro pcscd: commands.c:1317:CCID_Receive Card absent or mute
Jan 28 09:18:58 Ssandro pcscd: openct/proto-t1.c:214:t1_transceive() fatal: transmit/receive failed
Jan 28 09:18:58 Ssandro pcscd: ifdwrapper.c:746:IFDTransmit() Card not transacted: 612
Jan 28 09:18:58 Ssandro pcscd: winscard.c:1673:SCardTransmit() Card not transacted: 0x80100016
Jan 28 09:18:58 Ssandro pcscd: winscard_svc.c:640:ContextThread() TRANSMIT rv=0x80100016 for client 7
Jan 28 09:20:40 Ssandro pcscd: commands.c:1317:CCID_Receive Card absent or mute
Jan 28 09:20:40 Ssandro pcscd: openct/proto-t1.c:214:t1_transceive() fatal: transmit/receive failed
Jan 28 09:20:40 Ssandro pcscd: ifdwrapper.c:746:IFDTransmit() Card not transacted: 612
Jan 28 09:20:40 Ssandro pcscd: winscard.c:1673:SCardTransmit() Card not transacted: 0x80100016
Jan 28 09:20:40 Ssandro pcscd: winscard_svc.c:640:ContextThread() TRANSMIT rv=0x80100016 for client 7
Jan 28 09:22:07 Ssandro pcscd: commands.c:1317:CCID_Receive Card absent or mute
Jan 28 09:22:07 Ssandro pcscd: openct/proto-t1.c:214:t1_transceive() fatal: transmit/receive failed
Jan 28 09:22:07 Ssandro pcscd: ifdwrapper.c:746:IFDTransmit() Card not transacted: 612
Jan 28 09:22:07 Ssandro pcscd: winscard.c:1673:SCardTransmit() Card not transacted: 0x80100016
Jan 28 09:22:07 Ssandro pcscd: winscard_svc.c:640:ContextThread() TRANSMIT rv=0x80100016 for client 7
Jan 28 09:22:07 Ssandro pcscd: openct/proto-t1.c:170:t1_transceive() T=1 state machine is DEAD. Reset the card first.
Jan 28 09:22:07 Ssandro pcscd: ifdwrapper.c:746:IFDTransmit() Card not transacted: 612
Jan 28 09:22:07 Ssandro pcscd: winscard.c:1673:SCardTransmit() Card not transacted: 0x80100016
Jan 28 09:22:07 Ssandro pcscd: winscard_svc.c:640:ContextThread() TRANSMIT rv=0x80100016 for client 7
Jan 28 09:23:10 Ssandro pcscd: commands.c:1317:CCID_Receive Card absent or mute
Jan 28 09:23:10 Ssandro pcscd: openct/proto-t1.c:214:t1_transceive() fatal: transmit/receive failed
Jan 28 09:23:10 Ssandro pcscd: ifdwrapper.c:746:IFDTransmit() Card not transacted: 612
Jan 28 09:23:10 Ssandro pcscd: winscard.c:1673:SCardTransmit() Card not transacted: 0x80100016
Jan 28 09:23:10 Ssandro pcscd: winscard_svc.c:640:ContextThread() TRANSMIT rv=0x80100016 for client 7
Jan 28 09:25:37 Ssandro pcscd: commands.c:1317:CCID_Receive Card absent or mute
Jan 28 09:25:37 Ssandro pcscd: openct/proto-t1.c:214:t1_transceive() fatal: transmit/receive failed
Jan 28 09:25:37 Ssandro pcscd: ifdwrapper.c:746:IFDTransmit() Card not transacted: 612
Jan 28 09:25:37 Ssandro pcscd: winscard.c:1673:SCardTransmit() Card not transacted: 0x80100016
Jan 28 09:25:37 Ssandro pcscd: winscard_svc.c:640:ContextThread() TRANSMIT rv=0x80100016 for client 7
Jan 28 09:26:36 Ssandro pcscd: commands.c:1317:CCID_Receive Card absent or mute
Jan 28 09:26:36 Ssandro pcscd: openct/proto-t1.c:214:t1_transceive() fatal: transmit/receive failed
Jan 28 09:26:36 Ssandro pcscd: ifdwrapper.c:746:IFDTransmit() Card not transacted: 612
Jan 28 09:26:36 Ssandro pcscd: winscard.c:1673:SCardTransmit() Card not transacted: 0x80100016
Jan 28 09:26:36 Ssandro pcscd: winscard_svc.c:640:ContextThread() TRANSMIT rv=0x80100016 for client 7
Jan 28 09:28:14 Ssandro pcscd: commands.c:1317:CCID_Receive Card absent or mute
Jan 28 09:28:14 Ssandro pcscd: openct/proto-t1.c:214:t1_transceive() fatal: transmit/receive failed
Jan 28 09:28:14 Ssandro pcscd: ifdwrapper.c:746:IFDTransmit() Card not transacted: 612
Jan 28 09:28:14 Ssandro pcscd: winscard.c:1673:SCardTransmit() Card not transacted: 0x80100016
Jan 28 09:28:14 Ssandro pcscd: winscard_svc.c:640:ContextThread() TRANSMIT rv=0x80100016 for client 7
Jan 28 09:29:57 Ssandro pcscd: commands.c:1317:CCID_Receive Card absent or mute
Jan 28 09:29:57 Ssandro pcscd: openct/proto-t1.c:214:t1_transceive() fatal: transmit/receive failed
Jan 28 09:29:57 Ssandro pcscd: ifdwrapper.c:746:IFDTransmit() Card not transacted: 612
Jan 28 09:29:57 Ssandro pcscd: winscard.c:1673:SCardTransmit() Card not transacted: 0x80100016
Jan 28 09:29:57 Ssandro pcscd: winscard_svc.c:640:ContextThread() TRANSMIT rv=0x80100016 for client 7
Jan 28 09:29:57 Ssandro pcscd: openct/proto-t1.c:170:t1_transceive() T=1 state machine is DEAD. Reset the card first.
Jan 28 09:29:57 Ssandro pcscd: ifdwrapper.c:746:IFDTransmit() Card not transacted: 612
Jan 28 09:29:57 Ssandro pcscd: winscard.c:1673:SCardTransmit() Card not transacted: 0x80100016
Jan 28 09:29:57 Ssandro pcscd: winscard_svc.c:640:ContextThread() TRANSMIT rv=0x80100016 for client 7

Expected results:

key generated successfully

Additional info:

Any other command available with gpg --card-edit seems to work fine also using pcscd. It seems a bug reproducible only with generate command due to the long time needed to perform the action.

Comment 1 Sandro Bonazzola 2011-01-31 08:44:00 UTC
It seems that the problem is in ccid driver itself.
Just checking CCID_TIME_EXTENSION before CCID_COMMAND_FAILED seems to fix the issue for me.
ccid-1.4.1 is also affected by this bug.


diff -ru ccid-1.4.0.orig/src/commands.c ccid-1.4.0/src/commands.c
--- ccid-1.4.0.orig/src/commands.c	2010-08-01 19:05:25.000000000 +0200
+++ ccid-1.4.0/src/commands.c	2011-01-31 08:31:57.487803003 +0100
@@ -1312,6 +1312,12 @@
 		return IFD_COMMUNICATION_ERROR;
 	}

+	if (cmd[STATUS_OFFSET] & CCID_TIME_EXTENSION)
+	{
+		DEBUG_COMM2("Time extension requested: 0x%02X", cmd[ERROR_OFFSET]);
+		goto time_request;
+	}
+
 	if (cmd[STATUS_OFFSET] & CCID_COMMAND_FAILED)
 	{
 		ccid_error(cmd[ERROR_OFFSET], __FILE__, __LINE__, __FUNCTION__);    /* bError */
@@ -1341,11 +1347,6 @@
 		}
 	}

-	if (cmd[STATUS_OFFSET] & CCID_TIME_EXTENSION)
-	{
-		DEBUG_COMM2("Time extension requested: 0x%02X", cmd[ERROR_OFFSET]);
-		goto time_request;
-	}

 	/* we have read less (or more) data than the CCID frame says to contain */
 	if (length-10 != dw2i(cmd, 1))

Comment 2 Sandro Bonazzola 2011-01-31 10:07:51 UTC
(In reply to comment #1)

> Just checking CCID_TIME_EXTENSION before CCID_COMMAND_FAILED seems to fix the
> issue for me.

After some more testing, Ihave to say that this doesn't fix the issue: it's still present.

Comment 3 Kalev Lember 2011-05-05 10:28:59 UTC
This would be something you should take up with upstream; adding dr. Ludovic Rousseau to CC.

Comment 4 Ludovic Rousseau 2011-05-05 11:33:03 UTC
AFAIK it is a bug in the OpenPGP card. I corrected a bug like this in revision 3330 of the CCID driver [1].

What is the ATR of your card?

[1] http://lists.alioth.debian.org/pipermail/pcsclite-cvs-commit/2009-March/003514.html

Comment 5 Sandro Bonazzola 2011-05-10 12:02:18 UTC
(In reply to comment #4)
> AFAIK it is a bug in the OpenPGP card. I corrected a bug like this in revision
> 3330 of the CCID driver [1].
> 
> What is the ATR of your card?

Running pcsc_scan:

 Reader 0: SCM SCR 335 [CCID Interface] (60400813) 00 00
  Card state: Card inserted, 
  ATR: 3B FA 13 00 FF 81 31 80 45 00 31 C1 73 C0 01 00 00 90 00 B1

Comment 6 Ludovic Rousseau 2011-05-10 12:49:22 UTC
You have the OpenPGP with the problem fixed in revision 3330 I talked about.

The problem has been fixed in version 1.3.10 of the ccid driver. I am surprised you still have it with ccid-1.4.0-2.fc14.i686

Please generate a full log using http://pcsclite.alioth.debian.org/ccid.html#support

Comment 7 Kalev Lember 2011-05-10 13:01:03 UTC
> Jan 28 09:18:58 Ssandro pcscd: openct/proto-t1.c:214:t1_transceive() fatal:
transmit/receive failed

Looking at the log again, are you sure it's even using the ccid driver? The line above shows an error message from openct instead. Does anything change if you remove the openct ifdhandler package 'pcsc-lite-openct'?

Comment 8 Fedora End Of Life 2012-08-16 15:23:00 UTC
This message is a notice that Fedora 14 is now at end of life. Fedora 
has stopped maintaining and issuing updates for Fedora 14. It is 
Fedora's policy to close all bug reports from releases that are no 
longer maintained.  At this time, all open bugs with a Fedora 'version'
of '14' have been closed as WONTFIX.

(Please note: Our normal process is to give advanced warning of this 
occurring, but we forgot to do that. A thousand apologies.)

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, feel free to reopen 
this bug and simply change the 'version' to a later Fedora version.

Bug Reporter: Thank you for reporting this issue and we are sorry that 
we were unable to fix it before Fedora 14 reached end of life. If you 
would still like to see this bug fixed and are able to reproduce it 
against a later version of Fedora, you are encouraged to click on 
"Clone This Bug" (top right of this page) and open it against that 
version of Fedora.

Although we aim to fix as many bugs as possible during every release's 
lifetime, sometimes those efforts are overtaken by events.  Often a 
more recent Fedora release includes newer upstream software that fixes 
bugs or makes them obsolete.

The process we are following is described here: 
http://fedoraproject.org/wiki/BugZappers/HouseKeeping


Note You need to log in before you can comment on or make changes to this bug.