Bug 1875565

Summary: Add KRA Transport and Storage Certificates profiles for IPA
Product: Red Hat Enterprise Linux 8 Reporter: Asha Akkiangady <aakkiang>
Component: pki-coreAssignee: RHCS Maintainers <rhcs-maint>
Status: CLOSED DUPLICATE QA Contact: PKI QE <bugzilla-pkiqe>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 8.3Flags: pm-rhel: mirror+
Target Milestone: rc   
Target Release: 8.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2020-09-03 19:06:21 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 Asha Akkiangady 2020-09-03 19:03:39 UTC 
+++ This bug was initially created as a clone of Bug #1869605 +++

Description of problem:
My long-running FreeIPA public demo instance (upgraded to the newest Fedora from 2018) cannot update KRA certificates. They always end up with error "Server at "http://ipa.demo1.freeipa.org:8080/ca/ee/ca/profileSubmit" replied: Missing credential: sessionID"

# getcert list -i 20190903113316
Number of certificates and requests being tracked: 11.
Request ID '20190903113316':
	status: CA_UNREACHABLE
	ca-error: Internal error
	stuck: no
	key pair storage: type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='storageCert cert-pki-kra',token='NSS Certificate DB',pin set
	certificate: type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='storageCert cert-pki-kra',token='NSS Certificate DB'
	CA: dogtag-ipa-ca-renew-agent
	issuer: CN=Certificate Authority,O=DEMO1.FREEIPA.ORG
	subject: CN=KRA Storage Certificate,O=DEMO1.FREEIPA.ORG
	expires: 2020-08-19 10:35:41 UTC
	key usage: digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment
	eku: id-kp-clientAuth
	profile: caInternalAuthDRMstorageCert
	pre-save command: /usr/libexec/ipa/certmonger/stop_pkicad
	post-save command: /usr/libexec/ipa/certmonger/renew_ca_cert "storageCert cert-pki-kra"
	track: yes
	auto-renew: yes

# getcert resubmit -i 20190903113316


# getcert list -i 20190903113316
Number of certificates and requests being tracked: 11.
Request ID '20190903113316':
	status: MONITORING
	ca-error: Server at "http://ipa.demo1.freeipa.org:8080/ca/ee/ca/profileSubmit" replied: Missing credential: sessionID
	stuck: no
	key pair storage: type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='storageCert cert-pki-kra',token='NSS Certificate DB',pin set
	certificate: type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='storageCert cert-pki-kra',token='NSS Certificate DB'
	CA: dogtag-ipa-ca-renew-agent
	issuer: CN=Certificate Authority,O=DEMO1.FREEIPA.ORG
	subject: CN=KRA Storage Certificate,O=DEMO1.FREEIPA.ORG
	expires: 2020-08-19 10:35:41 UTC
	key usage: digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment
	eku: id-kp-clientAuth
	profile: caInternalAuthDRMstorageCert
	pre-save command: /usr/libexec/ipa/certmonger/stop_pkicad
	post-save command: /usr/libexec/ipa/certmonger/renew_ca_cert "storageCert cert-pki-kra"
	track: yes
	auto-renew: yes


Version-Release number of selected component (if applicable):
freeipa-server-4.8.7-1.fc32.x86_64
pki-ca-10.9.0-0.4.fc32.noarch
pki-kra-10.9.0-0.4.fc32.noarch
certmonger-0.79.11-2.fc32.x86_64

How reproducible:
Always

Steps to Reproduce:
1. Check the status of renewed certificates with "getcert list"
2. Move the date or wait 1 week before KRA Transport/Storage Certificate expires
3. See if the certificate renews

Actual results:
Certificate does not renew

Expected results:
Certificate renews

Additional info:
I assume that the root cause is somewhere in updates of the certmonger tracking list.

--- Additional comment from Martin Kosek on 2020-08-18 10:53:45 UTC ---

Starting with FreeIPA component first, as this problem may be specific to FreeIPA deployment or upgrade process, rather than pki-core component (feel free to change!)

--- Additional comment from Rob Crittenden on 2020-08-18 20:58:42 UTC ---

I don't believe this is an issue with certmonger, it seems to be correctly reporting back an error from the CA.

