The solution in this thread was to copy
/var/lib/ipa/ra-agent.* to the failing system.
After that I was able to restart (ipactl restart).
What remains a mystery is **why** this happened.
In my case, we have three CA masters, one is the CA renewal
master (of course).
Two days ago, linge, the renewal master, renewed a few
certificates. Here is a summary
of journalctl.
[root@linge ~]# journalctl | grep -E 'certmonger|dogtag'
sep 29 13:39:00 linge.ghs.nl certmonger[16288]: Certificate
in file "/var/lib/ipa/ra-agent.pem" will not be valid after
20201026201548.
sep 29 13:39:00 linge.ghs.nl certmonger[16289]: Certificate
named "auditSigningCert cert-pki-ca" in token "NSS
Certificate DB" in database "/etc/pki/pki-tomcat/alias" will
not be valid after 20201026201532.
sep 29 13:39:00 linge.ghs.nl certmonger[16290]: Certificate
named "ocspSigningCert cert-pki-ca" in token "NSS
Certificate DB" in database "/etc/pki/pki-tomcat/alias" will
not be valid after 20201026201531.
sep 29 13:39:00 linge.ghs.nl certmonger[16291]: Certificate
named "subsystemCert cert-pki-ca" in token "NSS Certificate
DB" in database "/etc/pki/pki-tomcat/alias" will not be
valid after 20201026201532.
sep 29 13:39:02 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[16298]: Forwarding request
to dogtag-ipa-renew-agent
sep 29 13:39:03 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[16298]:
dogtag-ipa-renew-agent returned 5
sep 29 13:39:05 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[16339]: Forwarding request
to dogtag-ipa-renew-agent
sep 29 13:39:06 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[16339]:
dogtag-ipa-renew-agent returned 5
sep 29 13:39:08 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[16354]: Forwarding request
to dogtag-ipa-renew-agent
sep 29 13:39:08 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[16354]:
dogtag-ipa-renew-agent returned 0
sep 29 13:39:20 linge.ghs.nl certmonger[16720]: Certificate
named "subsystemCert cert-pki-ca" in token "NSS Certificate
DB" in database "/etc/pki/pki-tomcat/alias" issued by CA and
saved.
sep 29 13:39:22 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[16297]: Forwarding request
to dogtag-ipa-renew-agent
sep 29 13:39:23 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[16297]:
dogtag-ipa-renew-agent returned 5
sep 29 13:39:25 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[16726]: Forwarding request
to dogtag-ipa-renew-agent
sep 29 13:39:25 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[16726]:
dogtag-ipa-renew-agent returned 5
sep 29 13:39:27 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[16741]: Forwarding request
to dogtag-ipa-renew-agent
sep 29 13:39:27 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[16741]:
dogtag-ipa-renew-agent returned 0
sep 29 13:39:39 linge.ghs.nl certmonger[17106]: Certificate
named "auditSigningCert cert-pki-ca" in token "NSS
Certificate DB" in database "/etc/pki/pki-tomcat/alias"
issued by CA and saved.
sep 29 13:39:42 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[16296]: Forwarding request
to dogtag-ipa-renew-agent
sep 29 13:39:43 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[16296]:
dogtag-ipa-renew-agent returned 5
sep 29 13:39:44 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[17112]: Forwarding request
to dogtag-ipa-renew-agent
sep 29 13:39:45 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[17112]:
dogtag-ipa-renew-agent returned 5
sep 29 13:39:47 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[17126]: Forwarding request
to dogtag-ipa-renew-agent
sep 29 13:39:47 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[17126]:
dogtag-ipa-renew-agent returned 0
sep 29 13:39:49 linge.ghs.nl certmonger[17156]: Certificate
in file "/var/lib/ipa/ra-agent.pem" issued by CA and saved.
sep 29 13:39:52 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[16299]: Forwarding request
to dogtag-ipa-renew-agent
sep 29 13:39:53 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[16299]:
dogtag-ipa-renew-agent returned 5
sep 29 13:39:54 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[17162]: Forwarding request
to dogtag-ipa-renew-agent
sep 29 13:39:55 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[17162]:
dogtag-ipa-renew-agent returned 5
sep 29 13:39:57 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[17177]: Forwarding request
to dogtag-ipa-renew-agent
sep 29 13:39:57 linge.ghs.nl
dogtag-ipa-ca-renew-agent-submit[17177]:
dogtag-ipa-renew-agent returned 0
sep 29 13:40:05 linge.ghs.nl certmonger[17540]: Certificate
named "ocspSigningCert cert-pki-ca" in token "NSS
Certificate DB" in database "/etc/pki/pki-tomcat/alias"
issued by CA and saved.
Today (two days later) I looked at the two other CA masters
to see if these same certificates were OK.
I saw this:
[root@iparep3 ~]# journalctl | grep -E 'certmonger|dogtag'
sep 29 11:22:13 iparep3.ghs.nl certmonger[214479]:
Certificate in file "/var/lib/ipa/ra-agent.pem" will not be
valid after 20201026201548.
sep 29 11:22:13 iparep3.ghs.nl certmonger[214480]:
Certificate named "auditSigningCert cert-pki-ca" in token
"NSS Certificate DB" in database "/etc/pki/pki-tomcat/alias"
will not be valid after 20201026201532.
sep 29 11:22:13 iparep3.ghs.nl certmonger[214481]:
Certificate named "ocspSigningCert cert-pki-ca" in token
"NSS Certificate DB" in database "/etc/pki/pki-tomcat/alias"
will not be valid after 20201026201531.
sep 29 11:22:13 iparep3.ghs.nl certmonger[214482]:
Certificate named "subsystemCert cert-pki-ca" in token "NSS
Certificate DB" in database "/etc/pki/pki-tomcat/alias" will
not be valid after 20201026201532.
sep 29 11:22:15 iparep3.ghs.nl
dogtag-ipa-ca-renew-agent-submit[214487]: Updated
certificate not available
sep 29 11:22:16 iparep3.ghs.nl
dogtag-ipa-ca-renew-agent-submit[214488]: Updated
certificate not available
sep 29 11:22:16 iparep3.ghs.nl
dogtag-ipa-ca-renew-agent-submit[214496]: Updated
certificate not available
sep 29 11:22:17 iparep3.ghs.nl
dogtag-ipa-ca-renew-agent-submit[214505]: Updated
certificate not available
sep 29 19:22:18 iparep3.ghs.nl certmonger[428]: 2020-09-29
19:22:18 [428] Invalid cookie: u''
sep 29 19:22:19 iparep3.ghs.nl certmonger[428]: 2020-09-29
19:22:19 [428] Invalid cookie: u''
sep 29 19:22:20 iparep3.ghs.nl certmonger[428]: 2020-09-29
19:22:20 [428] Invalid cookie: u''
sep 29 19:22:29 iparep3.ghs.nl certmonger[428]: 2020-09-29
19:22:29 [428] Invalid cookie: u''
[root@rotte ~]# journalctl | grep -E 'certmonger|dogtag'
sep 29 13:00:55 rotte.ghs.nl certmonger[166381]: Certificate
in file "/var/lib/ipa/ra-agent.pem" will not be valid after
20201026201548.
sep 29 13:00:55 rotte.ghs.nl certmonger[166382]: Certificate
named "auditSigningCert cert-pki-ca" in token "NSS
Certificate DB" in database "/etc/pki/pki-tomcat/alias" will
not be valid after 20201026201532.
sep 29 13:00:55 rotte.ghs.nl certmonger[166383]: Certificate
named "ocspSigningCert cert-pki-ca" in token "NSS
Certificate DB" in database "/etc/pki/pki-tomcat/alias" will
not be valid after 20201026201531.
sep 29 13:00:55 rotte.ghs.nl certmonger[166384]: Certificate
named "subsystemCert cert-pki-ca" in token "NSS Certificate
DB" in database "/etc/pki/pki-tomcat/alias" will not be
valid after 20201026201532.
sep 29 13:00:57 rotte.ghs.nl
dogtag-ipa-ca-renew-agent-submit[166389]: Updated
certificate not available
sep 29 13:00:58 rotte.ghs.nl
dogtag-ipa-ca-renew-agent-submit[166392]: Updated
certificate not available
sep 29 13:01:08 rotte.ghs.nl
dogtag-ipa-ca-renew-agent-submit[166391]: Updated
certificate not available
sep 29 13:01:08 rotte.ghs.nl
dogtag-ipa-ca-renew-agent-submit[166390]: Updated
certificate not available
sep 29 21:01:00 rotte.ghs.nl certmonger[97976]: 2020-09-29
21:01:00 [97976] Invalid cookie: u''
sep 29 21:01:01 rotte.ghs.nl certmonger[97976]: 2020-09-29
21:01:01 [97976] Invalid cookie: u''
sep 29 21:01:10 rotte.ghs.nl certmonger[97976]: 2020-09-29
21:01:10 [97976] Invalid cookie: u''
sep 29 21:01:11 rotte.ghs.nl certmonger[97976]: 2020-09-29
21:01:11 [97976] Invalid cookie: u''
So, both non-renewal masters started tried
dogtag-ipa-ca-renew-agent-submit, and both failed with
"Updated certificate not available"
Next, I did a "yum update", hoping to get rid of the invalid
cookie. This updated ipa from 4.6.5 to 4.6.6
The update failed because /var/lib/ipa/ra-agent.pem still
had the old certificate.
After manually copying ra-agent.* to the failing system I
was able to restart ipa. However, I suspect
that things are still not right. Too many certs on the
non-renewal masters still need to be renewed.
I'm digging further ...
-- Kees
On 20-11-2019 20:13, Natxo
Asenjo via FreeIPA-users wrote:
hi,
after patching our centos 7 hosts to the latest
version today, one of the two replicas is having
trouble.
[root@kdc2 ~]# ipactl status
Directory Service: RUNNING
krb5kdc Service: STOPPED
kadmin Service: STOPPED
named Service: STOPPED
httpd Service: RUNNING
ipa-custodia Service: STOPPED
ntpd Service: STOPPED
pki-tomcatd Service: RUNNING
smb Service: STOPPED
winbind Service: STOPPED
ipa-otpd Service: STOPPED
ipa-dnskeysyncd Service: STOPPED
ipa: INFO: The ipactl command was successful
and after digging in the logs I come across this
in /var/log/ipaupgrade.log:
2019-11-20T18:18:29Z DEBUG stderr=
2019-11-20T18:18:31Z INFO Certmonger certificate
renewal configuration already up-to-date
2019-11-20T18:18:31Z INFO [Enable PKIX certificate
path discovery and validation]
2019-11-20T18:18:31Z DEBUG Loading StateFile from
'/var/lib/ipa/sysupgrade/sysupgrade.state'
2019-11-20T18:18:31Z INFO PKIX already enabled
2019-11-20T18:18:31Z INFO [Authorizing RA Agent to
modify profiles]
2019-11-20T18:18:31Z INFO [Authorizing RA Agent to
manage lightweight CAs]
2019-11-20T18:18:31Z INFO [Ensuring Lightweight CAs
container exists in Dogtag database]
2019-11-20T18:18:31Z DEBUG Created connection
context.ldap2_139740162547472
2019-11-20T18:18:31Z DEBUG flushing
ldapi://%2fvar%2frun%2fslapd-L-DOMAIN-IT.socket from
SchemaCache
2019-11-20T18:18:31Z DEBUG retrieving schema for
SchemaCache
url=ldapi://%2fvar%2frun%2fslapd-L-DOMAIN-IT.socket
conn=<ldap.ldapobject.SimpleLDAPObject instance
at 0x7f17cc24b638>
2019-11-20T18:18:31Z DEBUG Destroyed connection
context.ldap2_139740162547472
2019-11-20T18:18:31Z INFO [Adding default OCSP URI
configuration]
2019-11-20T18:18:31Z INFO [Ensuring CA is using
LDAPProfileSubsystem]
2019-11-20T18:18:31Z INFO [Migrating certificate
profiles to LDAP]
2019-11-20T18:18:31Z DEBUG Created connection
context.ldap2_139740160021648
2019-11-20T18:18:31Z DEBUG flushing
ldapi://%2fvar%2frun%2fslapd-L-DOMAIN-IT.socket from
SchemaCache
2019-11-20T18:18:31Z DEBUG retrieving schema for
SchemaCache
url=ldapi://%2fvar%2frun%2fslapd-L-DOMAIN-IT.socket
conn=<ldap.ldapobject.SimpleLDAPObject instance
at 0x7f17cc289b00>
2019-11-20T18:18:31Z DEBUG Destroyed connection
context.ldap2_139740160021648
2019-11-20T18:18:31Z DEBUG request GET
https://kdc2.l.domain.it:8443/ca/rest/account/login
2019-11-20T18:18:31Z DEBUG request body ''
2019-11-20T18:18:31Z DEBUG response status 401
2019-11-20T18:18:31Z DEBUG response headers Server:
Apache-Coyote/1.1
Cache-Control: private
Expires: Thu, 01 Jan 1970 01:00:00 CET
WWW-Authenticate: Basic realm="Certificate
Authority"
Content-Type: text/html;charset=utf-8
Content-Language: en
Content-Length: 951
Date: Wed, 20 Nov 2019 18:18:31 GMT
2019-11-20T18:18:31Z DEBUG response body
'<html><head><title>Apache
Tomcat/7.0.76 - Error
report</title><style><!--H1
{font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:22px;}
H2
{font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:16px;}
H3
{font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;font-size:14px;}
BODY
{font-family:Tahoma,Arial,sans-serif;color:black;background-color:white;}
B
{font-family:Tahoma,Arial,sans-serif;color:white;background-color:#525D76;}
P
{font-family:Tahoma,Arial,sans-serif;background:white;color:black;font-size:12px;}A
{color : black;}A.name {color : black;}HR {color :
#525D76;}--></style>
</head><body><h1>HTTP Status 401 -
</h1><HR size="1"
noshade="noshade"><p><b>type</b>
Status
report</p><p><b>message</b>
<u></u></p><p><b>description</b>
<u>This request requires HTTP
authentication.</u></p><HR size="1"
noshade="noshade"><h3>Apache
Tomcat/7.0.76</h3></body></html>'
2019-11-20T18:18:31Z ERROR IPA server upgrade
failed: Inspect /var/log/ipaupgrade.log and run
command ipa-server-upgrade manually.
2019-11-20T18:18:31Z DEBUG File
"/usr/lib/python2.7/site-packages/ipapython/admintool.py",
line 178, in execute
return_value = self.run()
File
"/usr/lib/python2.7/site-packages/ipaserver/install/ipa_server_upgrade.py",
line 54, in run
server.upgrade()
File
"/usr/lib/python2.7/site-packages/ipaserver/install/server/upgrade.py",
line 2146, in upgrade
upgrade_configuration()
File
"/usr/lib/python2.7/site-packages/ipaserver/install/server/upgrade.py",
line 2018, in upgrade_configuration
ca_enable_ldap_profile_subsystem(ca)
File
"/usr/lib/python2.7/site-packages/ipaserver/install/server/upgrade.py",
line 406, in ca_enable_ldap_profile_subsystem
cainstance.migrate_profiles_to_ldap()
File
"/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py",
line 2027, in migrate_profiles_to_ldap
_create_dogtag_profile(profile_id, profile_data,
overwrite=False)
File
"/usr/lib/python2.7/site-packages/ipaserver/install/cainstance.py",
line 2033, in _create_dogtag_profile
with api.Backend.ra_certprofile as profile_api:
File
"/usr/lib/python2.7/site-packages/ipaserver/plugins/dogtag.py",
line 1315, in __enter__
raise
errors.RemoteRetrieveError(reason=_('Failed to
authenticate to CA REST API'))
2019-11-20T18:18:31Z DEBUG The ipa-server-upgrade
command failed, exception: RemoteRetrieveError:
Failed to authenticate to CA REST API
2019-11-20T18:18:31Z ERROR Unexpected error - see
/var/log/ipaupgrade.log for details:
RemoteRetrieveError: Failed to authenticate to CA
REST API
In this kdc I see these errors in getcert
list:
Request ID '20190220182014':
status: MONITORING
ca-error: Invalid cookie: u''
stuck: no
key pair storage:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='auditSigningCert
cert-pki-ca',token='NSS Certificate DB',pin
set
certificate:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='auditSigningCert
cert-pki-ca',token='NSS Certificate DB'
CA: dogtag-ipa-ca-renew-agent
issuer: CN=Certificate Authority,O=
L.DOMAIN.IT
subject: CN=CA Audit,O=
L.DOMAIN.IT
expires: 2019-12-05 13:58:24 UTC
key usage:
digitalSignature,nonRepudiation
pre-save command:
/usr/libexec/ipa/certmonger/stop_pkicad
post-save command:
/usr/libexec/ipa/certmonger/renew_ca_cert
"auditSigningCert cert-pki-ca"
track: yes
auto-renew: yes
Request ID '20190220182015':
status: MONITORING
ca-error: Invalid cookie: u''
stuck: no
key pair storage:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='ocspSigningCert
cert-pki-ca',token='NSS Certificate DB',pin
set
certificate:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='ocspSigningCert
cert-pki-ca',token='NSS Certificate DB'
CA: dogtag-ipa-ca-renew-agent
issuer: CN=Certificate Authority,O=
L.DOMAIN.IT
subject: CN=OCSP Subsystem,O=
L.DOMAIN.IT
expires: 2019-12-05 13:58:24 UTC
key usage:
digitalSignature,nonRepudiation,keyCertSign,cRLSign
eku: id-kp-OCSPSigning
pre-save command:
/usr/libexec/ipa/certmonger/stop_pkicad
post-save command:
/usr/libexec/ipa/certmonger/renew_ca_cert
"ocspSigningCert cert-pki-ca"
track: yes
auto-renew: yes
Request ID '20190220182016':
status: MONITORING
ca-error: Invalid cookie: u''
stuck: no
key pair storage:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='subsystemCert
cert-pki-ca',token='NSS Certificate DB',pin
set
certificate:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='subsystemCert
cert-pki-ca',token='NSS Certificate DB'
CA: dogtag-ipa-ca-renew-agent
issuer: CN=Certificate Authority,O=
L.DOMAIN.IT
subject: CN=CA Subsystem,O=
L.DOMAIN.IT
expires: 2019-12-05 13:58:24 UTC
key usage:
digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment
eku: id-kp-serverAuth,id-kp-clientAuth
pre-save command:
/usr/libexec/ipa/certmonger/stop_pkicad
post-save command:
/usr/libexec/ipa/certmonger/renew_ca_cert
"subsystemCert cert-pki-ca"
track: yes
auto-renew: yes
Request ID '20190220182018':
status: MONITORING
ca-error: Invalid cookie: u''
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=Certificate Authority,O=
L.DOMAIN.IT
subject: CN=IPA RA,O=
L.DOMAIN.IT
expires: 2019-12-05 13:58:44 UTC
key usage:
digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment
eku: id-kp-serverAuth,id-kp-clientAuth
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
Request ID '20190220182019':
status: MONITORING
ca-error: Server at "
https://kdc2.l.domain.it:8443/ca/agent/ca/profileProcess"
replied: 1: Invalid Credential.
stuck: no
key pair storage:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='Server-Cert
cert-pki-ca',token='NSS Certificate DB',pin
set
certificate:
type=NSSDB,location='/etc/pki/pki-tomcat/alias',nickname='Server-Cert
cert-pki-ca',token='NSS Certificate DB'
CA: dogtag-ipa-ca-renew-agent
issuer: CN=Certificate Authority,O=
L.DOMAIN.IT
subject: CN=
kdc2.l.domain.it,O=
L.DOMAIN.IT
expires: 2019-12-10 10:57:52 UTC
key usage:
digitalSignature,nonRepudiation,keyEncipherment,dataEncipherment
eku:
id-kp-serverAuth,id-kp-clientAuth,id-kp-emailProtection
pre-save command:
/usr/libexec/ipa/certmonger/stop_pkicad
post-save command:
/usr/libexec/ipa/certmonger/renew_ca_cert
"Server-Cert cert-pki-ca"
track: yes
auto-renew: yes
I still have a working replica, so I could
just reinstall and have a working set in a
couple of minutes, but I would like to find
out what has gone wrong.
The systems are running
ipa-server-4.6.5-11.el7.centos.3.x86_64
Any help welcome ;-)
Thanks,
_______________________________________________
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.fedorahosted.org