Bug 606842

Created attachment 425973 [details]
File: backtrace

Changing component to coolkey (dataStart function is in coolkey, not in pam_pkcs11) fortuately I'm the packager for both, so I recognized the coolkey function.

This crash looks familiar, can you tell me what brand of USB card this was? It wasn't the Gemalto 64K card was it? May be related to bug 604214.

I'm using an ActivIdentity ActivKey SIM USB Token. I don't know if they manufacture their own readers, though. I'll dig into it and see if I can find out more details.

lsusb lists the mfg as ActivIdentity and I'm not finding any information that even implies that the ActivKey and Gemalto HW are the same.

I took a look at bug 604212 and the failure doesn't look to be the same (to me at least). My /var/log/messages contains:

Jun 22 08:51:34 localhost kernel: usb 5-2: new full speed USB device using uhci_hcd and address 2
Jun 22 08:51:34 localhost kernel: usb 5-2: New USB device found, idVendor=09c3, idProduct=0014
Jun 22 08:51:34 localhost kernel: usb 5-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Jun 22 08:51:34 localhost kernel: usb 5-2: Product: Activkey_Sim
Jun 22 08:51:34 localhost kernel: usb 5-2: Manufacturer: ActivIdentity
Jun 22 08:51:36 localhost pcscd: winscard.c:309:SCardConnect() Reader E-Gate 0 0 Not Found
Jun 22 08:51:38 localhost pcscd: winscard.c:309:SCardConnect() Reader E-Gate 0 0 Not Found
Jun 22 08:51:47 localhost kernel: show_signal_msg: 152 callbacks suppressed
Jun 22 08:51:47 localhost kernel: pkcs11_inspect[3199]: segfault at 7792471 ip 00007f727ee0d342 sp 00007fff14e961a8 error 4 in libcoolkeypk11.so[7f727edff000+1f000]

Sorry, there was a typo in my last reply. I meant bug 604214.

A stack trace that shows what coolkey is doing at the time would help, if it's possible.

I think this is what you were looking for. If I'm wrong, could you point me in the right direction? I'm pretty new at this and I couldn't think of another way to get a stacktrace for coolkey (this was loading the coredump from previous crash and libcoolkey's debug symbols in gdb)

#0  0x00007f727ee0d342 in dataStart (buf=0x7792471 <Address 0x7792471 out of bounds>, length=4136367400, data_length=0x7fff14e96218, includeTag=false) at object.cpp:508
508         tag = buf[used_length++];
(gdb) bt
#0  0x00007f727ee0d342 in dataStart (buf=0x7792471 <Address 0x7792471 out of bounds>, length=4136367400, data_length=0x7fff14e96218, includeTag=false) at object.cpp:508
#1  0x00007f727ee0d4c5 in GetCertFieldItems (derCert=0xe85393, derSerial=0x7fff14e962b0, derSubject=0x7fff14e96290, derIssuer=0x7fff14e96270, subjectKey=0x7fff14e96478)
    at object.cpp:703
#2  GetCertFields (derCert=0xe85393, derSerial=0x7fff14e962b0, derSubject=0x7fff14e96290, derIssuer=0x7fff14e96270, subjectKey=0x7fff14e96478) at object.cpp:744
#3  0x00007f727ee0e687 in CACCert::CACCert (this=0x7fff14e96450, instance=<value optimized out>, derCert=0x7fff14e964e0) at object.cpp:1052
#4  0x00007f727ee143d4 in Slot::loadCACCert (this=<value optimized out>, instance=<value optimized out>) at slot.cpp:2209
#5  0x00007f727ee14cd6 in Slot::loadObjects (this=0xe84ae0) at slot.cpp:2244
#6  0x00007f727ee15278 in Slot::refreshTokenState (this=0xe84ae0) at slot.cpp:787
#7  0x00007f727ee16539 in Slot::isTokenPresent (this=0xe84ae0) at slot.cpp:802
#8  0x00007f727ee16cfa in SlotList::getSlotList (this=0xe848c0, tokenPresent=<value optimized out>, pSlotList=0x0, pulCount=<value optimized out>) at slot.cpp:524
#9  0x00007f727ee0bcba in C_GetSlotList (tokenPresent=0 '\000', pSlotList=0x0, pulCount=0x7fff14e966d0) at coolkey.cpp:175
#10 0x0000003bac0360f6 in secmod_LoadPKCS11Module (mod=0xe78980, oldModule=<value optimized out>) at pk11load.c:527
#11 0x0000003bac04a845 in SECMOD_LoadModule (modulespec=0xe71f80 "library=libcoolkeypk11.so name=\"CoolKey PKCS #11 Module\"  ", parent=0xe6eea0, recurse=1) at pk11pars.c:1108
#12 0x0000003bac04a9d0 in SECMOD_LoadModule (
    modulespec=0xe6db40 "name=\"NSS Internal Module\" parameters=\"configdir='/etc/pki/nssdb' certPrefix='' keyPrefix='' secmod='secmod.db' flags=readOnly,optimizeSpace updatedir='' updateCertPrefix='' updateKeyPrefix='' updatei"..., parent=0x0, recurse=1) at pk11pars.c:1143
