Bug 1491056 - [Modular Server] FreeIPA enrolment via kickstart fails
Summary: [Modular Server] FreeIPA enrolment via kickstart fails
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: freeipa
Version: 27
Hardware: All
OS: Linux
unspecified
high
Target Milestone: ---
Assignee: IPA Maintainers
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard: AcceptedBlocker
Depends On:
Blocks: F27BetaBlocker
TreeView+ depends on / blocked
 
Reported: 2017-09-12 23:21 UTC by Adam Williamson
Modified: 2017-10-16 22:23 UTC (History)
14 users (show)

Fixed In Version: freeipa-4.6.0-3.fc27
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2017-10-16 22:23:34 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
/var/log contents from the client (tar.gz) (663.74 KB, application/x-gzip)
2017-09-12 23:23 UTC, Adam Williamson
no flags Details
/var/log contents from the server (.tar.gz) - note other client enrolment tests ran against the same server, IP of failed client is 10.0.2.102 (1.54 MB, application/x-gzip)
2017-09-12 23:24 UTC, Adam Williamson
no flags Details

Description Adam Williamson 2017-09-12 23:21:12 UTC
In recent Fedora 27 and Rawhide, openQA tests which enrol to FreeIPA via cockpit and direct call of 'realm join' in the installed system pass, but enrolment via kickstart fails:

https://openqa.stg.fedoraproject.org/tests/159244

The installer logs reveal what happened:

=================

16:06:29,851 INF program: Running... realm join --install /mnt/sysimage --verbose --one-time-password=monkeys ipa001.domain.local
16:06:48,728 INF program: * Resolving: _ldap._tcp.ipa001.domain.local
16:06:48,729 INF program: * Resolving: ipa001.domain.local
16:06:48,731 INF program: * Performing LDAP DSE lookup on: 10.0.2.100
16:06:48,731 INF program: * Successfully discovered: domain.local
16:06:48,732 INF program: * Assuming packages are installed
16:06:48,733 INF program: * LANG=C /usr/sbin/ipa-client-install --domain domain.local --realm DOMAIN.LOCAL --mkhomedir --enable-dns-updates --unattended --force-join --server ipa001.domain.local --fixed-primary --password monkeys --force-ntpd
16:06:48,733 INF program: Client hostname: client001.domain.local
16:06:48,734 INF program: Realm: DOMAIN.LOCAL
16:06:48,734 INF program: DNS Domain: domain.local
16:06:48,735 INF program: IPA Server: ipa001.domain.local
16:06:48,736 INF program: BaseDN: dc=domain,dc=local
16:06:48,736 INF program: Synchronizing time with KDC...
16:06:48,737 INF program: Attempting to sync time using ntpd.  Will timeout after 15 seconds
16:06:48,737 INF program: Downloading the CA certificate via HTTP, this is INSECURE
16:06:48,738 INF program: Cannot obtain CA certificate
16:06:48,739 INF program: 'http://ipa001.domain.local/ipa/config/ca.crt' doesn't have a certificate.
16:06:48,739 INF program: Installation failed. Rolling back changes.
16:06:48,740 INF program: Unconfigured automount client failed: Command 'ipa-client-automount --uninstall --debug' returned non-zero exit status 1.
16:06:48,740 INF program: Failed to start certmonger
16:06:48,741 INF program: The ipa-client-install command failed. See /var/log/ipaclient-install.log for more information
16:06:48,742 INF program: 
16:06:48,742 INF program: ! Running ipa-client-install failed
16:06:48,743 INF program: realm: Couldn't join realm: Running ipa-client-install failed
16:06:48,743 DBG program: Return code: 1

===============

There is a var/log/ipaclient-install.log indeed, and it shows just slightly more detail:

===============

