Bug 1262039

roshni, since I don't have access to the kdcuser2 card, can you set up a debug environment for me? Thanks,

bob

Never mind, it's a simple error in the debug statements. I can attach a patch tomorrow...

If we can get the acks, I can supply a fix. NOTE: this is only a problem with the debugging output, so it's not a critical fix, but it's also a low risk, simple fix.

bob

Created attachment 1072609 [details]
Patch to fix the debug output

fixed in pam_pkcs11-0.6.2-24

[root@dhcp129-45 ~]# rpm -qi pam_pkcs11
Name        : pam_pkcs11
Version     : 0.6.2
Release     : 24.el7
Architecture: x86_64
Install Date: Fri 11 Sep 2015 04:37:12 PM EDT
Group       : System Environment/Base
Size        : 1104350
License     : LGPLv2+
Signature   : (none)
Source RPM  : pam_pkcs11-0.6.2-24.el7.src.rpm
Build Date  : Fri 11 Sep 2015 03:17:15 PM EDT
Build Host  : x86-021.build.eng.bos.redhat.com
Relocations : (not relocatable)
Packager    : Red Hat, Inc. <http://bugzilla.redhat.com/bugzilla>
Vendor      : Red Hat, Inc.
URL         : http://www.opensc-project.org/pam_pkcs11
Summary     : PKCS #11/NSS PAM login module


1. Make the following changes to /etc/pam_pkcs11/pam_pkcs11.conf

use_mappers = ldap;

# Directory ( ldap style ) mapper
  mapper ldap {
        debug = true;
        module = /usr/$LIB/pam_pkcs11/ldap_mapper.so;
        # where base directory resides
        basedir = /etc/pam_pkcs11/mapdir;
        # hostname of ldap server
        ldaphost = "yttrium.idmqe.lab.eng.bos.redhat.com";
        # Port on ldap server to connect
        ldapport = 1603;
        # Scope of search: 0 = x, 1 = y, 2 = z
        scope = 2;
        # DN to bind with. Must have read-access for user entries under "base"
        binddn = "cn=Directory Manager";
        # Password for above DN
        passwd = "Secret123";
        # Searchbase for user entries
        base = "ou=People,dc=pki-tps1";
        # Attribute of user entry which contains the certificate
        attribute = "userCertificate";
        # Searchfilter for user entry. Must only let pass user entry for the login user.
        filter = "(&(objectClass=posixAccount)(uid=%s))"
        uid_attribute = "uid";
        attribute_map = "uid=uid&mail=email", "redhatPrincipalName=upn", "userCertificate;binary=cert";
  }

2. Insert a smartcard enrolled with a kerberos user.

dn: uid=kdcuser2,ou=People,dc=pki-tps1
objectClass: top
objectClass: person
objectClass: inetOrgPerson
objectClass: organizationalPerson
objectClass: redhatKerberosUser
objectClass: posixAccount
cn: kdcuser2
sn: KDCUser
description: this is the description of kdcuser2
telephoneNumber: This the telephoneNumber of kdcuser2
businessCategory: This the businessCategory of kdcuser2
carLicense: This the carLicense of kdcuser2
departmentNumber: This the departmentNumber of kdcuser2
displayName: KDC User
employeeNumber: This the employeeNumber of kdcuser2
employeeType: This the employeeType of kdcuser2
givenName: GivenName
homePhone: This the homePhone of kdcuser2
homePostalAddress: This the homePostalAddress of kdcuser2
initials: This the initials of kdcuser2
labeledURI: This the labeledURL of kdcuser2
mail: rpattath
mobile: This the mobile of kdcuser2
o: This the o of kdcuser2
pager: This the pager of kdcuser2
preferredLanguage: This the preferredLanguage of kdcuser2
roomNumber: This the roomNumber of kdcuser2
uid: kdcuser2
userSMIMECertificate: This the userSMIMECertificate of kdcuser2
redhatPrincipalName: kdcuser2
uidNumber: 1001
gidNumber: 1000
loginShell: /bin/sh
homeDirectory: /home/kdcuser2
userPassword:: e1NTSEF9YVpVa1c5RkZ3UnB6ajFJeC9tVEtxcnNyVkRVWkNRc3Byd0I4ckE9PQ=
 =
