Cannot connect to the server, please check API accesibility (certificate, API, proxy, etc.)
Hi folks,
We've got an unusual issue that has started to occur recently when trying to view the Users tab in FreeIPA. Trying to load the page (and display all users) results in a popup with title "HTTP Error 404" and the text "Cannot connect to the server, please check API accesibility (certificate, API, proxy, etc.)". This error appears after "Working" has been displaying for 60 seconds, so it appears to be a timeout despite the 404 indication.
If we _search_ for a user, any users matching the search term are returned correctly in the UI. Only when no search is applied do we see the error. Hosts and groups also display correctly, though any sub page where all users are listed experiences the same issue (such as parts of Automember). We're able to list all users correctly with "ipa user-find --all".
There are no relevant browser errors (there's what appears to be an unrelated 404 error about a minified JS file). There doesn't seem to be anything useful in /var/log/messages or /var/log/ipa*, though /var/log/httpd/error_log contains the following after a failed lookup:
[Wed Jul 17 15:24:18.475814 2019] [:error] [pid 5383] ipa: DEBUG: WSGI wsgi_dispatch.__call__: [Wed Jul 17 15:24:18.475891 2019] [:error] [pid 5383] ipa: DEBUG: WSGI jsonserver_session.__call__: [Wed Jul 17 15:24:18.484387 2019] [:error] [pid 5383] ipa: DEBUG: Created connection context.ldap2_139831284142928 [Wed Jul 17 15:24:18.484471 2019] [:error] [pid 5383] ipa: DEBUG: WSGI jsonserver.__call__: [Wed Jul 17 15:24:18.484520 2019] [:error] [pid 5383] ipa: DEBUG: WSGI WSGIExecutioner.__call__: [Wed Jul 17 15:24:18.484830 2019] [:error] [pid 5383] ipa: DEBUG: raw: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True) [Wed Jul 17 15:24:18.485157 2019] [:error] [pid 5383] ipa: DEBUG: user_find(None, sizelimit=0, whoami=False, all=False, raw=False, version=u'2.230', no_members=True, pkey_only=True) [Wed Jul 17 15:24:18.493684 2019] [:error] [pid 5383] ipa: INFO: [jsonserver_session] admin@DOMAIN.NZ: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True): SUCCESS [Wed Jul 17 15:24:18.494662 2019] [:error] [pid 5383] ipa: DEBUG: Destroyed connection context.ldap2_139831284142928
The server was built 3 weeks ago to the day and has 11 users. I was thinking that 3 weeks is a rather convenient duration and could be something token related with a 21 day expiry, though this may also be a coincidence. However, the server admin assures me that nothing was changed between today and yesterday, so I thought it was worth mentioning.
Any help would be greatly appreciated. Thank you.
Ben Schofield via FreeIPA-users wrote:
Hi folks,
We've got an unusual issue that has started to occur recently when trying to view the Users tab in FreeIPA. Trying to load the page (and display all users) results in a popup with title "HTTP Error 404" and the text "Cannot connect to the server, please check API accesibility (certificate, API, proxy, etc.)". This error appears after "Working" has been displaying for 60 seconds, so it appears to be a timeout despite the 404 indication.
If we _search_ for a user, any users matching the search term are returned correctly in the UI. Only when no search is applied do we see the error. Hosts and groups also display correctly, though any sub page where all users are listed experiences the same issue (such as parts of Automember). We're able to list all users correctly with "ipa user-find --all".
There are no relevant browser errors (there's what appears to be an unrelated 404 error about a minified JS file). There doesn't seem to be anything useful in /var/log/messages or /var/log/ipa*, though /var/log/httpd/error_log contains the following after a failed lookup:
[Wed Jul 17 15:24:18.475814 2019] [:error] [pid 5383] ipa: DEBUG: WSGI wsgi_dispatch.__call__: [Wed Jul 17 15:24:18.475891 2019] [:error] [pid 5383] ipa: DEBUG: WSGI jsonserver_session.__call__: [Wed Jul 17 15:24:18.484387 2019] [:error] [pid 5383] ipa: DEBUG: Created connection context.ldap2_139831284142928 [Wed Jul 17 15:24:18.484471 2019] [:error] [pid 5383] ipa: DEBUG: WSGI jsonserver.__call__: [Wed Jul 17 15:24:18.484520 2019] [:error] [pid 5383] ipa: DEBUG: WSGI WSGIExecutioner.__call__: [Wed Jul 17 15:24:18.484830 2019] [:error] [pid 5383] ipa: DEBUG: raw: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True) [Wed Jul 17 15:24:18.485157 2019] [:error] [pid 5383] ipa: DEBUG: user_find(None, sizelimit=0, whoami=False, all=False, raw=False, version=u'2.230', no_members=True, pkey_only=True) [Wed Jul 17 15:24:18.493684 2019] [:error] [pid 5383] ipa: INFO: [jsonserver_session] admin@DOMAIN.NZ: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True): SUCCESS [Wed Jul 17 15:24:18.494662 2019] [:error] [pid 5383] ipa: DEBUG: Destroyed connection context.ldap2_139831284142928
The server was built 3 weeks ago to the day and has 11 users. I was thinking that 3 weeks is a rather convenient duration and could be something token related with a 21 day expiry, though this may also be a coincidence. However, the server admin assures me that nothing was changed between today and yesterday, so I thought it was worth mentioning.
Any help would be greatly appreciated. Thank you.
When you reproduce the failures look in the 389-ds access log for any searches that are timing out. Note that the log is buffered up to 30 seconds.
rob
Thanks for your assistance Rob. We had an admin hit refresh on the users page and I tailed all log files in /var/log/dirsrv/slapd-<domain>/. Other than anonymising the domain the logs are a direct copy. Interestingly, nothing new appeared in the error log (last entry was yesterday) though the access log appears to indicate errors (err=32/err=14):
==> /var/log/dirsrv/slapd-DOMAIN-NZ/access <== [18/Jul/2019:10:21:32.743893901 +1200] conn=579 op=8 SRCH base="cn=accounts,dc=domain,dc=nz" scope=2 filter="(&(uid=mailer-daemon)(objectClass=posixAccount)(uid=*)(&(uidNumber=*)(!(uidNumber=0))))" attrs="objectClass uid userPassword uidNumber gidNumber gecos homeDirectory loginShell krbPrincipalName cn memberOf ipaUniqueID ipaNTSecurityIdentifier modifyTimestamp entryusn shadowLastChange shadowMin shadowMax shadowWarning shadowInactive shadowExpire shadowFlag krbLastPwdChange krbPasswordExpiration pwdattribute authorizedService accountexpires useraccountcontrol nsAccountLock host logindisabled loginexpirationtime loginallowedtimemap ipaSshPubKey ipaUserAuthType usercertificate;binary mail" [18/Jul/2019:10:21:32.744157672 +1200] conn=579 op=8 RESULT err=0 tag=101 nentries=0 etime=0.0000454722 [18/Jul/2019:10:21:56.677736243 +1200] conn=583 fd=105 slot=105 connection from 172.30.2.21 to 172.30.2.21 [18/Jul/2019:10:21:56.679982423 +1200] conn=583 op=0 BIND dn="" method=sasl version=3 mech=GSS-SPNEGO [18/Jul/2019:10:21:56.682418635 +1200] conn=583 op=0 RESULT err=0 tag=97 nentries=0 etime=0.0002650664 dn="uid=yusuf,cn=users,cn=accounts,dc=domain,dc=nz" [18/Jul/2019:10:21:56.689593794 +1200] conn=583 op=1 SRCH base="cn=ipaconfig,cn=etc,dc=domain,dc=nz" scope=0 filter="(objectClass=*)" attrs=ALL [18/Jul/2019:10:21:56.690482586 +1200] conn=583 op=1 RESULT err=0 tag=101 nentries=1 etime=0.0000963835 [18/Jul/2019:10:21:56.691860968 +1200] conn=583 op=2 SRCH base="cn=ipaconfig,cn=etc,dc=domain,dc=nz" scope=0 filter="(objectClass=*)" attrs="ipaDefaultLoginShell ipaCertificateSubjectBase ipaUserSearchFields ipaSELinuxUserMapDefault ipaUserAuthType ipaGroupSearchFields ipaDefaultPrimaryGroup ipaPwdExpAdvNotify ipaDomainResolutionOrder ipaDefaultEmailDomain ipaHomesRootDir ipaSearchTimeLimit ipaKrbAuthzData ipaMigrationEnabled ipaSearchRecordsLimit ipaConfigString ipaMaxUsernameLength ipaSELinuxUserMapOrder" [18/Jul/2019:10:21:56.692082704 +1200] conn=583 op=2 RESULT err=0 tag=101 nentries=1 etime=0.0000316244 [18/Jul/2019:10:21:56.693128113 +1200] conn=583 op=3 SRCH base="cn=masters,cn=ipa,cn=etc,dc=domain,dc=nz" scope=2 filter="(cn=CA)" attrs="ipaConfigString cn" [18/Jul/2019:10:21:56.693610138 +1200] conn=583 op=3 RESULT err=0 tag=101 nentries=1 etime=0.0000542056 [18/Jul/2019:10:21:56.694663398 +1200] conn=583 op=4 SRCH base="cn=masters,cn=ipa,cn=etc,dc=domain,dc=nz" scope=1 filter="(objectClass=ipaConfigObject)" attrs="cn" [18/Jul/2019:10:21:56.695124028 +1200] conn=583 op=4 RESULT err=0 tag=101 nentries=2 etime=0.0000526921 [18/Jul/2019:10:21:56.695909846 +1200] conn=583 op=5 SRCH base="cn=masters,cn=ipa,cn=etc,dc=domain,dc=nz" scope=2 filter="(&(cn=CA)(ipaConfigString=caRenewalMaster))" attrs=ALL [18/Jul/2019:10:21:56.696468573 +1200] conn=583 op=5 RESULT err=0 tag=101 nentries=1 etime=0.0000620511 [18/Jul/2019:10:21:56.697116946 +1200] conn=583 op=6 SRCH base="cn=masters,cn=ipa,cn=etc,dc=domain,dc=nz" scope=2 filter="(cn=CA)" attrs="ipaConfigString cn" [18/Jul/2019:10:21:56.697520000 +1200] conn=583 op=6 RESULT err=0 tag=101 nentries=1 etime=0.0000470211 [18/Jul/2019:10:21:56.698159853 +1200] conn=583 op=7 SRCH base="cn=masters,cn=ipa,cn=etc,dc=domain,dc=nz" scope=1 filter="(objectClass=ipaConfigObject)" attrs="cn" [18/Jul/2019:10:21:56.698567839 +1200] conn=583 op=7 RESULT err=0 tag=101 nentries=2 etime=0.0000464594 [18/Jul/2019:10:21:56.699430708 +1200] conn=583 op=8 SRCH base="cn=masters,cn=ipa,cn=etc,dc=domain,dc=nz" scope=2 filter="(|(cn=HTTP)(cn=KDC)(cn=KPASSWD))" attrs="ipaConfigString cn" [18/Jul/2019:10:21:56.700805669 +1200] conn=583 op=8 RESULT err=0 tag=101 nentries=6 etime=0.0001447294 [18/Jul/2019:10:21:56.702777108 +1200] conn=583 op=9 SRCH base="cn=masters,cn=ipa,cn=etc,dc=domain,dc=nz" scope=1 filter="(objectClass=ipaConfigObject)" attrs="cn" [18/Jul/2019:10:21:56.703187156 +1200] conn=583 op=9 RESULT err=0 tag=101 nentries=2 etime=0.0000470000 [18/Jul/2019:10:21:56.703991617 +1200] conn=583 op=10 SRCH base="cn=masters,cn=ipa,cn=etc,dc=domain,dc=nz" scope=2 filter="(&(cn=KDC)(ipaConfigString=pkinitEnabled))" attrs=ALL [18/Jul/2019:10:21:56.704608201 +1200] conn=583 op=10 RESULT err=0 tag=101 nentries=2 etime=0.0000683819 [18/Jul/2019:10:21:56.705498825 +1200] conn=583 op=11 SRCH base="cn=masters,cn=ipa,cn=etc,dc=domain,dc=nz" scope=2 filter="(|(cn=HTTP)(cn=KDC)(cn=KPASSWD))" attrs="ipaConfigString cn" [18/Jul/2019:10:21:56.706796444 +1200] conn=583 op=11 RESULT err=0 tag=101 nentries=6 etime=0.0001368352 [18/Jul/2019:10:21:56.708749851 +1200] conn=583 op=12 SRCH base="cn=masters,cn=ipa,cn=etc,dc=domain,dc=nz" scope=1 filter="(objectClass=ipaConfigObject)" attrs="cn" [18/Jul/2019:10:21:56.709139727 +1200] conn=583 op=12 RESULT err=0 tag=101 nentries=2 etime=0.0000448452 [18/Jul/2019:10:21:56.709984111 +1200] conn=583 op=13 SRCH base="cn=masters,cn=ipa,cn=etc,dc=domain,dc=nz" scope=2 filter="(cn=NTP)" attrs="ipaConfigString cn" [18/Jul/2019:10:21:56.710416641 +1200] conn=583 op=13 RESULT err=0 tag=101 nentries=2 etime=0.0000488232 [18/Jul/2019:10:21:56.711367461 +1200] conn=583 op=14 SRCH base="cn=masters,cn=ipa,cn=etc,dc=domain,dc=nz" scope=1 filter="(objectClass=ipaConfigObject)" attrs="cn" [18/Jul/2019:10:21:56.711833608 +1200] conn=583 op=14 RESULT err=0 tag=101 nentries=2 etime=0.0000524228 [18/Jul/2019:10:21:56.713643579 +1200] conn=583 op=15 EXT oid="1.3.6.1.4.1.4203.1.11.3" name="whoami-plugin" [18/Jul/2019:10:21:56.713690341 +1200] conn=583 op=15 RESULT err=0 tag=120 nentries=0 etime=0.0000101013 [18/Jul/2019:10:21:56.714058200 +1200] conn=583 op=16 SRCH base="uid=yusuf,cn=users,cn=accounts,dc=domain,dc=nz" scope=0 filter="(objectClass=*)" attrs=ALL [18/Jul/2019:10:21:56.715729610 +1200] conn=583 op=16 RESULT err=0 tag=101 nentries=1 etime=0.0001727481 [18/Jul/2019:10:21:56.718868186 +1200] conn=583 op=17 SRCH base="cn=masters,cn=ipa,cn=etc,dc=domain,dc=nz" scope=2 filter="(&(objectClass=ipaConfigObject)(cn=DNS))" attrs=ALL [18/Jul/2019:10:21:56.718989678 +1200] conn=583 op=17 RESULT err=0 tag=101 nentries=0 etime=0.0000188568 [18/Jul/2019:10:21:56.719877244 +1200] conn=583 op=18 SRCH base="cn=domain.nz,cn=ad,cn=etc,dc=domain,dc=nz" scope=0 filter="(objectClass=*)" attrs="ipaNTFallbackPrimaryGroup ipaNTDomainGUID ipaNTSecurityIdentifier ipaNTFlatName cn" [18/Jul/2019:10:21:56.720092858 +1200] conn=583 op=18 RESULT err=32 tag=101 nentries=0 etime=0.0000273232 [18/Jul/2019:10:21:56.720879107 +1200] conn=583 op=19 SRCH base="cn=Domain Level,cn=ipa,cn=etc,dc=domain,dc=nz" scope=0 filter="(objectClass=*)" attrs="ipaDomainLevel" [18/Jul/2019:10:21:56.721086262 +1200] conn=583 op=19 RESULT err=0 tag=101 nentries=1 etime=0.0000261847 [18/Jul/2019:10:21:56.722073309 +1200] conn=583 op=20 SRCH base="cn=masters,cn=ipa,cn=etc,dc=domain,dc=nz" scope=2 filter="(&(objectClass=ipaConfigObject)(cn=CA))" attrs=ALL [18/Jul/2019:10:21:56.722563885 +1200] conn=583 op=20 RESULT err=0 tag=101 nentries=1 etime=0.0000563697 [18/Jul/2019:10:21:56.723796927 +1200] conn=583 op=21 SRCH base="cn=masters,cn=ipa,cn=etc,dc=domain,dc=nz" scope=2 filter="(&(objectClass=ipaConfigObject)(cn=KRA))" attrs=ALL [18/Jul/2019:10:21:56.723897525 +1200] conn=583 op=21 RESULT err=0 tag=101 nentries=0 etime=0.0000158808 [18/Jul/2019:10:21:56.728927145 +1200] conn=583 op=22 UNBIND [18/Jul/2019:10:21:56.728942256 +1200] conn=583 op=22 fd=105 closed - U1 [18/Jul/2019:10:21:56.830427620 +1200] conn=584 fd=105 slot=105 connection from 172.30.2.21 to 172.30.2.21 [18/Jul/2019:10:21:56.832717397 +1200] conn=584 op=0 BIND dn="" method=sasl version=3 mech=GSS-SPNEGO [18/Jul/2019:10:21:56.834168014 +1200] conn=584 op=0 RESULT err=0 tag=97 nentries=0 etime=0.0001598537 dn="uid=yusuf,cn=users,cn=accounts,dc=domain,dc=nz" [18/Jul/2019:10:21:56.835656032 +1200] conn=584 op=1 SRCH base="cn=ipaconfig,cn=etc,dc=domain,dc=nz" scope=0 filter="(objectClass=*)" attrs=ALL [18/Jul/2019:10:21:56.836531899 +1200] conn=584 op=1 RESULT err=0 tag=101 nentries=1 etime=0.0000956733 [18/Jul/2019:10:21:56.837870697 +1200] conn=584 op=2 SRCH base="uid=yusuf,cn=users,cn=accounts,dc=domain,dc=nz" scope=0 filter="(objectClass=*)" attrs="distinguishedName" [18/Jul/2019:10:21:56.838107132 +1200] conn=584 op=2 RESULT err=0 tag=101 nentries=1 etime=0.0000295050 [18/Jul/2019:10:21:56.838763396 +1200] conn=584 op=3 SRCH base="uid=yusuf,cn=users,cn=accounts,dc=domain,dc=nz" scope=0 filter="(objectClass=*)" attrs="telephoneNumber uid krbCanonicalName ipatokenRadiusUserName ipaUserAuthType krbPrincipalExpiration homeDirectory nsAccountLock usercertificate;binary title loginShell * uidNumber mail ipaCertMapData memberOf memberofindirect krbPrincipalName givenName gidNumber sn ou userClass ipatokenRadiusConfigLink aci" [18/Jul/2019:10:21:56.840471566 +1200] conn=584 op=3 RESULT err=0 tag=101 nentries=1 etime=0.0001794160 [18/Jul/2019:10:21:56.841591391 +1200] conn=585 fd=115 slot=115 connection from 172.30.2.21 to 172.30.2.21 [18/Jul/2019:10:21:56.841875245 +1200] conn=584 op=4 SRCH base="dc=domain,dc=nz" scope=2 filter="(|(member=uid=yusuf,cn=users,cn=accounts,dc=domain,dc=nz)(memberUser=uid=yusuf,cn=users,cn=accounts,dc=domain,dc=nz)(memberHost=uid=yusuf,cn=users,cn=accounts,dc=domain,dc=nz))" attrs="" [18/Jul/2019:10:21:56.842518705 +1200] conn=584 op=4 RESULT err=0 tag=101 nentries=3 etime=0.0000712599 notes=P pr_idx=0 pr_cookie=-1 [18/Jul/2019:10:21:56.843442959 +1200] conn=584 op=5 SRCH base="uid=yusuf,cn=users,cn=accounts,dc=domain,dc=nz" scope=0 filter="(userPassword=*)" attrs="userPassword" [18/Jul/2019:10:21:56.843725735 +1200] conn=584 op=5 RESULT err=0 tag=101 nentries=1 etime=0.0000390450 [18/Jul/2019:10:21:56.844257371 +1200] conn=584 op=6 SRCH base="uid=yusuf,cn=users,cn=accounts,dc=domain,dc=nz" scope=0 filter="(krbPrincipalKey=*)" attrs="krbPrincipalKey" [18/Jul/2019:10:21:56.844555395 +1200] conn=584 op=6 RESULT err=0 tag=101 nentries=1 etime=0.0000355189 [18/Jul/2019:10:21:56.846600138 +1200] conn=585 op=0 BIND dn="" method=sasl version=3 mech=GSS-SPNEGO [18/Jul/2019:10:21:56.847912921 +1200] conn=586 fd=116 slot=116 connection from 172.30.2.21 to 172.30.2.21 [18/Jul/2019:10:21:56.847999855 +1200] conn=585 op=0 RESULT err=0 tag=97 nentries=0 etime=0.0001535869 dn="uid=yusuf,cn=users,cn=accounts,dc=domain,dc=nz" [18/Jul/2019:10:21:56.849786211 +1200] conn=586 op=0 BIND dn="" method=sasl version=3 mech=GSS-SPNEGO [18/Jul/2019:10:21:56.851164107 +1200] conn=586 op=0 RESULT err=0 tag=97 nentries=0 etime=0.0001510374 dn="uid=yusuf,cn=users,cn=accounts,dc=domain,dc=nz" [18/Jul/2019:10:21:56.852626523 +1200] conn=584 op=7 UNBIND [18/Jul/2019:10:21:56.852642659 +1200] conn=584 op=7 fd=105 closed - U1 [18/Jul/2019:10:21:56.941411799 +1200] conn=585 op=1 SRCH base="cn=ipaconfig,cn=etc,dc=domain,dc=nz" scope=0 filter="(objectClass=*)" attrs=ALL [18/Jul/2019:10:21:56.942275498 +1200] conn=585 op=1 RESULT err=0 tag=101 nentries=1 etime=0.0000956579 [18/Jul/2019:10:21:57.152672440 +1200] conn=585 op=2 UNBIND [18/Jul/2019:10:21:57.152700335 +1200] conn=585 op=2 fd=115 closed - U1 [18/Jul/2019:10:21:58.398652311 +1200] conn=586 op=1 UNBIND [18/Jul/2019:10:21:58.398679927 +1200] conn=586 op=1 fd=116 closed - U1 [18/Jul/2019:10:21:59.048701032 +1200] conn=587 fd=105 slot=105 connection from 172.30.2.21 to 172.30.2.21 [18/Jul/2019:10:21:59.050977127 +1200] conn=587 op=0 BIND dn="" method=sasl version=3 mech=GSS-SPNEGO [18/Jul/2019:10:21:59.052787349 +1200] conn=587 op=0 RESULT err=0 tag=97 nentries=0 etime=0.0002020278 dn="uid=yusuf,cn=users,cn=accounts,dc=domain,dc=nz" [18/Jul/2019:10:21:59.055142264 +1200] conn=587 op=1 SRCH base="cn=ipaconfig,cn=etc,dc=domain,dc=nz" scope=0 filter="(objectClass=*)" attrs=ALL [18/Jul/2019:10:21:59.055997890 +1200] conn=587 op=1 RESULT err=0 tag=101 nentries=1 etime=0.0000923790 [18/Jul/2019:10:21:59.057469066 +1200] conn=587 op=2 SRCH base="cn=users,cn=accounts,dc=domain,dc=nz" scope=1 filter="(objectClass=posixaccount)" attrs="ipaSshPubKey uid" [18/Jul/2019:10:21:59.059974320 +1200] conn=587 op=2 RESULT err=0 tag=101 nentries=11 etime=0.0002589671 [18/Jul/2019:10:21:59.063797326 +1200] conn=587 op=3 UNBIND [18/Jul/2019:10:21:59.063813734 +1200] conn=587 op=3 fd=105 closed - U1 [18/Jul/2019:10:22:09.973091530 +1200] conn=581 op=8 SRCH base="cn=accounts,dc=domain,dc=nz" scope=2 filter="(&(uid=mailer-daemon)(objectClass=posixAccount)(uid=*)(&(uidNumber=*)(!(uidNumber=0))))" attrs="objectClass uid userPassword uidNumber gidNumber gecos homeDirectory loginShell krbPrincipalName cn memberOf ipaUniqueID ipaNTSecurityIdentifier modifyTimestamp entryusn shadowLastChange shadowMin shadowMax shadowWarning shadowInactive shadowExpire shadowFlag krbLastPwdChange krbPasswordExpiration pwdattribute authorizedService accountexpires useraccountcontrol nsAccountLock host logindisabled loginexpirationtime loginallowedtimemap ipaSshPubKey ipaUserAuthType usercertificate;binary mail" [18/Jul/2019:10:22:09.973358086 +1200] conn=581 op=8 RESULT err=0 tag=101 nentries=0 etime=0.0000443012 [18/Jul/2019:10:22:33.376536162 +1200] conn=12 op=689 MOD dn="cn=MasterCRL,ou=crlIssuingPoints,ou=ca,o=ipaca" [18/Jul/2019:10:22:33.377910138 +1200] conn=12 op=689 RESULT err=0 tag=103 nentries=0 etime=0.0001508058 [18/Jul/2019:10:22:33.740188105 +1200] conn=21 op=438 SRCH base="ou=sessions,ou=Security Domain,o=ipaca" scope=2 filter="(objectClass=securityDomainSessionEntry)" attrs="cn" [18/Jul/2019:10:22:33.740362398 +1200] conn=21 op=438 RESULT err=32 tag=101 nentries=0 etime=0.0000273265 [18/Jul/2019:10:22:33.806163157 +1200] conn=588 fd=105 slot=105 connection from 172.30.3.21 to 172.30.2.21 [18/Jul/2019:10:22:33.806692050 +1200] conn=588 op=0 BIND dn="" method=sasl version=3 mech=GSSAPI [18/Jul/2019:10:22:33.809154382 +1200] conn=588 op=0 RESULT err=14 tag=97 nentries=0 etime=0.0002637408, SASL bind in progress [18/Jul/2019:10:22:33.809715142 +1200] conn=588 op=1 BIND dn="" method=sasl version=3 mech=GSSAPI [18/Jul/2019:10:22:33.810987188 +1200] conn=588 op=1 RESULT err=14 tag=97 nentries=0 etime=0.0001307738, SASL bind in progress [18/Jul/2019:10:22:33.811419905 +1200] conn=588 op=2 BIND dn="" method=sasl version=3 mech=GSSAPI [18/Jul/2019:10:22:33.812018971 +1200] conn=588 op=2 RESULT err=0 tag=97 nentries=0 etime=0.0000635169 dn="krbprincipalname=ldap/intauth-w.domain.nz@domain.nz,cn=services,cn=accounts,dc=domain,dc=nz" [18/Jul/2019:10:22:33.812506463 +1200] conn=588 op=3 SRCH base="" scope=0 filter="(objectClass=*)" attrs="supportedControl supportedExtension" [18/Jul/2019:10:22:33.813700412 +1200] conn=588 op=3 RESULT err=0 tag=101 nentries=1 etime=0.0001272735 [18/Jul/2019:10:22:33.814259613 +1200] conn=588 op=4 SRCH base="" scope=0 filter="(objectClass=*)" attrs="supportedControl supportedExtension" [18/Jul/2019:10:22:33.815425899 +1200] conn=588 op=4 RESULT err=0 tag=101 nentries=1 etime=0.0001220905 [18/Jul/2019:10:22:33.816031871 +1200] conn=588 op=5 EXT oid="2.16.840.1.113730.3.5.12" name="replication-multimaster-extop" [18/Jul/2019:10:22:33.816449793 +1200] conn=588 op=5 RESULT err=0 tag=120 nentries=0 etime=0.0000465534 [18/Jul/2019:10:22:33.818423321 +1200] conn=588 op=6 EXT oid="2.16.840.1.113730.3.5.5" name="replication-multimaster-extop" [18/Jul/2019:10:22:33.819035963 +1200] conn=588 op=6 RESULT err=0 tag=120 nentries=0 etime=0.0000648457
To expand on this, this issue is now also affecting the "Hosts" tab. An admin added a new host, and since then that tab has exhibited the same behaviour - individual hosts display when searched, but when no search is applied the error occurs.
Ben Schofield via FreeIPA-users wrote:
To expand on this, this issue is now also affecting the "Hosts" tab. An admin added a new host, and since then that tab has exhibited the same behaviour - individual hosts display when searched, but when no search is applied the error occurs.
Do you get the same behavior on the command-line if you run: ipa user-find?
rob
Interesting... yes, we do. This wasn't an issue when I posted here first, but since the Hosts page broke the CLI has followed:
[root@intauth-e ~]# ipa user-find --all ipa: INFO: trying https://intauth-e.domain.nz/ipa/json ipa: DEBUG: Created connection context.rpcclient_139931459505488 ipa: INFO: [try 1]: Forwarding 'schema' to json server 'https://intauth-e.domain.nz/ipa/json' ipa: DEBUG: New HTTP connection (intauth-e.domain.nz) ipa: DEBUG: HTTP connection destroyed (intauth-e.domain.nz) Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/ipalib/rpc.py", line 699, in single_request self.get_auth_info() File "/usr/lib/python2.7/site-packages/ipalib/rpc.py", line 651, in get_auth_info self._handle_exception(e, service=service) File "/usr/lib/python2.7/site-packages/ipalib/rpc.py", line 608, in _handle_exception raise errors.CCacheError() CCacheError: did not receive Kerberos credentials ipa: DEBUG: Destroyed connection context.rpcclient_139931459505488 ipa: ERROR: did not receive Kerberos credentials
Ben Schofield via FreeIPA-users wrote:
Interesting... yes, we do. This wasn't an issue when I posted here first, but since the Hosts page broke the CLI has followed:
[root@intauth-e ~]# ipa user-find --all ipa: INFO: trying https://intauth-e.domain.nz/ipa/json ipa: DEBUG: Created connection context.rpcclient_139931459505488 ipa: INFO: [try 1]: Forwarding 'schema' to json server 'https://intauth-e.domain.nz/ipa/json' ipa: DEBUG: New HTTP connection (intauth-e.domain.nz) ipa: DEBUG: HTTP connection destroyed (intauth-e.domain.nz) Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/ipalib/rpc.py", line 699, in single_request self.get_auth_info() File "/usr/lib/python2.7/site-packages/ipalib/rpc.py", line 651, in get_auth_info self._handle_exception(e, service=service) File "/usr/lib/python2.7/site-packages/ipalib/rpc.py", line 608, in _handle_exception raise errors.CCacheError() CCacheError: did not receive Kerberos credentials ipa: DEBUG: Destroyed connection context.rpcclient_139931459505488 ipa: ERROR: did not receive Kerberos credentials
You'll need to poke through the server logs to see what is going on. I'd start with the Apache log. We've seen that the 389-ds logs seem ok.
Are all the services running ok? ipactl status
rob
Yep, all services are running. This is from the Apache error log, right after login and trying to load the Users page:
[Mon Jul 22 10:12:35.083278 2019] [:error] [pid 14474] ipa: DEBUG: WSGI wsgi_dispatch.__call__: [Mon Jul 22 10:12:35.083381 2019] [:error] [pid 14474] ipa: DEBUG: WSGI login_password.__call__: [Mon Jul 22 10:12:35.083996 2019] [:error] [pid 14474] ipa: DEBUG: Obtaining armor in ccache /var/run/ipa/ccaches/armor_14474 [Mon Jul 22 10:12:35.084074 2019] [:error] [pid 14474] ipa: DEBUG: Initializing anonymous ccache [Mon Jul 22 10:12:35.084211 2019] [:error] [pid 14474] ipa: DEBUG: Starting external process [Mon Jul 22 10:12:35.084261 2019] [:error] [pid 14474] ipa: DEBUG: args=/usr/bin/kinit -n -c /var/run/ipa/ccaches/armor_14474 -X X509_anchors=FILE:/var/kerberos/krb5kdc/kdc.crt -X X509_anchors=FILE:/var/lib/ipa-client/pki/kdc-ca-bundle.pem [Mon Jul 22 10:12:35.135499 2019] [:error] [pid 14474] ipa: DEBUG: Process finished, return code=0 [Mon Jul 22 10:12:35.135593 2019] [:error] [pid 14474] ipa: DEBUG: stdout= [Mon Jul 22 10:12:35.135638 2019] [:error] [pid 14474] ipa: DEBUG: stderr= [Mon Jul 22 10:12:35.135866 2019] [:error] [pid 14474] ipa: DEBUG: Initializing principal admin using password [Mon Jul 22 10:12:35.135925 2019] [:error] [pid 14474] ipa: DEBUG: Using armor ccache /var/run/ipa/ccaches/armor_14474 for FAST webauth [Mon Jul 22 10:12:35.135968 2019] [:error] [pid 14474] ipa: DEBUG: Using enterprise principal [Mon Jul 22 10:12:35.136067 2019] [:error] [pid 14474] ipa: DEBUG: Starting external process [Mon Jul 22 10:12:35.136112 2019] [:error] [pid 14474] ipa: DEBUG: args=/usr/bin/kinit admin -c /var/run/ipa/ccaches/kinit_14474 -T /var/run/ipa/ccaches/armor_14474 -E [Mon Jul 22 10:12:35.163806 2019] [:error] [pid 14474] ipa: DEBUG: Process finished, return code=0 [Mon Jul 22 10:12:35.163895 2019] [:error] [pid 14474] ipa: DEBUG: stdout=Password for admin@DOMAIN.NZ: [Mon Jul 22 10:12:35.163903 2019] [:error] [pid 14474] [Mon Jul 22 10:12:35.163942 2019] [:error] [pid 14474] ipa: DEBUG: stderr= [Mon Jul 22 10:12:35.164042 2019] [:error] [pid 14474] ipa: DEBUG: Cleanup the armor ccache [Mon Jul 22 10:12:35.164154 2019] [:error] [pid 14474] ipa: DEBUG: Starting external process [Mon Jul 22 10:12:35.164198 2019] [:error] [pid 14474] ipa: DEBUG: args=/usr/bin/kdestroy -A -c /var/run/ipa/ccaches/armor_14474 [Mon Jul 22 10:12:35.172420 2019] [:error] [pid 14474] ipa: DEBUG: Process finished, return code=0 [Mon Jul 22 10:12:35.172516 2019] [:error] [pid 14474] ipa: DEBUG: stdout= [Mon Jul 22 10:12:35.172565 2019] [:error] [pid 14474] ipa: DEBUG: stderr= [Mon Jul 22 10:12:35.189068 2019] [:error] [pid 14474] ipa: INFO: Starting new HTTP connection (1): intauth-e.domain.nz [Mon Jul 22 10:12:35.190276 2019] [:error] [pid 14474] ipa: DEBUG: "GET /ipa/session/cookie HTTP/1.1" 301 259 [Mon Jul 22 10:12:35.192124 2019] [:error] [pid 14474] ipa: INFO: Starting new HTTPS connection (1): intauth-e.domain.nz [Mon Jul 22 10:12:35.214459 2019] [:error] [pid 14474] ipa: DEBUG: "GET /ipa/session/cookie HTTP/1.1" 200 0 [Mon Jul 22 10:12:35.708087 2019] [:error] [pid 14475] ipa: DEBUG: WSGI wsgi_dispatch.__call__: [Mon Jul 22 10:12:35.708190 2019] [:error] [pid 14475] ipa: DEBUG: WSGI jsonserver_session.__call__: [Mon Jul 22 10:12:35.722673 2019] [:error] [pid 14475] ipa: DEBUG: Created connection context.ldap2_140655759869968 [Mon Jul 22 10:12:35.722743 2019] [:error] [pid 14475] ipa: DEBUG: WSGI jsonserver.__call__: [Mon Jul 22 10:12:35.722798 2019] [:error] [pid 14475] ipa: DEBUG: WSGI WSGIExecutioner.__call__: [Mon Jul 22 10:12:35.732842 2019] [:error] [pid 14475] ipa: DEBUG: raw: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True) [Mon Jul 22 10:12:35.733197 2019] [:error] [pid 14475] ipa: DEBUG: user_find(None, sizelimit=0, whoami=False, all=False, raw=False, version=u'2.230', no_members=True, pkey_only=True) [Mon Jul 22 10:12:35.735792 2019] [:error] [pid 14475] ipa: DEBUG: retrieving schema for SchemaCache url=ldapi://%2fvar%2frun%2fslapd-DOMAIN-NZ.socket conn=<ldap.ldapobject.SimpleLDAPObject instance at 0x7fecf7febcb0> [Mon Jul 22 10:12:35.963886 2019] [:warn] [pid 14478] [client 10.0.201.253:18606] failed to set perms (3140) on file (/var/run/ipa/ccaches/admin@DOMAIN.NZ)!, referer: https://intauth-e.domain.nz/ipa/ui/ [Mon Jul 22 10:12:35.964864 2019] [:error] [pid 14473] ipa: DEBUG: WSGI wsgi_dispatch.__call__: [Mon Jul 22 10:12:35.964951 2019] [:error] [pid 14473] ipa: DEBUG: WSGI jsonserver_session.__call__: [Mon Jul 22 10:12:35.975471 2019] [:error] [pid 14473] ipa: DEBUG: Created connection context.ldap2_140655759869968 [Mon Jul 22 10:12:35.975538 2019] [:error] [pid 14473] ipa: DEBUG: WSGI jsonserver.__call__: [Mon Jul 22 10:12:35.975597 2019] [:error] [pid 14473] ipa: DEBUG: WSGI WSGIExecutioner.__call__: [Mon Jul 22 10:12:35.985387 2019] [:error] [pid 14473] ipa: DEBUG: raw: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True) [Mon Jul 22 10:12:35.985762 2019] [:error] [pid 14473] ipa: DEBUG: user_find(None, sizelimit=0, whoami=False, all=False, raw=False, version=u'2.230', no_members=True, pkey_only=True) [Mon Jul 22 10:12:35.988056 2019] [:error] [pid 14473] ipa: DEBUG: retrieving schema for SchemaCache url=ldapi://%2fvar%2frun%2fslapd-DOMAIN-NZ.socket conn=<ldap.ldapobject.SimpleLDAPObject instance at 0x7fecf7febcb0> [Mon Jul 22 10:12:36.021489 2019] [:error] [pid 14475] ipa: INFO: [jsonserver_session] admin@DOMAIN.NZ: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True): SUCCESS [Mon Jul 22 10:12:36.022673 2019] [:error] [pid 14475] ipa: DEBUG: Destroyed connection context.ldap2_140655759869968 [Mon Jul 22 10:12:36.272817 2019] [:error] [pid 14473] ipa: INFO: [jsonserver_session] admin@DOMAIN.NZ: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True): SUCCESS [Mon Jul 22 10:12:36.273918 2019] [:error] [pid 14473] ipa: DEBUG: Destroyed connection context.ldap2_140655759869968 [Mon Jul 22 10:14:03.993422 2019] [:error] [pid 14477] SSL Library Error: -12195 Peer does not recognize and trust the CA that issued your certificate
The certificate is same self-signed certificate that was created during installation by the installer.
Though it's only a warning, I temporarily set 777 perms on this file "/var/run/ipa/ccaches/admin@DOMAIN.NZ" to see if it would help. It didn't. The file is updated frequently anyway (owned by ipaapi) so I think that warning is a red herring.
On 7/22/19 12:22 AM, Ben Schofield via FreeIPA-users wrote:
Yep, all services are running. This is from the Apache error log, right after login and trying to load the Users page:
[Mon Jul 22 10:12:35.083278 2019] [:error] [pid 14474] ipa: DEBUG: WSGI wsgi_dispatch.__call__: [Mon Jul 22 10:12:35.083381 2019] [:error] [pid 14474] ipa: DEBUG: WSGI login_password.__call__: [Mon Jul 22 10:12:35.083996 2019] [:error] [pid 14474] ipa: DEBUG: Obtaining armor in ccache /var/run/ipa/ccaches/armor_14474 [Mon Jul 22 10:12:35.084074 2019] [:error] [pid 14474] ipa: DEBUG: Initializing anonymous ccache [Mon Jul 22 10:12:35.084211 2019] [:error] [pid 14474] ipa: DEBUG: Starting external process [Mon Jul 22 10:12:35.084261 2019] [:error] [pid 14474] ipa: DEBUG: args=/usr/bin/kinit -n -c /var/run/ipa/ccaches/armor_14474 -X X509_anchors=FILE:/var/kerberos/krb5kdc/kdc.crt -X X509_anchors=FILE:/var/lib/ipa-client/pki/kdc-ca-bundle.pem [Mon Jul 22 10:12:35.135499 2019] [:error] [pid 14474] ipa: DEBUG: Process finished, return code=0 [Mon Jul 22 10:12:35.135593 2019] [:error] [pid 14474] ipa: DEBUG: stdout= [Mon Jul 22 10:12:35.135638 2019] [:error] [pid 14474] ipa: DEBUG: stderr= [Mon Jul 22 10:12:35.135866 2019] [:error] [pid 14474] ipa: DEBUG: Initializing principal admin using password [Mon Jul 22 10:12:35.135925 2019] [:error] [pid 14474] ipa: DEBUG: Using armor ccache /var/run/ipa/ccaches/armor_14474 for FAST webauth [Mon Jul 22 10:12:35.135968 2019] [:error] [pid 14474] ipa: DEBUG: Using enterprise principal [Mon Jul 22 10:12:35.136067 2019] [:error] [pid 14474] ipa: DEBUG: Starting external process [Mon Jul 22 10:12:35.136112 2019] [:error] [pid 14474] ipa: DEBUG: args=/usr/bin/kinit admin -c /var/run/ipa/ccaches/kinit_14474 -T /var/run/ipa/ccaches/armor_14474 -E [Mon Jul 22 10:12:35.163806 2019] [:error] [pid 14474] ipa: DEBUG: Process finished, return code=0 [Mon Jul 22 10:12:35.163895 2019] [:error] [pid 14474] ipa: DEBUG: stdout=Password for admin@DOMAIN.NZ: [Mon Jul 22 10:12:35.163903 2019] [:error] [pid 14474] [Mon Jul 22 10:12:35.163942 2019] [:error] [pid 14474] ipa: DEBUG: stderr= [Mon Jul 22 10:12:35.164042 2019] [:error] [pid 14474] ipa: DEBUG: Cleanup the armor ccache [Mon Jul 22 10:12:35.164154 2019] [:error] [pid 14474] ipa: DEBUG: Starting external process [Mon Jul 22 10:12:35.164198 2019] [:error] [pid 14474] ipa: DEBUG: args=/usr/bin/kdestroy -A -c /var/run/ipa/ccaches/armor_14474 [Mon Jul 22 10:12:35.172420 2019] [:error] [pid 14474] ipa: DEBUG: Process finished, return code=0 [Mon Jul 22 10:12:35.172516 2019] [:error] [pid 14474] ipa: DEBUG: stdout= [Mon Jul 22 10:12:35.172565 2019] [:error] [pid 14474] ipa: DEBUG: stderr= [Mon Jul 22 10:12:35.189068 2019] [:error] [pid 14474] ipa: INFO: Starting new HTTP connection (1): intauth-e.domain.nz [Mon Jul 22 10:12:35.190276 2019] [:error] [pid 14474] ipa: DEBUG: "GET /ipa/session/cookie HTTP/1.1" 301 259 [Mon Jul 22 10:12:35.192124 2019] [:error] [pid 14474] ipa: INFO: Starting new HTTPS connection (1): intauth-e.domain.nz [Mon Jul 22 10:12:35.214459 2019] [:error] [pid 14474] ipa: DEBUG: "GET /ipa/session/cookie HTTP/1.1" 200 0 [Mon Jul 22 10:12:35.708087 2019] [:error] [pid 14475] ipa: DEBUG: WSGI wsgi_dispatch.__call__: [Mon Jul 22 10:12:35.708190 2019] [:error] [pid 14475] ipa: DEBUG: WSGI jsonserver_session.__call__: [Mon Jul 22 10:12:35.722673 2019] [:error] [pid 14475] ipa: DEBUG: Created connection context.ldap2_140655759869968 [Mon Jul 22 10:12:35.722743 2019] [:error] [pid 14475] ipa: DEBUG: WSGI jsonserver.__call__: [Mon Jul 22 10:12:35.722798 2019] [:error] [pid 14475] ipa: DEBUG: WSGI WSGIExecutioner.__call__: [Mon Jul 22 10:12:35.732842 2019] [:error] [pid 14475] ipa: DEBUG: raw: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True) [Mon Jul 22 10:12:35.733197 2019] [:error] [pid 14475] ipa: DEBUG: user_find(None, sizelimit=0, whoami=False, all=False, raw=False, version=u'2.230', no_members=True, pkey_only=True) [Mon Jul 22 10:12:35.735792 2019] [:error] [pid 14475] ipa: DEBUG: retrieving schema for SchemaCache url=ldapi://%2fvar%2frun%2fslapd-DOMAIN-NZ.socket conn=<ldap.ldapobject.SimpleLDAPObject instance at 0x7fecf7febcb0> [Mon Jul 22 10:12:35.963886 2019] [:warn] [pid 14478] [client 10.0.201.253:18606] failed to set perms (3140) on file (/var/run/ipa/ccaches/admin@DOMAIN.NZ)!, referer: https://intauth-e.domain.nz/ipa/ui/ [Mon Jul 22 10:12:35.964864 2019] [:error] [pid 14473] ipa: DEBUG: WSGI wsgi_dispatch.__call__: [Mon Jul 22 10:12:35.964951 2019] [:error] [pid 14473] ipa: DEBUG: WSGI jsonserver_session.__call__: [Mon Jul 22 10:12:35.975471 2019] [:error] [pid 14473] ipa: DEBUG: Created connection context.ldap2_140655759869968 [Mon Jul 22 10:12:35.975538 2019] [:error] [pid 14473] ipa: DEBUG: WSGI jsonserver.__call__: [Mon Jul 22 10:12:35.975597 2019] [:error] [pid 14473] ipa: DEBUG: WSGI WSGIExecutioner.__call__: [Mon Jul 22 10:12:35.985387 2019] [:error] [pid 14473] ipa: DEBUG: raw: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True) [Mon Jul 22 10:12:35.985762 2019] [:error] [pid 14473] ipa: DEBUG: user_find(None, sizelimit=0, whoami=False, all=False, raw=False, version=u'2.230', no_members=True, pkey_only=True) [Mon Jul 22 10:12:35.988056 2019] [:error] [pid 14473] ipa: DEBUG: retrieving schema for SchemaCache url=ldapi://%2fvar%2frun%2fslapd-DOMAIN-NZ.socket conn=<ldap.ldapobject.SimpleLDAPObject instance at 0x7fecf7febcb0> [Mon Jul 22 10:12:36.021489 2019] [:error] [pid 14475] ipa: INFO: [jsonserver_session] admin@DOMAIN.NZ: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True): SUCCESS [Mon Jul 22 10:12:36.022673 2019] [:error] [pid 14475] ipa: DEBUG: Destroyed connection context.ldap2_140655759869968 [Mon Jul 22 10:12:36.272817 2019] [:error] [pid 14473] ipa: INFO: [jsonserver_session] admin@DOMAIN.NZ: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True): SUCCESS [Mon Jul 22 10:12:36.273918 2019] [:error] [pid 14473] ipa: DEBUG: Destroyed connection context.ldap2_140655759869968 [Mon Jul 22 10:14:03.993422 2019] [:error] [pid 14477] SSL Library Error: -12195 Peer does not recognize and trust the CA that issued your certificate
The certificate is same self-signed certificate that was created during installation by the installer.
Hi, I would check the permissions of the file /etc/ipa/ca.crt on the client (the host where you run ipa user-find). 0644 is expected. If SElinux is enabled, it should have unconfined_u:object_r:etc_t:s0. Does this file contain the self-signed CA?
You can also have a look at the permissions of the files in /var/lib/ipa-client/pki: # ls -l /var/lib/ipa-client/pki total 8 -rw-r--r--. 1 root root 3034 Jul 22 10:04 ca-bundle.pem -rw-r--r--. 1 root root 3034 Jul 22 10:04 kdc-ca-bundle.pem These files should also contain the self-signed CA.
flo
Though it's only a warning, I temporarily set 777 perms on this file "/var/run/ipa/ccaches/admin@DOMAIN.NZ" to see if it would help. It didn't. The file is updated frequently anyway (owned by ipaapi) so I think that warning is a red herring. _______________________________________________ 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.fedorahoste...
On 7/22/19 12:22 AM, Ben Schofield via FreeIPA-users wrote: Hi, I would check the permissions of the file /etc/ipa/ca.crt on the client (the host where you run ipa user-find). 0644 is expected. If SElinux is enabled, it should have unconfined_u:object_r:etc_t:s0. Does this file contain the self-signed CA?
You can also have a look at the permissions of the files in /var/lib/ipa-client/pki: # ls -l /var/lib/ipa-client/pki total 8 -rw-r--r--. 1 root root 3034 Jul 22 10:04 ca-bundle.pem -rw-r--r--. 1 root root 3034 Jul 22 10:04 kdc-ca-bundle.pem These files should also contain the self-signed CA.
flo
Hi flo,
I ran the command "ipa user-find" on the server itself, and was able to successfully list all users. Permissions of the ca.crt are also expected 0644 -rw-r--r-- 1 root root 1302 Jun 26 15:38 ca.crt Yes this file contains the self-signed CA.
SElinux is disabled on the server and clients.
Permissions of the files in /var/lib/ipa-client/pki are also expected 0644 -rw-r--r-- 1 root root 1302 Jun 26 15:41 ca-bundle.pem -rw-r--r-- 1 root root 1302 Jun 26 15:41 kdc-ca-bundle.pem They also contain the same self-signed CA.
Yusuf
On su, 21 heinä 2019, Ben Schofield via FreeIPA-users wrote:
Yep, all services are running. This is from the Apache error log, right after login and trying to load the Users page:
[Mon Jul 22 10:12:36.022673 2019] [:error] [pid 14475] ipa: DEBUG: Destroyed connection context.ldap2_140655759869968 [Mon Jul 22 10:12:36.272817 2019] [:error] [pid 14473] ipa: INFO: [jsonserver_session] admin@DOMAIN.NZ: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True): SUCCESS [Mon Jul 22 10:12:36.273918 2019] [:error] [pid 14473] ipa: DEBUG: Destroyed connection context.ldap2_140655759869968 [Mon Jul 22 10:14:03.993422 2019] [:error] [pid 14477] SSL Library Error: -12195 Peer does not recognize and trust the CA that issued your certificate
The error above says that a client is not trusting CA certificate. So the problem is on the client side, not a server one.
Like Flo said, check whether /etc/ipa/ca.crt is readable and is available for a client that uses it.
On su, 21 heinä 2019, Ben Schofield via FreeIPA-users wrote:
The error above says that a client is not trusting CA certificate. So the problem is on the client side, not a server one.
Like Flo said, check whether /etc/ipa/ca.crt is readable and is available for a client that uses it.
Hi Alexander,
I have checked the certificates and they look ok permission wise.
The problem is only on the web UI where the users and hosts fail to load.
Searching for individual users/host on the UI works.
Listing all hosts or users from CLI works too, from server and clients.
What else could we check?
Thanks
Ben Schofield via FreeIPA-users wrote:
Yep, all services are running. This is from the Apache error log, right after login and trying to load the Users page:
[Mon Jul 22 10:12:35.083278 2019] [:error] [pid 14474] ipa: DEBUG: WSGI wsgi_dispatch.__call__: [Mon Jul 22 10:12:35.083381 2019] [:error] [pid 14474] ipa: DEBUG: WSGI login_password.__call__: [Mon Jul 22 10:12:35.083996 2019] [:error] [pid 14474] ipa: DEBUG: Obtaining armor in ccache /var/run/ipa/ccaches/armor_14474 [Mon Jul 22 10:12:35.084074 2019] [:error] [pid 14474] ipa: DEBUG: Initializing anonymous ccache [Mon Jul 22 10:12:35.084211 2019] [:error] [pid 14474] ipa: DEBUG: Starting external process [Mon Jul 22 10:12:35.084261 2019] [:error] [pid 14474] ipa: DEBUG: args=/usr/bin/kinit -n -c /var/run/ipa/ccaches/armor_14474 -X X509_anchors=FILE:/var/kerberos/krb5kdc/kdc.crt -X X509_anchors=FILE:/var/lib/ipa-client/pki/kdc-ca-bundle.pem [Mon Jul 22 10:12:35.135499 2019] [:error] [pid 14474] ipa: DEBUG: Process finished, return code=0 [Mon Jul 22 10:12:35.135593 2019] [:error] [pid 14474] ipa: DEBUG: stdout= [Mon Jul 22 10:12:35.135638 2019] [:error] [pid 14474] ipa: DEBUG: stderr= [Mon Jul 22 10:12:35.135866 2019] [:error] [pid 14474] ipa: DEBUG: Initializing principal admin using password [Mon Jul 22 10:12:35.135925 2019] [:error] [pid 14474] ipa: DEBUG: Using armor ccache /var/run/ipa/ccaches/armor_14474 for FAST webauth [Mon Jul 22 10:12:35.135968 2019] [:error] [pid 14474] ipa: DEBUG: Using enterprise principal [Mon Jul 22 10:12:35.136067 2019] [:error] [pid 14474] ipa: DEBUG: Starting external process [Mon Jul 22 10:12:35.136112 2019] [:error] [pid 14474] ipa: DEBUG: args=/usr/bin/kinit admin -c /var/run/ipa/ccaches/kinit_14474 -T /var/run/ipa/ccaches/armor_14474 -E [Mon Jul 22 10:12:35.163806 2019] [:error] [pid 14474] ipa: DEBUG: Process finished, return code=0 [Mon Jul 22 10:12:35.163895 2019] [:error] [pid 14474] ipa: DEBUG: stdout=Password for admin@DOMAIN.NZ: [Mon Jul 22 10:12:35.163903 2019] [:error] [pid 14474] [Mon Jul 22 10:12:35.163942 2019] [:error] [pid 14474] ipa: DEBUG: stderr= [Mon Jul 22 10:12:35.164042 2019] [:error] [pid 14474] ipa: DEBUG: Cleanup the armor ccache [Mon Jul 22 10:12:35.164154 2019] [:error] [pid 14474] ipa: DEBUG: Starting external process [Mon Jul 22 10:12:35.164198 2019] [:error] [pid 14474] ipa: DEBUG: args=/usr/bin/kdestroy -A -c /var/run/ipa/ccaches/armor_14474 [Mon Jul 22 10:12:35.172420 2019] [:error] [pid 14474] ipa: DEBUG: Process finished, return code=0 [Mon Jul 22 10:12:35.172516 2019] [:error] [pid 14474] ipa: DEBUG: stdout= [Mon Jul 22 10:12:35.172565 2019] [:error] [pid 14474] ipa: DEBUG: stderr= [Mon Jul 22 10:12:35.189068 2019] [:error] [pid 14474] ipa: INFO: Starting new HTTP connection (1): intauth-e.domain.nz [Mon Jul 22 10:12:35.190276 2019] [:error] [pid 14474] ipa: DEBUG: "GET /ipa/session/cookie HTTP/1.1" 301 259 [Mon Jul 22 10:12:35.192124 2019] [:error] [pid 14474] ipa: INFO: Starting new HTTPS connection (1): intauth-e.domain.nz [Mon Jul 22 10:12:35.214459 2019] [:error] [pid 14474] ipa: DEBUG: "GET /ipa/session/cookie HTTP/1.1" 200 0 [Mon Jul 22 10:12:35.708087 2019] [:error] [pid 14475] ipa: DEBUG: WSGI wsgi_dispatch.__call__: [Mon Jul 22 10:12:35.708190 2019] [:error] [pid 14475] ipa: DEBUG: WSGI jsonserver_session.__call__: [Mon Jul 22 10:12:35.722673 2019] [:error] [pid 14475] ipa: DEBUG: Created connection context.ldap2_140655759869968 [Mon Jul 22 10:12:35.722743 2019] [:error] [pid 14475] ipa: DEBUG: WSGI jsonserver.__call__: [Mon Jul 22 10:12:35.722798 2019] [:error] [pid 14475] ipa: DEBUG: WSGI WSGIExecutioner.__call__: [Mon Jul 22 10:12:35.732842 2019] [:error] [pid 14475] ipa: DEBUG: raw: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True) [Mon Jul 22 10:12:35.733197 2019] [:error] [pid 14475] ipa: DEBUG: user_find(None, sizelimit=0, whoami=False, all=False, raw=False, version=u'2.230', no_members=True, pkey_only=True) [Mon Jul 22 10:12:35.735792 2019] [:error] [pid 14475] ipa: DEBUG: retrieving schema for SchemaCache url=ldapi://%2fvar%2frun%2fslapd-DOMAIN-NZ.socket conn=<ldap.ldapobject.SimpleLDAPObject instance at 0x7fecf7febcb0> [Mon Jul 22 10:12:35.963886 2019] [:warn] [pid 14478] [client 10.0.201.253:18606] failed to set perms (3140) on file (/var/run/ipa/ccaches/admin@DOMAIN.NZ)!, referer: https://intauth-e.domain.nz/ipa/ui/ [Mon Jul 22 10:12:35.964864 2019] [:error] [pid 14473] ipa: DEBUG: WSGI wsgi_dispatch.__call__: [Mon Jul 22 10:12:35.964951 2019] [:error] [pid 14473] ipa: DEBUG: WSGI jsonserver_session.__call__: [Mon Jul 22 10:12:35.975471 2019] [:error] [pid 14473] ipa: DEBUG: Created connection context.ldap2_140655759869968 [Mon Jul 22 10:12:35.975538 2019] [:error] [pid 14473] ipa: DEBUG: WSGI jsonserver.__call__: [Mon Jul 22 10:12:35.975597 2019] [:error] [pid 14473] ipa: DEBUG: WSGI WSGIExecutioner.__call__: [Mon Jul 22 10:12:35.985387 2019] [:error] [pid 14473] ipa: DEBUG: raw: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True) [Mon Jul 22 10:12:35.985762 2019] [:error] [pid 14473] ipa: DEBUG: user_find(None, sizelimit=0, whoami=False, all=False, raw=False, version=u'2.230', no_members=True, pkey_only=True) [Mon Jul 22 10:12:35.988056 2019] [:error] [pid 14473] ipa: DEBUG: retrieving schema for SchemaCache url=ldapi://%2fvar%2frun%2fslapd-DOMAIN-NZ.socket conn=<ldap.ldapobject.SimpleLDAPObject instance at 0x7fecf7febcb0> [Mon Jul 22 10:12:36.021489 2019] [:error] [pid 14475] ipa: INFO: [jsonserver_session] admin@DOMAIN.NZ: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True): SUCCESS [Mon Jul 22 10:12:36.022673 2019] [:error] [pid 14475] ipa: DEBUG: Destroyed connection context.ldap2_140655759869968 [Mon Jul 22 10:12:36.272817 2019] [:error] [pid 14473] ipa: INFO: [jsonserver_session] admin@DOMAIN.NZ: user_find(u'', sizelimit=0, version=u'2.230', pkey_only=True): SUCCESS [Mon Jul 22 10:12:36.273918 2019] [:error] [pid 14473] ipa: DEBUG: Destroyed connection context.ldap2_140655759869968 [Mon Jul 22 10:14:03.993422 2019] [:error] [pid 14477] SSL Library Error: -12195 Peer does not recognize and trust the CA that issued your certificate
The certificate is same self-signed certificate that was created during installation by the installer.
Though it's only a warning, I temporarily set 777 perms on this file "/var/run/ipa/ccaches/admin@DOMAIN.NZ" to see if it would help. It didn't. The file is updated frequently anyway (owned by ipaapi) so I think that warning is a red herring.
I think the certificate error might be a red herring. The other requests look like they are working fine. You could double-check this by trying again on a quiet system to confirm that no errors are thrown.
I looked at the client side you had provided earlier and it failed with a CCacheError. Had you done a kinit beforehand? The above shows requests coming in, can you show the client-side for this?
rob
Ben Schofield via FreeIPA-users wrote:
I think the certificate error might be a red herring. The other requests look like they are working fine. You could double-check this by trying again on a quiet system to confirm that no errors are thrown.
I looked at the client side you had provided earlier and it failed with a CCacheError. Had you done a kinit beforehand? The above shows requests coming in, can you show the client-side for this?
rob
Hi Rob,
I think so too, the certs seem fine to me. I ran the ipa commands after kinit, and they work fine without any CCacheErrors.
How do you mean show the client-side for this? We are running the ipa commands on the server itself.
Thanks
Yusuf
freeipa-users@lists.fedorahosted.org
-
Alexander Bokovoy -
Ben Schofield -
Florence Blanc-Renaud -
Rob Crittenden -
Yusuf Shamim