#6739 Cannot login to replica's WebUI
Closed: fixed Opened by stlaz.

After a replica has been set up, there's no way to log in to the WebUI.

  1. Set up an IPA master
  2. Set up an IPA replica
  3. In firefox, go to replica's hostname
  4. Try to log in

Expected result:
User gets successfully logged in the Web UI.

Actual result:
There's a red message Login failed due to an unknown reason.

Further info:
/var/log/http/error_log:

c1:ad8d:208] mod_wsgi (pid=127361): Exception occurred processing WSGI script '/usr/share/ipa/wsgi.py'.
[Wed Mar 08 17:08:06.024523 2017] [wsgi:error] [pid 127361] [remote 2620:52:0:2280:6af7:28ff:fec1:ad8d:208] Traceback (most recent call last):
[Wed Mar 08 17:08:06.024565 2017] [wsgi:error] [pid 127361] [remote 2620:52:0:2280:6af7:28ff:fec1:ad8d:208]   File "/usr/share/ipa/wsgi.py", line 51, in application
[Wed Mar 08 17:08:06.024660 2017] [wsgi:error] [pid 127361] [remote 2620:52:0:2280:6af7:28ff:fec1:ad8d:208]     return api.Backend.wsgi_dispatch(environ, start_response)
[Wed Mar 08 17:08:06.024682 2017] [wsgi:error] [pid 127361] [remote 2620:52:0:2280:6af7:28ff:fec1:ad8d:208]   File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 263, in __call__
[Wed Mar 08 17:08:06.024742 2017] [wsgi:error] [pid 127361] [remote 2620:52:0:2280:6af7:28ff:fec1:ad8d:208]     return self.route(environ, start_response)
[Wed Mar 08 17:08:06.024774 2017] [wsgi:error] [pid 127361] [remote 2620:52:0:2280:6af7:28ff:fec1:ad8d:208]   File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 275, in route
[Wed Mar 08 17:08:06.024800 2017] [wsgi:error] [pid 127361] [remote 2620:52:0:2280:6af7:28ff:fec1:ad8d:208]     return app(environ, start_response)
[Wed Mar 08 17:08:06.024815 2017] [wsgi:error] [pid 127361] [remote 2620:52:0:2280:6af7:28ff:fec1:ad8d:208]   File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 921, in __call__
[Wed Mar 08 17:08:06.024856 2017] [wsgi:error] [pid 127361] [remote 2620:52:0:2280:6af7:28ff:fec1:ad8d:208]     self.kinit(user, self.api.env.realm, password, ipa_ccache_name)
[Wed Mar 08 17:08:06.024871 2017] [wsgi:error] [pid 127361] [remote 2620:52:0:2280:6af7:28ff:fec1:ad8d:208]   File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 955, in kinit
[Wed Mar 08 17:08:06.024893 2017] [wsgi:error] [pid 127361] [remote 2620:52:0:2280:6af7:28ff:fec1:ad8d:208]     kinit_armor(armor_path)
[Wed Mar 08 17:08:06.024910 2017] [wsgi:error] [pid 127361] [remote 2620:52:0:2280:6af7:28ff:fec1:ad8d:208]   File "/usr/lib/python2.7/site-packages/ipalib/install/kinit.py", line 125, in kinit_armor
[Wed Mar 08 17:08:06.024938 2017] [wsgi:error] [pid 127361] [remote 2620:52:0:2280:6af7:28ff:fec1:ad8d:208]     run(args, env=env, raiseonerr=True, capture_error=True)
[Wed Mar 08 17:08:06.024965 2017] [wsgi:error] [pid 127361] [remote 2620:52:0:2280:6af7:28ff:fec1:ad8d:208]   File "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 495, in run
[Wed Mar 08 17:08:06.024993 2017] [wsgi:error] [pid 127361] [remote 2620:52:0:2280:6af7:28ff:fec1:ad8d:208]     raise CalledProcessError(p.returncode, arg_string, str(output))
[Wed Mar 08 17:08:06.025044 2017] [wsgi:error] [pid 127361] [remote 2620:52:0:2280:6af7:28ff:fec1:ad8d:208] CalledProcessError: Command '/usr/bin/kinit -n -c /var/run/ipa/ccaches/armor_127361' returned non-zero exit status 1

/var/log/httpd/access_log:

2620:52:0:2280:6af7:28ff:fec1:ad8d - - [08/Mar/2017:17:08:05 +0100] "POST /ipa/session/login_password HTTP/1.1" 500 527

Metadata Update from @stlaz:
- Issue set to the milestone: 0.0 NEEDS_TRIAGE

Metadata Update from @stlaz:
- Issue priority set to: 1
- Issue set to the milestone: FreeIPA 4.5 (was: 0.0 NEEDS_TRIAGE)
- Issue tagged with: regression