userCertificate;binary:: MIID9jCCAt6gAwIBAgIBOjANBgkqhkiG9w0BAQsFADBYMTUwMwYDV
 QQKDCxpZG1xZS5sYWIuZW5nLmJvcy5yZWRoYXQuY29tIFNlY3VyaXR5IERvbWFpbjEfMB0GA1UEAw
 wWQ0EgU2lnbmluZyBDZXJ0aWZpY2F0ZTAeFw0xNTA5MDkxODQwMTZaFw0yMDA5MDcxODQwMTZaMDM
 xFzAVBgNVBAoMDlRva2VuIEtleSBVc2VyMRgwFgYKCZImiZPyLGQBAQwIa2RjdXNlcjIwgZ8wDQYJ
 KoZIhvcNAQEBBQADgY0AMIGJAoGBAIxF7FWEeCGBph/9D7Z7gsFH3gQAgc4BPkRGl/FJgM+StxChy
 RUk+zfDNXnWLOAs1t2sZvqUEcR4GnvsRqRG57CO9ks1seJQy7dj2+4ChQs8SpRrJ/V/LuQM+Xfc9s
 2bhj0osWoxr2TZXpbwh9BXMZJje9K/EiDB5cX9UPeMVSbtAgMBAAGjggFyMIIBbjAOBgNVHQ8BAf8
 EBAMCBsAwgYUGA1UdEQR+MHyBE3JwYXR0YXRoQHJlZGhhdC5jb22gJAYKKwYBBAGCNxQCA6AWDBRr
 ZGN1c2VyMkBFWEFNUExFLkNPTaA/BgYrBgEFAgKgNTAzoA0bC0VYQU1QTEUuQ09NoSIwIKADAgEBo
 RkwFxsIa2RjdXNlcjIbC0VYQU1QTEUuQ09NMB0GA1UdDgQWBBTLLVbh9rTYVyQCUv/GP3fA76X8Bz
 AfBgNVHSMEGDAWgBSprEnWriPbYG15LDE8qnQ2YmoTATAJBgNVHRMEAjAAMFQGCCsGAQUFBwEBBEg
 wRjBEBggrBgEFBQcwAYY4aHR0cDovL3l0dHJpdW0uaWRtcWUubGFiLmVuZy5ib3MucmVkaGF0LmNv
 bTo4MDgwL2NhL29jc3AwMwYDVR0lBCwwKgYIKwYBBQUHAwEGCCsGAQUFBwMCBggrBgEFBQcDBAYKK
 wYBBAGCNxQCAjANBgkqhkiG9w0BAQsFAAOCAQEAiYl2gxEEHFKOeyYtCnMammJAgBjBgaob+ktigd
 zaj370H5HKYks7eDs6CSffbjMBY+Qv8J+nZ3xkqZ7nVUcn6DCBfPzUd2JmFoLL24JAC16IfoRJQmp
 KR/xCcAif+LOIgFrNhmmWr1dIk7myChbWCS55U9RZZFHNdASpydPnFRfy5CmxW7tu3EaBKxiIva6o
 X2nuV0yU722eprwX/NmKwdU61oQ8WBEvUHH5sbQpNHRsxNt+RNmdVYNzq01VPX6npxYbpNDLGj7Ot
 M4zDfae/sV9aTXdLIZ6uxYJsztp6RgsNZiKEwXCsteMKPSLEuxdTkhd5wVfEcxvQ2/hmnqBZQ==

3. Import and trust the issuing CA cert under /etc/pki/nssdb

4. Run pklogin_finder

[root@dhcp129-45 ~]# pklogin_finder debug
DEBUG:pam_config.c:238: Using config file /etc/pam_pkcs11/pam_pkcs11.conf
DEBUG:pkcs11_lib.c:182: Initializing NSS ...
DEBUG:pkcs11_lib.c:192: Initializing NSS ... database=/etc/pki/nssdb
DEBUG:pkcs11_lib.c:210: ...  NSS Complete
DEBUG:pklogin_finder.c:71: loading pkcs #11 module...
DEBUG:pkcs11_lib.c:235: Looking up module in list
DEBUG:pkcs11_lib.c:238: modList = 0x15d6770 next = 0x15e2270

DEBUG:pkcs11_lib.c:239: dllName= <null> 

DEBUG:pkcs11_lib.c:238: modList = 0x15e2270 next = 0x0

DEBUG:pkcs11_lib.c:239: dllName= libcoolkeypk11.so 

