Description of problem: On the test2 release of FC7 we have observed through testing ESC, flaky detection of smart card removal events. ESC's display is updated just fine when placing an initial key into the computer. If the key is then removed, ESC is not responding to the removal, leaving the display thinking that the key is still inserted. Version-Release number of selected component (if applicable): Stack of related components tested with: FC7 test2 esc-1.0.1-1.fc7 pcsc-lite-1.3.3-1.fc7 coolkey-1.1.0-1.fc7 ifd-egate-0.05-16 How reproducible: Always Steps to Reproduce: 1. Log in with smart card. 2. ESC gives card insertion notification. 3. Bring up ESC to view information about the card. 4. Remove the card from the computer. Actual results: ESC still thinks that the previously removed card is still in the machine. Expected results: ESC's display should be updated to reflect that is is has no keys in the computer. Additional info: In an effort to downgrade components to possibly isolate the problem, I downgraded the "ifd-egate" component from "ifd-egate-0.05-16" to "ifd-egate-0.05-15" on local machine. The result of some brief testing was that ESC was once again detecting card removal events just fine. It is not clear that "ifd-egate" is soley responsible for the issue. Since it interacts tightly with the also recently updraded "pcsc-lite" component, "pcsc-lite" could be at issue or even the interaction between the two could be of issue.
Update: Running the latest pcsc-lite with the downgraded ifd-egate, noticed that pcscd was using a good chunk of the cpu. Apparently the latest pcsc-lite relies heavily on polling when not paired with the latest ifd-egate driver.
Further Update: Just as an experiment, did the following: Upgraded ifd-egate back up to 0.05-16 and tried "pcsc-lite-1.3.1-7" and then tried "pcsc-lite-1.3.2-1". With the latest egate, both of the above downgraded pcsc-lite rpms worked fine with card removals.
More info: This not covers the situation where a downgraded ifd-egate is used with the latest pcsc-lite. Took a look at the code in pcsc-lite. It supports a driver capability flag called IFD_GENERATE_HOTPLUG . This is set to true for drivers that don't want to use polling such as the latest ifd-egate driver. In the case of using a non-latest version 05-15 of ifd-egate, the given capability is not set. This would lead pcsc to use its old polling model. Unfortunately, the code also supports a command line param that can force polling called "force-reader-polling". This flag allows the caller the ability to set a variable called HPForceReaderPolling to some integer value. This variable is initialized to 0 on startup if the flag is not used. This sets up the scenario where a version of ifd-egate is used that does not either support IFD_GENERATE_HOTPLUG OR use the "force-reader-polling" flag. The following code is then run in a thread: while (do_polling) { SYS_Sleep(HPForceReaderPolling); HPRescanUsbBus(); } I believe that HPForceReaderPolling may be set to zero, thus not making the sleep interval very long and using up the CPU.
Thanks Jack, I believe there's another bug about the polling issue. I'll track it down an link it in. Good work. bob
Further information: I did some more poking around. The latest pcsc with the latest egate are designed to work together through the "udev" deamon. The ifd-egate installer installs some rules for udev to follow in the case of token events. The rule file is: /etc/udev/rules.d/85-pcscd_egate.rule looks like this: # udev rules for pcscd and egate readers BUS=="usb", SYSFS{idVendor}=="0973", SYSFS{idProduct}=="0001", ACTION=="add", RUN+="/usr/sbin/pcscd --hotplug" Note that there is also a similar rule file for pcsc and ccid interaction. The rule above appears to contain a simple action in the case a usb device is added. In this case the program "/usr/sbin/pcscd --hotplug" is called. At this point pcsc reacts with the following log messages: pcscdaemon.c:110:SendHotplugSignal() Send hotplug signal to pcscd (pid=26383) This results in pcsc scanning for new hardware and doing the right thing. The problem appears to be that when the token is removed, nobody is notified. The only trace of this removal in the log shows up as: Mar 21 15:36:25 dhcp-172-16-25-199 kernel: usb 2-2: USB disconnect, address 39 I attempted to play with the rule to somehow account for the "remove" ACTION to no success. I also tried removing the ACTION clause all together in hopes that the rule would fire on either a removal or insertion. In practice it only fired on an insertion. Just for fun, I disabled the rule and made manual calls from a terminal of: /usr/sbin/pcscd --hotplug Once after manually inserting the key and once after manually removing the key. In both cases the pcsc logs reflected the right behavior. Conclusions 1. The udev rule is in error and needs to be something else. 2. The event for a usb device removal is not getting bubbled up by the udev daemon. Even worse would be that udev itself does not get the event.
Created attachment 150697 [details] Output of /usr/sbin/udevmonitor
More info: The attachment containing the output of "udevmonitor" shows us what is going on when our egate device is plugged in and then removed. Revisiting the current udev rule for the usb egate device. BUS=="usb", SYSFS{idVendor}=="0973", SYSFS{idProduct}=="0001", ACTION=="add", RUN+="/usr/sbin/pcscd --hotplug" The above rule does not handle the ACTION of "remove". When I tried to duplicate the above rule only makeing the ACTION "remove" it did not work either. After researching and playing with udev, I found out that when you remove the the device the directroy that represents the device goes away, taking with it much of the information used in the rules to match the event. I found that once I added the following experimental rule, the rule began to fire on the token removal: BUS=="usb", ENV{PRODUCT}=="973/1/100", ACTION=="remove", RUN+="/usr/sbin/pcscd --hotplug" Observering the logs showed that pcsc was in fact now being contacted when the token was removed. I also ran a quick test with ESC and it was able to see the token removal event. The new wrinkle above was to query the PRODUCT environment variable which was apparently still available after token removal. The actual value above "973/1/100" was observed in the attachment of the output of "/usr/sbin/udevmonitor". Conclusions: 1. We could fix this by carefully crafting new rules for 85-pcscd_egate.rules and 85-pcscd_ccid.rules located in the directory /etc/udev/rules.d . Caveat: While debugging I noticed that when the token is inserted 3 separate "add" events are being caught by the rule, thus resulting in the signaling of pcscd three times instead of once. I believe the same thing will happen on token removal when the rules are set up properly. 2. We could also fix this by carefully reverting the packages of pcsc-lite and ifd-egate to levels where everything at least works ok.
More info: output of udevinfo -a -p /sys/bus/usb/devices/2-1 to view the attributes of a plugged in token: udevinfo -a -p /sys/bus/usb/devices/2-1 Udevinfo starts with the device specified by the devpath and then walks up the chain of parent devices. It prints for every device found, all possible attributes in the udev rules key format. A rule to match, can be composed by the attributes of the device and the attributes from one single parent device. looking at device '/devices/pci0000:00/0000:00:1d.1/usb2/2-1': KERNEL=="2-1" SUBSYSTEM=="usb" DRIVER=="usb" ATTR{product}=="SchlumbergerSema Cyberflex e-gate" ATTR{manufacturer}=="SchlumbergerSema" ATTR{quirks}=="0x0" ATTR{maxchild}=="0" ATTR{version}==" 1.10" ATTR{devnum}=="20" ATTR{speed}=="1.5" ATTR{bMaxPacketSize0}=="8" ATTR{bNumConfigurations}=="1" ATTR{bDeviceProtocol}=="00" ATTR{bDeviceSubClass}=="00" ATTR{bDeviceClass}=="ff" ATTR{bcdDevice}=="0100" ATTR{idProduct}=="0001" ATTR{idVendor}=="0973" ATTR{bMaxPower}==" 30mA" ATTR{bmAttributes}=="80" ATTR{bConfigurationValue}=="1" ATTR{bNumInterfaces}==" 1" ATTR{configuration}=="" looking at parent device '/devices/pci0000:00/0000:00:1d.1/usb2': KERNELS=="usb2" SUBSYSTEMS=="usb" DRIVERS=="usb" ATTRS{serial}=="0000:00:1d.1" ATTRS{product}=="UHCI Host Controller" ATTRS{manufacturer}=="Linux 2.6.20-1.2990.fc7 uhci_hcd" ATTRS{quirks}=="0x0" ATTRS{maxchild}=="2" ATTRS{version}==" 1.10" ATTRS{devnum}=="1" ATTRS{speed}=="12" ATTRS{bMaxPacketSize0}=="64" ATTRS{bNumConfigurations}=="1" ATTRS{bDeviceProtocol}=="00" ATTRS{bDeviceSubClass}=="00" ATTRS{bDeviceClass}=="09" ATTRS{bcdDevice}=="0206" ATTRS{idProduct}=="0000" ATTRS{idVendor}=="0000" ATTRS{bMaxPower}==" 0mA" ATTRS{bmAttributes}=="e0" ATTRS{bConfigurationValue}=="1" ATTRS{bNumInterfaces}==" 1" ATTRS{configuration}=="" looking at parent device '/devices/pci0000:00/0000:00:1d.1': KERNELS=="0000:00:1d.1" SUBSYSTEMS=="pci" DRIVERS=="uhci_hcd" ATTRS{msi_bus}=="" ATTRS{broken_parity_status}=="0" ATTRS{enable}=="1" ATTRS{modalias}=="pci:v00008086d000027C9sv00001179sd0000FF10bc0Csc03i00" ATTRS{local_cpus}=="ffffffff" ATTRS{irq}=="20" ATTRS{class}=="0x0c0300" ATTRS{subsystem_device}=="0xff10" ATTRS{subsystem_vendor}=="0x1179" ATTRS{device}=="0x27c9" ATTRS{vendor}=="0x8086" looking at parent device '/devices/pci0000:00': KERNELS=="pci0000:00" SUBSYSTEMS=="" DRIVERS==""
More info: The rule file for CCID, which has been mentioned before is below: Note: If we chose the "add ACTION="remove" rules" approach, this file will need new content as well. # udev rules for pcscd and CCID readers # Gemplus PCMCIA Card #SUBSYSTEMS=="pcmcia", DRIVER=="serial_cs", ACTION=="add", SYSFS{prod_id1}=="Gemplus", SYSFS{prod_id2}=="SerialPort", SYSFS{prod_id3}=="GemPC Card", RUN+="/usr/sbin/pcscd --hotplug" # generic CCID device BUS=="usb", SYSFS{bInterfaceClass}=="0b", ACTION=="add", RUN+="/usr/sbin/pcscd --hotplug" # non CCID generic (InterfaceClass: 0xFF) # CherrySmartTerminalST2XXX.txt BUS=="usb", SYSFS{idVendor}=="046a", SYSFS{idProduct}=="003e", ACTION=="add", RUN+="/usr/sbin/pcscd --hotplug" # DellSK-3106.txt BUS=="usb", SYSFS{idVendor}=="413c", SYSFS{idProduct}=="2100", ACTION=="add", RUN+="/usr/sbin/pcscd --hotplug" # MySmartPad.txt BUS=="usb", SYSFS{idVendor}=="09be", SYSFS{idProduct}=="0002", ACTION=="add", RUN+="/usr/sbin/pcscd --hotplug" # SCR331-DI-NTTCom.txt BUS=="usb", SYSFS{idVendor}=="04e6", SYSFS{idProduct}=="5120", ACTION=="add", RUN+="/usr/sbin/pcscd --hotplug" # SCR331-DI.txt BUS=="usb", SYSFS{idVendor}=="04e6", SYSFS{idProduct}=="5111", ACTION=="add", RUN+="/usr/sbin/pcscd --hotplug" # SDI010.txt BUS=="usb", SYSFS{idVendor}=="04e6", SYSFS{idProduct}=="5121", ACTION=="add", RUN+="/usr/sbin/pcscd --hotplug" # SPR532.txt BUS=="usb", SYSFS{idVendor}=="04e6", SYSFS{idProduct}=="e003", ACTION=="add", RUN+="/usr/sbin/pcscd --hotplug" # Verisign_secure_storage_token.txt BUS=="usb", SYSFS{idVendor}=="08e6", SYSFS{idProduct}=="1359", ACTION=="add", RUN+="/usr/sbin/pcscd --hotplug" # Verisign_secure_token.txt BUS=="usb", SYSFS{idVendor}=="08e6", SYSFS{idProduct}=="ace0", ACTION=="add", RUN+="/usr/sbin/pcscd --hotplug"
More info: Further investigation into the issuer where we are getting 3 insertion and removal events has shed some lite on what could be done. Apparently one of the environment variables available on token removal is called "SEQNUM" which gets incremented each pass through. Instead of having the rule run "/usr/sbin/pcscd --hotplug", we could have it run a shell script that first queries the various environment variables to tell if it is really necessary to launch pcscd.
More info: Testing of an actual CAC card with a CAC card reader works ok. The udev rule takes care of the case when the CCID card reader is inserted. From that point, pcsc-lite looks like it knows how to handle actual CAC card insertions and deletions just fine. The trouble appears to be with standard egate cards. The udev stuff detects the normal token insertion. Then normal operation of pcsc creates this thead called EHStatusHandlerThread that runs through a loop each second checking the status of the card it has been created to oversee. The following function call: rv = IFDStatusICC(rContext, &dwStatus, rContext->readerState->cardAtr, &rContext->readerState->cardAtrLength); persists in returning the value SCARD_PRESENT within the argument dwStatus even when the card has long been removed. IFDStatusICC calls down into a callback provided by the egate driver itself that reports the status of the card. I believe this function is now always returing SCARD_PRESENT.
Diff of one file changed: --- ./pcscd_egate.rules.udev-rules 2007-03-23 14:16:49.000000000 -0700 +++ ./pcscd_egate.rules 2007-03-23 14:17:25.000000000 -0700 @@ -1,3 +1,5 @@ # udev rules for pcscd and egate readers BUS=="usb", SYSFS{idVendor}=="0973", SYSFS{idProduct}=="0001", ACTION=="add", RUN+="/usr/sbin/pcscd --hotplug" + +BUS=="usb", ENV{PRODUCT}=="973/1/100", ACTION=="remove", RUN+="/usr/sbin/pcscd --hotplug"
Proposed spec:
Created attachment 150800 [details] Proposed new spec file.
More info: The real problem has been tracked down into the ifd-egate driver itself. The file "ifdhandler.c" has a function called "RESPONSECODE IFDHICCPresence(DWORD Lun);" which calls into "egate_probe" which is as follows: RESPONSECODE egate_probe(struct egate *egate) { unsigned char c; int rc; usb_dev_handle *myhandle; if (!egate) return IFD_COMMUNICATION_ERROR; if (!egate->usb) { return egate_get_usb(egate); } return IFD_ICC_PRESENT; } Note that the var egate->usb will always have a value once the token is inserted. Unfortunately it will continue to have a value once the card is removed. Therefore "egate_get_usb" never gets called again with the predictable results. The old version of this looks like: int egate_probe(struct egate *egate) { unsigned char c; int rc; usb_dev_handle *myhandle; if (!egate) return 0; if (!egate->usb) { return 0; } myhandle=egate->usb; rc = do_usb(myhandle, USB_ENDPOINT_IN|USB_TYPE_VENDOR, EGATE_CMD_FETCHSTATUS,0, 0, &c, 1, EGATE_TIMEOUT); sleep(1); if (rc == 1) return 1; return 0; } Here it is obvious that the old code was detecting the token's removal. I suspect the new code was an attempt to avoid the polling done here. The first experiment was to actually call egate_get_usb(egate); in all situations. This did not work because "egate_get_usb" has not been set up to handle the case where the argument "egate" already exists. More later...
The following patch was used to get ifd-egate working WITHOUT the need to alter the file "/etc/udev/rules.d/85-pcscd_egate.rules" . Proposed solution diff: [root@dhcp-172-16-25-199 ifd-egate-0.05]# diff -c egate.c.presence egate.c *** egate.c.presence Mon Mar 26 11:03:12 2007 --- egate.c Mon Mar 26 11:32:10 2007 *************** *** 96,121 **** struct usb_device *mydev = NULL; usb_dev_handle *myhandle; ! if (egate->usb) { ! return 0; ! } usb_init(); usb_find_busses(); usb_find_devices(); for (mybus = usb_busses; mybus; mybus = mybus->next) { for (mydev = mybus->devices; mydev; mydev = mydev->next) { ! if ((mydev->descriptor.idVendor == 0x973) && ! (mydev->descriptor.idProduct == 0x001) && ! egate_is_device_free(mydev)) { ! goto found; ! } } } syslog(LOG_ERR,"egate_get_usb %x: No devices found\n", egate->lun); return IFD_NO_SUCH_DEVICE; ! found: myhandle=usb_open(mydev); if (!myhandle) { syslog(LOG_ERR,"egate_get_usb %x: Couldn't open %s %s\n", --- 96,127 ---- struct usb_device *mydev = NULL; usb_dev_handle *myhandle; ! int is_found = 0; usb_init(); usb_find_busses(); usb_find_devices(); for (mybus = usb_busses; mybus; mybus = mybus->next) { for (mydev = mybus->devices; mydev; mydev = mydev->next) { ! ! if ((mydev->descriptor.idVendor == 0x973) && ! (mydev->descriptor.idProduct == 0x001)) { ! ! is_found = 1; ! ! if( egate_is_device_free(mydev)) ! goto foundnew; ! } ! ! if ( is_found ) ! goto found; ! } } syslog(LOG_ERR,"egate_get_usb %x: No devices found\n", egate->lun); return IFD_NO_SUCH_DEVICE; ! foundnew: myhandle=usb_open(mydev); if (!myhandle) { syslog(LOG_ERR,"egate_get_usb %x: Couldn't open %s %s\n", *************** *** 128,133 **** --- 134,140 ---- egate->dirname = strdup(mydev->bus->dirname); egate->filename = strdup(mydev->filename); } + found: return IFD_ICC_PRESENT; } *************** *** 154,161 **** if (!egate) return IFD_COMMUNICATION_ERROR; ! if (!egate->usb) { ! return egate_get_usb(egate); } return IFD_ICC_PRESENT; --- 161,170 ---- if (!egate) return IFD_COMMUNICATION_ERROR; ! rc = egate_get_usb(egate); ! ! if (rc == IFD_NO_SUCH_DEVICE) { ! return rc; } return IFD_ICC_PRESENT;
Jack checked in his fix in ifd-egate-0.05-17
Based on the date this bug was created, it appears to have been reported against rawhide during the development of a Fedora release that is no longer maintained. In order to refocus our efforts as a project we are flagging all of the open bugs for releases which are no longer maintained. If this bug remains in NEEDINFO thirty (30) days from now, we will automatically close it. If you can reproduce this bug in a maintained Fedora version (7, 8, or rawhide), please change this bug to the respective version and change the status to ASSIGNED. (If you're unable to change the bug's version or status, add a comment to the bug and someone will change it for you.) Thanks for your help, and we apologize again that we haven't handled these issues to this point. The process we're following is outlined here: http://fedoraproject.org/wiki/BugZappers/F9CleanUp We will be following the process here: http://fedoraproject.org/wiki/BugZappers/HouseKeeping to ensure this doesn't happen again.
This bug has been in NEEDINFO for more than 30 days since feedback was first requested. As a result we are closing it. If you can reproduce this bug in the future against a maintained Fedora version please feel free to reopen it against that version. The process we're following is outlined here: http://fedoraproject.org/wiki/BugZappers/F9CleanUp