Indeed this ignores IPA altogether and renews directly against the CA using the RA cert for auth.

So you need to look in the CA debug log for more details.

The journal may include the output that certmonger received.

--- Additional comment from Martin Kosek on 2020-08-19 12:36:35 UTC ---

Good point. Let me include output from certmonger and related PKI error file.

# systemctl status certmonger.service -l
● certmonger.service - Certificate monitoring and PKI enrollment
     Loaded: loaded (/usr/lib/systemd/system/certmonger.service; enabled; vendor preset: disabled)
     Active: active (running) since Wed 2020-08-19 05:02:24 UTC; 7h ago
   Main PID: 807 (certmonger)
      Tasks: 2 (limit: 2335)
     Memory: 119.2M
        CPU: 25min 949ms
     CGroup: /system.slice/certmonger.service
             ├─  807 /usr/sbin/certmonger -S -p /run/certmonger.pid -n -d2
             └─11733 /usr/bin/python3 -I /usr/libexec/certmonger/dogtag-ipa-ca-renew-agent-submit

Aug 19 12:35:57 ipa.demo1.freeipa.org certmonger[11733]: Kh2TvPM0a8/8kr4WqVKH6GptBArjV/tRFRn1lr7xv1UkNoE6oy/ES2xDjrlzRTtp
Aug 19 12:35:57 ipa.demo1.freeipa.org certmonger[11733]: ZUQYCdrldOYWNrrKFtG5vq2jOd2tvYdwCcy33Rrszu0gc7EAH5qDiQ==
Aug 19 12:35:57 ipa.demo1.freeipa.org certmonger[11733]: -----END CERTIFICATE-----
Aug 19 12:35:57 ipa.demo1.freeipa.org certmonger[11733]: " for child.
Aug 19 12:35:57 ipa.demo1.freeipa.org certmonger[11733]: 2020-08-19 12:35:57 [11733] Redirecting stdin to /dev/null, leaving stdout and stderr open for child "/usr/libexec/certmonger/dogtag-ipa-ca-renew-agent-submit".
Aug 19 12:35:57 ipa.demo1.freeipa.org certmonger[11733]: 2020-08-19 12:35:57 [11733] Running enrollment helper "/usr/libexec/certmonger/dogtag-ipa-ca-renew-agent-submit".
Aug 19 12:35:59 ipa.demo1.freeipa.org /dogtag-ipa-ca-renew-agent-submit[11733]: Forwarding request to dogtag-ipa-renew-agent
Aug 19 12:35:59 ipa.demo1.freeipa.org dogtag-ipa-renew-agent-submit[11738]: usr/lib/api/apiutil.c Could not open /run/lock/opencryptoki/LCK..APIlock
Aug 19 12:35:59 ipa.demo1.freeipa.org /dogtag-ipa-ca-renew-agent-submit[11733]: dogtag-ipa-renew-agent returned 2
Aug 19 12:35:59 ipa.demo1.freeipa.org certmonger[807]: 2020-08-19 12:35:59 [807] Certificate submission still ongoing.

--- Additional comment from Martin Kosek on 2020-08-19 12:39:59 UTC ---

/var/log/pki/pki-tomcat/ca/debug.2020-07-14.log:

2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Property useThreadNaming not found
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting useThreadNaming=false
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CMSServlet:service() uri: /ca/ee/ca/profileSubmit
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CMSServlet::service() param name='profileId' value='caInternalAuthAuditSigningCert'
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CMSServlet::service() param name='cert_request_type' value='pkcs10'
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CMSServlet::service() param name='cert_request' value='(sensitive)'
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CMSServlet::service() param name='xml' value='true'
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CMSServlet::service() param name='requestor_name' value='IPA'
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CMSServlet: caProfileSubmit start to service.
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: GET r=http-request-params,k=authenticator,v=null,d=null
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: xmlOutput true
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: ProfileSubmitServlet: isRenewal false
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Property processor.caProfileSubmit.profileId not found
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting processor.caProfileSubmit.profileId=
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting processor.caProfileSubmit.authzResourceName=certServer.ee.profile
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting processor.caProfileSubmit.authzResourceName=certServer.ee.profile
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting processor.caProfileSubmit.authzResourceName=certServer.ee.profile
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Property processor.caProfileSubmit.authMgr not found
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting processor.caProfileSubmit.authMgr=
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting processor.caProfileSubmit.getClientCert=false
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting processor.caProfileSubmit.getClientCert=false
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting processor.caProfileSubmit.getClientCert=false
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Property processor.caProfileSubmit.profileSubId not found
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting processor.caProfileSubmit.profileSubId=
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Property processor.caProfileSubmit.ACLinfo not found
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting processor.caProfileSubmit.ACLinfo=
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting processor.caProfileSubmit.authzMgr=BasicAclAuthz
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting processor.caProfileSubmit.authzMgr=BasicAclAuthz
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting processor.caProfileSubmit.authzMgr=BasicAclAuthz
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting authz.sourceType=ldap
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting authz.sourceType=ldap
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: ServletUtils: according to ccMode, authorization for servlet: caProfileSubmit is LDAP based, not XML {1}, use default authz mgr: {2}.
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: ProfileSubmitServlet: profile: caInternalAuthAuditSigningCert
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: GET r=http-request-params,k=cert_request_type,v=pkcs10,d=null
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: GET r=http-request-params,k=cert_request,v=-----BEGIN NEW CERTIFICATE REQUEST-----
MIIDZTCCAk0CAQAwMDEaMBgGA1UECgwRREVNTzEuRlJFRUlQQS5PUkcxEjAQBgNV
BAMMCUtSQSBBdWRpdDCCASIwDQYJKoZIhvcNAQEBBQADggEPADCCAQoCggEBAM6E
Y4UA9vLK3jR4cekjbfYNYr8CFAliA/QxgPWRnqh6VfvZ3+Y3378csIuhEFefR89R
93oPt5OCqotEBHKCHkDqYKHeqvS+NKE5DicfEeOjRuR2sWYFXTVNn+1W6nNK0Y/l
PIYg/DeQ4UU08nlzNnYxFIu16bZ/UQcta00a2Wb119RdSQbTzptLJSRZt/WattNs
KzOzi0p18gDKPqRVVbV3VR77Yq6KnsIweTB9N7gaWNfPpU5YWBf4QTVEK43HBNF4
6s3X8zdYXh+Zn+FmLCSDEELaLbBCZVZ+lM7oYE7WxfvD3hmTSZYIOhOk37Rr+x1p
WwBS8BuK1a03cOITLDECAwEAAaCB7zBJBgkqhkiG9w0BCRQxPB46AGEAdQBkAGkA
dABTAGkAZwBuAGkAbgBnAEMAZQByAHQAIABjAGUAcgB0AC0AcABrAGkALQBrAHIA
YTCBoQYJKoZIhvcNAQkOMYGTMIGQMA4GA1UdDwEBAAQEAwIGwDAMBgNVHRMBAf8E
AjAAMCAGA1UdDgEBAAQWBBTBT9Znj0Ri1GOS4Vnb0ahgUDNeEzBOBgkrBgEEAYI3
FAIBAQAEPh48AGMAYQBJAG4AdABlAHIAbgBhAGwAQQB1AHQAaABBAHUAZABpAHQA
UwBpAGcAbgBpAG4AZwBDAGUAcgB0MA0GCSqGSIb3DQEBCwUAA4IBAQBgrQdFWBwl
V8lleevn+FYehajPZBvz4/Q+k+wW4pdy7r+GisQEJsW/9o9U4O9YUY/5AAnfraGw
Xx/sQImFO+DFXAFw2ePnIvgR8Gno5Cdj9PcmRHiMqO7vwcKuN2Q8iRqa32DgoalH
wFhkkDE/5V6u5nlD4E33HLuaCTnvTvAMJYM5GLshEyBxOwhRZAkZDzYz/cUR/sWi
7wyjxo4TWDRsKPX6QEl1q8RG+VUIzYdTry4MLjGxioF1FG4kO5UTRfuejJjzAnrr
ghW5Z3bAWupjjFrukTg14PIKuMPLy08T4gaWZHOuxuBztbPw1B0bcYaq9Wy5udTz
eqf3blQPb9KL
-----END NEW CERTIFICATE REQUEST-----
,d=null
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: GET r=http-request-params,k=requestor_name,v=IPA,d=null
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: GET r=http-request-params,k=requestor_email,v=null,d=null
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: GET r=http-request-params,k=requestor_phone,v=null,d=null
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CAProcessor: Input Parameters:
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CAProcessor: - isRenewal: false
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CAProcessor: - remoteHost: 127.0.0.1
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CAProcessor: - cert_request_type: pkcs10
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CAProcessor: - profileId: caInternalAuthAuditSigningCert
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CAProcessor: - cert_request: (sensitive)
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CAProcessor: - requestor_name: IPA
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CAProcessor: - remoteAddr: 127.0.0.1
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: EnrollmentProcessor: isRenewal false
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: EnrollmentProcessor: profileId caInternalAuthAuditSigningCert
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting enable=true
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting enable=true
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: EnrollmentProcessor: set Inputs into profile Context
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: EnrollmentProcessor: authenticator TokenAuth found
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CertProcessor: Authentication credentials:
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: EnrollmentProcessor: set sslClientCertProvider
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: authenticate: authentication required.
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CAProcessor: in auditSubjectID
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CAProcessor: auditSubjectID auditContext {sslClientCertProvider=com.netscape.cms.servlet.profile.SSLClientCertProvider@c1c7291, profileContext={cert_request_type=pkcs10, cert_request=-----BEGIN NEW CERTIFICATE REQUEST-----
MIIDZTCCAk0CAQAwMDEaMBgGA1UECgwRREVNTzEuRlJFRUlQQS5PUkcxEjAQBgNV
BAMMCUtSQSBBdWRpdDCCASIwDQYJKoZIhvcNAQEBBQADggEPADCCAQoCggEBAM6E
Y4UA9vLK3jR4cekjbfYNYr8CFAliA/QxgPWRnqh6VfvZ3+Y3378csIuhEFefR89R
93oPt5OCqotEBHKCHkDqYKHeqvS+NKE5DicfEeOjRuR2sWYFXTVNn+1W6nNK0Y/l
PIYg/DeQ4UU08nlzNnYxFIu16bZ/UQcta00a2Wb119RdSQbTzptLJSRZt/WattNs
KzOzi0p18gDKPqRVVbV3VR77Yq6KnsIweTB9N7gaWNfPpU5YWBf4QTVEK43HBNF4
6s3X8zdYXh+Zn+FmLCSDEELaLbBCZVZ+lM7oYE7WxfvD3hmTSZYIOhOk37Rr+x1p
WwBS8BuK1a03cOITLDECAwEAAaCB7zBJBgkqhkiG9w0BCRQxPB46AGEAdQBkAGkA
dABTAGkAZwBuAGkAbgBnAEMAZQByAHQAIABjAGUAcgB0AC0AcABrAGkALQBrAHIA
YTCBoQYJKoZIhvcNAQkOMYGTMIGQMA4GA1UdDwEBAAQEAwIGwDAMBgNVHRMBAf8E
AjAAMCAGA1UdDgEBAAQWBBTBT9Znj0Ri1GOS4Vnb0ahgUDNeEzBOBgkrBgEEAYI3
FAIBAQAEPh48AGMAYQBJAG4AdABlAHIAbgBhAGwAQQB1AHQAaABBAHUAZABpAHQA
UwBpAGcAbgBpAG4AZwBDAGUAcgB0MA0GCSqGSIb3DQEBCwUAA4IBAQBgrQdFWBwl
V8lleevn+FYehajPZBvz4/Q+k+wW4pdy7r+GisQEJsW/9o9U4O9YUY/5AAnfraGw
Xx/sQImFO+DFXAFw2ePnIvgR8Gno5Cdj9PcmRHiMqO7vwcKuN2Q8iRqa32DgoalH
wFhkkDE/5V6u5nlD4E33HLuaCTnvTvAMJYM5GLshEyBxOwhRZAkZDzYz/cUR/sWi
7wyjxo4TWDRsKPX6QEl1q8RG+VUIzYdTry4MLjGxioF1FG4kO5UTRfuejJjzAnrr
ghW5Z3bAWupjjFrukTg14PIKuMPLy08T4gaWZHOuxuBztbPw1B0bcYaq9Wy5udTz
eqf3blQPb9KL
-----END NEW CERTIFICATE REQUEST-----
, requestor_name=IPA}}
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CAProcessor auditSubjectID: subjectID: null
2020-08-19 12:35:50 [http-nio-8080-exec-23] SEVERE: CAProcessor: authentication error: Missing credential: sessionID
Missing credential: sessionID
	at com.netscape.cms.servlet.common.AuthCredentials.set(AuthCredentials.java:57)
	at com.netscape.cms.servlet.processors.CAProcessor.authenticate(CAProcessor.java:423)
	at com.netscape.cms.servlet.processors.CAProcessor.authenticate(CAProcessor.java:482)
	at com.netscape.cms.servlet.cert.EnrollmentProcessor.processEnrollment(EnrollmentProcessor.java:178)
	at com.netscape.cms.servlet.cert.EnrollmentProcessor.processEnrollment(EnrollmentProcessor.java:97)
	at com.netscape.cms.servlet.profile.ProfileSubmitServlet.processEnrollment(ProfileSubmitServlet.java:276)
	at com.netscape.cms.servlet.profile.ProfileSubmitServlet.process(ProfileSubmitServlet.java:130)
	at com.netscape.cms.servlet.base.CMSServlet.service(CMSServlet.java:494)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
	at sun.reflect.GeneratedMethodAccessor45.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:282)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:279)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAsPrivileged(Subject.java:549)
	at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:314)
	at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:170)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:225)
	at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:47)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:149)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:145)
	at java.security.AccessController.doPrivileged(Native Method)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
	at sun.reflect.GeneratedMethodAccessor44.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:282)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:279)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAsPrivileged(Subject.java:549)
	at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:314)
	at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:253)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:191)
	at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:47)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:149)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:145)
	at java.security.AccessController.doPrivileged(Native Method)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
	at com.netscape.cms.tomcat.ExternalAuthenticationValve.invoke(ExternalAuthenticationValve.java:82)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:690)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:373)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1590)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:748)