DEBUG:pklogin_finder.c:79: initialising pkcs #11 module...
PIN for token: 
DEBUG:pkcs11_lib.c:48: PIN = [redhat]
DEBUG:pkcs11_lib.c:759: cert 0: found (kdcuser2:signing key for kdcuser2), "UID=kdcuser2,OU=People,DC=pki-tps1"
DEBUG:mapper_mgr.c:172: Retrieveing mapper module list
DEBUG:mapper_mgr.c:95: Loading dynamic module for mapper 'ldap'
DEBUG:ldap_mapper.c:1172: test ssltls = default
DEBUG:ldap_mapper.c:1174: LDAP mapper started.
DEBUG:ldap_mapper.c:1175: debug         = 1
DEBUG:ldap_mapper.c:1176: ignorecase    = 0
DEBUG:ldap_mapper.c:1177: ldaphost      = yttrium.idmqe.lab.eng.bos.redhat.com
DEBUG:ldap_mapper.c:1178: ldapport      = 1603
DEBUG:ldap_mapper.c:1179: ldapURI       = 
DEBUG:ldap_mapper.c:1180: scope         = 2
DEBUG:ldap_mapper.c:1181: binddn        = cn=Directory Manager
DEBUG:ldap_mapper.c:1182: passwd        = Secret123
DEBUG:ldap_mapper.c:1183: base          = ou=People,dc=pki-tps1
DEBUG:ldap_mapper.c:1184: attribute     = userCertificate
DEBUG:ldap_mapper.c:1185: uid_attribute = uid
DEBUG:ldap_mapper.c:1187: attribute_map = uid=uid&mail=email
DEBUG:ldap_mapper.c:1187: attribute_map = krbprincipalname=upn
DEBUG:ldap_mapper.c:1187: attribute_map = userCertificate;binary=cert
DEBUG:ldap_mapper.c:1189: filter        = (&(objectClass=posixAccount)(uid=%s))
DEBUG:ldap_mapper.c:1190: searchtimeout = 20
DEBUG:ldap_mapper.c:1191: ssl_on        = 0
DEBUG:ldap_mapper.c:1193: tls_randfile  = 
DEBUG:ldap_mapper.c:1194: tls_cacertfile= 
DEBUG:ldap_mapper.c:1195: tls_cacertdir = 
DEBUG:ldap_mapper.c:1196: tls_checkpeer = -1
DEBUG:ldap_mapper.c:1197: tls_ciphers   = 
DEBUG:ldap_mapper.c:1198: tls_cert      = 
DEBUG:ldap_mapper.c:1199: tls_key       = 
DEBUG:mapper_mgr.c:197: Inserting mapper [ldap] into list
DEBUG:pklogin_finder.c:127: Found '1' certificate(s)
DEBUG:pklogin_finder.c:131: verifing the certificate #1
DEBUG:cert_vfy.c:34: Verifying Cert: kdcuser2:signing key for kdcuser2 (UID=kdcuser2,OU=People,DC=pki-tps1)
DEBUG:pklogin_finder.c:145: Trying to deduce login from certificate
DEBUG:ldap_mapper.c:931: ldap_get_certificate(): begin login unknown
DEBUG:ldap_mapper.c:582: added URI ldap://yttrium.idmqe.lab.eng.bos.redhat.com:1603
DEBUG:ldap_mapper.c:991: ldap_get_certificate(): try do_open for ldap://yttrium.idmqe.lab.eng.bos.redhat.com:1603
DEBUG:ldap_mapper.c:145: do_init():
DEBUG:ldap_mapper.c:415: Set connection timeout to 8
DEBUG:ldap_mapper.c:323: do_bind(): bind DN="cn=Directory Manager" pass="Secret123"
DEBUG:ldap_mapper.c:356: do_bind rc=97
DEBUG:ldap_mapper.c:1023: ldap_get_certificate(): building filter_str from template 'uid=uid&mail=email'
DEBUG:ldap_mapper.c:791: ldap_build_cert_filter(): building filter 'uid=uid&mail=email'
DEBUG:ldap_mapper.c:740: ldap_build_cert_filter(): building subfilter 'uid'='uid'
DEBUG:ldap_mapper.c:740: ldap_build_cert_filter(): building subfilter 'mail'='email'
DEBUG:ldap_mapper.c:1039: ldap_get_certificate(): searching with filter_str = (&(&(objectClass=posixAccount)(uid=*))(&(uid=kdcuser2)(mail=rpattath)))
DEBUG:ldap_mapper.c:1051: ldap_get_certificate(): found an entry
DEBUG:ldap_mapper.c:1071: ldap_get_certificate(): entries = 1
DEBUG:ldap_mapper.c:1091: attribute name = userCertificate
DEBUG:ldap_mapper.c:1094: number of user certificates = 0
DEBUG:ldap_mapper.c:1103: number of user names ('uid' values) = 1
DEBUG:ldap_mapper.c:1126: ldap_get_certificate(): end
DEBUG:ldap_mapper.c:1227: Found matching entry for user
DEBUG:pklogin_finder.c:151: Certificate is valid and maps to user kdcuser2
kdcuser2
DEBUG:mapper_mgr.c:214: unloading mapper module list
DEBUG:mapper_mgr.c:137: calling mapper_module_end() ldap
DEBUG:mapper_mgr.c:145: unloading module ldap
DEBUG:pklogin_finder.c:169: releasing pkcs #11 module...
DEBUG:pklogin_finder.c:172: Process completed

Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://rhn.redhat.com/errata/RHEA-2015-2415.html