Bug 1294287 - After F22->23 upgrade, ipa-server-upgrade fails
After F22->23 upgrade, ipa-server-upgrade fails
Status: CLOSED UPSTREAM
Product: Fedora
Classification: Fedora
Component: freeipa (Show other bugs)
23
Unspecified Unspecified
unspecified Severity unspecified
: ---
: ---
Assigned To: IPA Maintainers
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2015-12-26 07:58 EST by Tomasz Torcz
Modified: 2016-02-23 09:33 EST (History)
10 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2016-02-23 09:33:53 EST
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)
ipaupgrade.log (3.82 MB, text/plain)
2015-12-26 07:58 EST, Tomasz Torcz
no flags Details
upgrade screentshot (28.46 KB, image/png)
2015-12-26 07:59 EST, Tomasz Torcz
no flags Details
catalina.2015-12-26.log (3.08 MB, text/plain)
2016-01-11 05:01 EST, Tomasz Torcz
no flags Details
error_log-20160103 (14.26 KB, text/plain)
2016-01-11 05:02 EST, Tomasz Torcz
no flags Details
pki-server-upgrade-10.2.6.log (763 bytes, text/plain)
2016-01-11 05:03 EST, Tomasz Torcz
no flags Details
pki-upgrade-10.2.6.log (647 bytes, text/plain)
2016-01-11 05:03 EST, Tomasz Torcz
no flags Details
pki-tomcat_ca_debug.txt (2.67 MB, text/plain)
2016-02-08 06:28 EST, Tomasz Torcz
no flags Details

  None (edit)
Description Tomasz Torcz 2015-12-26 07:58:33 EST
Created attachment 1109598 [details]
ipaupgrade.log

Description of problem:
I've used "dnf system-upgrade" to go from Fedora 22 to 23 on my IPA replica. IPA documentation says that "ipa-server-upgrade" must be invoked in such situation.
I've run it, but it ended with "IPA server upgrade failed".

Version-Release number of selected component (if applicable):
freeipa-server-4.2.3-2.fc23.x86_64

How reproducible:
Just happened.

Steps to Reproduce:
1. Have freeipa on f22
2. Upgrade to f23
3. run ipa-server-upgrade
Comment 1 Tomasz Torcz 2015-12-26 07:59 EST
Created attachment 1109599 [details]
upgrade screentshot
Comment 2 Martin Kosek 2016-01-04 04:00:45 EST
It looks like your CA certificate is expired. However, it may not be the main root cause, at least for upgrade, I see server is giving Internal Error. It should help to check

/var/log/httpd/error_log