2017-09-12T20:06:42Z WARNING Downloading the CA certificate via HTTP, this is INSECURE
2017-09-12T20:06:42Z DEBUG trying to retrieve CA cert via HTTP from http://ipa001.domain.local/ipa/config/ca.crt
2017-09-12T20:06:42Z DEBUG Starting external process
2017-09-12T20:06:42Z DEBUG args=/usr/bin/curl -o - http://ipa001.domain.local/ipa/config/ca.crt
2017-09-12T20:06:42Z DEBUG Process finished, return code=0
2017-09-12T20:06:42Z DEBUG stdout=-----BEGIN CERTIFICATE-----
MIIDjjCCAnagAwIBAgIBATANBgkqhkiG9w0BAQsFADA3MRUwEwYDVQQKDAxET01B
SU4uTE9DQUwxHjAcBgNVBAMMFUNlcnRpZmljYXRlIEF1dGhvcml0eTAeFw0xNzA5
MTIxOTU0NTFaFw0zNzA5MTIxOTU0NTFaMDcxFTATBgNVBAoMDERPTUFJTi5MT0NB
TDEeMBwGA1UEAwwVQ2VydGlmaWNhdGUgQXV0aG9yaXR5MIIBIjANBgkqhkiG9w0B
AQEFAAOCAQ8AMIIBCgKCAQEAzwLddjqRUfEGOunM9olMmrxKSiO7M2vU75j6+W7f
JOUUSn0PRXVrm6zFnhthNVTXp1iAhbVInz41BXD2NVyHOi2OEO7GHMkhNyWC0yom
iXRjW4fMkcolICC05w9ZmMeqeFrnGZzMg8Ts6q0K70I26NnKSQZxwqnzNnhKTx9h
Q9e4f6wPH70SvbVohucNiYJaOZs3LXugmed4aWIUCHnPXqseIKEh20JxQGB/cfhl
HN00mQ3yvCCHYYsQsSuiIk7RPY+S8dgRtB2B4Q+ALQ/eE6xgeAwZuANDKL6GGr7q
RqTds+BASxe5vZywg+TreTRXew5PTm+3yyN2S5NfB1SFHwIDAQABo4GkMIGhMB8G
A1UdIwQYMBaAFCSQ457w4ZYelOEbdC1TSGcoI3EIMA8GA1UdEwEB/wQFMAMBAf8w
DgYDVR0PAQH/BAQDAgHGMB0GA1UdDgQWBBQkkOOe8OGWHpThG3QtU0hnKCNxCDA+
BggrBgEFBQcBAQQyMDAwLgYIKwYBBQUHMAGGImh0dHA6Ly9pcGEtY2EuZG9tYWlu
LmxvY2FsL2NhL29jc3AwDQYJKoZIhvcNAQELBQADggEBADUS1C9R/A8QOtn+R5re
9urteA7VSJUBCPyT2+EWPd1Zea4JmZrvsnQ06SCxpsd995XSTtCqDqtHCe8Q2xdg
L+qfVahiU2ylE/6EWpIt9q/37A8/qo9OOe4+9m4f29ruMRpDrFBK22Jel/tjP+Of
QNpq84n3DJsRdn+JKUZj1PHBeQc6DvW9kQxYO5EFz6gjTDgU0R4ZwkqaanUbJgYT
RE5qy4qabdEGhJ7pHzMMwmqmzxW8x8207MGMUYcrVlGR4N4M4kQ1KN1LJW1c93AV
zGaqFYyBGwh90YWD3mZtJf+lVSy19amE3y9kVWtJ6XB2XQVqqOYhZhUb0sDxZmpg
aeM=
-----END CERTIFICATE-----

2017-09-12T20:06:42Z DEBUG stderr=  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
^M  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0^M100  1294  100  1294    0     0   1294      0  0:00:01 --:--:--  0:00:01  252k

2017-09-12T20:06:42Z DEBUG 'http://ipa001.domain.local/ipa/config/ca.crt' doesn't have a certificate.
2017-09-12T20:06:42Z ERROR Cannot obtain CA certificate
'http://ipa001.domain.local/ipa/config/ca.crt' doesn't have a certificate.
2017-09-12T20:06:42Z ERROR Installation failed. Rolling back changes.

===================

A bit later in the log, there's what looks a lot like a classic Python 2 vs. 3 string type bug, which presumably happens during the rollback attempt:

2017-09-12T20:06:48Z DEBUG Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/ipaclient/install/client.py", line 1621, in get_ca_certs_from_http
    certs = x509.load_certificate_list(stdout)
  File "/usr/lib/python3.6/site-packages/ipalib/x509.py", line 452, in load_certificate_list
    certs = PEM_REGEX.findall(data)