More details from debug mode:

ipa: INFO: *** PROCESS START ***
ipa: DEBUG: WSGI wsgi_dispatch.__call__:
ipa: DEBUG: WSGI login_password.__call__:
ipa: DEBUG: Obtaining armor in ccache /var/run/ipa/ccaches/armor_5385
ipa: DEBUG: Initializing anonymous ccache
ipa: DEBUG: Starting external process
ipa: DEBUG: args=/usr/bin/kinit -k -t /var/lib/ipa/api/anon.keytab WELLKNOWN/ANONYMOUS -c /var/run/ipa/ccaches/armor_5385
ipa: DEBUG: Process finished, return code=1
ipa: DEBUG: stdout= 
ipa: DEBUG: stderr=kinit: Reply has wrong form of session key for anonymous request while getting initial credentials
ipa: DEBUG: Failed to init Anonymous keytab: Command '/usr/bin/kinit -k -t /var/lib/ipa/api/anon.keytab WELLKNOWN/ANONYMOUS -c /var/run/ipa/ccaches/armor_5385' returned non-zero exit status 1
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/ipalib/install/kinit.py", line 114, in kinit_armor
    run(args, env=env, raiseonerr=True, capture_error=True)
  File "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 495, in run
    raise CalledProcessError(p.returncode, arg_string, str(output))
CalledProcessError: Command '/usr/bin/kinit -k -t /var/lib/ipa/api/anon.keytab WELLKNOWN/ANONYMOUS -c /var/run/ipa/ccaches/armor_5385' returned non-zero exit status 1
ipa: DEBUG: Fallback to slower Anonymous PKINIT
ipa: DEBUG: Starting external process
ipa: DEBUG: args=/usr/bin/kinit -n -c /var/run/ipa/ccaches/armor_5385
ipa: DEBUG: Process finished, return code=1
ipa: DEBUG: stdout=Password for WELLKNOWN/ANONYMOUS@ABC.IDM.LAB.ENG.BRQ.REDHAT.COM:
ipa: DEBUG: stderr=kinit: Pre-authentication failed: Cannot read password while getting initial credentials
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160] mod_wsgi (pid=5385): Exception occurred processing WSGI script '/usr/share/ipa/wsgi.py'.
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160] Traceback (most recent call last):
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160]   File "/usr/share/ipa/wsgi.py", line 51, in application
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160]     return api.Backend.wsgi_dispatch(environ, start_response)
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160]   File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 262, in __call__
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160]     return self.route(environ, start_response)
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160]   File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 274, in route
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160]     return app(environ, start_response)
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160]   File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 901, in __call__
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160]     self.kinit(user_principal, password, ipa_ccache_name)
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160]   File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 935, in kinit
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160]     kinit_armor(armor_path)
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160]   File "/usr/lib/python2.7/site-packages/ipalib/install/kinit.py", line 125, in kinit_armor
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160]     run(args, env=env, raiseonerr=True, capture_error=True)
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160]   File "/usr/lib/python2.7/site-packages/ipapython/ipautil.py", line 495, in run
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160]     raise CalledProcessError(p.returncode, arg_string, str(output))
[remote 2620:52:0:2280:56ee:75ff:fe5c:14c6:160] CalledProcessError: Command '/usr/bin/kinit -n -c /var/run/ipa/ccaches/armor_5385' returned non-zero exit status 1

KRB5_TRACE from annon kinit

