Bug 2050921 - kinit as admin immediately after FreeIPA server deployment fails with openldap 2.6
Summary: kinit as admin immediately after FreeIPA server deployment fails with openlda...
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: freeipa
Version: rawhide
Hardware: Unspecified
OS: Unspecified
unspecified
urgent
Target Milestone: ---
Assignee: IPA Maintainers
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard: openqa
: 2051233 (view as bug list)
Depends On:
Blocks: F36BetaBlocker
TreeView+ depends on / blocked
 
Reported: 2022-02-05 00:16 UTC by Adam Williamson
Modified: 2022-02-07 16:02 UTC (History)
16 users (show)

Fixed In Version: freeipa-4.9.8-3.fc36
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2022-02-07 13:09:22 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)
tarball of /var/log from a failed run (2.49 MB, application/gzip)
2022-02-05 00:16 UTC, Adam Williamson
no flags Details


Links
System ID Private Priority Status Summary Last Updated
Red Hat Issue Tracker FREEIPA-7807 0 None None None 2022-02-07 06:09:11 UTC

Description Adam Williamson 2022-02-05 00:16:44 UTC
Created attachment 1859169 [details]
tarball of /var/log from a failed run

389-ds-base 2.1.0 landed in Rawhide in the 20220202.n.1 compose. Starting with that compose, the openQA FreeIPA server deployment test is failing. The test runs:

ipa-server-install -U --auto-forwarders --realm=TEST.OPENQA.FEDORAPROJECT.ORG --domain=test.openqa.fedoraproject.org --ds-password=monkeys123 --admin-password=monkeys123 --setup-dns --reverse-zone=2.16.172.in-addr.arpa --allow-zone-overlap

then immediately after that, runs:

echo "monkeys123" | kinit admin

to kinit as the admin user. That now fails, where it worked in previous composes. I'll attach the /var/log tarball from a failed test run.

Proposing as an F36 Beta blocker as a violation of "Once deployed, the system must handle multiple client enrolments and unenrolments, and client authentication via Kerberos." from the Basic requirements:

https://fedoraproject.org/wiki/Basic_Release_Criteria#FreeIPA_server_requirements

Comment 1 Adam Williamson 2022-02-05 00:18:21 UTC
Oh, the error message shown is "kinit: Pre-authentication failed: Invalid argument while getting initial credentials": https://openqa.fedoraproject.org/tests/1118902#step/role_deploy_domain_controller/41

Comment 2 mreynolds 2022-02-05 01:58:52 UTC
Did a brief look at the DS logs and I see nothing obviously wrong.  Need an IPA engineer to tell us what exactly is misbehaving.

Comment 3 Alexander Bokovoy 2022-02-05 10:52:27 UTC
I don't see any problem in ds logs.

KDC gets request:

Feb 03 13:29:46 ipa002.test.openqa.fedoraproject.org krb5kdc[33318](info): AS_REQ (6 etypes {aes256-cts-hmac-sha1-96(18), aes256-cts-hmac-sha384-192(20), camellia256-cts-cmac(26), aes128-cts-hmac-sha256-128(19), aes128-cts-hmac-sha1-96(17), camellia128-cts-cmac(25)}) 172.16.2.106: NEEDED_PREAUTH: admin.FEDORAPROJECT.ORG for krbtgt/TEST.OPENQA.FEDORAPROJECT.ORG.FEDORAPROJECT.ORG, Additional pre-authentication required
Feb 03 13:29:46 ipa002.test.openqa.fedoraproject.org krb5kdc[33318](info): closing down fd 4

Here is a set of queries done by KDC to produce a TGT for admin.FEDORAPROJECT.ORG:

