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 1746543

Summary:

Certmonger fails to read token in HSM

Product:

Red Hat Enterprise Linux 8

Reporter:

Rob Crittenden <rcritten>

Component:

certmonger

Assignee:

Rob Crittenden <rcritten>

Status:

CLOSED ERRATA

QA Contact:

ipa-qe <ipa-qe>

Severity:

unspecified

Docs Contact:

Priority:

unspecified

Version:

8.0

CC:

cpatil, ksiddiqu, myusuf, nalin, pcech

Target Milestone:

Flags:

pm-rhel: mirror+

Target Release:

8.0

Hardware:

Unspecified

OS:

Unspecified

Whiteboard:

Fixed In Version:

certmonger-0.79.7-4

Doc Type:

If docs needed, set a value

Doc Text:

Story Points:

---

Clone Of:

Clones:

1746545 (view as bug list)

Environment:

Last Closed:

2020-04-28 16:01:49 UTC

Type:

---

Regression:

---

Mount Type:

---

Documentation:

---

CRM:

Verified Versions:

Category:

---

oVirt Team:

---

RHEL 7.3 requirements from Atomic Host:

Cloudforms Team:

---

Target Upstream Version:

Embargoed:

Bug Depends On:

Bug Blocks:

1746545

Attachments:

Description	Flags
console.log	none

Description Rob Crittenden 2019-08-28 18:01:28 UTC

This bug is created as a clone of upstream ticket:
https://pagure.io/certmonger/issue/125

I'm helping to add HSM support for FreeIPA.

I have disabled p11-kit https://pagure.io/freeipa/issue/7810
$ rm -f /etc/crypto-policies/local.d/nss-p11-kit.config && update-crypto-policies
$ reboot