2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: SignedAuditLogger: event AUTH
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting pidDir=/var/run/pki/tomcat
2020-08-19 12:35:50 [http-nio-8080-exec-23] FINEST: Getting pidDir=/var/run/pki/tomcat
2020-08-19 12:35:50 [http-nio-8080-exec-23] SEVERE: ProfileSubmitServlet: authentication error in processing request: Missing credential: sessionID
Missing credential: sessionID
	at com.netscape.cms.servlet.common.AuthCredentials.set(AuthCredentials.java:57)
	at com.netscape.cms.servlet.processors.CAProcessor.authenticate(CAProcessor.java:423)
	at com.netscape.cms.servlet.processors.CAProcessor.authenticate(CAProcessor.java:482)
	at com.netscape.cms.servlet.cert.EnrollmentProcessor.processEnrollment(EnrollmentProcessor.java:178)
	at com.netscape.cms.servlet.cert.EnrollmentProcessor.processEnrollment(EnrollmentProcessor.java:97)
	at com.netscape.cms.servlet.profile.ProfileSubmitServlet.processEnrollment(ProfileSubmitServlet.java:276)
	at com.netscape.cms.servlet.profile.ProfileSubmitServlet.process(ProfileSubmitServlet.java:130)
	at com.netscape.cms.servlet.base.CMSServlet.service(CMSServlet.java:494)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:741)
	at sun.reflect.GeneratedMethodAccessor45.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:282)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:279)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAsPrivileged(Subject.java:549)
	at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:314)
	at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:170)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:225)
	at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:47)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:149)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:145)
	at java.security.AccessController.doPrivileged(Native Method)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
	at sun.reflect.GeneratedMethodAccessor44.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:282)
	at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:279)
	at java.security.AccessController.doPrivileged(Native Method)
	at javax.security.auth.Subject.doAsPrivileged(Subject.java:549)
	at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:314)
	at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:253)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:191)
	at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:47)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:149)
	at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:145)
	at java.security.AccessController.doPrivileged(Native Method)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:144)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:96)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541)
	at com.netscape.cms.tomcat.ExternalAuthenticationValve.invoke(ExternalAuthenticationValve.java:82)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:139)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:690)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:74)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:343)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:373)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:868)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1590)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.lang.Thread.run(Thread.java:748)

