Bug 1430247

Summary: FreeIPA server deployment runs ipa-custodia on Python 3, should use Python 2
Product: [Fedora] Fedora Reporter: Adam Williamson <awilliam>
Component: freeipaAssignee: IPA Maintainers <ipa-maint>
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: urgent Docs Contact:
Priority: unspecified    
Version: rawhideCC: abokovoy, cheimes, ipa-maint, jcholast, jhrozek, mruckman, pvoborni, pvomacka, rcritten, ssorce, tkrizek
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: freeipa-4.4.4-2.fc26 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2017-06-09 19:08:52 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Adam Williamson 2017-03-08 07:36:18 UTC
During FreeIPA server deployment on Fedora 26 and Fedora Rawhide, the 'ipa-custodia' service keeps failing, with these errors:

Mar 07 12:52:57 ipa001.domain.local systemd[1]: ipa-custodia.service: Service hold-off time over, scheduling restart.
Mar 07 12:52:58 ipa001.domain.local system-python[9430]: detected unhandled Python exception in '/usr/sbin/custodia'
Mar 07 12:52:58 ipa001.domain.local custodia[9430]: Traceback (most recent call last):
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "/usr/lib/python3.6/site-packages/custodia/server/__init__.py", line 86, in _create_plugin
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:     handler = _load_plugin_class(menu, handler_name)
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "/usr/lib/python3.6/site-packages/custodia/server/__init__.py", line 73, in _load_plugin_class
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:     m = importlib.import_module(module)
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "/usr/lib64/python3.6/importlib/__init__.py", line 126, in import_module
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:     return _bootstrap._gcd_import(name[level:], package, level)
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "<frozen importlib._bootstrap>", line 978, in _gcd_import
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "<frozen importlib._bootstrap>", line 961, in _find_and_load
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "<frozen importlib._bootstrap>", line 936, in _find_and_load_unlocked
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "<frozen importlib._bootstrap>", line 205, in _call_with_frames_removed
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "<frozen importlib._bootstrap>", line 978, in _gcd_import
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "<frozen importlib._bootstrap>", line 961, in _find_and_load
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "<frozen importlib._bootstrap>", line 936, in _find_and_load_unlocked
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "<frozen importlib._bootstrap>", line 205, in _call_with_frames_removed
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "<frozen importlib._bootstrap>", line 978, in _gcd_import
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "<frozen importlib._bootstrap>", line 961, in _find_and_load
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "<frozen importlib._bootstrap>", line 948, in _find_and_load_unlocked
Mar 07 12:52:58 ipa001.domain.local custodia[9430]: ModuleNotFoundError: No module named 'ipapython'
Mar 07 12:52:58 ipa001.domain.local custodia[9430]: During handling of the above exception, another exception occurred:
Mar 07 12:52:58 ipa001.domain.local custodia[9430]: Traceback (most recent call last):
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "/usr/lib/python3.6/site-packages/custodia/server/__init__.py", line 181, in parse_config
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:     config[menu][name] = _create_plugin(parser, s, menu)
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "/usr/lib/python3.6/site-packages/custodia/server/__init__.py", line 91, in _create_plugin
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:     '[%r]: %s' % (e, handler_name))
Mar 07 12:52:58 ipa001.domain.local custodia[9430]: ValueError: Invalid format for "handler" option [ModuleNotFoundError("No module named 'ipapython'",)]: ipapython.secrets.kem.IPAKEMKeys
Mar 07 12:52:58 ipa001.domain.local custodia[9430]: During handling of the above exception, another exception occurred:
Mar 07 12:52:58 ipa001.domain.local custodia[9430]: Traceback (most recent call last):
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "/usr/sbin/custodia", line 11, in <module>
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:     load_entry_point('custodia==0.3.0', 'console_scripts', 'custodia')()
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "/usr/lib/python3.6/site-packages/custodia/server/__init__.py", line 198, in main
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:     config = parse_config(args)
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:   File "/usr/lib/python3.6/site-packages/custodia/server/__init__.py", line 183, in parse_config
Mar 07 12:52:58 ipa001.domain.local custodia[9430]:     raise RuntimeError(menu, name, e)
Mar 07 12:52:58 ipa001.domain.local custodia[9430]: RuntimeError: ('authorizers', 'kemkeys', ValueError('Invalid format for "handler" option [ModuleNotFoundError("No module named \'ipapython\'",)]: ipapython.secrets.kem.IPAKEMKeys',))
Mar 07 12:52:58 ipa001.domain.local systemd[1]: ipa-custodia.service: Main process exited, code=exited, status=1/FAILURE
Mar 07 12:52:58 ipa001.domain.local systemd[1]: ipa-custodia.service: Unit entered failed state.
Mar 07 12:52:58 ipa001.domain.local systemd[1]: ipa-custodia.service: Failed with result 'exit-code'.

