On Fri, 16 Jun 2023 10:36:02 -0400 Rob Crittenden <[email protected]> wrote:
> Jernej Jakob via FreeIPA-users wrote: > > Hi, I have a client whose host certificate expired on 2023-06-07. > > Today I logged into the FreeIPA webui and went to the certificates page > > which was very slow to load. I had this problem before when there was > > one host (a different one) stuck in a certificate request loop, so I > > immediately suspected the same thing happened again. Sure enough, there > > are >3000 certificates for this host listed in IPA. > > Running 'getcert list' on the host shows: > > > > Number of certificates and requests being tracked: 1. > > Request ID '20190703221417': > > status: SUBMITTING > > stuck: no > > key pair storage: > > type=NSSDB,location='/etc/ipa/nssdb',nickname='Local IPA host',token='NSS > > Certificate DB',pinfile='/etc/ipa/nssdb/pwdfile.txt' > > certificate: type=NSSDB,location='/etc/ipa/nssdb',nickname='Local > > IPA host',token='NSS Certificate DB' > > CA: IPA > > issuer: CN=Certificate Authority,O=EXAMPLE.COM > > subject: CN=redacted.example.com,O=EXAMPLE.com > > expires: 2023-06-07 00:14:30 CEST > > dns: redacted.example.com > > principal name: host/[email protected] > > key usage: > > digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment > > eku: id-kp-serverAuth,id-kp-clientAuth > > pre-save command: > > post-save command: > > track: yes > > auto-renew: yes > > > > I stopped certmonger to stop the loop. Then checked if the problem was > > the same as on that other host some time ago, but it was not. > > I saw one error in syslog (this turned out to not be the issue): > > > > "Server at https://ipa1.example.com/ipa/xml failed request, will retry: > > -504 (libcurl failed to execute the HTTP POST transaction, explaining: > > Could not resolve host: ipa1.example.com)." > > > > That is a server that has been shut down. It was the first server I > > installed IPA onto, which had a replica ipa2. That was on CentOS 7. > > This year I migrated to Rocky 8 by adding two new clients, ipa3 and > > ipa4, following the official procedure by promoting each client to a > > replica, set ipa3 as CA renewal master, and so on. Then after that was > > done I removed the old servers from replication, shut down IPA services, > > unenrolled them and updated all SRV records in DNS. I forgot about > > A/AAAA ipa-ca, which was left pointing at two addresses, that of ipa1 > > and ipa3. > > > > It's weird becase it can obviously contact and obtain a certificate > > from ipa3, whose logs contain these successful issuances. It could > > contact it on 2023-06-07, when the ipa-ca record was still pointing to > > both the ipa1 and ipa3 servers. > > On 2023-06-09 I dist-upgraded both ipa3/4 servers, at which time I also > > found the incorrect ipa-ca A/AAAA records (coincidentally as I was > > configuring a smart card CA certificate), so I corrected it. But the > > failing certmonger client still kept failing which makes me believe > > it was not the fault of the incorrect ipa-ca records. > > > > I searched around on the "redacted.example.com" for ipa1. It's not in > > /var/lib/certmonger/requests/20190703221417 (the failing request) > > but it is in /etc/ipa/default.conf: > > > > server = ipa1.example.com > > xmlrpc_uri = https://ipa1.example.com/ipa/xml > > > > I changed these values to ipa3 now, started certmonger and resubmitted > > the request. Unfortunately no change. That libcurl error for ipa1 is > > gone now: > > > > Jun 16 15:28:01 redacted certmonger[2091940]: 2023-06-16 15:28:01 [2091940] > > Token is named "NSS Generic Crypto Services", not "NSS Certificate DB", > > skipping. > > Jun 16 15:28:01 redacted certmonger[2091940]: 2023-06-16 15:28:01 [2091940] > > Unable to initialize NSS. > > Jun 16 15:28:01 redacted certmonger[2091941]: 2023-06-16 15:28:01 [2091941] > > Setting "CERTMONGER_REQ_SUBJECT" to "CN=redacted.example.com,O=EXAMPLE.COM" > > for child. > > Jun 16 15:28:01 redacted certmonger[2091941]: 2023-06-16 15:28:01 [2091941] > > Setting "CERTMONGER_REQ_PRINCIPAL" to > > "host/[email protected]" for child. > > Jun 16 15:28:01 redacted certmonger[2091941]: 2023-06-16 15:28:01 [2091941] > > Setting "CERTMONGER_OPERATION" to "SUBMIT" for child. > > Jun 16 15:28:01 redacted certmonger[2091941]: 2023-06-16 15:28:01 [2091941] > > Setting "CERTMONGER_CSR" to "-----BEGIN NEW CERTIFICATE REQUEST----- > > Jun 16 15:28:01 redacted certmonger[2091941]: ...redacted..." for child. > > Jun 16 15:28:01 redacted certmonger[2091941]: 2023-06-16 15:28:01 [2091941] > > Setting "CERTMONGER_SPKAC" to ...redacted... > > Jun 16 15:28:01 redacted certmonger[2091941]: 2023-06-16 15:28:01 [2091941] > > Setting "CERTMONGER_SPKI" to ...redacted... > > Jun 16 15:28:01 redacted certmonger[2091941]: 2023-06-16 15:28:01 [2091941] > > Setting "CERTMONGER_LOCAL_CA_DIR" to "/var/lib/certmonger/local" for child. > > Jun 16 15:28:01 redacted certmonger[2091941]: 2023-06-16 15:28:01 [2091941] > > Setting "CERTMONGER_KEY_TYPE" to "RSA" for child. > > Jun 16 15:28:01 redacted certmonger[2091941]: 2023-06-16 15:28:01 [2091941] > > Setting "CERTMONGER_CA_NICKNAME" to "IPA" for child. > > Jun 16 15:28:01 redacted certmonger[2091941]: 2023-06-16 15:28:01 [2091941] > > Setting "CERTMONGER_CERTIFICATE" to "-----BEGIN CERTIFICATE----- > > Jun 16 15:28:01 redacted certmonger[2091941]: ...redacted..." for child. > > Jun 16 15:28:01 redacted certmonger[2091941]: 2023-06-16 15:28:01 [2091941] > > Redirecting stdin and stderr to /dev/null, leaving stdout open for child > > "/usr/lib/certmonger/ipa-submit". > > > > At this point it just keeps repeating the same over and over again. > > > > I would appreciate any help. Thanks. > > What version of {free}ipa-server and certmonger? Servers: ipa-server.x86_64 4.9.11-5.module+el8.8.0+1277+af9ff11b @appstream Client: Ubuntu 20.04 LTS freeipa-client 4.8.6-1ubuntu2 sssd-ipa 2.2.3-3ubuntu0.9 certmonger 0.79.9-2 > > The initial looping on this client was just certmonger trying to submit > to an old host, is that correct? I don't think so, the failures to resolve the offline server ipa1 were always followed by successful issuance, for example: Jun 9 00:03:42 redacted certmonger[899]: 2023-06-09 00:03:42 [899] Certificate submission still ongoing. Jun 9 00:03:42 redacted certmonger[899]: 2023-06-09 00:03:42 [899] Certificate submission attempt complete. Jun 9 00:03:42 redacted certmonger[899]: 2023-06-09 00:03:42 [899] Child status = 0. Jun 9 00:03:42 redacted certmonger[899]: 2023-06-09 00:03:42 [899] Child output: Jun 9 00:03:42 redacted certmonger[899]: "Server at https://ipa1.example.com/ipa/xml failed request, will retry: -504 (libcurl failed to execute the HTTP POST transaction, explaining: Could not resolve host: ipa1.example.com). Jun 9 00:03:42 redacted certmonger[899]: -----BEGIN CERTIFICATE----- Jun 9 00:03:42 redacted certmonger[899]: redacted Jun 9 00:03:42 redacted certmonger[899]: -----END CERTIFICATE----- Jun 9 00:03:42 redacted certmonger[899]: " Jun 9 00:03:42 redacted certmonger[1572205]: 2023-06-09 00:03:42 [1572205] Postprocessing output "Server at https://ipa1.example.com/ipa/xml failed request, will retry: -504 (libcurl failed to execute the HTTP POST transaction, explaining: Could not resolve host: ipa1.example.com). Jun 9 00:03:42 redacted certmonger[1572205]: -----BEGIN CERTIFICATE----- Jun 9 00:03:42 redacted certmonger[899]: redacted Jun 9 00:03:42 redacted certmonger[1572205]: -----END CERTIFICATE----- Jun 9 00:03:42 redacted certmonger[1572205]: ". Jun 9 00:03:42 redacted certmonger[899]: 2023-06-09 00:03:42 [899] Certificate submission still ongoing. Jun 9 00:03:42 redacted certmonger[899]: 2023-06-09 00:03:42 [899] Certificate submission postprocessing complete. Jun 9 00:03:42 redacted certmonger[899]: 2023-06-09 00:03:42 [899] Child status = 0. Jun 9 00:03:42 redacted certmonger[899]: 2023-06-09 00:03:42 [899] Child output: Jun 9 00:03:42 redacted certmonger[899]: "{"certificate":"-----BEGIN CERTIFICATE-----\nredacted \n-----END CERTIFICATE-----\n","key_checked":true} Jun 9 00:03:42 redacted certmonger[899]: " Jun 9 00:03:42 redacted certmonger[899]: 2023-06-09 00:03:42 [899] Issued certificate is "-----BEGIN CERTIFICATE----- Jun 9 00:03:42 redacted certmonger[899]: redacted Jun 9 00:03:42 redacted certmonger[899]: -----END CERTIFICATE----- Jun 9 00:03:42 redacted certmonger[899]: ". Jun 9 00:03:42 redacted certmonger[899]: 2023-06-09 00:03:42 [899] Certificate issued (0 chain certificates, 0 roots). Jun 9 00:03:42 redacted certmonger[899]: 2023-06-09 00:03:42 [899] No hooks set for pre-save command. Jun 9 00:03:42 redacted certmonger[1572206]: 2023-06-09 00:03:42 [1572206] Token is named "NSS Generic Crypto Services", not "NSS Certificate DB", skipping. Jun 9 00:03:42 redacted certmonger[1572206]: 2023-06-09 00:03:42 [1572206] Imported certificate with nickname "Local IPA host". Jun 9 00:03:42 redacted certmonger[1572206]: 2023-06-09 00:03:42 [1572206] Error shutting down NSS. Jun 9 00:03:42 redacted certmonger[1572208]: 2023-06-09 00:03:42 [1572208] Token is named "NSS Generic Crypto Services", not "NSS Certificate DB", skipping. Jun 9 00:03:42 redacted certmonger[1572208]: 2023-06-09 00:03:42 [1572208] Unable to initialize NSS. Jun 9 00:03:42 redacted certmonger[899]: 2023-06-09 00:03:42 [899] No hooks set for post-save command. Jun 9 00:03:42 redacted certmonger: Certificate named "Local IPA host" in token "NSS Certificate DB" in database "/etc/ipa/nssdb" issued by CA and saved. Jun 9 00:03:47 redacted certmonger: Certificate named "Local IPA host" in token "NSS Certificate DB" in database "/etc/ipa/nssdb" is no longer valid. Jun 9 00:03:47 redacted certmonger[1572213]: 2023-06-09 00:03:47 [1572213] Setting "CERTMONGER_REQ_SUBJECT" to "CN=redacted.example.com,O=EXAMPLE.COM" for child. Jun 9 00:03:47 redacted certmonger[1572213]: 2023-06-09 00:03:47 [1572213] Setting "CERTMONGER_REQ_PRINCIPAL" to "host/[email protected]" for child. Jun 9 00:03:47 redacted certmonger[1572213]: 2023-06-09 00:03:47 [1572213] Setting "CERTMONGER_OPERATION" to "SUBMIT" for child. Jun 9 00:03:47 redacted certmonger[1572213]: 2023-06-09 00:03:47 [1572213] Setting "CERTMONGER_CSR" to "-----BEGIN NEW CERTIFICATE REQUEST----- Jun 9 00:03:47 redacted certmonger[1572213]: redacted Jun 9 00:03:47 redacted certmonger[1572213]: -----END NEW CERTIFICATE REQUEST----- Jun 9 00:03:47 redacted certmonger[1572213]: " for child. Jun 9 00:03:47 redacted certmonger[1572213]: 2023-06-09 00:03:47 [1572213] Setting "CERTMONGER_SPKAC" to "redacted" for child. Jun 9 00:03:47 redacted certmonger[1572213]: 2023-06-09 00:03:47 [1572213] Setting "CERTMONGER_SPKI" to "redacted" for child. Jun 9 00:03:47 redacted certmonger[1572213]: 2023-06-09 00:03:47 [1572213] Setting "CERTMONGER_LOCAL_CA_DIR" to "/var/lib/certmonger/local" for child. Jun 9 00:03:47 redacted certmonger[1572213]: 2023-06-09 00:03:47 [1572213] Setting "CERTMONGER_KEY_TYPE" to "RSA" for child. Jun 9 00:03:47 redacted certmonger[1572213]: 2023-06-09 00:03:47 [1572213] Setting "CERTMONGER_CA_NICKNAME" to "IPA" for child. Jun 9 00:03:47 redacted certmonger[1572213]: 2023-06-09 00:03:47 [1572213] Setting "CERTMONGER_CERTIFICATE" to "-----BEGIN CERTIFICATE----- Jun 9 00:03:47 redacted certmonger[1572213]: redacted Jun 9 00:03:47 redacted certmonger[1572213]: -----END CERTIFICATE----- Jun 9 00:03:47 redacted certmonger[1572213]: " for child. Jun 9 00:03:47 redacted certmonger[1572213]: 2023-06-09 00:03:47 [1572213] Redirecting stdin and stderr to /dev/null, leaving stdout open for child "/usr/lib/certmonger/ipa-submit". Jun 9 00:07:25 redacted certmonger[899]: 2023-06-09 00:07:25 [899] Certificate submission still ongoing. Jun 9 00:07:25 redacted certmonger[899]: 2023-06-09 00:07:25 [899] Certificate submission attempt complete. Jun 9 00:07:25 redacted certmonger[899]: 2023-06-09 00:07:25 [899] Child status = 0. Jun 9 00:07:25 redacted certmonger[899]: 2023-06-09 00:07:25 [899] Child output: Jun 9 00:07:25 redacted certmonger[899]: "Server at https://ipa1.example.com/ipa/xml failed request, will retry: -504 (libcurl failed to execute the HTTP POST transaction, explaining: Could not resolve host: ipa1.example.com). Jun 9 00:07:25 redacted certmonger[899]: -----BEGIN CERTIFICATE----- Jun 9 00:07:25 redacted certmonger[899]: redacted Jun 9 00:07:25 redacted certmonger[899]: -----END CERTIFICATE----- Jun 9 00:07:25 redacted certmonger[899]: " Jun 9 00:07:25 redacted certmonger[1572493]: 2023-06-09 00:07:25 [1572493] Postprocessing output "Server at https://ipa1.example.com/ipa/xml failed request, will retry: -504 (libcurl failed to execute the HTTP POST transaction, explaining: Could not resolve host: ipa1.example.com). the parts that I redacted are the certificates, and they are always different, so it's not just repeating the one it already has. > > The new looping is actually generating a new certificate but not > installing it? It seems so. > > Does this client use its host certificate in some way? No, I haven't used it for any service, unless FreeIPA used it for one of its services, I don't know. > > What are the contents of /etc/sysconfig/certmonger? If it is not not > OPTS=-d2 I'd recommend updating/creating this file with those options > and restart certmonger. This is Ubuntu so there is no /etc/sysconfig. /etc/certmonger/certmonger.conf only has comments. /etc/default/certmonger has "OPTS=-d2". > > I think I'll need to see more context from the journal to see what is > going on. If the logs above from the client's journal are not enough, I can take a bigger chunk out of the server's pki-tomcat/ca debug log, but those are quite large. > > rob >
pgp6pJ7BMPU74.pgp
Description: OpenPGP digital signature
_______________________________________________ FreeIPA-users mailing list -- [email protected] To unsubscribe send an email to [email protected] 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/[email protected] Do not reply to spam, report it: https://pagure.io/fedora-infrastructure/new_issue