2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: CMSServlet: curDate: Wed Aug 19 12:35:50 UTC 2020 id: caProfileSubmit time: 21

--- Additional comment from Rob Crittenden on 2020-08-20 11:58:09 UTC ---

I have no idea what session ID this is referring to and what is responsible for setting it. Need some assistance from the pki team on this.

--- Additional comment from Alex Scheel on 2020-08-20 15:29:49 UTC ---

Rob, note the profile used above:

2020-08-19 12:35:50 [http-nio-8080-exec-23] FINE: EnrollmentProcessor: profileId caInternalAuthAuditSigningCert

This profile (internalAuthAuditSigningCert) requires token authentication (passed as "sessionID"). This is only used during installation. 


However, above, in mkosek's request, we see:

	profile: caInternalAuthDRMstorageCert

So something is not correctly passing or handling the profile. It isn't obvious to me how or why or what changed, so I'll needinfo jmagne and cfu to see if they can assist.

--- Additional comment from Christina Fu on 2020-08-24 17:50:21 UTC ---

As Alex pointed out, those caInternalXXX enrollment profiles require "token authentication", where tokens are per "session" during installation.  They are only meant to be used for installation, unless of course someone has changed the "auth.instance_id" in those profiles to something else.  And that I would not recommend.  It's best if you create new profiles specific to your need.