TypeError: cannot use a bytes pattern on a string-like object

I'll attach the tarball of the whole /var/log from the client for inspection.

Comment 1 Adam Williamson 2017-09-12 23:22:13 UTC
Proposing as a Beta blocker, per Alpha criterion "It must be possible to join the system to a FreeIPA or Active Directory domain at install time and post-install, and the system must respect the identity, authentication and access control configuration provided by the domain" - kickstart is the only available mechanism for enrolling in a FreeIPA domain at install time, and per this test, it's failing.

Comment 2 Adam Williamson 2017-09-12 23:22:48 UTC
CC some FreeIPA folks.

Comment 3 Adam Williamson 2017-09-12 23:23:33 UTC
Created attachment 1325079 [details]
/var/log contents from the client (tar.gz)

Comment 4 Adam Williamson 2017-09-12 23:24:33 UTC
Created attachment 1325080 [details]
/var/log contents from the server (.tar.gz) - note other client enrolment tests ran against the same server, IP of failed client is 10.0.2.102

Comment 5 Rob Crittenden 2017-09-13 03:20:47 UTC
Looks like you're right. The regex is expecting bytes but getting a string. CC'ing Standa as he is more familiar with the Py3 conversion, particularly with this code.

Comment 6 Adam Williamson 2017-09-13 03:35:09 UTC
I don't think that's the cause of the key bug here, though - from the timestamps and log sequence it looks like the bytes thing happens during the attempt to rollback the failed client enrolment process. i.e. it's really a separate bug during rollback. Unless I'm missing something. I can file it separately if you like.

Comment 7 Standa Laznicka 2017-09-13 06:35:17 UTC
Adam, sorry about this issue. It does not usually happen for the CA certs retrieval to fallback to HTTP so nobody probably ran into this during development, neither did our testing suite, I guess.

I created a fix, please, see if it helps: https://patch-diff.githubusercontent.com/raw/freeipa/freeipa/pull/1071.patch

Looking into the log on the client, you see that the try to get the CA cert is actually the last thing that was there before the uninstall attempt.

Comment 8 Adam Williamson 2017-09-13 06:46:36 UTC
Testing is slightly tricky because this is triggered from the installer...thinking about it, it probably does the enrolment from a chroot into the installed system, so just getting the patch into the installed system somehow should be enough. I'll try and work on that tomorrow.

Is the fact that it falls back to HTTP on this path a problem in itself?

Comment 9 Sumit Bose 2017-09-13 07:02:23 UTC
Looks like it turned out to be an IPA issue, changing component to FreeIPA.

Comment 10 Standa Laznicka 2017-09-13 07:41:30 UTC
Hopefully it should not be a problem if it succeeds retrieving the certificate successfully.

Comment 12 Fedora Update System 2017-09-13 20:35:49 UTC
freeipa-4.6.0-3.fc27 has been submitted as an update to Fedora 27. https://bodhi.fedoraproject.org/updates/FEDORA-2017-9a6df5d962

Comment 13 Dennis Gilmore 2017-09-14 17:20:08 UTC
+1 Beta Blocker

Comment 14 Fedora Update System 2017-09-14 18:22:07 UTC
freeipa-4.6.0-3.fc27 has been pushed to the Fedora 27 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2017-9a6df5d962

Comment 15 Adam Williamson 2017-09-15 02:06:37 UTC
Discussed at 2017-09-14 Beta Go/No-Go meeting, acting as a blocker review meeting: https://meetbot-raw.fedoraproject.org/fedora-meeting-2/2017-09-14/f27-beta-go-no-go-meeting.2017-09-14-17.00.html . Accepted as a blocker per criterion cited in #c1.

Comment 16 Fedora Update System 2017-09-20 15:25:53 UTC
freeipa-4.6.0-3.fc27 has been pushed to the Fedora 27 stable repository. If problems still persist, please make note of it in this bug report.

Comment 17 Kamil Páral 2017-09-20 15:33:21 UTC
This is an accepted blocker, we still need to verify the fix.

Comment 18 Adam Williamson 2017-10-16 22:23:34 UTC
Works fine in current F27, e.g. https://openqa.fedoraproject.org/tests/158733 .


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