Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.
RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.

Bug 1593034

Summary: NIPR-ALT card (a Giesecke & Devrient "SmartCafe Expert v7.0 144K DI") cannot be read by OpenSC
Product: Red Hat Enterprise Linux 7 Reporter: Josip Vilicic <jvilicic>
Component: openscAssignee: Jakub Jelen <jjelen>
Status: CLOSED DUPLICATE QA Contact: Asha Akkiangady <aakkiang>
Severity: medium Docs Contact:
Priority: medium    
Version: 7.5CC: jvilicic
Target Milestone: rc   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-11-15 13:06:17 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Josip Vilicic 2018-06-19 22:41:26 UTC
Description of problem:
NIPR-ALT card (a Giesecke & Devrient "SmartCafe Expert v7.0 144K DI") does not work with OpenSC


Version-Release number of selected component (if applicable):
opensc-0.16.0-8.20170227git777e2a3.el7


How reproducible:
Consistent


Steps to Reproduce:
1. Configure a RHEL 7.5 host to authenticate with SmartCards
2. Try to log in with a Giesecke & Devrient "SmartCafe Expert v7.0 144K DI"


Actual results:
User cannot log in


Expected results:
Cards to allow logging in


Additional info:

$ grep Bus lsusb.txt 
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 011: ID 058f:9540 Alcor Micro Corp. AU9540 Smartcard Reader
      (Bus Powered)
        bMaxCCIDBusySlots       1
  (Bus Powered)
Bus 001 Device 005: ID 03f0:1198 Hewlett-Packard HID-compliant mouse
      (Bus Powered)
  (Bus Powered)
Bus 001 Device 003: ID 0e8d:1887 MediaTek Inc. 
      (Bus Powered)
  (Bus Powered)
Bus 001 Device 002: ID 03f0:104a Hewlett-Packard 
      (Bus Powered)
        bMaxCCIDBusySlots       1
  (Bus Powered)
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub


_______________________________________________________________________________________