for this error.
Comment 3 Petr Vobornik 2016-01-04 04:31:51 EST
The internal error is related to PKI therefore I also suggest to check /var/log/pki/* for more clues.
Comment 4 Tomasz Torcz 2016-01-05 08:27:38 EST
Log files in /var/log/pki/* shows no errors, as far as I can see. I will attach them later.

error_log for apache shows couple of SSL establishment errors but those also seem not to be related.

So I've run 'ipa-cacert-manage status', it finished successfuly but:

1) the error message in journal (Jan 05 14:25:35 okda.pipebreaker.pl certmonger[12198]: Certificate named "Server-Cert cert-pki-ca" in token "NSS Certificate DB" in database "/etc/pki/pki-tomcat/alias" is no longer valid.
) still appear every couple of seconds.

2) I suggest this should be added to upgrade script, if it is needed.
Comment 5 Tomasz Torcz 2016-01-11 05:01 EST
Created attachment 1113563 [details]
catalina.2015-12-26.log
Comment 6 Tomasz Torcz 2016-01-11 05:02 EST
Created attachment 1113564 [details]
error_log-20160103
Comment 7 Tomasz Torcz 2016-01-11 05:03 EST
Created attachment 1113565 [details]
pki-server-upgrade-10.2.6.log
Comment 8 Tomasz Torcz 2016-01-11 05:03 EST
Created attachment 1113566 [details]
pki-upgrade-10.2.6.log
Comment 9 Martin Kosek 2016-01-11 07:04:52 EST
CCing Endi, to be aware of the upgrade bug and logs.
Comment 10 Endi Sukma Dewata 2016-01-28 10:48:24 EST
The catalina.log indicates that the Tomcat is started but the CA subsystem is not loaded. An expired CA certificate would cause the selftest to fail, so the CA subsystem will not load. The details should be available in /var/log/pki/pki-tomcat/ca/selftests.log. If you have this file could you post it so we can confirm it?
Comment 11 Tomasz Torcz 2016-01-28 15:08:10 EST
This is full content of this file:

#v+
0.localhost-startStop-1 - [03/Nov/2015:10:10:08 CET] [20] [1] SelfTestSubsystem: Initializing self test plugins:
0.localhost-startStop-1 - [03/Nov/2015:10:10:08 CET] [20] [1] SelfTestSubsystem:  loading all self test plugin logger parameters
0.localhost-startStop-1 - [03/Nov/2015:10:10:08 CET] [20] [1] SelfTestSubsystem:  loading all self test plugin instances
0.localhost-startStop-1 - [03/Nov/2015:10:10:08 CET] [20] [1] SelfTestSubsystem:  loading all self test plugin instance parameters
0.localhost-startStop-1 - [03/Nov/2015:10:10:08 CET] [20] [1] SelfTestSubsystem:  loading self test plugins in on-demand order
0.localhost-startStop-1 - [03/Nov/2015:10:10:08 CET] [20] [1] SelfTestSubsystem:  loading self test plugins in startup order
0.localhost-startStop-1 - [03/Nov/2015:10:10:08 CET] [20] [1] SelfTestSubsystem: Self test plugins have been successfully loaded!
0.localhost-startStop-1 - [03/Nov/2015:10:10:12 CET] [20] [1] SelfTestSubsystem: Running self test plugins specified to be executed at startup:
0.localhost-startStop-1 - [03/Nov/2015:10:10:12 CET] [20] [1] CAPresence:  CA is present
0.localhost-startStop-1 - [03/Nov/2015:10:10:12 CET] [20] [1] SystemCertsVerification: system certs verification success
0.localhost-startStop-1 - [03/Nov/2015:10:10:12 CET] [20] [1] SelfTestSubsystem: All CRITICAL self test plugins ran SUCCESSFULLY at startup!
#v-


As for certs, CA cert looks indeed expired:
$ certutil -d /etc/pki/pki-tomcat/alias/ -L -n "Server-Cert cert-pki-ca" | grep After
            Not After : Fri Nov 06 12:28:56 2015

There are instruction for renewing CA cert on the wiki, but they require changing the time on the server to before CA expiration. However, server certificate for this machine (CN=okda.pipebreaker.pl,O=PIPEBREAKER.PL) was generated on December 10th. When I set date to before Nov 06, server certificate is not valid _yet_ and refreshing fails.

This is awfully manual and error prone, so should be done by upgrade scripts.
Comment 12 Endi Sukma Dewata 2016-01-28 16:15:46 EST
The failures in catalina.out are from Dec 26, but the selftest logs are from Nov 3. Is this an old log, or was it taken after you changed the date back (i.e. so the cert was still valid)? Could you also post the debug log in /var/log/pki/pki-tomcat/ca/debug from when the upgrade failed?

Changing the system date is indeed problematic. I've filed a ticket to provide a better mechanism to renew an already expired CA certificate:
https://fedorahosted.org/pki/ticket/1752

I don't think the upgrade script should automatically renew the expired CA certificate, but at least the upgrade should not fail because of that, and there's a simple way to renew the certificate.
Comment 13 Marc Sauton 2016-02-01 14:05:17 EST
there is a feature in 8.1 that could be re-used: 
https://access.redhat.com/documentation/en-US/Red_Hat_Certificate_System/8.1/html/Admin_Guide/managing-ca-related-profiles.html#ca-validity-default
in pki-common
CAValidityDefault.java
Comment 14 Tomasz Torcz 2016-02-08 06:28 EST
Created attachment 1122148 [details]
pki-tomcat_ca_debug.txt

Here's pki-tomcat/ca/debug log. I had to trim earlier entries (full log is 120 MB big).
You can see the upgrade on Dec 26th, then I rewinded date to nov 03 to recover expired CA.
Comment 15 Endi Sukma Dewata 2016-02-23 09:33:53 EST
Thanks for the info. The issue will be addressed in future upstream tickets:
* https://fedorahosted.org/pki/ticket/1752
* https://fedorahosted.org/pki/ticket/1962

If the issue needs to be addressed sooner, please indicate so in the above tickets.

Note You need to log in before you can comment on or make changes to this bug.