[03/Feb/2022:13:29:46.166877774 -0500] conn=8 op=83 SRCH base="dc=test,dc=openqa,dc=fedoraproject,dc=org" scope=2 filter="(&(|(objectClass=krbprincipalaux)(objectClass=krbprincipal)(objectClass=ipakrbprincipal))(|(ipaKrbPrincipalAlias=admin.FEDORAPROJECT.ORG)(krbPrincipalName:caseIgnoreIA5Match:=admin.FEDORAPROJECT.ORG)))" attrs="krbPrincipalName krbCanonicalName krbUPEnabled krbPrincipalKey krbTicketPolicyReference krbPrincipalExpiration krbPasswordExpiration krbPwdPolicyReference krbPrincipalType krbPwdHistory krbLastPwdChange krbPrincipalAliases krbLastSuccessfulAuth krbLastFailedAuth krbLoginFailedCount krbPrincipalAuthInd krbExtraData krbLastAdminUnlock krbObjectReferences krbTicketFlags krbMaxTicketLife krbMaxRenewableAge uid nsAccountLock passwordHistory ipaKrbAuthzData ipaUserAuthType ipatokenRadiusConfigLink krbAuthIndMaxT..."
[03/Feb/2022:13:29:46.167682545 -0500] conn=8 op=83 RESULT err=0 tag=101 nentries=1 wtime=0.000348167 optime=0.000812822 etime=0.001155634
[03/Feb/2022:13:29:46.167821951 -0500] conn=8 op=84 SRCH base="cn=ipaConfig,cn=etc,dc=test,dc=openqa,dc=fedoraproject,dc=org" scope=0 filter="(objectClass=*)" attrs="ipaConfigString ipaKrbAuthzData ipaUserAuthType"
[03/Feb/2022:13:29:46.167997633 -0500] conn=8 op=84 RESULT err=0 tag=101 nentries=1 wtime=0.000091131 optime=0.000179060 etime=0.000266494
[03/Feb/2022:13:29:46.168612525 -0500] conn=8 op=85 SRCH base="cn=TEST.OPENQA.FEDORAPROJECT.ORG,cn=kerberos,dc=test,dc=openqa,dc=fedoraproject,dc=org" scope=0 filter="(objectClass=krbticketpolicyaux)" attrs="krbMaxTicketLife krbMaxRenewableAge krbTicketFlags krbAuthIndMaxTicketLife krbAuthIndMaxRenewableAge"
[03/Feb/2022:13:29:46.168789642 -0500] conn=8 op=85 RESULT err=0 tag=101 nentries=1 wtime=0.000584503 optime=0.000180081 etime=0.000761230
[03/Feb/2022:13:29:46.168966205 -0500] conn=8 op=86 SRCH base="dc=test,dc=openqa,dc=fedoraproject,dc=org" scope=2 filter="(&(|(objectClass=krbprincipalaux)(objectClass=krbprincipal)(objectClass=ipakrbprincipal))(|(ipaKrbPrincipalAlias=krbtgt/TEST.OPENQA.FEDORAPROJECT.ORG.FEDORAPROJECT.ORG)(krbPrincipalName:caseIgnoreIA5Match:=krbtgt/TEST.OPENQA.FEDORAPROJECT.ORG.FEDORAPROJECT.ORG)))" attrs="krbPrincipalName krbCanonicalName krbUPEnabled krbPrincipalKey krbTicketPolicyReference krbPrincipalExpiration krbPasswordExpiration krbPwdPolicyReference krbPrincipalType krbPwdHistory krbLastPwdChange krbPrincipalAliases krbLastSuccessfulAuth krbLastFailedAuth krbLoginFailedCount krbPrincipalAuthInd krbExtraData krbLastAdminUnlock krbObjectReferences krbTicketFlags krbMaxTicketLife krbMaxRenewableAge uid nsAccountLock passwordHistory ipaKrbAuthzData ipaUserAuthType ipatokenRadiusConfigLink krbAuthIndMaxT..."
[03/Feb/2022:13:29:46.169624548 -0500] conn=8 op=86 RESULT err=0 tag=101 nentries=1 wtime=0.000145014 optime=0.000662183 etime=0.000803297
[03/Feb/2022:13:29:46.170306237 -0500] conn=8 op=87 SRCH base="cn=global_policy,cn=TEST.OPENQA.FEDORAPROJECT.ORG,cn=kerberos,dc=test,dc=openqa,dc=fedoraproject,dc=org" scope=0 filter="(objectClass=*)" attrs="krbMaxPwdLife krbMinPwdLife krbPwdMinDiffChars krbPwdMinLength krbPwdHistoryLength krbPwdMaxFailure krbPwdFailureCountInterval krbPwdLockoutDuration ipaPwdMaxRepeat ipaPwdMaxSequence ipaPwdDictCheck ipaPwdUserCheck"
[03/Feb/2022:13:29:46.171049236 -0500] conn=8 op=87 RESULT err=0 tag=101 nentries=1 wtime=0.000634905 optime=0.000749979 etime=0.001379847