The problem is pretty obvious: the 'ipapython' library is missing. This library is provided by python3-ipalib, but python3-custodia does not depend on python3-ipalib (either the 0.2.0 build in F26, or the 0.3.0 build in Rawhide).

Proposing as at least a freeze exception for F26 Alpha, it may be a blocker (I'm not sure how critical ipa-custodia is to FreeIPA functionality).

Comment 1 Christian Heimes 2017-03-08 10:19:04 UTC
python3-custodia does not depend on python3-ipalib. Only the specialized Custodia instance of FreeIPA loads an additional plugin that is provided by ipapython and ipaserver. The ipa-custodia is critical for replica install.

For FreeIPA 4.4 and Custodia 0.2, ipa-custodia must be run with Python 2. Once https://github.com/freeipa/freeipa/pull/517 has landed, it's all handled by FreeIPA internally.

Comment 2 Adam Williamson 2017-03-08 15:41:20 UTC
Better?

Comment 3 Petr Vobornik 2017-03-10 14:39:34 UTC
Christian, I don't get how PR 517 should fix F26. Custodia 0.3 is built only for Fedora 27 and not Fedora 26.

So neither FreeIPA 4.4 nor 4.5(master) will be fixed by it and it will only says that we are missing dependencies. Or do you plan to add Custodia 0.3 to Fedora 26?

Comment 4 Adam Williamson 2017-03-10 14:43:36 UTC
Can someone say whether this is a critical issue - i.e. whether FreeIPA will fail to work correctly without ipa-custodia? I'm not sure what it's for. Thanks!

Comment 5 Alexander Bokovoy 2017-03-10 14:53:55 UTC
I think it is a critical issue. Christian is traveling right now, so his response will be delayed.

Comment 6 Christian Heimes 2017-03-12 14:26:18 UTC
Adam, which version of Custodia and FreeIPA are you running? The Fedora 26 package should still default to Python 2. I don't understand why your system runs Custodia with Python 3.

$ rpm -qa custodia freeipa-server
freeipa-server-4.4.3-8.fc26.x86_64
custodia-0.2.0-3.fc26.noarch

$ head -n1 /usr/sbin/custodia
#!/usr/bin/python2

$ grep ExecStart /usr/lib/systemd/system/ipa-custodia.service 
ExecStart=/usr/sbin/custodia /etc/ipa/custodia/custodia.conf

Comment 7 Mike Ruckman 2017-03-13 18:48:05 UTC
Discussed in today's Blocker Review meeting. It'd be really good to get a fix in for this before Alpha release. Please update the bug if this issue is more severe than we currently suspect.

Comment 8 Adam Williamson 2017-03-13 19:51:44 UTC
Note, in further discussion between me and sgallagh, it transpires that this issue may not affect F26. It may only affect 0.3.0-1+, which are only in Rawhide. F26 tests have been running into *other* issues, so we haven't reached this point in the F26 tests yet. Once the other issues are resolved, I'll check if this is really affect current F26.

Comment 9 Adam Williamson 2017-03-15 16:52:38 UTC
This indeed doesn't seem to affect F26 (at present), so switching to Rawhide and dropping Alpha FE status.

Comment 10 Petr Vobornik 2017-03-24 11:06:55 UTC
Upstream ticket:
https://pagure.io/freeipa/issue/5825

Comment 12 Fedora Update System 2017-05-23 11:15:37 UTC
freeipa-4.4.4-2.fc26 has been submitted as an update to Fedora 26. https://bodhi.fedoraproject.org/updates/FEDORA-2017-0d0ec3e0af

Comment 13 Fedora Update System 2017-05-23 18:16:52 UTC
freeipa-4.4.4-2.fc26 has been pushed to the Fedora 26 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-0d0ec3e0af

Comment 14 Fedora Update System 2017-06-01 18:06:07 UTC
custodia-0.3.1-2.fc26 freeipa-4.4.4-2.fc26 has been submitted as an update to Fedora 26. https://bodhi.fedoraproject.org/updates/FEDORA-2017-0d0ec3e0af

Comment 15 Fedora Update System 2017-06-04 19:38:52 UTC
custodia-0.3.1-2.fc26, freeipa-4.4.4-2.fc26 has been pushed to the Fedora 26 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-0d0ec3e0af

Comment 16 Fedora Update System 2017-06-09 19:08:52 UTC
custodia-0.3.1-2.fc26, freeipa-4.4.4-2.fc26 has been pushed to the Fedora 26 stable repository. If problems still persist, please make note of it in this bug report.