$ less -r apdux.txt

      1 00000000 debuglog.c:269:DebugLogSetLevel() debug level=debug
      2 00000034 debuglog.c:298:DebugLogSetCategory() Debug options: APDU
      3 00000008 pcscdaemon.c:238:main() Force colored logs
      4 00000171 utils.c:53:GetDaemonPid() Can't open /var/run/pcscd/pcscd.pid: No such file or directory
      5 00000161 configfile.l:245:DBGetReaderListDir() Parsing conf directory: /etc/reader.conf.d
      6 00000008 configfile.l:257:DBGetReaderListDir() Skipping non regular file: ..
      7 00000002 configfile.l:257:DBGetReaderListDir() Skipping non regular file: .
      8 00000006 pcscdaemon.c:525:main() pcsc-lite 1.8.8 daemon ready.
      9 00002864 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001
     10 00000209 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001
     11 00000207 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x03F0, PID: 0x104A, path: /dev/bus/usb/001/002
     12 00000061 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x03F0, PID: 0x104A, path: /dev/bus/usb/001/002
     13 00000004 hotplug_libudev.c:312:HPAddDevice() Adding USB device: Hewlett-Packard Company HP Smart Card Terminal KUS1206
     14 00000140 readerfactory.c:978:RFInitializeReader() Attempting startup of Hewlett-Packard Company HP Smart Card Terminal KUS1206 [HP Keyboard Smartcard Reader] (17042800000480) 00 00 using /usr/lib64/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libccid.sodler 3.0
     16 00000020 ifdhandler.c:1840:init_driver() Driver version: 1.4.10
     17 00000361 ifdhandler.c:1857:init_driver() LogLevel: 0x0003
     18 00000005 ifdhandler.c:1868:init_driver() DriverOptions: 0x0000
     19 00000052 ifdhandler.c:1881:init_driver() LogLevel from LIBCCID_ifdLogLevel: 0x000F
     20 00000006 ifdhandler.c:83:CreateChannelByNameOrChannel() Lun: 0, device: usb:03f0/104a:libudev:0:/dev/bus/usb/001/002
     21 00000004 ccid_usb.c:210:OpenUSBByName() Reader index: 0, Device: usb:03f0/104a:libudev:0:/dev/bus/usb/001/002
     22 00000016 ccid_usb.c:242:OpenUSBByName() interface_number: 0
     23 00000002 ccid_usb.c:258:OpenUSBByName() Using: /usr/lib64/pcsc/drivers/ifd-ccid.bundle/Contents/Info.plist
     24 00000311 ccid_usb.c:276:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (ludovic.rousseau)
     25 00000004 ccid_usb.c:277:OpenUSBByName() ifdProductString: Generic CCID driver
     26 00000003 ccid_usb.c:278:OpenUSBByName() Copyright: This driver is protected by terms of the GNU Lesser General Public License version 2.1, or (at your option) any later version.
     27 00005033 ccid_usb.c:405:OpenUSBByName() Checking device: 1/2
     28 00000007 ccid_usb.c:460:OpenUSBByName() Trying to open USB bus/device: 1/2
     29 00000218 ccid_usb.c:529:OpenUSBByName() Found interface 0 but expecting 1
     30 00000004 ccid_usb.c:531:OpenUSBByName() Wrong interface for USB device 1/2. Checking next one.
     33 00000004 readerfactory.c:1009:RFInitializeReader() Open Port 0x200000 Failed (usb:03f0/104a:libudev:0:/dev/bus/usb/001/002)
     34 00000003 readerfactory.c:312:RFAddReader() Hewlett-Packard Company HP Smart Card Terminal KUS1206 [HP Keyboard Smartcard Reader] (17042800000480) init failed.
     35 00000006 readerfactory.c:529:RFRemoveReader() UnrefReader() count was: 1
     36 00000002 readerfactory.c:1029:RFUnInitializeReader() Attempting shutdown of Hewlett-Packard Company HP Smart Card Terminal KUS1206 [HP Keyboard Smartcard Reader] (17042800000480) 00 00.
     37 00000003 readerfactory.c:905:RFUnloadReader() Unloading reader driver.
     38 00000261 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x03F0, PID: 0x104A, path: /dev/bus/usb/001/002
     39 00000061 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x03F0, PID: 0x104A, path: /dev/bus/usb/001/002
     40 00000003 hotplug_libudev.c:312:HPAddDevice() Adding USB device: Hewlett-Packard Company HP Smart Card Terminal KUS1206
     41 00000118 readerfactory.c:978:RFInitializeReader() Attempting startup of Hewlett-Packard Company HP Smart Card Terminal KUS1206 [HP Smartcard Keyboard] (17042800000480) 00 00 using /usr/lib64/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libccid.so
     42 00000256 readerfactory.c:868:RFBindFunctions() Loading IFD Handler 3.0
     43 00000018 ifdhandler.c:1840:init_driver() Driver version: 1.4.10
     44 00000362 ifdhandler.c:1857:init_driver() LogLevel: 0x0003
     45 00000005 ifdhandler.c:1868:init_driver() DriverOptions: 0x0000
     46 00000064 ifdhandler.c:1881:init_driver() LogLevel from LIBCCID_ifdLogLevel: 0x000F
     47 00000005 ifdhandler.c:83:CreateChannelByNameOrChannel() Lun: 0, device: usb:03f0/104a:libudev:1:/dev/bus/usb/001/002
     48 00000004 ccid_usb.c:210:OpenUSBByName() Reader index: 0, Device: usb:03f0/104a:libudev:1:/dev/bus/usb/001/002
     49 00000004 ccid_usb.c:242:OpenUSBByName() interface_number: 1
     50 00000003 ccid_usb.c:258:OpenUSBByName() Using: /usr/lib64/pcsc/drivers/ifd-ccid.bundle/Contents/Info.plist
     51 00000321 ccid_usb.c:276:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (ludovic.rousseau)
     52 00000004 ccid_usb.c:277:OpenUSBByName() ifdProductString: Generic CCID driver
     53 00000003 ccid_usb.c:278:OpenUSBByName() Copyright: This driver is protected by terms of the GNU Lesser General Public License version 2.1, or (at your option) any later version.
     54 00004185 ccid_usb.c:405:OpenUSBByName() Checking device: 1/2
     55 00000007 ccid_usb.c:460:OpenUSBByName() Trying to open USB bus/device: 1/2
     56 00000172 ccid_usb.c:551:OpenUSBByName() Found Vendor/Product: 03F0/104A (Hewlett-Packard Company HP Smart Card Terminal KUS1206)
     57 00000007 ccid_usb.c:553:OpenUSBByName() Using USB bus/device: 1/2
     58 00000003 ccid_usb.c:1074:ControlUSB() request: 0x03
     59 00000171 ccid_usb.c:1087:ControlUSB() control failed (1/2): -9 Resource temporarily unavailable
     60 00000003 ccid_usb.c:1018:get_data_rates() IFD does not support GET_DATA_RATES request: -9
     63 00000047 -> 000000 65 00 00 00 00 00 00 00 00 00 
     64 00000408 <- 000000 81 00 00 00 00 00 00 42 FE 01 
     65 00000023 -> 000000 65 00 00 00 00 00 01 00 00 00 
     66 00000336 <- 000000 81 00 00 00 00 00 01 42 FE 01 
     67 00000047 ifdhandler.c:358:IFDHGetCapabilities() tag: 0xFB3, usb:03f0/104a:libudev:1:/dev/bus/usb/001/002 (lun: 0)
     68 00000011 readerfactory.c:332:RFAddReader() Using the reader polling thread
     69 00000045 ifdhandler.c:1703:IFDHICCPresence() usb:03f0/104a:libudev:1:/dev/bus/usb/001/002 (lun: 0)
     70 00000029 -> 000000 65 00 00 00 00 00 02 00 00 00 
     71 00000304 <- 000000 81 00 00 00 00 00 02 42 FE 01 
     72 00000019 ifdhandler.c:1821:IFDHICCPresence() Card absent
     73 00000099 ifdhandler.c:358:IFDHGetCapabilities() tag: 0xFAE, usb:03f0/104a:libudev:1:/dev/bus/usb/001/002 (lun: 0)
     74 00000010 ifdhandler.c:446:IFDHGetCapabilities() Reader supports 1 slot(s)
     75 00000055 ifdhandler.c:1703:IFDHICCPresence() usb:03f0/104a:libudev:1:/dev/bus/usb/001/002 (lun: 0)
     76 00000021 -> 000000 65 00 00 00 00 00 03 00 00 00 
     77 00000318 <- 000000 81 00 00 00 00 00 03 42 FE 01 
     78 00000017 ifdhandler.c:1821:IFDHICCPresence() Card absent
     79 00000016 ifdhandler.c:1703:IFDHICCPresence() usb:03f0/104a:libudev:1:/dev/bus/usb/001/002 (lun: 0)
     80 00000024 -> 000000 65 00 00 00 00 00 04 00 00 00 
     81 00000334 <- 000000 81 00 00 00 00 00 04 42 FE 01 
     82 00000017 ifdhandler.c:1821:IFDHICCPresence() Card absent
     83 00000010 ifdhandler.c:287:IFDHPolling() usb:03f0/104a:libudev:1:/dev/bus/usb/001/002 (lun: 0) 600000 ms
     84 00000009 ccid_usb.c:1123:InterruptRead() before (0)
     85 00000097 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x03F0, PID: 0x104A, path: /dev/bus/usb/001/002
     86 00000216 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x03F0, PID: 0x104A, path: /dev/bus/usb/001/002
     87 00000015 hotplug_libudev.c:312:HPAddDevice() Adding USB device: Hewlett-Packard Company HP Smart Card Terminal KUS1206
     88 00000409 ifdhandler.c:358:IFDHGetCapabilities() tag: 0xFAF, usb:03f0/104a:libudev:1:/dev/bus/usb/001/002 (lun: 0)
     89 00000014 readerfactory.c:651:RFSetReaderName() Support 32 simultaneous readers
     90 00000013 ifdhandler.c:358:IFDHGetCapabilities() tag: 0xFAD, usb:03f0/104a:libudev:1:/dev/bus/usb/001/002 (lun: 0)
     91 00000008 readerfactory.c:274:RFAddReader() Driver is thread safe
     92 00000010 readerfactory.c:978:RFInitializeReader() Attempting startup of Hewlett-Packard Company HP Smart Card Terminal KUS1206 [HP Smartcard Keyboard Hotkey] (17042800000480) 01 00 using /usr/lib64/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libccid.so
     93 00000011 readerfactory.c:782:RFLoadReader() Reusing already loaded driver for /usr/lib64/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libccid.so
     94 00000021 readerfactory.c:868:RFBindFunctions() Loading IFD Handler 3.0
     95 00000043 ifdhandler.c:83:CreateChannelByNameOrChannel() Lun: 10000, device: usb:03f0/104a:libudev:2:/dev/bus/usb/001/002
     96 00000010 ccid_usb.c:210:OpenUSBByName() Reader index: 1, Device: usb:03f0/104a:libudev:2:/dev/bus/usb/001/002
     97 00000014 ccid_usb.c:242:OpenUSBByName() interface_number: 2
     98 00000010 ccid_usb.c:258:OpenUSBByName() Using: /usr/lib64/pcsc/drivers/ifd-ccid.bundle/Contents/Info.plist
     99 00001140 ccid_usb.c:276:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (ludovic.rousseau)
    100 00000016 ccid_usb.c:277:OpenUSBByName() ifdProductString: Generic CCID driver
    101 00000010 ccid_usb.c:278:OpenUSBByName() Copyright: This driver is protected by terms of the GNU Lesser General Public License version 2.1, or (at your option) any later version.
    102 00000198 ccid_usb.c:405:OpenUSBByName() Checking device: 1/2
    103 00000012 ccid_usb.c:460:OpenUSBByName() Trying to open USB bus/device: 1/2
    104 00000605 ccid_usb.c:529:OpenUSBByName() Found interface 2 but expecting 1
    105 00000013 ccid_usb.c:531:OpenUSBByName() Wrong interface for USB device 1/2. Checking next one.
    106 00000528 ifdhandler.c:117:CreateChannelByNameOrChannel() failed
    107 00000014 readerfactory.c:1009:RFInitializeReader() Open Port 0x200002 Failed (usb:03f0/104a:libudev:2:/dev/bus/usb/001/002)
    108 00000009 readerfactory.c:312:RFAddReader() Hewlett-Packard Company HP Smart Card Terminal KUS1206 [HP Smartcard Keyboard Hotkey] (17042800000480) init failed.
    109 00000010 readerfactory.c:529:RFRemoveReader() UnrefReader() count was: 1
    110 00000009 readerfactory.c:1029:RFUnInitializeReader() Attempting shutdown of Hewlett-Packard Company HP Smart Card Terminal KUS1206 [HP Smartcard Keyboard Hotkey] (17042800000480) 01 00. 111 00000753 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001
    112 00000750 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x0E8D, PID: 0x1887, path: /dev/bus/usb/001/003
    113 00000705 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001
    114 00000740 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x03F0, PID: 0x1198, path: /dev/bus/usb/001/005
    115 00000735 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x03F0, PID: 0x1198, path: /dev/bus/usb/001/005
    116 00000711 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0002, path: /dev/bus/usb/001/001
    117 00000712 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x058F, PID: 0x9540, path: /dev/bus/usb/001/012
    118 00000235 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x058F, PID: 0x9540, path: /dev/bus/usb/001/012
    119 00000014 hotplug_libudev.c:312:HPAddDevice() Adding USB device: Alcor Micro AU9540
    120 00000065 ifdhandler.c:358:IFDHGetCapabilities() tag: 0xFAF, usb:03f0/104a:libudev:1:/dev/bus/usb/001/002 (lun: 0)
    121 00000008 readerfactory.c:651:RFSetReaderName() Support 32 simultaneous readers
    122 00000013 ifdhandler.c:358:IFDHGetCapabilities() tag: 0xFAD, usb:03f0/104a:libudev:1:/dev/bus/usb/001/002 (lun: 0)
    123 00000007 readerfactory.c:274:RFAddReader() Driver is thread safe
    124 00000009 readerfactory.c:978:RFInitializeReader() Attempting startup of Alcor Micro AU9540 01 00 using /usr/lib64/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libccid.so
    125 00000008 readerfactory.c:782:RFLoadReader() Reusing already loaded driver for /usr/lib64/pcsc/drivers/ifd-ccid.bundle/Contents/Linux/libccid.so
    126 00000015 readerfactory.c:868:RFBindFunctions() Loading IFD Handler 3.0
    127 00000038 ifdhandler.c:83:CreateChannelByNameOrChannel() Lun: 10000, device: usb:058f/9540:libudev:0:/dev/bus/usb/001/012
    128 00000010 ccid_usb.c:210:OpenUSBByName() Reader index: 1, Device: usb:058f/9540:libudev:0:/dev/bus/usb/001/012
    129 00000012 ccid_usb.c:242:OpenUSBByName() interface_number: 0
    130 00000009 ccid_usb.c:258:OpenUSBByName() Using: /usr/lib64/pcsc/drivers/ifd-ccid.bundle/Contents/Info.plist
    131 00001205 ccid_usb.c:276:OpenUSBByName() ifdManufacturerString: Ludovic Rousseau (ludovic.rousseau)
    132 00000017 ccid_usb.c:277:OpenUSBByName() ifdProductString: Generic CCID driver
    133 00000011 ccid_usb.c:278:OpenUSBByName() Copyright: This driver is protected by terms of the GNU Lesser General Public License version 2.1, or (at your option) any later version.
    134 00000026 ccid_usb.c:405:OpenUSBByName() Checking device: 1/12
    135 00000009 ccid_usb.c:460:OpenUSBByName() Trying to open USB bus/device: 1/12
    136 00000617 ccid_usb.c:551:OpenUSBByName() Found Vendor/Product: 058F/9540 (Alcor Micro AU9540)
    137 00000013 ccid_usb.c:553:OpenUSBByName() Using USB bus/device: 1/12
    138 00000020 ccid_usb.c:1074:ControlUSB() request: 0x03
    139 03000382 ccid_usb.c:1087:ControlUSB() control failed (1/12): -7 Resource temporarily unavailable
    140 00000025 ccid_usb.c:1018:get_data_rates() IFD does not support GET_DATA_RATES request: -7
    141 00001284 ccid_usb.c:1123:InterruptRead() before (1)
    142 00000713 ccid_usb.c:1165:InterruptRead() after (1) (0)
    143 00000027 NotifySlotChange: 50 03 
    144 00000014 -> 000001 65 00 00 00 00 00 00 00 00 00 
    145 00000987 <- 000001 81 00 00 00 00 00 00 01 00 01 
    146 00000033 -> 000001 65 00 00 00 00 00 01 00 00 00 
    147 00000831 <- 000001 81 00 00 00 00 00 01 01 00 01 
    148 00000030 ifdhandler.c:358:IFDHGetCapabilities() tag: 0xFB3, usb:058f/9540:libudev:0:/dev/bus/usb/001/012 (lun: 10000)
    149 00000010 readerfactory.c:332:RFAddReader() Using the reader polling thread
    150 00000009 ifdhandler.c:1703:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/012 (lun: 10000)
    151 00000013 -> 000001 65 00 00 00 00 00 02 00 00 00 
    152 00001006 <- 000001 81 00 00 00 00 00 02 01 00 01 
    153 00000031 ifdhandler.c:1821:IFDHICCPresence() Card present
    154 00000107 ifdhandler.c:358:IFDHGetCapabilities() tag: 0xFAE, usb:058f/9540:libudev:0:/dev/bus/usb/001/012 (lun: 10000)
    155 00000016 ifdhandler.c:446:IFDHGetCapabilities() Reader supports 1 slot(s)
    156 00000072 ifdhandler.c:1703:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/012 (lun: 10000)
    157 00000035 -> 000001 65 00 00 00 00 00 03 00 00 00 
    158 00000861 <- 000001 81 00 00 00 00 00 03 01 00 01 
    159 00000021 ifdhandler.c:1821:IFDHICCPresence() Card present
    160 00000011 ifdhandler.c:1703:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/012 (lun: 10000)
    161 00000011 -> 000001 65 00 00 00 00 00 04 00 00 00 
    162 00000158 hotplug_libudev.c:260:get_driver() Looking for a driver for VID: 0x1D6B, PID: 0x0003, path: /dev/bus/usb/002/001
    163 00000119 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    164 00000582 <- 000001 81 00 00 00 00 00 04 01 00 01 
    165 00000024 ifdhandler.c:1821:IFDHICCPresence() Card present
    166 00000024 ifdhandler.c:1122:IFDHPowerICC() action: PowerUp, usb:058f/9540:libudev:0:/dev/bus/usb/001/012 (lun: 10000)
    167 00000013 -> 000001 62 00 00 00 00 00 05 00 00 00 
    168 00009507 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    169 00010263 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    170 00010261 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    171 00010262 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    172 00010279 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    173 00010261 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    174 00010256 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    175 00010262 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    176 00010243 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    177 00010266 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    178 00010159 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    179 00010161 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    180 00010253 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    181 00010261 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    182 00010230 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    183 00010151 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    184 00010266 readerfactory.c:1309:RFWaitForReaderInit() Waiting init for reader: Alcor Micro AU9540 01 00
    185 00009996 <- 000001 80 13 00 00 00 00 05 00 00 00 3B F9 96 00 00 80 31 FE 45 53 43 45 37 20 03 00 20 46 42 
    186 00000067 eventhandler.c:256:EHStatusHandlerThread() powerState: POWER_STATE_POWERED
    187 00000014 Card ATR: 3B F9 96 00 00 80 31 FE 45 53 43 45 37 20 03 00 20 46 42 
    188 00000014 ifdhandler.c:1703:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/012 (lun: 10000)
    189 00000011 -> 000001 65 00 00 00 00 00 06 00 00 00 
    190 00000058 winscard_msg_srv.c:230:ProcessEventsServer() Common channel packet arrival
    191 00000047 winscard_msg_srv.c:242:ProcessEventsServer() ProcessCommonChannelRequest detects: 13
    192 00000011 pcscdaemon.c:93:SVCServiceRunLoop() A new context thread creation is requested: 13
    193 00000482 winscard_svc.c:299:ContextThread() Thread is started: dwClientID=13, threadContext @0x55efb3f1e8c0
    194 00000049 winscard_svc.c:317:ContextThread() Received command: CMD_VERSION from client 13
    195 00000030 winscard_svc.c:329:ContextThread() Client is protocol version 4:2
    196 00000014 winscard_svc.c:349:ContextThread() CMD_VERSION rv=0x0 for client 13
    197 00000104 <- 000001 81 00 00 00 00 00 06 00 00 00 
    198 00000018 ifdhandler.c:1821:IFDHICCPresence() Card present
    199 00000011 ifdhandler.c:287:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/001/012 (lun: 10000) 5000 ms
    200 00000009 ccid_usb.c:1123:InterruptRead() before (1)
    201 00000014 winscard_svc.c:317:ContextThread() Received command: ESTABLISH_CONTEXT from client 13
    202 00000063 winscard.c:193:SCardEstablishContext() Establishing Context: 0x5A8FA7DD
    203 00000015 winscard_svc.c:410:ContextThread() ESTABLISH_CONTEXT rv=0x0 for client 13
    204 00000128 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    205 00000134 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    206 00000195 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    207 00000187 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    208 00000123 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    209 00000120 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    210 00500174 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    211 00000121 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    212 00000157 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    213 00000148 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    214 00000094 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    215 00000096 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    216 00500017 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    217 00000085 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    218 00000042 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    219 00000087 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    220 00000021 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    221 00000042 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    222 00500175 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    223 00000206 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    224 00000202 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    225 00000184 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    226 00000085 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    227 00000090 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    228 00500229 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    229 00000199 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    230 00000175 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    231 00000152 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    232 00000090 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    233 00000077 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    234 00500270 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    235 00000156 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    236 00000190 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    237 00000213 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    238 00000106 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    239 00000089 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    240 00500118 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    241 00000163 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    242 00000168 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    243 00000164 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    244 00000080 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    245 00000086 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    246 00500830 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    247 00000108 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    248 00000104 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    249 00000125 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    250 00000094 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    251 00000141 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    252 00500153 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    253 00000221 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    254 00000202 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    255 00000193 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    256 00000088 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    257 00000127 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    258 00500079 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    259 00000152 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    260 00000178 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    261 00000199 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    262 00000110 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    263 00000094 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    264 00491327 ccid_usb.c:1165:InterruptRead() after (1) (2)
    265 00000030 ifdhandler.c:1703:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/012 (lun: 10000)
    266 00000016 -> 000001 65 00 00 00 00 00 07 00 00 00 
    267 00001881 <- 000001 81 00 00 00 00 00 07 00 00 00 
    268 00000008 ifdhandler.c:1821:IFDHICCPresence() Card present
    269 00000004 ifdhandler.c:1122:IFDHPowerICC() action: PowerDown, usb:058f/9540:libudev:0:/dev/bus/usb/001/012 (lun: 10000)
    270 00000004 -> 000001 63 00 00 00 00 00 08 00 00 00 
    271 00007122 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    272 00000124 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    273 00000114 winscard_svc.c:317:ContextThread() Received command: CMD_GET_READERS_STATE from client 13
    274 00034283 <- 000001 81 00 00 00 00 00 08 01 00 01 
    275 00000019 eventhandler.c:446:EHStatusHandlerThread() powerState: POWER_STATE_UNPOWERED
    276 00000008 ifdhandler.c:1703:IFDHICCPresence() usb:058f/9540:libudev:0:/dev/bus/usb/001/012 (lun: 10000)
    277 00000007 -> 000001 65 00 00 00 00 00 09 00 00 00 
    278 00000815 <- 000001 81 00 00 00 00 00 09 01 00 01 
    279 00000015 ifdhandler.c:1821:IFDHICCPresence() Card present
    280 00000007 ifdhandler.c:287:IFDHPolling() usb:058f/9540:libudev:0:/dev/bus/usb/001/012 (lun: 10000) 600000 ms
    281 00000006 ccid_usb.c:1123:InterruptRead() before (1)


