`ipa-acme-manager --enable` command failed on master replica. On other replicas, the command completes successfully.
FreeIPA 4.11, RockyLinux 9.4
Output fragment from failed command:
``` ipaserver.masters: DEBUG: Discovery: available servers for service 'CA' are ipa01.example.com, ipa11.example.com, ipa02.example.com ipaserver.masters: DEBUG: Discovery: using ipa01.example.com for 'CA' service ipapython.dogtag: DEBUG: request POST https://ipa01.example.com:8443/acme/login ipapython.dogtag: DEBUG: request body '' ipapython.dogtag: DEBUG: response status 404 ipapython.dogtag: DEBUG: response headers Content-Type: text/html;charset=utf-8 Content-Language: en Content-Length: 765
ipapython.dogtag: DEBUG: response body (decoded): b'<!doctype html><html lang="en"><head><title>HTTP Status 404 \xe2\x80\x93 Not Found</title><style type="text/css">body {font-family:Tahoma,Arial,sans-serif;} h1, h2, h3, b {color:white;background-color:#525D76;} h1 {font-size:22px;} h2 {font-size:16px;} h3 {font-size:14px;} p {font-size:12px;} a {color:black;} .line {height:1px;background-color:#525D76;border:none;}</style></head><body><h1>HTTP Status 404 \xe2\x80\x93 Not Found</h1><hr class="line" /><p><b>Type</b> Status Report</p><p><b>Message</b> The requested resource [/acme/login] is not available</p><p><b>Description</b> The origin server did not find a current representation for the target resource or is not willing to disclose that one exists.</p><hr class="line" /><h3>Apache Tomcat/9.0.87</h3></body></html>' ipapython.admintool: DEBUG: File "/usr/lib/python3.9/site-packages/ipapython/admintool.py", line 180, in execute return_value = self.run() File "/usr/lib/python3.9/site-packages/ipaserver/install/ipa_acme_manage.py", line 403, in run with state as ca_api: File "/usr/lib/python3.9/site-packages/ipaserver/install/ipa_acme_manage.py", line 103, in __enter__ raise errors.RemoteRetrieveError(
ipapython.admintool: DEBUG: The ipa-acme-manage command failed, exception: RemoteRetrieveError: Failed to authenticate to CA REST API ipapython.admintool: ERROR: Failed to authenticate to CA REST API ipapython.admintool: ERROR: The ipa-acme-manage command failed. ```
How can I fix this problem?
Vadim Dobroskokin via FreeIPA-users wrote:
`ipa-acme-manager --enable` command failed on master replica. On other replicas, the command completes successfully.
FreeIPA 4.11, RockyLinux 9.4
Output fragment from failed command:
ipaserver.masters: DEBUG: Discovery: available servers for service 'CA' are ipa01.example.com, ipa11.example.com, ipa02.example.com ipaserver.masters: DEBUG: Discovery: using ipa01.example.com for 'CA' service ipapython.dogtag: DEBUG: request POST https://ipa01.example.com:8443/acme/login ipapython.dogtag: DEBUG: request body '' ipapython.dogtag: DEBUG: response status 404 ipapython.dogtag: DEBUG: response headers Content-Type: text/html;charset=utf-8 Content-Language: en Content-Length: 765 ipapython.dogtag: DEBUG: response body (decoded): b'<!doctype html><html lang="en"><head><title>HTTP Status 404 \xe2\x80\x93 Not Found</title><style type="text/css">body {font-family:Tahoma,Arial,sans-serif;} h1, h2, h3, b {color:white;background-color:#525D76;} h1 {font-size:22px;} h2 {font-size:16px;} h3 {font-size:14px;} p {font-size:12px;} a {color:black;} .line {height:1px;background-color:#525D76;border:none;}</style></head><body><h1>HTTP Status 404 \xe2\x80\x93 Not Found</h1><hr class="line" /><p><b>Type</b> Status Report</p><p><b>Message</b> The requested resource [/acme/login] is not available</p><p><b>Description</b> The origin server did not find a current representation for the target resource or is not willing to disclose that one exists.</p><hr class="line" /><h3>Apache Tomcat/9.0.87</h3></body></html>' ipapython.admintool: DEBUG: File "/usr/lib/python3.9/site-packages/ipapython/admintool.py", line 180, in execute return_value = self.run() File "/usr/lib/python3.9/site-packages/ipaserver/install/ipa_acme_manage.py", line 403, in run with state as ca_api: File "/usr/lib/python3.9/site-packages/ipaserver/install/ipa_acme_manage.py", line 103, in __enter__ raise errors.RemoteRetrieveError( ipapython.admintool: DEBUG: The ipa-acme-manage command failed, exception: RemoteRetrieveError: Failed to authenticate to CA REST API ipapython.admintool: ERROR: Failed to authenticate to CA REST API ipapython.admintool: ERROR: The ipa-acme-manage command failed.
How can I fix this problem?
We've had a few other reports of this but have never gotten to the bottom of it.
The root cause is that the CA doesn't appear to have acme deployed at all.
Do you have the directory /var/lib/pki/pki-tomcat/conf/acme ?
rob
Yes, the directory is in place.
``` $ sudo ls -lah /var/lib/pki/pki-tomcat/conf/acme total 24K drwxr-x---. 2 pkiuser pkiuser 109 Mar 16 2023 . drwxrwx---. 8 pkiuser pkiuser 4.0K May 13 12:38 .. -rw-------. 1 pkiuser pkiuser 157 Mar 16 2023 configsources.conf -rw-------. 1 pkiuser pkiuser 149 Mar 16 2023 database.conf -rw-------. 1 pkiuser pkiuser 389 Mar 16 2023 engine.conf -rw-------. 1 pkiuser pkiuser 242 Mar 16 2023 issuer.conf -rw-------. 1 pkiuser pkiuser 325 Mar 16 2023 realm.conf ```
Initially, when I deployed the first and second replicas, command `ipa-acme-manage enable` was executed successfully. But recently, when I executed `ipa-acme-manage status` on the first replica, I got an error "Failed to authenticate to CA REST API".
Vadim Dobroskokin via FreeIPA-users wrote:
Yes, the directory is in place.
$ sudo ls -lah /var/lib/pki/pki-tomcat/conf/acme total 24K drwxr-x---. 2 pkiuser pkiuser 109 Mar 16 2023 . drwxrwx---. 8 pkiuser pkiuser 4.0K May 13 12:38 .. -rw-------. 1 pkiuser pkiuser 157 Mar 16 2023 configsources.conf -rw-------. 1 pkiuser pkiuser 149 Mar 16 2023 database.conf -rw-------. 1 pkiuser pkiuser 389 Mar 16 2023 engine.conf -rw-------. 1 pkiuser pkiuser 242 Mar 16 2023 issuer.conf -rw-------. 1 pkiuser pkiuser 325 Mar 16 2023 realm.conf
Initially, when I deployed the first and second replicas, command `ipa-acme-manage enable` was executed successfully. But recently, when I executed `ipa-acme-manage status` on the first replica, I got an error "Failed to authenticate to CA REST API".
Do you have the acme deployment file /etc/pki/pki-tomcat/Catalina/localhost/acme.xml ? What are the contents?
rob
Yes, i have `/etc/pki/pki-tomcat/Catalina/localhost/acme.xml`
``` $ sudo cat /etc/pki/pki-tomcat/Catalina/localhost/acme.xml <!-- Copyright Red Hat, Inc.
SPDX-License-Identifier: GPL-2.0-or-later --> <Context docBase="/usr/share/pki/acme/webapps/acme" crossContext="true"> <Manager secureRandomProvider="Mozilla-JSS" secureRandomAlgorithm="pkcs11prng"/> <Valve className="com.netscape.cms.tomcat.ExternalAuthenticationValve"/> <Valve className="com.netscape.cms.tomcat.SSLAuthenticatorWithFallback" alwaysUseSession="true" secureRandomProvider="Mozilla-JSS" secureRandomAlgorithm="pkcs11prng"/> <Realm className="com.netscape.cms.tomcat.ProxyRealm"/> <Resources allowLinking="true"/> </Context> ```
vadim
Vadim Dobroskokin via FreeIPA-users wrote:
Yes, i have `/etc/pki/pki-tomcat/Catalina/localhost/acme.xml`
I've cc'd one of the PKI developers.
Perhaps next take a look at /var/log/pki/pki-tomcat/acme/debug.<date>.log for any errors during startup.
The final line should read "INFO: ACME engine started"
rob
Rob Crittenden wrote: The final line should read "INFO: ACME engine started"
Yes, this line is in the log ``` 2024-07-18 13:18:27 [main] INFO: Loading ACME monitors config from /var/lib/pki/pki-tomcat/conf/acme/configsources.conf 2024-07-18 13:18:27 [main] INFO: ACME service is DISABLED by configuration 2024-07-18 13:18:27 [main] INFO: ACME wildcard issuance is DISABLED by configuration 2024-07-18 13:18:27 [main] INFO: Loading ACME realm config from /var/lib/pki/pki-tomcat/conf/acme/realm.conf 2024-07-18 13:18:27 [main] INFO: Initializing ACME realm 2024-07-18 13:18:27 [main] INFO: Initializing LDAP realm 2024-07-18 13:18:27 [ACMEEngineConfigFileSource] INFO: ACMEEngineConfigSource: watching /etc/pki/pki-tomcat/acme/engine.conf 2024-07-18 13:18:27 [main] INFO: Loading LDAP realm config from /etc/pki/pki-tomcat/ca/CS.cfg 2024-07-18 13:18:27 [main] INFO: - users DN: ou=people,o=ipaca 2024-07-18 13:18:27 [main] INFO: - groups DN: ou=groups,o=ipaca 2024-07-18 13:18:27 [main] INFO: PKISocketFactory: Initializing PKISocketFactory 2024-07-18 13:18:27 [main] INFO: PKISocketFactory: Creating SSL socket for ipa01.example.com:636 2024-07-18 13:18:27 [main] INFO: ACME engine started 2024-07-18 13:18:27 [main] INFO: Initializing ACMEApplication 2024-07-18 13:23:27 [pool-3-thread-1] INFO: Running ACME maintenance ``` vadim
Vadim Dobroskokin via FreeIPA-users wrote:
Rob Crittenden wrote: The final line should read "INFO: ACME engine started"
Yes, this line is in the log
2024-07-18 13:18:27 [main] INFO: Loading ACME monitors config from /var/lib/pki/pki-tomcat/conf/acme/configsources.conf 2024-07-18 13:18:27 [main] INFO: ACME service is DISABLED by configuration 2024-07-18 13:18:27 [main] INFO: ACME wildcard issuance is DISABLED by configuration 2024-07-18 13:18:27 [main] INFO: Loading ACME realm config from /var/lib/pki/pki-tomcat/conf/acme/realm.conf 2024-07-18 13:18:27 [main] INFO: Initializing ACME realm 2024-07-18 13:18:27 [main] INFO: Initializing LDAP realm 2024-07-18 13:18:27 [ACMEEngineConfigFileSource] INFO: ACMEEngineConfigSource: watching /etc/pki/pki-tomcat/acme/engine.conf 2024-07-18 13:18:27 [main] INFO: Loading LDAP realm config from /etc/pki/pki-tomcat/ca/CS.cfg 2024-07-18 13:18:27 [main] INFO: - users DN: ou=people,o=ipaca 2024-07-18 13:18:27 [main] INFO: - groups DN: ou=groups,o=ipaca 2024-07-18 13:18:27 [main] INFO: PKISocketFactory: Initializing PKISocketFactory 2024-07-18 13:18:27 [main] INFO: PKISocketFactory: Creating SSL socket for ipa01.example.com:636 2024-07-18 13:18:27 [main] INFO: ACME engine started 2024-07-18 13:18:27 [main] INFO: Initializing ACMEApplication 2024-07-18 13:23:27 [pool-3-thread-1] INFO: Running ACME maintenance
vadim
That's pretty similar to my working system.
Endi, what do you think we should try next?
rob
On Mon, Jul 22, 2024 at 10:24:15AM -0400, Rob Crittenden via FreeIPA-users wrote:
Endi, what do you think we should try next?
I hit this problem, too, and I'd like to help with debugging.
Up-to-date FreeIPA on Fedora 40 (freeipa-server-4.12.1-1.fc40.x86_64, dogtag-pki-acme-11.5.0-3.fc40.noarch), logs show ACME is started, but "GET /acme/directory HTTP/1.1" and "POST /acme/login HTTP/1.1" return 404.
Hi,
On Mon, Jul 22, 2024 at 4:33 PM Rob Crittenden via FreeIPA-users < freeipa-users@lists.fedorahosted.org> wrote:
Vadim Dobroskokin via FreeIPA-users wrote:
Rob Crittenden wrote: The final line should read "INFO: ACME engine started"
Yes, this line is in the log
2024-07-18 13:18:27 [main] INFO: Loading ACME monitors config from
/var/lib/pki/pki-tomcat/conf/acme/configsources.conf
2024-07-18 13:18:27 [main] INFO: ACME service is DISABLED by
configuration
2024-07-18 13:18:27 [main] INFO: ACME wildcard issuance is DISABLED by
configuration
2024-07-18 13:18:27 [main] INFO: Loading ACME realm config from
/var/lib/pki/pki-tomcat/conf/acme/realm.conf
2024-07-18 13:18:27 [main] INFO: Initializing ACME realm
2024-07-18 13:18:27 [main] INFO: Initializing LDAP realm
2024-07-18 13:18:27 [ACMEEngineConfigFileSource] INFO:
ACMEEngineConfigSource: watching /etc/pki/pki-tomcat/acme/engine.conf
2024-07-18 13:18:27 [main] INFO: Loading LDAP realm config from
/etc/pki/pki-tomcat/ca/CS.cfg
2024-07-18 13:18:27 [main] INFO: - users DN: ou=people,o=ipaca
2024-07-18 13:18:27 [main] INFO: - groups DN: ou=groups,o=ipaca
2024-07-18 13:18:27 [main] INFO: PKISocketFactory: Initializing
PKISocketFactory
2024-07-18 13:18:27 [main] INFO: PKISocketFactory: Creating SSL socket
for ipa01.example.com:636
2024-07-18 13:18:27 [main] INFO: ACME engine started
2024-07-18 13:18:27 [main] INFO: Initializing ACMEApplication
2024-07-18 13:23:27 [pool-3-thread-1] INFO: Running ACME maintenance
vadim
That's pretty similar to my working system.
Endi, what do you think we should try next?
I a previous email there was mention of the following error message: ipapython.admintool: ERROR: Failed to authenticate to CA REST API
Can you check if the issue is indeed related to an authentication issue? curl -v --cert /var/lib/ipa/ra-agent.pem --key /var/lib/ipa/ra-agent.key https://%60hostname%60:8443/acme/login
If this command fails, it may be related to an expired ra-agent.pem certificate. Check its expiration status with getcert list -f /var/lib/ipa/ra-agent.pem (it should show as MONITORING and should have an expiration date in the future).
flo
rob
-- _______________________________________________ FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org To unsubscribe send an email to freeipa-users-leave@lists.fedorahosted.org Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/ List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines List Archives: https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahoste... Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue
the certificate is ok:
``` $ sudo curl -v --cert /var/lib/ipa/ra-agent.pem --key /var/lib/ipa/ra-agent.key https://ipa01.example.com:8443/acme/login .... .... * SSL connection using TLSv1.3 / TLS_AES_128_GCM_SHA256 * ALPN, server did not agree to a protocol * Server certificate: * subject: O=EXAMPLE; CN=ipa01.example.com * start date: Mar 16 08:01:12 2023 GMT * expire date: Mar 5 08:01:12 2025 GMT * subjectAltName: host "ipa01.example.com" matched cert's "ipa01.example.com" * issuer: O=EXAMPLE; CN=IPACA01 * SSL certificate verify ok. * TLSv1.2 (OUT), TLS header, Unknown (23):
GET /acme/login HTTP/1.1 Host: ipa01.example.com:8443 User-Agent: curl/7.76.1 Accept: */*
* TLSv1.2 (IN), TLS header, Unknown (23): * Mark bundle as not supporting multiuse < HTTP/1.1 404 < Content-Type: text/html;charset=utf-8 < Content-Language: en < Content-Length: 765 < Date: Fri, 02 Aug 2024 19:29:55 GMT < * Connection #0 to host ipa01.example.com left intact <!doctype html><html lang="en"><head><title>HTTP Status 404 – Not Found</title><style type="text/css">body {font-family:Tahoma,Arial,sans-serif;} h1, h2, h3, b {color:white;background-color:#525D76;} h1 {font-size:22px;} h2 {font-size:16px;} h3 {font-size:14px;} p {font-size:12px;} a {color:black;} .line {height:1px;background-color:#525D76;border:none;}</style></head><body><h1>HTTP Status 404 – Not Found</h1><hr class="line" /><p><b>Type</b> Status Report</p><p><b>Message</b> The requested resource [/acme/login] is not available</p><p><b>Description</b> The origin server did not find a current representation for the target resource or is not willing to disclose that one exists.</p><hr class="line" /><h3>Apache Tomcat/9.0.87</h3></body></html>
$ sudo getcert list -f /var/lib/ipa/ra-agent.pem Number of certificates and requests being tracked: 12. Request ID '20230316080240': status: MONITORING stuck: no key pair storage: type=FILE,location='/var/lib/ipa/ra-agent.key' certificate: type=FILE,location='/var/lib/ipa/ra-agent.pem' CA: dogtag-ipa-ca-renew-agent issuer: CN=IPACA01,O=AEXAMPLE subject: CN=IPA RA,O=EXAMPLE issued: 2023-03-16 11:02:42 MSK expires: 2025-03-05 11:02:42 MSK key usage: digitalSignature,keyEncipherment,dataEncipherment eku: id-kp-clientAuth profile: caSubsystemCert pre-save command: /usr/libexec/ipa/certmonger/renew_ra_cert_pre post-save command: /usr/libexec/ipa/certmonger/renew_ra_cert track: yes auto-renew: yes ```
On Fri, Aug 02, 2024 at 07:51:38PM -0000, Vadim Dobroskokin via FreeIPA-users wrote:
It seems we are hitting this bug: Bug 2277151 - ipa-acme-manage fails after upgrade from Fedora 39 to 40 https://bugzilla.redhat.com/show_bug.cgi?id=2277151
Unfortunately no resolution was given in the bug (except to reinstall) and the comments went sideways about some KRA issue.
freeipa-users@lists.fedorahosted.org