Modified the FreeIPA python scripts so that internal (mostly dogtag) certificate is stored in HSM (I'm using SoftHSM for development)

$ modutil -dbdir /etc/pki/pki-tomcat/alias -list

Listing of PKCS 11 Modules

  1. NSS Internal PKCS 11 Module
	   uri: pkcs11:library-manufacturer=Mozilla%20Foundation;library-description=NSS%20Internal%20Crypto%20Services;library-version=3.44
	 slots: 2 slots attached
	status: loaded

	 slot: NSS Internal Cryptographic Services
	token: NSS Generic Crypto Services
	  uri: pkcs11:token=NSS%20Generic%20Crypto%20Services;manufacturer=Mozilla%20Foundation;serial=0000000000000000;model=NSS%203

	 slot: NSS User Private Key and Certificate Services
	token: NSS Certificate DB
	  uri: pkcs11:token=NSS%20Certificate%20DB;manufacturer=Mozilla%20Foundation;serial=0000000000000000;model=NSS%203

  2. softhsm
	library name: /usr/lib64/pkcs11/libsofthsm2.so
	   uri: pkcs11:library-manufacturer=SoftHSM;library-description=Implementation%20of%20PKCS11;library-version=2.5
	 slots: 2 slots attached
	status: loaded

	 slot: SoftHSM slot ID 0x1e204b1f
	token: Dogtag
	  uri: pkcs11:token=Dogtag;manufacturer=SoftHSM%20project;serial=2e2e45569e204b1f;model=SoftHSM%20v2

	 slot: SoftHSM slot ID 0x1
	token: 
	  uri: pkcs11:manufacturer=SoftHSM%20project;model=SoftHSM%20v2


$ certutil -L -d /etc/pki/pki-tomcat/alias -h all

Certificate Nickname                                         Trust Attributes
                                                             SSL,S/MIME,JAR/XPI

Enter Password or Pin for "Dogtag":
Server-Cert cert-pki-ca                                      u,u,u
auditSigningCert cert-pki-ca                                 u,u,Pu
caSigningCert cert-pki-ca                                    CTu,Cu,Cu
Dogtag:caSigningCert cert-pki-ca                             CTu,Cu,Cu
Dogtag:auditSigningCert cert-pki-ca                          u,u,Pu
Dogtag:ocspSigningCert cert-pki-ca                           u,u,u
Dogtag:subsystemCert cert-pki-ca                             u,u,u

$ certutil -K -d /etc/pki/pki-tomcat/alias -h all
certutil: Checking token "NSS Generic Crypto Services" in slot "NSS Internal Cryptographic Services"
certutil: no keys found
certutil: Checking token "NSS Certificate DB" in slot "NSS User Private Key and Certificate Services"
Enter Password or Pin for "NSS Certificate DB":
< 0> rsa      a6793d9d3d8333c7c0de32d8ed8fe974b109f137   NSS Certificate DB:Server-Cert cert-pki-ca
certutil: Checking token "Dogtag" in slot "SoftHSM slot ID 0x1e204b1f"
Enter Password or Pin for "Dogtag":
< 0> rsa      87f899a34660a00bc8db2df813200d80254bb8cd   ocspSigningCert cert-pki-ca
< 1> rsa      a15e8133b16a6a194225274283c95f90b2edfebf   auditSigningCert cert-pki-ca
< 2> rsa      d722c8de0c89b73fd7adbc9329ede583e7c5428a   caSigningCert cert-pki-ca
< 3> rsa      f9d9e20d507d236f762a4a4102bc6b55cc6fedb3   subsystemCert cert-pki-ca

But ran into problem that certmonger will not found above token 'Dogtag'

Stop dogtag, so that certmonger can get read/write lock on nss db
$ systemctl stop pki-tomcatd

Manually add certmonger tracking (which is the same that is done in freeipa python script)
$ getcert start-tracking -d /etc/pki/pki-tomcat/alias -n 'ocspSigningCert cert-pki-ca' -t 'Dogtag' -P redhat123 -r -c dogtag-ipa-ca-renew-agent -S -B /usr/libexec/ipa/certmonger/stop_pkicad -C "/usr/libexec/ipa/certmonger/renew_ca_cert 'ocspSigningCert cert-pki-ca'"

But the token 'Dogtag' is never found
$ journalctl -f -t certmonger
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Pending GetConnectionUnixUser serial 5804
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Pending GetConnectionUnixProcessID serial 5805
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Queuing FD 7 for Read for 0x5598c2efcd30:0x5598c2f1ed30.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Dequeuing FD 7 for Read for 0x5598c2efcd30:0x5598c2f1ed30.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Handling D-Bus traffic (Read) on FD 7 for 0x5598c2efcd30.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] message 0x5598c2efcd30(method_return)->5804->4294967295
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] message 0x5598c2efcd30(method_return)->5805->4294967295
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] User ID 0 PID 8390 called /org/fedorahosted/certmonger:org.fedorahosted.certmonger.add_request.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8391] Read value "0" from "/proc/sys/crypto/fips_enabled".
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8391] Not attempting to set NSS FIPS mode.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8391] Skipping NSS internal slot (NSS Generic Crypto Services).
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8391] Found token 'NSS Certificate DB'.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8391] Token is named "NSS Certificate DB", not "Dogtag", skipping.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8391] Error locating a key.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8392] Read value "0" from "/proc/sys/crypto/fips_enabled".
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8392] Not attempting to set NSS FIPS mode.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8392] Found token 'NSS Generic Crypto Services'.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8392] Token is named "NSS Generic Crypto Services", not "Dogtag", skipping.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8392] Found token 'NSS Certificate DB'.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8392] Token is named "NSS Certificate DB", not "Dogtag", skipping.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8392] Error locating certificate.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Request11('20190822103540') starts in state 'NEWLY_ADDED'
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Request11('20190822103540') taking writing lock
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Request11('20190822103540') moved to state 'NEWLY_ADDED_START_READING_KEYINFO'
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Will revisit Request11('20190822103540') now.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Started Request11('20190822103540').
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Queuing FD 7 for Read for 0x5598c2efcd30:0x5598c2f0a420.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Request11('20190822103540') moved to state 'NEWLY_ADDED_READING_KEYINFO'
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Will revisit Request11('20190822103540') on traffic from 11.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Dequeuing FD 7 for Read for 0x5598c2efcd30:0x5598c2f0a420.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Handling D-Bus traffic (Read) on FD 7 for 0x5598c2efcd30.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] message 0x5598c2efcd30(method_call)->org.fedorahosted.certmonger:/org/fedorahosted/certmonger/requests/Request11:org.fedorahosted.certmonger.request.get_nickname
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Pending GetConnectionUnixUser serial 5809
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Pending GetConnectionUnixProcessID serial 5810
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Queuing FD 7 for Read for 0x5598c2efcd30:0x5598c2f1bd90.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Dequeuing FD 7 for Read for 0x5598c2efcd30:0x5598c2f1bd90.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Handling D-Bus traffic (Read) on FD 7 for 0x5598c2efcd30.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] message 0x5598c2efcd30(method_return)->5809->4294967295
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] message 0x5598c2efcd30(method_return)->5810->4294967295
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] User ID 0 PID 8390 called /org/fedorahosted/certmonger/requests/Request11:org.fedorahosted.certmonger.request.get_nickname.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Queuing FD 7 for Read for 0x5598c2efcd30:0x5598c2f0a420.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8393] Read value "0" from "/proc/sys/crypto/fips_enabled".
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8393] Not attempting to set NSS FIPS mode.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8393] Skipping NSS internal slot (NSS Generic Crypto Services).
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8393] Found token 'NSS Certificate DB'.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8393] Token is named "NSS Certificate DB", not "Dogtag", skipping.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [8393] Error locating a key.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Request11('20190822103540') releasing writing lock
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Request11('20190822103540') moved to state 'NEWLY_ADDED_NEED_KEYINFO_READ_TOKEN'
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Will revisit Request11('20190822103540') now.
Aug 22 12:35:40 freeipa-fedora30-master-hsm.magnuskkarlsson.local certmonger[7909]: 2019-08-22 12:35:40 [7909] Waiting for instructions for Request11('20190822103540').

Comment 1 Rob Crittenden 2019-09-06 17:41:25 UTC

master:
34c120f0259750ff2228def2955de9ad985340e6
59df833ca5fb80c596df621a24dc461a550dba71

Comment 9 Rob Crittenden 2019-12-03 16:00:18 UTC

Clearing needinfo

Comment 10 Mohammad Rizwan 2020-01-22 10:38:13 UTC

Created attachment 1654519 [details]
console.log

Comment 11 Mohammad Rizwan 2020-01-22 10:40:12 UTC

version:
certmonger-0.79.7-6.el8.x86_64
ipa-server-4.8.4-2.module+el8.2.0+5265+c70de5c4.x86_64

Certificate added is in MONITORING state and tracked by certmonger. Hence based on the observation, marking the bug as verified.

Comment 13 errata-xmlrpc 2020-04-28 16:01:49 UTC

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://access.redhat.com/errata/RHBA-2020:1704