they all successfully return required entries and they are all expected.

It would be great to enable krb5 trace on the client side. E.g. do

export KRB5_trace=/dev/stderr
echo "monkeys123" | kinit admin

looks like the problem is on the client side here. Something returned EINVAL but we don't know what.

Comment 4 Alexander Bokovoy 2022-02-06 18:17:13 UTC
Flo opened upstream issue https://pagure.io/freeipa/issue/9106 and logs there show ldappasswd failing to parse command line options. Looks like it is a bug in new openldap update that was merged to rawhide:

CalledProcessError(Command ['/usr/bin/ldappasswd', '-h', 'server.ipa.test', '-ZZ', '-x', '-D', 'cn=Directory Manager', '-y', '/var/lib/ipa/tmpp4tale3j', '-T', '/var/lib/ipa/tmpzznbx6s3', 'uid=admin,cn=users,cn=accounts,dc=ipa,dc=test'] returned non-zero exit status 1: 'ldappasswd: unrecognized option -\x00\nChange password of an LDAP user\n\nusage:

Comment 5 Simon Pichugin 2022-02-07 04:35:38 UTC
From the upstream issue's reply:

All OpenLDAP 2.6 client tools accept only "-H URI - LDAP Uniform Resource Identifier(s)" now.
I went through official release notes but they, for some reason, haven't mentioned the exact Bug Number where it was changed...

I found the issue though - https://bugs.openldap.org/show_bug.cgi?id=8618

So it's not a bug and the usage should be changed in the tests.

Comment 6 Adam Williamson 2022-02-07 05:57:01 UTC
Aha, indeed, openldap did change in the same Rawhide compose, from 2.4.59 to 2.6.1. I filed against 389-ds-base as it seemed to be the only obviously relevant component that changed, but I missed openldap.

So, re-assigning to freeipa. Thanks for the catch, Alexander.

Comment 7 Alexander Bokovoy 2022-02-07 06:12:01 UTC
Simon,

it is a behavior change and it needs to be mentioned in Fedora release notes, please prepare one. It is sad that OpenLDAP upstream is not really helping its users but the announcement for deprecating -h -p was on the wall for twenty years, so we cannot really say it wasn't out there. Still, it will take a lot of people by surprise in Fedora 36, so you need to make it very visible.

We'll handle IPA side changes.

Comment 8 Alexander Bokovoy 2022-02-07 06:52:25 UTC
Upstream PR: https://github.com/freeipa/freeipa/pull/6166

Comment 9 Alexander Bokovoy 2022-02-07 06:57:38 UTC
*** Bug 2051233 has been marked as a duplicate of this bug. ***

Comment 11 Alexander Bokovoy 2022-02-07 11:05:42 UTC
ipa-4-9:

* 85ce7acb733e09ea7916a8a26d42fb3d4b5fe3bd OpenLDAP 2.6+: use only -H option to specify LDAP url
* 10d32d43e4640f61aa3d021b3e8136ca6132e493 pylint: workaround incorrect pylint detection of a local function
* 0d034d7fd409a8dbbc48a7307ad6d042a4098a74 translations: regenerate translations after changes in help message in sudorule

Comment 12 Fedora Update System 2022-02-07 11:25:16 UTC
FEDORA-2022-b5101e15dd has been submitted as an update to Fedora 36. https://bodhi.fedoraproject.org/updates/FEDORA-2022-b5101e15dd

Comment 13 Fedora Update System 2022-02-07 13:09:22 UTC
FEDORA-2022-b5101e15dd has been pushed to the Fedora 36 stable repository.
If problem still persists, please make note of it in this bug report.


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