Bug 1759290 - Web UI login always fails ("preexec_fn not supported within subinterpreters")
Summary: Web UI login always fails ("preexec_fn not supported within subinterpreters")
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: freeipa
Version: rawhide
Hardware: x86_64
OS: Linux
unspecified
high
Target Milestone: ---
Assignee: IPA Maintainers
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard: openqa
Depends On:
Blocks: F32BetaBlocker
TreeView+ depends on / blocked
 
Reported: 2019-10-07 18:45 UTC by Adam Williamson
Modified: 2019-10-26 17:23 UTC (History)
11 users (show)

Fixed In Version: freeipa-4.8.1-4.fc32 freeipa-4.8.1-3.fc31
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2019-10-09 17:02:59 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Github freeipa freeipa pull 3769 0 None None None 2019-10-07 20:13:12 UTC
Python 37951 0 None None None 2019-10-07 18:46:06 UTC

Description Adam Williamson 2019-10-07 18:45:19 UTC
Since FreeIPA server deployment was fixed in Rawhide (https://bugzilla.redhat.com/show_bug.cgi?id=1747901 was the bug), openQA client tests which involve logging into the web UI always seem to fail. The error displayed is "The password or username you entered is incorrect", but as this is an automated test I'm pretty sure it's not mistyping the password every time.

https://openqa.fedoraproject.org/tests/464194 is one affected test, for e.g. - that was with Fedora-Rawhide-20191007.n.0 . You can get the client logs at https://openqa.fedoraproject.org/tests/464194/file/freeipa_webui-var_log.tar.gz and the server logs at https://openqa.fedoraproject.org/tests/464189/file/role_deploy_domain_controller_check-var_log.tar.gz . The failed attempt to log into the web UI occurs at around 13:22:19 UTC. I do see this in the httpd error logs on the server:

[Mon Oct 07 09:22:19.519389 2019] [wsgi:error] [pid 32989:tid 139746234119936] [remote 10.0.2.102:56054] ipa: DEBUG: WSGI wsgi_dispatch.__call__:
[Mon Oct 07 09:22:19.519559 2019] [wsgi:error] [pid 32989:tid 139746234119936] [remote 10.0.2.102:56054] ipa: DEBUG: WSGI login_password.__call__:
[Mon Oct 07 09:22:19.520153 2019] [wsgi:error] [pid 32989:tid 139746234119936] [remote 10.0.2.102:56054] ipa: DEBUG: Obtaining armor in ccache /run/ipa/ccaches/armor_32989
[Mon Oct 07 09:22:19.520307 2019] [wsgi:error] [pid 32989:tid 139746234119936] [remote 10.0.2.102:56054] ipa: DEBUG: Initializing anonymous ccache
[Mon Oct 07 09:22:19.520509 2019] [wsgi:error] [pid 32989:tid 139746234119936] [remote 10.0.2.102:56054] ipa: DEBUG: Starting external process
[Mon Oct 07 09:22:19.520595 2019] [wsgi:error] [pid 32989:tid 139746234119936] [remote 10.0.2.102:56054] ipa: DEBUG: args=['/usr/bin/kinit', '-n', '-c', '/run/ipa/ccaches/armor_32989', '-X', 'X509_anchors=FILE:/var/kerberos/krb5kdc/kdc.crt', '-X', 'X509_anchors=FILE:/var/lib/ipa-client/pki/kdc-ca-bundle.pem']
[Mon Oct 07 09:22:19.521072 2019] [wsgi:error] [pid 32989:tid 139746234119936] [remote 10.0.2.102:56054] ipa: DEBUG: Process execution failed
[Mon Oct 07 09:22:19.521207 2019] [wsgi:error] [pid 32989:tid 139746234119936] [remote 10.0.2.102:56054] ipa: ERROR: Failed to obtain armor cache
[Mon Oct 07 09:22:19.521340 2019] [wsgi:error] [pid 32989:tid 139746234119936] [remote 10.0.2.102:56054] ipa: DEBUG: Initializing principal admin using password
[Mon Oct 07 09:22:19.521414 2019] [wsgi:error] [pid 32989:tid 139746234119936] [remote 10.0.2.102:56054] ipa: DEBUG: Using enterprise principal
[Mon Oct 07 09:22:19.521528 2019] [wsgi:error] [pid 32989:tid 139746234119936] [remote 10.0.2.102:56054] ipa: DEBUG: Starting external process
[Mon Oct 07 09:22:19.521604 2019] [wsgi:error] [pid 32989:tid 139746234119936] [remote 10.0.2.102:56054] ipa: DEBUG: args=['/usr/bin/kinit', 'admin', '-c', '/run/ipa/ccaches/kinit_32989', '-E']
[Mon Oct 07 09:22:19.521996 2019] [wsgi:error] [pid 32989:tid 139746234119936] [remote 10.0.2.102:56054] ipa: DEBUG: Process execution failed
[Mon Oct 07 09:22:19.522189 2019] [wsgi:error] [pid 32989:tid 139746234119936] [remote 10.0.2.102:56054] ipa: INFO: 401 Unauthorized: preexec_fn not supported within subinterpreters

That error rang bells for me, and sure enough, this looks similar to:

https://bugs.python.org/issue37951

only now it's 'preexec_fn' we're having trouble with rather than 'fork'. I'll add a comment there.

Proposing as an F32 Beta blocker: "It must be possible to configure a Fedora Server system installed according to the above criteria as a FreeIPA domain controller, using the official deployment tools provided in the distribution FreeIPA packages. Once deployed, the system must handle multiple client enrolments and unenrolments, and client authentication via Kerberos. The web UI must be available and allow at least basic configuration of user accounts and permissions." - https://fedoraproject.org/wiki/Basic_Release_Criteria#FreeIPA_server_requirements

Comment 1 Christian Heimes 2019-10-07 20:13:12 UTC
Upstream PR https://github.com/freeipa/freeipa/pull/3769 makes the preexec_fn optional. Before the function was always installed although it was not used by WSGI worker.

Comment 2 Christian Heimes 2019-10-08 08:56:58 UTC
Fixed in freeipa-4.8.1-4.fc32

Alexander is going to backport the fix to f31, too.

Comment 3 Fedora Update System 2019-10-08 09:01:21 UTC
FEDORA-2019-0994155465 has been submitted as an update to Fedora 31. https://bodhi.fedoraproject.org/updates/FEDORA-2019-0994155465

Comment 4 Fedora Update System 2019-10-09 03:25:12 UTC
freeipa-4.8.1-3.fc31 has been pushed to the Fedora 31 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-2019-0994155465

Comment 5 Christian Heimes 2019-10-09 10:33:00 UTC
Adamn, OpenQA did not start for update https://bodhi.fedoraproject.org/updates/FEDORA-2019-0994155465. Could you please take a look and check why the automated QA tests have not been executed?

Comment 6 Adam Williamson 2019-10-09 15:02:15 UTC
Huh, it seems the scheduler stalled out somehow and just wasn't doing anything. I think the fedora-messaging broker kicked it off the bus for some reason? I've restarted it and it's catching up now. Thanks.

Comment 7 Adam Williamson 2019-10-09 15:10:24 UTC
Note this bug was not apparent on F31 in the first place (not a new enough Python, I think) so the F31 update test will only tell us if the fix broke something, not whether the fix actually fixes the bug. However, a Rawhide compose containing freeipa-4.8.1-4.fc32 is currently being tested, and *that* will tell us whether this is fixed:

https://openqa.fedoraproject.org/tests/overview?distri=fedora&version=Rawhide&build=Fedora-Rawhide-20191009.n.0&groupid=1

Comment 8 Christian Heimes 2019-10-09 15:41:01 UTC
Fedora 31 is still on Python 3.7 which is not affected by the upstream API limitation. There is no need to rush the fix before F31 is released.

Comment 9 Adam Williamson 2019-10-09 17:02:59 UTC
This indeed looks fixed in the latest Rawhide compose, all FreeIPA tests now pass. Thanks.

Comment 10 Rob Crittenden 2019-10-18 13:58:52 UTC
Fixed upstream
ipa-4-8:
https://pagure.io/freeipa/c/3fbd0abf253c4d46134820337269008bfa2a7240

Comment 11 Fedora Update System 2019-10-26 17:23:41 UTC
freeipa-4.8.1-3.fc31 has been pushed to the Fedora 31 stable repository. If problems still persist, 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.