_______________________________________________________________________________________



$ less -r pcsc_scan.txt

      1 PC/SC device scanner
      2 V 1.4.25 (c) 2001-2011, Ludovic Rousseau <ludovic.rousseau>
      3 Compiled with PC/SC lite version: 1.8.8
      4 Using reader plug'n play mechanism
      5 Scanning present readers...
      6 0: Hewlett-Packard Company HP Smart Card Terminal KUS1206 [HP Smartcard Keyboard] (17042800000480) 00 00
      7 1: SCM Microsystems Inc. SCR 331 [CCID Interface] (50401EB2) 01 00
      8 
      9 Thu Jun  7 11:08:01 2018
     10 Reader 0: Hewlett-Packard Company HP Smart Card Terminal KUS1206 [HP Smartcard Keyboard] (17042800000480) 00 00
     11   Card state: Card removed, 
     12 Reader 1: SCM Microsystems Inc. SCR 331 [CCID Interface] (50401EB2) 01 00
     13   Card state: Card removed, 


_______________________________________________________________________________________



We have removed the Centrify module from their configuration, so we will update this bug with newer OpenSC-configured `pkcs11_listcerts debug` output, but this is the previous output:

$ cat pkcs11-debug.txt 
pkcs11_listcerts debug
DEBUG:pam_config.c:238: Using config file /etc/pam_pkcs11/pam_pkcs11.conf
DEBUG:pkcs11_lib.c:1008: Requested FIPS mode [0]
DEBUG:pkcs11_listcerts.c:72: loading pkcs #11 module...
DEBUG:pkcs11_lib.c:1039: PKCS #11 module = [/usr/lib64/pkcs11/libcentrifypkcs11.so]
DEBUG:pkcs11_lib.c:1056: module permissions: uid = 0, gid = 0, mode = 755
DEBUG:pkcs11_lib.c:1065: loading module /usr/lib64/pkcs11/libcentrifypkcs11.so
DEBUG:pkcs11_lib.c:1073: getting function list
DEBUG:pkcs11_listcerts.c:80: initialising pkcs #11 module...
DEBUG:pkcs11_lib.c:1183: module information:
DEBUG:pkcs11_lib.c:1184: - version: 2.11
DEBUG:pkcs11_lib.c:1185: - manufacturer: Mozilla Foundation
DEBUG:pkcs11_lib.c:1186: - flags: 0000
DEBUG:pkcs11_lib.c:1187: - library description: CoolKey PKCS #11 Module
DEBUG:pkcs11_lib.c:1188: - library version: 1.0
DEBUG:pkcs11_lib.c:1195: number of slots (a): 2
DEBUG:pkcs11_lib.c:1218: number of slots (b): 2
DEBUG:pkcs11_lib.c:1105: slot 1:
DEBUG:pkcs11_lib.c:1115: - description: Hewlett-Packard Company HP Smart Card Terminal KUS1206 [HP Smart
DEBUG:pkcs11_lib.c:1116: - manufacturer: Unknown
DEBUG:pkcs11_lib.c:1117: - flags: 0006
DEBUG:pkcs11_lib.c:1105: slot 2:
DEBUG:pkcs11_lib.c:1115: - description: Alcor Micro AU9540 01 00
DEBUG:pkcs11_lib.c:1116: - manufacturer: Unknown
DEBUG:pkcs11_lib.c:1117: - flags: 0007
DEBUG:pkcs11_lib.c:1119: - token:
DEBUG:pkcs11_lib.c:1125:   - label: CoolKey
DEBUG:pkcs11_lib.c:1126:   - manufacturer:
DEBUG:pkcs11_lib.c:1127:   - model:
DEBUG:pkcs11_lib.c:1128:   - serial:
DEBUG:pkcs11_lib.c:1129:   - flags: 040e
DEBUG:pkcs11_lib.c:1443: opening a new PKCS #11 session for slot 2
PIN for token:
DEBUG:pkcs11_lib.c:50: PIN = [wtf]
DEBUG:pkcs11_lib.c:1462: login as user CKU_USER
DEBUG:pkcs11_listcerts.c:128: Login failed: C_Login() failed: 0x00000032


______________________________________________________________________________________



$ cat pkcs11-login.txt
pkcs11-tool --login -O
Using slot 1 with a present token (0x4)
Logging in to "CAC II (Long.Corey".
Please enter User PIN:
Private Key Object; RSA
  label:      CAC Email Signature Certificate
  ID:         0002
  Usage:      sign
Public Key Object; RSA 2048 bits
  label:      CAC Email Signature Certificate
  ID:         0002
  Usage:      verify
Certificate Object; type = X.509 cert
  label:      CAC Email Signature Certificate
  ID:         0002


$ cat pkcs11-L.txt
Available slots:
Slot 0 (0x0): Hewlett-Packard Company HP Smart Card Terminal KUS1206 [HP Smart
  (empty)
Slot 1 (0x4): Alcor Micro AU9540 01 00
  token label        : CAC II (Long.Corey)
  token manufacturer : Common Access Card
  token model        : PKCS#15 emulated
  token flags        : login required, rng, token initialized, PIN initialized
  hardware version   : 0.0
  firmware version   : 0.0
  serial num         : 00000000


_______________________________________________________________________________________



$ cat pkcs11-O.txt 
Public Key Object; RSA 2048 bits
  label:      CAC Email Signature Certificate
  ID:         0002
  Usage:      verify
Certificate Object; type = X.509 cert
  label:      CAC Email Signature Certificate
  ID:         0002



_______________________________________________________________________________________




$ egrep -v "^$|#|^\;|^\//" pam_pkcs11.conf 
pam_pkcs11 {
  nullok = true;
  debug = false; 
  card_only = true;
  use_first_pass = false;
  try_first_pass = false;
  use_authtok = false;
  use_pkcs11_module = opensc;
  screen_savers = gnome-screensaver,xscreensaver,kscreensaver
  pkcs11_module centrify {
    module = /usr/lib64/pkcs11/libcentrifypkcs11.so;
    slot_num = 0;
    ca_dir = /etc/pam_pkcs11/cacerts;
    nss_dir = /etc/pki/nssdb;
  
    crl_dir = /etc/pam_pkcs11/crls;
    cert_policy=ocsp_on, ca, signature;
  }
  pkcs11_module coolkey {
    module = /usr/lib64/libcoolkeypk11.so;
    description = "Cool Key"
    slot_num = 0;
    ca_dir = /etc/pam_pkcs11/cacerts;
    nss_dir = /etc/pki/nssdb;
  
    crl_dir = /etc/pam_pkcs11/crls;
    cert_policy=ocsp_on, ca, signature;
  }
  pkcs11_module opensc {
    module = /usr/lib64/opensc-pkcs11.so;
    slot_num = 0;
    ca_dir = /etc/pam_pkcs11/cacerts;
    nss_dir = /etc/pki/nssdb;
  
    crl_dir = /etc/pam_pkcs11/crls;
  
    cert_policy=ocsp_on, ca, signature;
  }
  pkcs11_module default {
    module = /usr/$LIB/pam_pkcs11/pkcs11_module.so;
    slot_num = 0;
    ca_dir = /etc/pam_pkcs11/cacerts;
    crl_dir = /etc/pam_pkcs11/crls;
    cert_policy=signature;
  }
  use_mappers = ms;
  mapper_search_path = /usr/$LIB/pam_pkcs11;
  mapper generic {
        debug = true;
        module = /usr/$LIB/pam_pkcs11/generic_mapper.so;
        ignorecase = false;
        cert_item  = cn;
        mapfile = file:///etc/pam_pkcs11/generic_mapping
        use_getpwent = false;
  }
  mapper subject {
	debug = false;
	module = internal;
	ignorecase = false;
	mapfile = file:///etc/pam_pkcs11/subject_mapping;
  }
  mapper openssh {
	debug = false;
	module = /usr/$LIB/pam_pkcs11/openssh_mapper.so;
  }
  mapper opensc {
	debug = false;
	module = /usr/$LIB/pam_pkcs11/opensc_mapper.so;
  }
  mapper pwent {
	debug = false;
	ignorecase = false;
	module = internal;
  }
  mapper null {
	debug = false;
	module = internal ;
	default_match = false;
        default_user = nobody ;
  }
  mapper ldap {
	debug = false;
	module = /usr/$LIB/pam_pkcs11/ldap_mapper.so;
	basedir = /etc/pam_pkcs11/mapdir;
        ldaphost = "localhost";
        ldapport = 389;
        scope = 2;
        binddn = "cn=pam,o=example,c=com";
        passwd = "test";
        base = "ou=People,o=example,c=com";
        attribute = "userCertificate";
        filter = "(&(objectClass=posixAccount)(uid=%s))"
  }
  mapper cn {
	debug = false;
	module = internal;
	ignorecase = true;
	mapfile = file:///etc/pam_pkcs11/cn_map;
  }
  mapper mail {
	debug = false;
	module = internal;
	mapfile = file:///etc/pam_pkcs11/mail_mapping;
	ignorecase = true;
	ignoredomain = false;
  }
  mapper ms {
	debug = false;
	module = internal;
	ignorecase = true;
	ignoredomain = true;
	domain = "domain.com";
  }
  mapper krb {
	debug = false;
	module = internal;
	ignorecase = false;
	mapfile = "none";
  }
  mapper uid {
	debug = false;
	module = internal;
	ignorecase = false;
	mapfile = "none";
  }
  mapper digest {
	debug = false;
	module = internal;
	algorithm = "sha1";
	mapfile = file:///etc/pam_pkcs11/digest_mapping;
  }
}


_______________________________________________________________________


We are also changing this to reference 


$ egrep -v "^$|#|^\;|^\//" pkcs11_eventmgr.conf 
pkcs11_eventmgr {
	daemon = true;
	debug = false;
	
	polling_time = 1;
	expire_time = 0;
	
	pkcs11_module = /usr/$LIB/libcoolkeypk11.so;
	event card_insert {
		on_error = ignore ;
		action = "/usr/sbin/gdm-safe-restart";
	}
	event card_remove { 
		on_error = ignore;
		action = "/usr/sbin/gdm-safe-restart";
	}
	event expire_time { 
		on_error = ignore;
		action = "/bin/false";
	}
}

Comment 9 Jakub Jelen 2018-11-15 13:06:17 UTC

*** This bug has been marked as a duplicate of bug 1645581 ***