{"update": {"autokarma": true, "autotime": true, "stable_karma": 5, "stable_days": 14, "unstable_karma": -3, "require_bugs": true, "require_testcases": true, "display_name": "", "notes": "Update of Python and python3-docs to 3.9.9. Fixed python3-typed_ast for this Python version.\n\n\n\n\n\n", "type": "enhancement", "status": "stable", "request": null, "severity": "unspecified", "suggest": "unspecified", "locked": false, "pushed": true, "critpath": true, "critpath_groups": null, "close_bugs": true, "date_submitted": "2021-11-09 09:41:10", "date_modified": "2021-11-20 07:40:53", "date_approved": null, "date_testing": "2021-11-20 02:05:17", "date_stable": "2021-12-05 01:37:20", "alias": "FEDORA-2021-e152ce5f31", "test_gating_status": "passed", "from_tag": null, "date_pushed": "2021-12-05 01:37:20", "meets_testing_requirements": true, "url": "https://bodhi.fedoraproject.org/updates/FEDORA-2021-e152ce5f31", "title": "python3-docs-3.9.9-1.fc34 python3-typed_ast-1.4.3-4.fc34 python3.9-3.9.9-2.fc34", "version_hash": "4e33e578ce778e539a450ef4c694ead723bc950b", "release": {"name": "F34", "long_name": "Fedora 34", "version": "34", "id_prefix": "FEDORA", "branch": "f34", "dist_tag": "f34", "stable_tag": "f34-updates", "testing_tag": "f34-updates-testing", "candidate_tag": "f34-updates-candidate", "pending_signing_tag": "f34-signing-pending", "pending_testing_tag": "f34-updates-testing-pending", "pending_stable_tag": "f34-updates-pending", "override_tag": "f34-override", "mail_template": "fedora_errata_template", "state": "archived", "composed_by_bodhi": true, "create_automatic_updates": false, "package_manager": "dnf", "testing_repository": "updates-testing", "released_on": null, "eol": null, "critpath_mandatory_days_in_testing": 14, "mandatory_days_in_testing": 7, "critpath_min_karma": 2, "min_karma": 1, "setting_status": null}, "user": {"name": "thrnciar", "email": "thrnciar@redhat.com", "id": 5427, "avatar": "https://seccdn.libravatar.org/avatar/a973da034e49a14259bb98d71a1c60082c29ebcb91c4d7c9c8cb567099bad334?s=24&d=retro", "openid": "thrnciar.id.fedoraproject.org", "groups": [{"name": "packager"}, {"name": "provenpackager"}, {"name": "python-sig"}, {"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}, {"name": "gitcopr"}, {"name": "python-packagers-sig"}]}, "comments": [{"karma": 0, "karma_critpath": 0, "text": "This update has been submitted for testing by thrnciar. ", "timestamp": "2021-11-09 09:41:10", "update_id": 353349, "user_id": 91, "id": 2278061, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "This update's test gating status has been changed to 'failed'.", "timestamp": "2021-11-09 09:41:11", "update_id": 353349, "user_id": 91, "id": 2278062, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "This update's test gating status has been changed to 'waiting'.", "timestamp": "2021-11-09 09:41:11", "update_id": 353349, "user_id": 91, "id": 2278063, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "This update's test gating status has been changed to 'failed'.", "timestamp": "2021-11-09 09:46:51", "update_id": 353349, "user_id": 91, "id": 2278068, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "churchyard edited this update.", "timestamp": "2021-11-09 09:59:13", "update_id": 353349, "user_id": 91, "id": 2278073, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": -1, "karma_critpath": 0, "text": "The automated test failures here are failing on FreeIPA shutdown. It appears to be a real failure - it's reproducible, and tests of other updates are not hitting it. The shutdown does *eventually* work, but it's taking way longer than it should.\n\nThe holdup seems to be to do with httpd. In a sample test, the test runs `systemctl stop ipa.service` at 03:10:04, and it doesn't finally finish stopping until 03:11:39 (so it takes 95 seconds to stop). The big jump in the logs is here:\n\n    Nov 09 11:10:07 ipa001.test.openqa.fedoraproject.org systemd[1]: pki-tomcatd@pki-tomcat.service: Consumed 41.396s CPU time.\n    Nov 09 11:11:19 ipa001.test.openqa.fedoraproject.org sssd_be[10225]: GSSAPI client step 1\n    Nov 09 11:11:19 ipa001.test.openqa.fedoraproject.org sssd_be[10225]: GSSAPI client step 1\n    Nov 09 11:11:19 ipa001.test.openqa.fedoraproject.org sssd_be[10225]: GSSAPI client step 1\n    Nov 09 11:11:19 ipa001.test.openqa.fedoraproject.org sssd_be[10225]: GSSAPI client step 2\n    Nov 09 11:11:36 ipa001.test.openqa.fedoraproject.org systemd[1]: httpd.service: State 'stop-sigterm' timed out. Killing.\n    Nov 09 11:11:36 ipa001.test.openqa.fedoraproject.org systemd[1]: httpd.service: Killing process 9800 (httpd) with signal SIGKILL.\n    Nov 09 11:11:36 ipa001.test.openqa.fedoraproject.org systemd[1]: httpd.service: Killing process 9802 (httpd) with signal SIGKILL.\n    Nov 09 11:11:36 ipa001.test.openqa.fedoraproject.org systemd[1]: httpd.service: Killing process 9803 (httpd) with signal SIGKILL.\n\nFrom that it looks like it tries to stop httpd with SIGTERM around 11:10:06 and waits 90 seconds for that to work, but it doesn't, so it stops it with SIGKILL at 11:11:36.\n\n`/var/log/httpd/error_log` ends with this line:\n\n    [Tue Nov 09 06:10:06.707303 2021] [mpm_event:notice] [pid 9800:tid 9800] AH00492: caught SIGWINCH, shutting down gracefully\n\nwhich I think matches the SIGTERM at 11:10:06 in the journal - 11:10:06 is UTC (I used `journalctl --utc`), 06:10:06 is system local time (the system is in US Eastern time). But it looks like it *didn't* actually shut down gracefully, though I can't find any messages indicating why.\n\nI checked the timestamps on a test of a different update, also for F34; in that test, `systemctl stop ipa.service` returns after 8 seconds.", "timestamp": "2021-11-09 23:35:51", "update_id": 353349, "user_id": 302, "id": 2278745, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "adamwill", "email": "awilliam@redhat.com", "id": 302, "avatar": "https://seccdn.libravatar.org/avatar/51720fbb2ec5dfd2bc005ac374a3bfd3190cb8f45f3bb8d6bdf35fb6a051d03b?s=24&d=retro", "openid": "adamwill.id.fedoraproject.org", "groups": [{"name": "proventesters"}, {"name": "provenpackager"}, {"name": "packager"}, {"name": "qa-tools-sig"}, {"name": "fedora-contributor"}, {"name": "news"}, {"name": "gittriage"}, {"name": "sysadmin"}, {"name": "gitspin-kickstarts"}, {"name": "signed_fpca"}, {"name": "gitgeneric-release"}, {"name": "yak_farmers"}, {"name": "triagers"}, {"name": "qa"}, {"name": "sysadmin-qa"}, {"name": "fedorabugs"}, {"name": "ipausers"}, {"name": "gitmkinitrd"}, {"name": "qa-admin"}, {"name": "aws-qa"}, {"name": "change-wranglers"}, {"name": "fedora-ci-admins"}, {"name": "common-issues-triage"}, {"name": "sysadmin-main"}, {"name": "program-management"}, {"name": "gitfedora-project-schedule"}]}}, {"karma": 0, "karma_critpath": 0, "text": "@churchyard for info.", "timestamp": "2021-11-09 23:37:28", "update_id": 353349, "user_id": 302, "id": 2278747, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "adamwill", "email": "awilliam@redhat.com", "id": 302, "avatar": "https://seccdn.libravatar.org/avatar/51720fbb2ec5dfd2bc005ac374a3bfd3190cb8f45f3bb8d6bdf35fb6a051d03b?s=24&d=retro", "openid": "adamwill.id.fedoraproject.org", "groups": [{"name": "proventesters"}, {"name": "provenpackager"}, {"name": "packager"}, {"name": "qa-tools-sig"}, {"name": "fedora-contributor"}, {"name": "news"}, {"name": "gittriage"}, {"name": "sysadmin"}, {"name": "gitspin-kickstarts"}, {"name": "signed_fpca"}, {"name": "gitgeneric-release"}, {"name": "yak_farmers"}, {"name": "triagers"}, {"name": "qa"}, {"name": "sysadmin-qa"}, {"name": "fedorabugs"}, {"name": "ipausers"}, {"name": "gitmkinitrd"}, {"name": "qa-admin"}, {"name": "aws-qa"}, {"name": "change-wranglers"}, {"name": "fedora-ci-admins"}, {"name": "common-issues-triage"}, {"name": "sysadmin-main"}, {"name": "program-management"}, {"name": "gitfedora-project-schedule"}]}}, {"karma": 0, "karma_critpath": 0, "text": "This update has been pushed to testing.", "timestamp": "2021-11-10 04:04:35", "update_id": 353349, "user_id": 91, "id": 2279098, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "Bodhi is disabling automatic push to stable due to negative karma. The maintainer may push manually if they determine that the issue is not severe.", "timestamp": "2021-11-10 04:04:38", "update_id": 353349, "user_id": 91, "id": 2279122, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "churchyard edited this update.", "timestamp": "2021-11-10 12:37:11", "update_id": 353349, "user_id": 91, "id": 2279530, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "Thanks for the notice. I've disabled autopush on f33 as well.", "timestamp": "2021-11-10 12:38:02", "update_id": 353349, "user_id": 533, "id": 2279531, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "churchyard", "email": "mhroncok@redhat.com", "id": 533, "avatar": "https://seccdn.libravatar.org/avatar/e221b70024cf971d8b43de0260d2babde9179cdf72605bf3168420e3efe07423?s=24&d=retro", "openid": "churchyard.id.fedoraproject.org", "groups": [{"name": "provenpackager"}, {"name": "packager"}, {"name": "python-sig"}, {"name": "signed_fpca"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}, {"name": "fedora-contributor"}, {"name": "sysadmin-badges"}, {"name": "ipausers"}, {"name": "sysadmin"}, {"name": "lua-packagers-sig"}, {"name": "fedorabugs"}, {"name": "cvsadmin"}, {"name": "ambassadors"}, {"name": "packaging-committee"}, {"name": "advocates"}]}}, {"karma": 0, "karma_critpath": 0, "text": "Will also need to include https://src.fedoraproject.org/rpms/python3-typed_ast/pull-request/2", "timestamp": "2021-11-10 13:17:33", "update_id": 353349, "user_id": 533, "id": 2279566, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "churchyard", "email": "mhroncok@redhat.com", "id": 533, "avatar": "https://seccdn.libravatar.org/avatar/e221b70024cf971d8b43de0260d2babde9179cdf72605bf3168420e3efe07423?s=24&d=retro", "openid": "churchyard.id.fedoraproject.org", "groups": [{"name": "provenpackager"}, {"name": "packager"}, {"name": "python-sig"}, {"name": "signed_fpca"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}, {"name": "fedora-contributor"}, {"name": "sysadmin-badges"}, {"name": "ipausers"}, {"name": "sysadmin"}, {"name": "lua-packagers-sig"}, {"name": "fedorabugs"}, {"name": "cvsadmin"}, {"name": "ambassadors"}, {"name": "packaging-committee"}, {"name": "advocates"}]}}, {"karma": 0, "karma_critpath": 0, "text": "churchyard edited this update.\n\nNew build(s):\n\n- python3-typed_ast-1.4.3-4.fc34\n\nKarma has been reset.", "timestamp": "2021-11-10 15:02:07", "update_id": 353349, "user_id": 91, "id": 2279785, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "This update has been submitted for testing by churchyard. ", "timestamp": "2021-11-10 15:02:09", "update_id": 353349, "user_id": 91, "id": 2279786, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "Adam, could you please provide a reproducer for the FreeIPA shutdown failure? Ideally over bugzilla. Thanks.", "timestamp": "2021-11-10 15:30:13", "update_id": 353349, "user_id": 533, "id": 2279831, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "churchyard", "email": "mhroncok@redhat.com", "id": 533, "avatar": "https://seccdn.libravatar.org/avatar/e221b70024cf971d8b43de0260d2babde9179cdf72605bf3168420e3efe07423?s=24&d=retro", "openid": "churchyard.id.fedoraproject.org", "groups": [{"name": "provenpackager"}, {"name": "packager"}, {"name": "python-sig"}, {"name": "signed_fpca"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}, {"name": "fedora-contributor"}, {"name": "sysadmin-badges"}, {"name": "ipausers"}, {"name": "sysadmin"}, {"name": "lua-packagers-sig"}, {"name": "fedorabugs"}, {"name": "cvsadmin"}, {"name": "ambassadors"}, {"name": "packaging-committee"}, {"name": "advocates"}]}}, {"karma": 0, "karma_critpath": 0, "text": "Well, the test deploys a server and a client, runs through some tests, and then stops the service on the server. I don't know whether it's necessary to have a client and do some stuff with it, or whether the bug would reproduce just by deploying FreeIPA, letting it start up, and then trying to stop it...", "timestamp": "2021-11-10 16:19:58", "update_id": 353349, "user_id": 302, "id": 2279913, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "adamwill", "email": "awilliam@redhat.com", "id": 302, "avatar": "https://seccdn.libravatar.org/avatar/51720fbb2ec5dfd2bc005ac374a3bfd3190cb8f45f3bb8d6bdf35fb6a051d03b?s=24&d=retro", "openid": "adamwill.id.fedoraproject.org", "groups": [{"name": "proventesters"}, {"name": "provenpackager"}, {"name": "packager"}, {"name": "qa-tools-sig"}, {"name": "fedora-contributor"}, {"name": "news"}, {"name": "gittriage"}, {"name": "sysadmin"}, {"name": "gitspin-kickstarts"}, {"name": "signed_fpca"}, {"name": "gitgeneric-release"}, {"name": "yak_farmers"}, {"name": "triagers"}, {"name": "qa"}, {"name": "sysadmin-qa"}, {"name": "fedorabugs"}, {"name": "ipausers"}, {"name": "gitmkinitrd"}, {"name": "qa-admin"}, {"name": "aws-qa"}, {"name": "change-wranglers"}, {"name": "fedora-ci-admins"}, {"name": "common-issues-triage"}, {"name": "sysadmin-main"}, {"name": "program-management"}, {"name": "gitfedora-project-schedule"}]}}, {"karma": 0, "karma_critpath": 0, "text": "Where can I see how the test does that? I have no idea how to deploy a server and a client. I am looking at https://fedoraproject.org/wiki/FreeIPA_step_by_step but it feels quite old and it gives very ambiguous instructions like \"make sure that the host names are set properly\" -- it seems I need to know what I am trying to accomplish when I want to setup FreeIPA and unfortunately I don't.", "timestamp": "2021-11-10 16:29:27", "update_id": 353349, "user_id": 533, "id": 2279918, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "churchyard", "email": "mhroncok@redhat.com", "id": 533, "avatar": "https://seccdn.libravatar.org/avatar/e221b70024cf971d8b43de0260d2babde9179cdf72605bf3168420e3efe07423?s=24&d=retro", "openid": "churchyard.id.fedoraproject.org", "groups": [{"name": "provenpackager"}, {"name": "packager"}, {"name": "python-sig"}, {"name": "signed_fpca"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}, {"name": "fedora-contributor"}, {"name": "sysadmin-badges"}, {"name": "ipausers"}, {"name": "sysadmin"}, {"name": "lua-packagers-sig"}, {"name": "fedorabugs"}, {"name": "cvsadmin"}, {"name": "ambassadors"}, {"name": "packaging-committee"}, {"name": "advocates"}]}}, {"karma": 0, "karma_critpath": 0, "text": "This update has been pushed to testing.", "timestamp": "2021-11-11 02:13:46", "update_id": 353349, "user_id": 91, "id": 2280704, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "I'm looking into it. No results so far. I'm trying to find someone from the IPA team to help me with debugging.", "timestamp": "2021-11-11 16:25:55", "update_id": 353349, "user_id": 2936, "id": 2281273, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "lbalhar", "email": "lbalhar@redhat.com", "id": 2936, "avatar": "https://seccdn.libravatar.org/avatar/789052d5e25db3b2c36725adeaa296f78df20334671edbb69ba42f419e1bfac4?s=24&d=retro", "openid": "lbalhar.id.fedoraproject.org", "groups": [{"name": "packager"}, {"name": "python-sig"}, {"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}, {"name": "realtime"}, {"name": "machine-learning-sig"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}]}}, {"karma": 0, "karma_critpath": 0, "text": "@churchyard sorry, had some other fire to deal with today. The test case is probably more up to date and to the point: https://fedoraproject.org/wiki/QA:Testcase_freeipa_trust_server_installation . The test pretty much automates that. You can see the code for any openQA \"test module\" (the individual bits of a test, like \"_console_wait_login\" and \"role_deploy_domain_controller\" - by clicking on them at the test overview screen, e.g. https://openqa.fedoraproject.org/tests/1059611/modules/role_deploy_domain_controller/steps/1/src shows you the code of `role_deploy_domain_controller`. Sometimes these call library functions that the web UI can't show you, though. The test repo is https://pagure.io/fedora-qa/os-autoinst-distri-fedora/tree/master , there you can find all the test code under `tests/` and the libraries of shared functions under `lib/`. In this case, though, pretty much everything is in the test code itself, and you should see it matches the test case quite closely (it's perl code, but most of what it's doing is just running console commands, so it should be relatively easy to follow). \"role_deploy_domain_controller_check\" - the module that fails - first checks `ipa.service` is running after deployment, then waits for the clients to complete, then the next thing it does is the thing that fails (`systemctl stop ipa.service`).", "timestamp": "2021-11-12 06:45:21", "update_id": 353349, "user_id": 302, "id": 2281968, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "adamwill", "email": "awilliam@redhat.com", "id": 302, "avatar": "https://seccdn.libravatar.org/avatar/51720fbb2ec5dfd2bc005ac374a3bfd3190cb8f45f3bb8d6bdf35fb6a051d03b?s=24&d=retro", "openid": "adamwill.id.fedoraproject.org", "groups": [{"name": "proventesters"}, {"name": "provenpackager"}, {"name": "packager"}, {"name": "qa-tools-sig"}, {"name": "fedora-contributor"}, {"name": "news"}, {"name": "gittriage"}, {"name": "sysadmin"}, {"name": "gitspin-kickstarts"}, {"name": "signed_fpca"}, {"name": "gitgeneric-release"}, {"name": "yak_farmers"}, {"name": "triagers"}, {"name": "qa"}, {"name": "sysadmin-qa"}, {"name": "fedorabugs"}, {"name": "ipausers"}, {"name": "gitmkinitrd"}, {"name": "qa-admin"}, {"name": "aws-qa"}, {"name": "change-wranglers"}, {"name": "fedora-ci-admins"}, {"name": "common-issues-triage"}, {"name": "sysadmin-main"}, {"name": "program-management"}, {"name": "gitfedora-project-schedule"}]}}, {"karma": 0, "karma_critpath": 0, "text": "I've filled an upstream issue (https://pagure.io/freeipa/issue/9034) and I'm gonna try to reproduce the problem in the meantime.", "timestamp": "2021-11-12 08:46:54", "update_id": 353349, "user_id": 2936, "id": 2282032, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "lbalhar", "email": "lbalhar@redhat.com", "id": 2936, "avatar": "https://seccdn.libravatar.org/avatar/789052d5e25db3b2c36725adeaa296f78df20334671edbb69ba42f419e1bfac4?s=24&d=retro", "openid": "lbalhar.id.fedoraproject.org", "groups": [{"name": "packager"}, {"name": "python-sig"}, {"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}, {"name": "realtime"}, {"name": "machine-learning-sig"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}]}}, {"karma": 0, "karma_critpath": 0, "text": "I've tried to reproduce the issue in a virtual machine and IPA installed as described in the Wiki page but I was not successful. The start of the service took ~40 s and the stop took ~6 no matter which version of Python I had installed. I'm gonna try it once more carefully following the test case.", "timestamp": "2021-11-12 10:41:17", "update_id": 353349, "user_id": 2936, "id": 2282088, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "lbalhar", "email": "lbalhar@redhat.com", "id": 2936, "avatar": "https://seccdn.libravatar.org/avatar/789052d5e25db3b2c36725adeaa296f78df20334671edbb69ba42f419e1bfac4?s=24&d=retro", "openid": "lbalhar.id.fedoraproject.org", "groups": [{"name": "packager"}, {"name": "python-sig"}, {"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}, {"name": "realtime"}, {"name": "machine-learning-sig"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}]}}, {"karma": 0, "karma_critpath": 0, "text": "Ok, so, now I have exactly the same environment installed following the rules in the `role_deploy_domain_controller`. I've compared the output of the commands in my VM with the screenshots and they are almost the same. And I'm still not able to reproduce the issue, stopping the service takes around 6 seconds with both old and new Python.\n\nI'm out of ideas. Is it possible to keep the testing virtual machine running after the failed test so we can connect there and debug the problem in the testing environment? Or start it manually somehow? Is there any way how to get the list of installed packages to compare them with my environment? I might have something different.", "timestamp": "2021-11-12 12:31:16", "update_id": 353349, "user_id": 2936, "id": 2282137, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "lbalhar", "email": "lbalhar@redhat.com", "id": 2936, "avatar": "https://seccdn.libravatar.org/avatar/789052d5e25db3b2c36725adeaa296f78df20334671edbb69ba42f419e1bfac4?s=24&d=retro", "openid": "lbalhar.id.fedoraproject.org", "groups": [{"name": "packager"}, {"name": "python-sig"}, {"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}, {"name": "realtime"}, {"name": "machine-learning-sig"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}]}}, {"karma": 0, "karma_critpath": 0, "text": "I suppose the other possibility is that we do need to run the client tests as well. The client tests do include one which exercises the FreeIPA web UI, and the shutdown issue is in httpd, so it's plausible we don't hit the bug unless the web UI gets exercised.\n\nThe openQA client test that exercises the web UI is the slightly misleadingly-named `realmd_join_cockpit` (it *does* enrol via Cockpit, but then it also goes on to do the web UI tests as well). Both the `freeipa_webui` and `freeipa_password_change` modules exercise the web UI to some extent. If you can add those steps to your reproducer attempt it may help. You may not need to have an actual second client VM, you may be able to just do it all on the server, I haven't tried that though.", "timestamp": "2021-11-12 18:37:57", "update_id": 353349, "user_id": 302, "id": 2282382, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "adamwill", "email": "awilliam@redhat.com", "id": 302, "avatar": "https://seccdn.libravatar.org/avatar/51720fbb2ec5dfd2bc005ac374a3bfd3190cb8f45f3bb8d6bdf35fb6a051d03b?s=24&d=retro", "openid": "adamwill.id.fedoraproject.org", "groups": [{"name": "proventesters"}, {"name": "provenpackager"}, {"name": "packager"}, {"name": "qa-tools-sig"}, {"name": "fedora-contributor"}, {"name": "news"}, {"name": "gittriage"}, {"name": "sysadmin"}, {"name": "gitspin-kickstarts"}, {"name": "signed_fpca"}, {"name": "gitgeneric-release"}, {"name": "yak_farmers"}, {"name": "triagers"}, {"name": "qa"}, {"name": "sysadmin-qa"}, {"name": "fedorabugs"}, {"name": "ipausers"}, {"name": "gitmkinitrd"}, {"name": "qa-admin"}, {"name": "aws-qa"}, {"name": "change-wranglers"}, {"name": "fedora-ci-admins"}, {"name": "common-issues-triage"}, {"name": "sysadmin-main"}, {"name": "program-management"}, {"name": "gitfedora-project-schedule"}]}}, {"karma": 0, "karma_critpath": 0, "text": "Oh, sorry, to answer your questions:\n\n\"Is it possible to keep the testing virtual machine running after the failed test so we can connect there and debug the problem in the testing environment? Or start it manually somehow?\"\n\nThe answer is sort of \"theoretically yes, practically it's difficult\". We can leave the test 'open' (at least for a couple of hours - after that it would time out, I think there's a setting to override that though), but the tricky part is connecting to it. The official openQA instance runs inside Fedora's infrastructure, which is quite heavily firewalled, it would be rather difficult to get things configured such that you could route a VNC connection all the way in there, I think. RH IT is in charge of some of the firewalling, too, so getting any changes made involves filing a ticket and waiting for weeks.\n\nThe other option is to reproduce the bug on an instance of openQA sited somewhere more convenient for connecting to, but setting up a pet openQA deployment is kind of a drag, and it's especially a drag for these tests where we have a server/client setup going on (because it involves special networking configuration). I used to keep a pet deployment in my home office but I got rid of it last year. @lruzicka has one, I think, but I don't know if his is set up to do the client/server tests.\n\nWhat I usually wind up doing instead is just rewriting the openQA tests on the fly to add whatever debugging steps we need. If you can suggest some stuff you'd like done from the broken state that might help identify what the problem is, I can usually manage to tweak the test environment to do it and get the info out, so just let me know.\n\n\"Is there any way how to get the list of installed packages to compare them with my environment?\"\n\nYeah, that we can do quite easily, I'll grab it for you later today.", "timestamp": "2021-11-12 18:43:43", "update_id": 353349, "user_id": 302, "id": 2282383, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "adamwill", "email": "awilliam@redhat.com", "id": 302, "avatar": "https://seccdn.libravatar.org/avatar/51720fbb2ec5dfd2bc005ac374a3bfd3190cb8f45f3bb8d6bdf35fb6a051d03b?s=24&d=retro", "openid": "adamwill.id.fedoraproject.org", "groups": [{"name": "proventesters"}, {"name": "provenpackager"}, {"name": "packager"}, {"name": "qa-tools-sig"}, {"name": "fedora-contributor"}, {"name": "news"}, {"name": "gittriage"}, {"name": "sysadmin"}, {"name": "gitspin-kickstarts"}, {"name": "signed_fpca"}, {"name": "gitgeneric-release"}, {"name": "yak_farmers"}, {"name": "triagers"}, {"name": "qa"}, {"name": "sysadmin-qa"}, {"name": "fedorabugs"}, {"name": "ipausers"}, {"name": "gitmkinitrd"}, {"name": "qa-admin"}, {"name": "aws-qa"}, {"name": "change-wranglers"}, {"name": "fedora-ci-admins"}, {"name": "common-issues-triage"}, {"name": "sysadmin-main"}, {"name": "program-management"}, {"name": "gitfedora-project-schedule"}]}}, {"karma": 0, "karma_critpath": 0, "text": "Thanks for your help. Now, I'm able to reproduce the issue. The only thing I need to do is to log out and back in in the FreeIPA web UI and then it takes more than 90 seconds to stop the webserver even when I do it directly via `systemctl stop httpd` or `apachectl stop` commands.\n\nUnfortunately, the log of httpd does not provide anything useful because it does not generate any messages after the sigkill signal.\n```\n[Mon Nov 15 09:51:38.171812 2021] [core:info] [pid 8369:tid 8369] AH00096: removed PID file /etc/httpd/run/httpd.pid (pid=8369)\n[Mon Nov 15 09:51:38.171876 2021] [mpm_event:notice] [pid 8369:tid 8369] AH00492: caught SIGWINCH, shutting down gracefully\n[Mon Nov 15 09:51:38.171916 2021] [mpm_event:debug] [pid 8378:tid 8378] event.c(569): wake up listener\n[Mon Nov 15 09:51:38.172071 2021] [mpm_event:debug] [pid 8380:tid 8380] event.c(569): wake up listener\n[Mon Nov 15 09:51:38.173648 2021] [mpm_event:debug] [pid 8379:tid 8379] event.c(569): wake up listener\n[Mon Nov 15 09:51:38.174300 2021] [mpm_event:debug] [pid 8609:tid 8609] event.c(569): wake up listener\n[Mon Nov 15 09:51:38.182319 2021] [ssl:debug] [pid 8380:tid 8504] ssl_engine_io.c(1148): [client 10.0.0.129:43366] AH02001: Connection closed to child 128 with standard shutdown (server test.openqa.fedoraproject.org:443)\n[Mon Nov 15 09:51:38.184108 2021] [ssl:debug] [pid 8379:tid 8478] ssl_engine_io.c(1148): [client 10.0.0.129:43360] AH02001: Connection closed to child 64 with standard shutdown (server test.openqa.fedoraproject.org:443)\n[Mon Nov 15 09:51:38.187906 2021] [http2:debug] [pid 8609:tid 8609] h2_workers.c(326): h2_workers: cleanup 2 workers idling\n[Mon Nov 15 09:51:38.188243 2021] [http2:debug] [pid 8378:tid 8378] h2_workers.c(326): h2_workers: cleanup 2 workers idling\n[Mon Nov 15 09:51:38.188538 2021] [ssl:debug] [pid 8380:tid 8504] ssl_engine_io.c(1148): [client 10.0.0.129:43362] AH02001: Connection closed to child 128 with standard shutdown (server test.openqa.fedoraproject.org:443)\n[Mon Nov 15 09:51:38.189110 2021] [http2:debug] [pid 8378:tid 8378] h2_workers.c(356): h2_workers: cleanup all workers terminated\n[Mon Nov 15 09:51:38.189467 2021] [http2:debug] [pid 8378:tid 8378] h2_workers.c(359): h2_workers: cleanup zombie workers joined\n[Mon Nov 15 09:51:38.189618 2021] [wsgi:info] [pid 8378:tid 8378] mod_wsgi (pid=8378): Destroying interpreters.\n[Mon Nov 15 09:51:38.189643 2021] [wsgi:info] [pid 8378:tid 8378] mod_wsgi (pid=8378): Cleanup interpreter ''.\n[Mon Nov 15 09:51:38.190201 2021] [http2:debug] [pid 8609:tid 8609] h2_workers.c(356): h2_workers: cleanup all workers terminated\n[Mon Nov 15 09:51:38.190468 2021] [http2:debug] [pid 8609:tid 8609] h2_workers.c(359): h2_workers: cleanup zombie workers joined\n[Mon Nov 15 09:51:38.190633 2021] [wsgi:info] [pid 8609:tid 8609] mod_wsgi (pid=8609): Destroying interpreters.\n[Mon Nov 15 09:51:38.190648 2021] [wsgi:info] [pid 8609:tid 8609] mod_wsgi (pid=8609): Cleanup interpreter ''.\n[Mon Nov 15 09:51:38.192098 2021] [wsgi:info] [pid 8609:tid 8609] mod_wsgi (pid=8609): Terminating Python.\n[Mon Nov 15 09:51:38.195954 2021] [wsgi:info] [pid 8609:tid 8609] mod_wsgi (pid=8609): Python has shutdown.\n[Mon Nov 15 09:51:38.198071 2021] [http2:debug] [pid 8380:tid 8380] h2_workers.c(326): h2_workers: cleanup 2 workers idling\n[Mon Nov 15 09:51:38.198140 2021] [http2:debug] [pid 8380:tid 8380] h2_workers.c(356): h2_workers: cleanup all workers terminated\n[Mon Nov 15 09:51:38.198308 2021] [http2:debug] [pid 8380:tid 8380] h2_workers.c(359): h2_workers: cleanup zombie workers joined\n[Mon Nov 15 09:51:38.198363 2021] [wsgi:info] [pid 8380:tid 8380] mod_wsgi (pid=8380): Destroying interpreters.\n[Mon Nov 15 09:51:38.198369 2021] [wsgi:info] [pid 8380:tid 8380] mod_wsgi (pid=8380): Cleanup interpreter ''.\n[Mon Nov 15 09:51:38.199229 2021] [wsgi:info] [pid 8380:tid 8380] mod_wsgi (pid=8380): Terminating Python.\n[Mon Nov 15 09:51:38.203173 2021] [watchdog:debug] [pid 8379:tid 8382] mod_watchdog.c(257): AH02973: Singleton Watchdog (_proxy_hcheck_) stopping\n[Mon Nov 15 09:51:38.203612 2021] [http2:debug] [pid 8379:tid 8379] h2_workers.c(326): h2_workers: cleanup 2 workers idling\n[Mon Nov 15 09:51:38.203692 2021] [http2:debug] [pid 8379:tid 8379] h2_workers.c(356): h2_workers: cleanup all workers terminated\n[Mon Nov 15 09:51:38.203886 2021] [http2:debug] [pid 8379:tid 8379] h2_workers.c(359): h2_workers: cleanup zombie workers joined\n[Mon Nov 15 09:51:38.203972 2021] [wsgi:info] [pid 8379:tid 8379] mod_wsgi (pid=8379): Destroying interpreters.\n[Mon Nov 15 09:51:38.203979 2021] [wsgi:info] [pid 8379:tid 8379] mod_wsgi (pid=8379): Destroy interpreter 'test.openqa.fedoraproject.org|/ipa/wsgi/plugins.py'.\n[Mon Nov 15 09:51:38.204094 2021] [wsgi:info] [pid 8379:tid 8379] mod_wsgi (pid=8379): End interpreter 'test.openqa.fedoraproject.org|/ipa/wsgi/plugins.py'.\n[Mon Nov 15 09:51:38.204991 2021] [wsgi:info] [pid 8378:tid 8378] mod_wsgi (pid=8378): Terminating Python.\n[Mon Nov 15 09:51:38.209249 2021] [wsgi:info] [pid 8378:tid 8378] mod_wsgi (pid=8378): Python has shutdown.\n[Mon Nov 15 09:51:38.211236 2021] [watchdog:debug] [pid 8380:tid 8399] mod_watchdog.c(257): AH02973: Singleton Watchdog (_proxy_hcheck_) stopping\n[Mon Nov 15 09:51:38.213406 2021] [wsgi:info] [pid 8380:tid 8380] mod_wsgi (pid=8380): Python has shutdown.\n```\nI'm gonna try strace.", "timestamp": "2021-11-15 09:05:51", "update_id": 353349, "user_id": 2936, "id": 2284300, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "lbalhar", "email": "lbalhar@redhat.com", "id": 2936, "avatar": "https://seccdn.libravatar.org/avatar/789052d5e25db3b2c36725adeaa296f78df20334671edbb69ba42f419e1bfac4?s=24&d=retro", "openid": "lbalhar.id.fedoraproject.org", "groups": [{"name": "packager"}, {"name": "python-sig"}, {"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}, {"name": "realtime"}, {"name": "machine-learning-sig"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}]}}, {"karma": 0, "karma_critpath": 0, "text": "I'm still not sure where the problem is and I'm reaching my debugging limits but this strace output seems to be important:\n\nOld Python:\n```\n[pid  9336] 10:06:23 openat(AT_FDCWD, \"/proc/thread-self/attr/fscreate\", O_RDWR|O_CLOEXEC) = 4\n[pid  9336] 10:06:23 write(4, NULL, 0)  = 0\n[pid  9336] 10:06:23 close(4)           = 0\n[pid  9336] 10:06:23 newfstatat(AT_FDCWD, \"/run/systemd/ask-password\", {st_mode=S_IFDIR|0775, st_size=40, ...}, 0) = 0\n[pid  9336] 10:06:23 rt_sigprocmask(SIG_SETMASK, [TERM], NULL, 8) = 0\n[pid  9336] 10:06:23 signalfd4(-1, [TERM], 8, SFD_CLOEXEC|SFD_NONBLOCK) = 4\n[pid  9336] 10:06:23 inotify_init1(IN_CLOEXEC) = 5\n[pid  9336] 10:06:23 inotify_add_watch(5, \"/run/systemd/ask-password\", IN_CLOSE_WRITE|IN_MOVED_TO) = 1\n[pid  9336] 10:06:23 openat(AT_FDCWD, \"/run/systemd/ask-password\", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 6\n[pid  9336] 10:06:23 newfstatat(6, \"\", {st_mode=S_IFDIR|0775, st_size=40, ...}, AT_EMPTY_PATH) = 0\n[pid  9336] 10:06:23 getdents64(6, 0x55813e5b29c0 /* 2 entries */, 32768) = 48\n[pid  9336] 10:06:23 getdents64(6, 0x55813e5b29c0 /* 0 entries */, 32768) = 0\n[pid  9336] 10:06:23 close(6)           = 0\n[pid  9336] 10:06:23 ppoll([{fd=4, events=POLLIN}, {fd=5, events=POLLIN}], 2, NULL, NULL, 8 <unfinished ...>\n[pid  9335] 10:07:52 <... ppoll resumed>) = 1 ([{fd=3, revents=POLLIN}])\n[pid  9335] 10:07:52 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"l\\4\\1\\1\\213\\3\\0\\0\\f\\0\\0\\0\\266\\0\\0\\0\\1\\1o\\0.\\0\\0\\0\", iov_len=24}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 24\n[pid  9335] 10:07:52 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"/org/freedesktop/systemd1/unit/h\"..., iov_len=1083}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 1083\n[pid  9335] 10:07:52 recvmsg(3, {msg_namelen=0}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable)\n[pid  9335] 10:07:52 ppoll([{fd=3, events=POLLIN}], 1, NULL, NULL, 8) = 1 ([{fd=3, revents=POLLIN}])\n```\nNew Python:\n```\n[pid 10340] 10:24:43 openat(AT_FDCWD, \"/proc/thread-self/attr/fscreate\", O_RDWR|O_CLOEXEC) = 4\n[pid 10340] 10:24:43 write(4, NULL, 0)  = 0\n[pid 10340] 10:24:43 close(4)           = 0\n[pid 10340] 10:24:43 newfstatat(AT_FDCWD, \"/run/systemd/ask-password\", {st_mode=S_IFDIR|0775, st_size=40, ...}, 0) = 0\n[pid 10340] 10:24:43 rt_sigprocmask(SIG_SETMASK, [TERM], NULL, 8) = 0\n[pid 10340] 10:24:43 signalfd4(-1, [TERM], 8, SFD_CLOEXEC|SFD_NONBLOCK) = 4\n[pid 10340] 10:24:43 inotify_init1(IN_CLOEXEC) = 5\n[pid 10340] 10:24:43 inotify_add_watch(5, \"/run/systemd/ask-password\", IN_CLOSE_WRITE|IN_MOVED_TO) = 1\n[pid 10340] 10:24:43 openat(AT_FDCWD, \"/run/systemd/ask-password\", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 6\n[pid 10340] 10:24:43 newfstatat(6, \"\", {st_mode=S_IFDIR|0775, st_size=40, ...}, AT_EMPTY_PATH) = 0\n[pid 10340] 10:24:43 getdents64(6, 0x56247fdb59c0 /* 2 entries */, 32768) = 48\n[pid 10340] 10:24:43 getdents64(6, 0x56247fdb59c0 /* 0 entries */, 32768) = 0\n[pid 10340] 10:24:43 close(6)           = 0\n[pid 10340] 10:24:43 ppoll([{fd=4, events=POLLIN}, {fd=5, events=POLLIN}], 2, NULL, NULL, 8 <unfinished ...>\n[pid 10339] 10:24:44 <... ppoll resumed>) = 1 ([{fd=3, revents=POLLIN}])\n[pid 10339] 10:24:44 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"l\\4\\1\\1\\213\\3\\0\\0\\f\\0\\0\\0\\266\\0\\0\\0\\1\\1o\\0.\\0\\0\\0\", iov_len=24}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 24\n[pid 10339] 10:24:44 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"/org/freedesktop/systemd1/unit/h\"..., iov_len=1083}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 1083\n[pid 10339] 10:24:44 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"l\\4\\1\\1\\254\\3\\0\\0\\r\\0\\0\\0\\266\\0\\0\\0\\1\\1o\\0.\\0\\0\\0\", iov_len=24}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 24\n[pid 10339] 10:24:44 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"/org/freedesktop/systemd1/unit/h\"..., iov_len=1116}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 1116\n[pid 10339] 10:24:44 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"l\\4\\1\\1I\\0\\0\\0\\16\\0\\0\\0\\242\\0\\0\\0\\1\\1o\\0\\31\\0\\0\\0\", iov_len=24}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 24\n[pid 10339] 10:24:44 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"/org/freedesktop/systemd1\\0\\0\\0\\0\\0\\0\\0\"..., iov_len=233}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 233\n[pid 10339] 10:24:44 sendmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"l\\1\\4\\0012\\0\\0\\0\\4\\0\\0\\0\\240\\0\\0\\0\\1\\1o\\0.\\0\\0\\0/org/fre\"..., iov_len=176}, {iov_base=\"\\35\\0\\0\\0org.freedesktop.systemd1.Uni\"..., iov_len=50}], msg_iovlen=2, msg_controllen=0, msg_flags=0}, MSG_DONTWAIT|MSG_NOSIGNAL) = 226\n[pid 10339] 10:24:44 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"l\\4\\1\\1\\213\\3\\0\\0\\17\\0\\0\\0\\266\\0\\0\\0\\1\\1o\\0.\\0\\0\\0\", iov_len=24}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 24\n[pid 10339] 10:24:44 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"/org/freedesktop/systemd1/unit/h\"..., iov_len=1083}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 1083\n[pid 10339] 10:24:44 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"l\\4\\1\\1\\214\\3\\0\\0\\20\\0\\0\\0\\266\\0\\0\\0\\1\\1o\\0.\\0\\0\\0\", iov_len=24}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 24\n[pid 10339] 10:24:44 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"/org/freedesktop/systemd1/unit/h\"..., iov_len=1084}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 1084\n[pid 10339] 10:24:44 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"l\\4\\1\\1G\\0\\0\\0\\21\\0\\0\\0\\240\\0\\0\\0\\1\\1o\\0\\31\\0\\0\\0\", iov_len=24}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 24\n[pid 10339] 10:24:44 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"/org/freedesktop/systemd1\\0\\0\\0\\0\\0\\0\\0\"..., iov_len=223}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 223\n[pid 10339] 10:24:44 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"l\\4\\1\\1R\\0\\0\\0\\22\\0\\0\\0\\240\\0\\0\\0\\1\\1o\\0\\31\\0\\0\\0\", iov_len=24}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 24\n[pid 10339] 10:24:44 recvmsg(3, {msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base=\"/org/freedesktop/systemd1\\0\\0\\0\\0\\0\\0\\0\"..., iov_len=234}], msg_iovlen=1, msg_controllen=0, msg_flags=MSG_CMSG_CLOEXEC}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = 234\n[pid 10339] 10:24:44 recvmsg(3, {msg_namelen=0}, MSG_DONTWAIT|MSG_CMSG_CLOEXEC) = -1 EAGAIN (Resource temporarily unavailable)\n```", "timestamp": "2021-11-15 09:47:12", "update_id": 353349, "user_id": 2936, "id": 2284320, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "lbalhar", "email": "lbalhar@redhat.com", "id": 2936, "avatar": "https://seccdn.libravatar.org/avatar/789052d5e25db3b2c36725adeaa296f78df20334671edbb69ba42f419e1bfac4?s=24&d=retro", "openid": "lbalhar.id.fedoraproject.org", "groups": [{"name": "packager"}, {"name": "python-sig"}, {"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}, {"name": "realtime"}, {"name": "machine-learning-sig"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}]}}, {"karma": 0, "karma_critpath": 0, "text": "The strace logs and switched, there is no deadlock in the old Python, of course, sorry for that.", "timestamp": "2021-11-15 09:48:51", "update_id": 353349, "user_id": 2936, "id": 2284321, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "lbalhar", "email": "lbalhar@redhat.com", "id": 2936, "avatar": "https://seccdn.libravatar.org/avatar/789052d5e25db3b2c36725adeaa296f78df20334671edbb69ba42f419e1bfac4?s=24&d=retro", "openid": "lbalhar.id.fedoraproject.org", "groups": [{"name": "packager"}, {"name": "python-sig"}, {"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}, {"name": "realtime"}, {"name": "machine-learning-sig"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}]}}, {"karma": 0, "karma_critpath": 0, "text": "strace logs from `strace -t -fff apachectl stop` are available here:\n\n* https://lbalhar.fedorapeople.org/strace_python_3.9.7.txt\n* https://lbalhar.fedorapeople.org/strace_python_3.9.8.txt", "timestamp": "2021-11-15 10:09:39", "update_id": 353349, "user_id": 2936, "id": 2284366, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "lbalhar", "email": "lbalhar@redhat.com", "id": 2936, "avatar": "https://seccdn.libravatar.org/avatar/789052d5e25db3b2c36725adeaa296f78df20334671edbb69ba42f419e1bfac4?s=24&d=retro", "openid": "lbalhar.id.fedoraproject.org", "groups": [{"name": "packager"}, {"name": "python-sig"}, {"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}, {"name": "realtime"}, {"name": "machine-learning-sig"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}]}}, {"karma": 0, "karma_critpath": 0, "text": "Its unclear from the web server log the time the shutdown was requested. Do you see in those logs a request to stop and the next log line being ~90 seconds later? We sort of see that in the apachectl log but its waiting on a POLL so isn't particularly enlightening. It appears to be just waiting for Apache to stop.", "timestamp": "2021-11-15 14:29:54", "update_id": 353349, "user_id": 1255, "id": 2284606, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "rcritten", "email": "rcritten@redhat.com", "id": 1255, "avatar": "https://seccdn.libravatar.org/avatar/170a44090c681a8b42a8cb53b0952228413f629b4696953d22ea19a847fd4b4a?s=24&d=retro", "openid": "rcritten.id.fedoraproject.org", "groups": [{"name": "packager"}, {"name": "gitfreeipa-docs"}, {"name": "gitfreeipa"}, {"name": "cvsdirsec"}, {"name": "svnpki"}, {"name": "gitipsilon"}, {"name": "gitnsspem"}, {"name": "git389"}, {"name": "svnidmcommon"}, {"name": "fedorabugs"}, {"name": "gitfreeipa-foreman-smartproxy"}, {"name": "signed_fpca"}, {"name": "gitmod_nss"}, {"name": "fedora-contributor"}, {"name": "gitcertmonger"}, {"name": "ipausers"}, {"name": "gitmod_revocator"}]}}, {"karma": 0, "karma_critpath": 0, "text": "I did a time-consuming bisection of commits in Python between 3.9.7 and 3.9.8 and now I can point to the specific commit causing this issue, the winner is: https://github.com/python/cpython/commit/1ecb641b887af2feb026a266e2fceedee0815ca8 \n\nI don't understand mod_wsgi well enough to see the connection between the commit and the issue it causes but I'm a bit closer to the finish.\n\n@vstinner is the author of the code so we might be able to debug it together.", "timestamp": "2021-11-15 20:19:20", "update_id": 353349, "user_id": 2936, "id": 2284833, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "lbalhar", "email": "lbalhar@redhat.com", "id": 2936, "avatar": "https://seccdn.libravatar.org/avatar/789052d5e25db3b2c36725adeaa296f78df20334671edbb69ba42f419e1bfac4?s=24&d=retro", "openid": "lbalhar.id.fedoraproject.org", "groups": [{"name": "packager"}, {"name": "python-sig"}, {"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}, {"name": "realtime"}, {"name": "machine-learning-sig"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}]}}, {"karma": 0, "karma_critpath": 0, "text": "Seems like Python 3.9.8 introduced a regression in argparse which causes complex command-line tools to fail to recognize sub-commands properly.  You can find more info here: https://bugs.python.org/issue45235\n\nUpstream already published hotfix release 3.9.9. I think we shouldn't ship 3.9.8 at all and do a 3.9.9 update where we can revert the commit causing freeipa to fail. WDYT?\n", "timestamp": "2021-11-16 07:44:06", "update_id": 353349, "user_id": 5427, "id": 2285292, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "thrnciar", "email": "thrnciar@redhat.com", "id": 5427, "avatar": "https://seccdn.libravatar.org/avatar/a973da034e49a14259bb98d71a1c60082c29ebcb91c4d7c9c8cb567099bad334?s=24&d=retro", "openid": "thrnciar.id.fedoraproject.org", "groups": [{"name": "packager"}, {"name": "provenpackager"}, {"name": "python-sig"}, {"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}, {"name": "gitcopr"}, {"name": "python-packagers-sig"}]}}, {"karma": 0, "karma_critpath": 0, "text": "I've tried to bisect the commit again because I wasn't able to reproduce the issue with reverted commit 1ecb641b887af2feb026a266e2fceedee0815ca8 and now it seems that the issue is caused by an earlier commit: https://github.com/python/cpython/commit/94d19f606fa18a1c4d2faca1caf2f470a8ce6d46 \n\nAlso, it seems that the only thing one needs to do to reproduce the issue is: start the webserver \u2192 login to the FreeIPA web UI \u2192 log out from the web UI \u2192 stop the webserver.\n\nIt makes sense to try Python 3.9.9 even I think this problem has nothing to do with argparse. I'm gonna take a look on the changed files in the new release. I might find something else interesting as well.", "timestamp": "2021-11-16 09:46:55", "update_id": 353349, "user_id": 2936, "id": 2285347, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "lbalhar", "email": "lbalhar@redhat.com", "id": 2936, "avatar": "https://seccdn.libravatar.org/avatar/789052d5e25db3b2c36725adeaa296f78df20334671edbb69ba42f419e1bfac4?s=24&d=retro", "openid": "lbalhar.id.fedoraproject.org", "groups": [{"name": "packager"}, {"name": "python-sig"}, {"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}, {"name": "realtime"}, {"name": "machine-learning-sig"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}]}}, {"karma": 0, "karma_critpath": 0, "text": "By the way, I've also tried to set up a simple Python wsgi application and I'm not able to reproduce the same issue with it. From the FreeIPA configuration, it also seems that it does not use threads in mod_wsgi but uses some threading in its own code so it might be related to FreeIPA and not to mod_wsgi in general.", "timestamp": "2021-11-16 09:53:29", "update_id": 353349, "user_id": 2936, "id": 2285355, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "lbalhar", "email": "lbalhar@redhat.com", "id": 2936, "avatar": "https://seccdn.libravatar.org/avatar/789052d5e25db3b2c36725adeaa296f78df20334671edbb69ba42f419e1bfac4?s=24&d=retro", "openid": "lbalhar.id.fedoraproject.org", "groups": [{"name": "packager"}, {"name": "python-sig"}, {"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}, {"name": "realtime"}, {"name": "machine-learning-sig"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}]}}, {"karma": 0, "karma_critpath": 0, "text": "After one more day of debugging, I've created an upstream issue because it does not seem to me that the problem is in FreeIPA: https://github.com/GrahamDumpleton/mod_wsgi/issues/730", "timestamp": "2021-11-16 23:24:08", "update_id": 353349, "user_id": 2936, "id": 2286067, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "lbalhar", "email": "lbalhar@redhat.com", "id": 2936, "avatar": "https://seccdn.libravatar.org/avatar/789052d5e25db3b2c36725adeaa296f78df20334671edbb69ba42f419e1bfac4?s=24&d=retro", "openid": "lbalhar.id.fedoraproject.org", "groups": [{"name": "packager"}, {"name": "python-sig"}, {"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}, {"name": "realtime"}, {"name": "machine-learning-sig"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}]}}, {"karma": 0, "karma_critpath": 0, "text": "Thanks a lot for all the work on this (and the continuing work in the github issue)! Sorry I went AWOL after that last comment, I didn't manage to get the package list on that day and then I was on vacation. Seems like you got along fine without me, though. :D", "timestamp": "2021-11-19 17:13:27", "update_id": 353349, "user_id": 302, "id": 2288231, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "adamwill", "email": "awilliam@redhat.com", "id": 302, "avatar": "https://seccdn.libravatar.org/avatar/51720fbb2ec5dfd2bc005ac374a3bfd3190cb8f45f3bb8d6bdf35fb6a051d03b?s=24&d=retro", "openid": "adamwill.id.fedoraproject.org", "groups": [{"name": "proventesters"}, {"name": "provenpackager"}, {"name": "packager"}, {"name": "qa-tools-sig"}, {"name": "fedora-contributor"}, {"name": "news"}, {"name": "gittriage"}, {"name": "sysadmin"}, {"name": "gitspin-kickstarts"}, {"name": "signed_fpca"}, {"name": "gitgeneric-release"}, {"name": "yak_farmers"}, {"name": "triagers"}, {"name": "qa"}, {"name": "sysadmin-qa"}, {"name": "fedorabugs"}, {"name": "ipausers"}, {"name": "gitmkinitrd"}, {"name": "qa-admin"}, {"name": "aws-qa"}, {"name": "change-wranglers"}, {"name": "fedora-ci-admins"}, {"name": "common-issues-triage"}, {"name": "sysadmin-main"}, {"name": "program-management"}, {"name": "gitfedora-project-schedule"}]}}, {"karma": 0, "karma_critpath": 0, "text": "churchyard edited this update.\n\nNew build(s):\n\n- python3.9-3.9.9-2.fc34\n\nRemoved build(s):\n\n- python3.9-3.9.8-1.fc34\n\nKarma has been reset.", "timestamp": "2021-11-19 18:59:48", "update_id": 353349, "user_id": 91, "id": 2288321, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "This update has been submitted for testing by churchyard. ", "timestamp": "2021-11-19 18:59:50", "update_id": 353349, "user_id": 91, "id": 2288322, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "churchyard edited this update.\n\nNew build(s):\n\n- python3-docs-3.9.9-1.fc34\n\nRemoved build(s):\n\n- python3-docs-3.9.8-1.fc34\n\nKarma has been reset.", "timestamp": "2021-11-19 19:00:58", "update_id": 353349, "user_id": 91, "id": 2288323, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "This update's test gating status has been changed to 'passed'.", "timestamp": "2021-11-19 21:00:45", "update_id": 353349, "user_id": 91, "id": 2288471, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "This update has been pushed to testing.", "timestamp": "2021-11-20 02:05:54", "update_id": 353349, "user_id": 91, "id": 2288631, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "churchyard edited this update.", "timestamp": "2021-11-20 07:40:53", "update_id": 353349, "user_id": 91, "id": 2288813, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "We have reverted the problematic commit. The test passed.", "timestamp": "2021-11-20 07:41:56", "update_id": 353349, "user_id": 533, "id": 2288817, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "churchyard", "email": "mhroncok@redhat.com", "id": 533, "avatar": "https://seccdn.libravatar.org/avatar/e221b70024cf971d8b43de0260d2babde9179cdf72605bf3168420e3efe07423?s=24&d=retro", "openid": "churchyard.id.fedoraproject.org", "groups": [{"name": "provenpackager"}, {"name": "packager"}, {"name": "python-sig"}, {"name": "signed_fpca"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}, {"name": "fedora-contributor"}, {"name": "sysadmin-badges"}, {"name": "ipausers"}, {"name": "sysadmin"}, {"name": "lua-packagers-sig"}, {"name": "fedorabugs"}, {"name": "cvsadmin"}, {"name": "ambassadors"}, {"name": "packaging-committee"}, {"name": "advocates"}]}}, {"karma": 1, "karma_critpath": 0, "text": "I've verified it also manually.", "timestamp": "2021-11-20 08:29:13", "update_id": 353349, "user_id": 2936, "id": 2288856, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "lbalhar", "email": "lbalhar@redhat.com", "id": 2936, "avatar": "https://seccdn.libravatar.org/avatar/789052d5e25db3b2c36725adeaa296f78df20334671edbb69ba42f419e1bfac4?s=24&d=retro", "openid": "lbalhar.id.fedoraproject.org", "groups": [{"name": "packager"}, {"name": "python-sig"}, {"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}, {"name": "realtime"}, {"name": "machine-learning-sig"}, {"name": "3d-printing-sig"}, {"name": "python-packagers-sig"}]}}, {"karma": 1, "karma_critpath": 0, "text": "wfm", "timestamp": "2021-12-01 07:03:54", "update_id": 353349, "user_id": 4555, "id": 2297798, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "t3rm1n4l", "email": "stealthcipher@gmail.com", "id": 4555, "avatar": "https://seccdn.libravatar.org/avatar/cb6c19faf9628e1df86e8566dea353017cb4d032ca56ef353fdb860693df9fef?s=24&d=retro", "openid": "t3rm1n4l.id.fedoraproject.org", "groups": [{"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}]}}, {"karma": 0, "karma_critpath": 0, "text": "This update can be pushed to stable now if the maintainer wishes", "timestamp": "2021-12-01 07:06:29", "update_id": 353349, "user_id": 91, "id": 2297799, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 1, "karma_critpath": 0, "text": "Works for me.", "timestamp": "2021-12-01 11:10:46", "update_id": 353349, "user_id": 273, "id": 2298051, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "wolnei", "email": "e@wolnei.com.br", "id": 273, "avatar": "https://seccdn.libravatar.org/avatar/80619c350617edf030f2667bd8ffe77ff68f515022f339677c4571a0b2ec8296?s=24&d=retro", "openid": "wolnei.id.fedoraproject.org", "groups": [{"name": "qa"}, {"name": "ipausers"}, {"name": "fedora-contributor"}, {"name": "signed_fpca"}, {"name": "fedorabugs"}, {"name": "ambassadors"}, {"name": "fedora-br"}, {"name": "triagers"}, {"name": "advocates"}]}}, {"karma": 0, "karma_critpath": 0, "text": "This update has been submitted for stable by bodhi. ", "timestamp": "2021-12-04 02:05:18", "update_id": 353349, "user_id": 91, "id": 2300626, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}, {"karma": 0, "karma_critpath": 0, "text": "This update has been pushed to stable.", "timestamp": "2021-12-05 01:37:51", "update_id": 353349, "user_id": 91, "id": 2301223, "bug_feedback": [], "testcase_feedback": [], "user": {"name": "bodhi", "email": null, "id": 91, "avatar": "https://apps.fedoraproject.org/img/icons/bodhi-24.png", "openid": "bodhi.id.fedoraproject.org", "groups": []}}], "builds": [{"nvr": "python3.9-3.9.9-2.fc34", "signed": true, "release_id": 47, "type": "rpm", "epoch": 0}, {"nvr": "python3-docs-3.9.9-1.fc34", "signed": true, "release_id": 47, "type": "rpm", "epoch": 0}, {"nvr": "python3-typed_ast-1.4.3-4.fc34", "signed": true, "release_id": 47, "type": "rpm", "epoch": 0}], "bugs": [], "updateid": "FEDORA-2021-e152ce5f31", "karma": 3, "content_type": "rpm", "test_cases": []}, "can_edit": false, "ci_allowed": false}