Seeing that you seem to want to do "renewal", did you really intend to use those caInternalXXX profiles?  Has it always been the case for FreeIPA to renew using those profiles?  If so, then I suspect someone must have changed the auth.instance_id values for those profiles.

If you want to use RA cert to authenticate, the auth.instance_id value in the profile should be "AgentCertAuth".
Hope this helps.

--- Additional comment from Alex Scheel on 2020-08-24 21:37:10 UTC ---

To clarify, this is a bug in FreeIPA.


These profiles are for subsystem installation only. If you require similar profiles with agent auth, please ask. Until then, this commit should probably be reverted, as it will not work.

https://github.com/freeipa/freeipa/commit/3c388f5a228b767dfd92bd824dfced166acda143
https://github.com/freeipa/freeipa/blob/master/ipaserver/install/krainstance.py#L72

--- Additional comment from Christina Fu on 2020-08-24 22:01:21 UTC ---

So, I think the proper KRA profiles to use would be caStorageCert.cfg and caTransportCert.cfg.  However, the out of box authentication method used is manual agent approval for those.

If you wish to use RA cert to authenticate, copy each profile to something like ipaKRAStorageCert and ipaKRATransportCert, change the authentication id to the following:
auth.instance_id=AgentCertAuth

Anyways, there's a bit more details than that to create customized profiles.  Is this what you guys need from us?

--- Additional comment from Alexander Bokovoy on 2020-08-25 09:49:37 UTC ---

Yes, more details would be good to have.

My guess is that we need:

1. Create new profiles, as outlined by Christina in comment #9.

2. Add the profiles to LDAP store during upgrade or install

3. Add use of KRA profiles to a specific CA ACL so that IPA replica host can request one

4. Make sure to use the profiles when issuing KRA certificate

5. Convert existing KRA certificate's request in certmonger to use new profile

Most of these steps are on IPA side.

--- Additional comment from Martin Kosek on 2020-08-26 07:10:00 UTC ---

Thanks for the quick analysis. I think you are getting somewhere.
Please let me know if you need to get an access to the FreeIPA demo machine, I can easily provide it. But I assume this is a general problem, since I was not doing lot of special configuration to the FreeIPA demo, I just keep it up-to-date.

--- Additional comment from Rob Crittenden on 2020-08-26 19:19:10 UTC ---

I think Alexander's proposal is the way to go. We can't revert the suggested commit as it does more than just define the KRA tracking profiles. We'll adjust it with the new names once the profiles are created.
Comment 1 Asha Akkiangady 2020-09-03 19:06:21 UTC 

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