#13 0x0000003bac019456 in nss_InitModules (configdir=0xe64920 "/etc/pki/nssdb", certPrefix=<value optimized out>, keyPrefix=<value optimized out>,
    secmodName=0x3bac0fc81b "secmod.db", updateDir=0xe6daa0 "\001", updCertPrefix=0xe6dac0 "", updKeyPrefix=0x3bac0fce2f "", updateID=0x3bac0fce2f "", updateName=0x3bac0fce2f "",
    initContextPtr=0x0, initParams=0x0, readOnly=1, noCertDB=0, noModDB=0, forceOpen=0, noRootInit=0, optimizeSpace=1, noSingleThreadedModules=0, allowAlreadyInitializedModules=0,
    dontFinalizeModules=0) at nssinit.c:461
#14 nss_Init (configdir=0xe64920 "/etc/pki/nssdb", certPrefix=<value optimized out>, keyPrefix=<value optimized out>, secmodName=0x3bac0fc81b "secmod.db",
    updateDir=0xe6daa0 "\001", updCertPrefix=0xe6dac0 "", updKeyPrefix=0x3bac0fce2f "", updateID=0x3bac0fce2f "", updateName=0x3bac0fce2f "", initContextPtr=0x0, initParams=0x0,
    readOnly=1, noCertDB=0, noModDB=0, forceOpen=0, noRootInit=0, optimizeSpace=1, noSingleThreadedModules=0, allowAlreadyInitializedModules=0, dontFinalizeModules=0)
    at nssinit.c:620
#15 0x0000003bac019f68 in NSS_Init (configdir=<value optimized out>) at nssinit.c:714
#16 0x0000000000408876 in ?? ()
#17 0x00007fff14e96b18 in ?? ()
#18 0x000000000061b158 in ?? ()
#19 0x0000000000000000 in ?? ()

Created attachment 426144 [details]
Related segfault backtrace from etc (not the same crash as originally reported)

When I was trying to reproduce this again, I noticed something in the process that I hadn't put together until now because I was really just not looking for it:
1. Insert USB card
2. segfault in etc
3. run pkcs11_inspect
4. segfault while running pkcs11_inspect

I take back what I said about not looking like bug 604214, the backtrace from the etc crash (attached to this comment instead of pasting this time) looks awfully similar.

I applied the patch from bug 604214 and rebuilt the coolkey rpm. I no longer see the etc crash when I put my USB key in for the first time but I am still seeing the same libcoolkey segfault if I try to use pkcs11_inspect.

Created attachment 426147 [details]
Full backtrace from crash

(In reply to comment #7)
I apologize for my lack of manners in pasting the backtrace into a comment. I assume that the information would be easier to parse as an attachment so I am re-posting it that way.

Backtrace in the bug is useful.

A couple of questions:
   1) Is your card a CAC card?
   2) If so is it a 'new' CAC card?
   3) If not is it a PIV card?

If either question 2 or 3 is correct, does the latest rawhide build fix the problem:
https://koji.fedoraproject.org/koji/buildinfo?buildID=178395

Also, Jack's fix for Gemalto should also solve the crash, but probably won't fix any real issues with the card unless your card is a coolkey (The bug on the Gemalto is that for some reason the card couldn't select the coolkey applet, but was 'selecting' a non-existant CAC applet.

Created attachment 426355 [details]
Possible cac crash fix

Putting the patch here first.

From the explanation of the user, it sounds like this patch may fix the issue when he inserts the key but may not solve his issue when he runs the utility program.

Build with latest patches done here:

http://koji.fedoraproject.org/koji/buildinfo?buildID=179475

Created attachment 426626 [details]
backtrace from crash with latest build

I installed the newest coolkey (build 16) and pkcs11_inspect still crashes. The crash in etc came back, too. I'll add an initial reboot into my testing process to verify consistency.

(In reply to comment #10)
>    1) Is your card a CAC card?
>    2) If so is it a 'new' CAC card?
>    3) If not is it a PIV card?