[root@vm-024 ~]# KRB5_TRACE=/dev/stderr kinit -kt /var/lib/ipa/api/anon.keytab WELLKNOWN/ANONYMOUS@ABC.IDM.LAB.ENG.BRQ.REDHAT.COM
[5536] 1489075718.704944: Resolving unique ccache of type KEYRING
[5536] 1489075718.704988: Getting initial credentials for WELLKNOWN/ANONYMOUS@ABC.IDM.LAB.ENG.BRQ.REDHAT.COM
[5536] 1489075718.707036: Looked up etypes in keytab: aes256-cts, aes128-cts
[5536] 1489075718.707102: Sending request (218 bytes) to ABC.IDM.LAB.ENG.BRQ.REDHAT.COM
[5536] 1489075718.707303: Initiating TCP connection to stream 10.34.78.24:88
[5536] 1489075718.707418: Sending TCP request to stream 10.34.78.24:88
[5536] 1489075718.710392: Received answer (315 bytes) from stream 10.34.78.24:88
[5536] 1489075718.710406: Terminating TCP connection to stream 10.34.78.24:88
[5536] 1489075718.710499: Response was from master KDC
[5536] 1489075718.710531: Received error from KDC: -1765328359/Additional pre-authentication required
[5536] 1489075718.710551: Processing preauth types: 136, 19, 2, 133
[5536] 1489075718.710561: Selected etype info: etype aes256-cts, salt "PZ] ?o7{.L,>&isq", params ""
[5536] 1489075718.710567: Received cookie: MIT
[5536] 1489075718.710612: Retrieving WELLKNOWN/ANONYMOUS@ABC.IDM.LAB.ENG.BRQ.REDHAT.COM from FILE:/var/lib/ipa/api/anon.keytab (vno 0, enctype aes256-cts) with result: 0/Success
[5536] 1489075718.710624: AS key obtained for encrypted timestamp: aes256-cts/E1B5
[5536] 1489075718.710661: Encrypted timestamp (for 1489075718.710364): plain 301AA011180F32303137303330393136303833385AA10502030AD6DC, encrypted 34DABD3E426FB2D12AB7083AAF6CA9A9ADB919CBD28E6348996674D1FD8CCF781DCC5F1326CC888811BBC14803B38CA70F7675A9D6BF1C29
[5536] 1489075718.710672: Preauth module encrypted_timestamp (2) (real) returned: 0/Success
[5536] 1489075718.710678: Produced preauth for next request: 133, 2
[5536] 1489075718.710688: Sending request (313 bytes) to ABC.IDM.LAB.ENG.BRQ.REDHAT.COM
[5536] 1489075718.710740: Initiating TCP connection to stream 10.34.78.24:88
[5536] 1489075718.710815: Sending TCP request to stream 10.34.78.24:88
[5536] 1489075718.750009: Received answer (768 bytes) from stream 10.34.78.24:88
[5536] 1489075718.750033: Terminating TCP connection to stream 10.34.78.24:88
[5536] 1489075718.750111: Response was from master KDC
[5536] 1489075718.750141: Processing preauth types: 19
[5536] 1489075718.750153: Selected etype info: etype aes256-cts, salt "PZ] ?o7{.L,>&isq", params ""
[5536] 1489075718.750162: Produced preauth for next request: (empty)
[5536] 1489075718.750169: AS key determined by preauth: aes256-cts/E1B5
[5536] 1489075718.750234: Decrypted AS reply; session key is: aes256-cts/F41C
[5536] 1489075718.750256: FAST negotiation: available
kinit: Reply has wrong form of session key for anonymous request while getting initial credentials
2017-03-09T15:58:04Z DEBUG   [3/5]: installing X509 Certificate for PKINIT
2017-03-09T15:58:04Z DEBUG certmonger request is in state dbus.String(u'GENERATING_KEY_PAIR', variant_level=1)
2017-03-09T15:58:09Z DEBUG certmonger request is in state dbus.String(u'CA_UNREACHABLE', variant_level=1)
2017-03-09T15:58:09Z DEBUG   duration: 5 seconds
2017-03-09T15:58:09Z DEBUG   [4/5]: starting the KDC

There is missing kdc.crt because certmonger failed to receive certificate

because certmonger cannot connect to KDC

Mar 09 16:58:04 vm-024.abc.idm.lab.eng.brq.redhat.com certmonger[3819]: 2017-03-09 16:58:04 [3819] Error setting up ccache for "host" service on client using default keytab: Cannot contact any KDC for requested 

Because installer configured krb5.conf to point to replica before local KDC is operational

So this is error in replica installer, probably KDC config should be upgraded after this step

master:

  • 95768de06fbef78169329af12b29e4d65e4bf157 Make PKINIT certificate request logic consistent with other installers
  • b5b23e073e59930e4dcf14ea8031c2c0441e6344 Request PKINIT cert directly from Dogtag API on first master
  • bd18b5f91e3f98fa877def245c54c1cd33bd372e Move PKINIT configuration to a later stage of server/replica install
  • 069948466e81d99a0dd48ffffa32af50351d0189 Make wait_for_entry raise exceptions
  • 8f4abf7bc1607fc44f528b8a443b69cb82269e69 check that the master requesting PKINIT cert has KDC enabled
  • b45629fc480e61464b402ac2fc52c6f9fc61df0e check for replica's KDC entry on master before requesting PKINIT cert
  • a1686a90c0cc8c16c89ef1bada7f507729bf3252 Try out anonymous PKINIT after it is configured

Metadata Update from @mbasti:
- Issue close_status updated to: fixed
- Issue status updated to: Closed (was: Open)

master:

  • 98a88bd71976919d52e5806daf887e42ef3eb320 Fix cert_request for KDC cert

ipa-4-9:

  • 2c48897ed1700725d3cd07a4a106e40f62d76c47 Fix cert_request for KDC cert

ipa-4-6:

  • ad8556beff19e15fdefbbc3b7655e6b63d8e1d04 Fix cert_request for KDC cert

ipa-4-8:

  • f45a79c437fa9e774940913b6ae2b091590bcf37 Fix cert_request for KDC cert
Metadata