Bug 232983 - Propagation of smart card removal events to apps flaky
Propagation of smart card removal events to apps flaky
Status: CLOSED INSUFFICIENT_DATA
Product: Fedora
Classification: Fedora
Component: ifd-egate (Show other bugs)
rawhide
All Linux
medium Severity medium
: ---
: ---
Assigned To: Bob Relyea
bzcl34nup
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2007-03-19 14:59 EDT by Jack Magne
Modified: 2008-05-06 21:18 EDT (History)
1 user (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2008-05-06 21:18:43 EDT
Type: ---
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
Output of /usr/sbin/udevmonitor (4.84 KB, text/plain)
2007-03-22 16:44 EDT, Jack Magne
no flags Details
Proposed new spec file. (3.89 KB, text/plain)
2007-03-23 18:01 EDT, Jack Magne
no flags Details

  None (edit)
Description Jack Magne 2007-03-19 14:59:36 EDT
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.
Comment 1 Jack Magne 2007-03-19 17:06:22 EDT
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.
Comment 2 Jack Magne 2007-03-19 18:16:21 EDT
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.
Comment 3 Jack Magne 2007-03-19 20:48:09 EDT
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.


Comment 4 Bob Relyea 2007-03-20 11:51:23 EDT
Thanks Jack, I believe there's another bug about the polling issue. I'll track
it down an link it in. Good work.

bob
Comment 5 Jack Magne 2007-03-21 18:50:12 EDT
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.

Comment 6 Jack Magne 2007-03-22 16:44:43 EDT
Created attachment 150697 [details]
Output of /usr/sbin/udevmonitor
Comment 7 Jack Magne 2007-03-22 16:52:19 EDT
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.







Comment 8 Jack Magne 2007-03-22 17:28:57 EDT
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==""
Comment 9 Jack Magne 2007-03-22 17:44:57 EDT
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"
Comment 10 Jack Magne 2007-03-22 19:00:39 EDT
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.
Comment 11 Jack Magne 2007-03-23 17:00:40 EDT
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.

Comment 12 Jack Magne 2007-03-23 17:59:17 EDT
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"
Comment 13 Jack Magne 2007-03-23 18:00:03 EDT
Proposed spec:

Comment 14 Jack Magne 2007-03-23 18:01:00 EDT
Created attachment 150800 [details]
Proposed new spec file.
Comment 15 Jack Magne 2007-03-26 14:21:59 EDT
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...


Comment 16 Jack Magne 2007-03-26 14:42:59 EDT
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;
Comment 17 Bob Relyea 2007-06-11 18:17:01 EDT
Jack checked in his fix in ifd-egate-0.05-17
Comment 18 Bug Zapper 2008-04-03 19:43:27 EDT
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.
Comment 19 Bug Zapper 2008-05-06 21:18:41 EDT
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

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