If by CAC card, you mean the cards issued by the US DoD then no. If by PIV card, you are talking about the US government PIV program then also, no.

I don't know if this helps, but I have been trying to follow these tutorials:
(debian based, same token type) http://vanalboom.org/node/12
(RHEL5) http://ryandlane.com/blog/2008/10/21/seamless-smartcard-login-with-pam_pkcs11-and-pam_krb5-against-an-active-directory-domain-using-red-hat-enterprise-linux-5-part-1/

Created attachment 426629 [details]
New etc crash backtrace

etc crash when USB key is first plugged in (using latest libcoolkey build)

> If by CAC card, you mean the cards issued by the US DoD then no. If by PIV
> card, you are talking about the US government PIV program then also, no.

No, I mean a card that uses the CAC interface or the PIV interface. Looking at your descriptions, it sounds like the answer is yes, since HP clearly suggests that you use the coolkey pkcs #11 module, and you have a card from ActiveCard (who has their own CAC applets), and the crash is in the CAC portion of the code, I'm going to assume that you do indeed have a 'CAC' card, and not a coolkey card that is acting in a broken manner somehow.

Since the code changes didn't seem to fix the problem, I'm also going to assume that you don't have an empty cert slot 0.

I'm also going to assume that there isn't something inherently broken with the card itself, otherwise HP wouldn't be suggesting that users turn on the cards. This leaves some sort of environmental cause. Try the following:

Look in /var/cache/coolkey.
Move all the files in there to a saved area.

rerun your test.

If this causes things to work, attack the file with the name coolkeypk11s{your reader}-{your user id}

where {your reader} is the name of the reader you have installed and {your user id} is the user id you ran the inspect program under (probably 500).

bob

I've been working on this and while the segfaults went away once I moved the files in /var/cache/coolkey, I can't get etc or any of the pkcs11 programs outside of "pkcs11-dump slotlist" to recognize the USB key anymore.

I also don't think that the card is broken, it works fine under windows with ActivIdentity's client. I just don't have access to their linux client.

pkcs11-dump shows the USB key in slot 1 but I'm not clear on whether that's just a difference in numbering schemes.

running pkcs11_inspect debug yields the following output:

DEBUG:pkcs11_lib.c:226: dllName= /usr/lib64/libcoolkeypk11.so
DEBUG:pkcs11_lib.c:272: loading Module explictly, moduleSpec=<library="libcoolkeypk11.so" name="SmartCard"> module=libcoolkeypk11.so
DEBUG:pkcs11_lib.c:276: Failed to load SmartCard software An I/O error occurred during security authorization.
ERROR:pkcs11_inspect.c:73: load_pkcs11_module(libcoolkeypk11.so) failed

running "pkcs11-dump dump /usr/lib64/libcoolkeypk11.so 1 -" yields the following error message:
Fatal: C_OpenSession-CKR_DEVICE_REMOVED

> running "pkcs11-dump dump /usr/lib64/libcoolkeypk11.so 1 -" yields the
> following error message:
> Fatal: C_OpenSession-CKR_DEVICE_REMOVED  

This can happen if the pcscd is locked or dead

$service pcscd status

This message is a reminder that Fedora 13 is nearing its end of life.
Approximately 30 (thirty) days from now Fedora will stop maintaining
and issuing updates for Fedora 13.  It is Fedora's policy to close all
bug reports from releases that are no longer maintained.  At that time
this bug will be closed as WONTFIX if it remains open with a Fedora 
'version' of '13'.

Package Maintainer: If you wish for this bug to remain open because you
plan to fix it in a currently maintained version, simply change the 'version' 
to a later Fedora version prior to Fedora 13's end of life.

Bug Reporter: Thank you for reporting this issue and we are sorry that 
we may not be able to fix it before Fedora 13 is 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 please change the 'version' of this 
bug to the applicable version.  If you are unable to change the version, 
please add a comment here and someone will do it for you.

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

Fedora 13 changed to end-of-life (EOL) status on 2011-06-25. Fedora 13 is 
no longer maintained, which means that it will not receive any further 
security or bug fix updates. As a result we are closing this bug.

If you can reproduce this bug against a currently maintained version of 
Fedora please feel free to reopen this bug against that version.

Thank you for reporting this bug and we are sorry it could not be fixed.