2026-03-06 00:06:52.325345 | Job console starting... 2026-03-06 00:06:52.334961 | Updating repositories 2026-03-06 00:06:55.586995 | Preparing job workspace 2026-03-06 00:07:02.458517 | Running Ansible setup... 2026-03-06 00:07:07.646580 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-03-06 00:07:08.300000 | 2026-03-06 00:07:08.300135 | PLAY [localhost] 2026-03-06 00:07:08.308646 | 2026-03-06 00:07:08.308723 | TASK [Gathering Facts] 2026-03-06 00:07:09.377868 | localhost | ok 2026-03-06 00:07:09.402290 | 2026-03-06 00:07:09.402494 | TASK [Setup log path fact] 2026-03-06 00:07:09.423029 | localhost | ok 2026-03-06 00:07:09.440979 | 2026-03-06 00:07:09.441160 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-06 00:07:09.470549 | localhost | ok 2026-03-06 00:07:09.480051 | 2026-03-06 00:07:09.480179 | TASK [emit-job-header : Print job information] 2026-03-06 00:07:09.508589 | # Job Information 2026-03-06 00:07:09.508747 | Ansible Version: 2.15.12 2026-03-06 00:07:09.508778 | Job: ansible-test-sanity-docker-milestone 2026-03-06 00:07:09.508799 | Pipeline: periodic 2026-03-06 00:07:09.508818 | Executor: ze01.softwarefactory-project.io 2026-03-06 00:07:09.508836 | Triggered by: https://github.com/ansible-collections/ansible.network 2026-03-06 00:07:09.508857 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/495/ansible/4951d689f16148c58743c9f654cf4312/ 2026-03-06 00:07:09.508876 | Event ID: cd32135b903048a8b5523f70ed18b23e 2026-03-06 00:07:09.513074 | 2026-03-06 00:07:09.513154 | LOOP [emit-job-header : Print node information] 2026-03-06 00:07:09.619333 | localhost | ok: 2026-03-06 00:07:09.619626 | localhost | # Node Information 2026-03-06 00:07:09.619690 | localhost | Inventory Hostname: controller 2026-03-06 00:07:09.619741 | localhost | Hostname: np0005639332 2026-03-06 00:07:09.619792 | localhost | Username: zuul 2026-03-06 00:07:09.619849 | localhost | Distro: Fedora 37 2026-03-06 00:07:09.619899 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2026-03-06 00:07:09.619948 | localhost | Region: ca-ymq-1 2026-03-06 00:07:09.619996 | localhost | Label: ansible-fedora-37-1vcpu 2026-03-06 00:07:09.620083 | localhost | Product Name: OpenStack Nova 2026-03-06 00:07:09.620133 | localhost | Interface IP: 162.253.55.70 2026-03-06 00:07:09.637995 | 2026-03-06 00:07:09.638117 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2026-03-06 00:07:09.989058 | localhost -> localhost | changed 2026-03-06 00:07:09.994752 | 2026-03-06 00:07:09.994821 | TASK [log-inventory : Copy ansible inventory to logs dir] 2026-03-06 00:07:11.087557 | localhost -> localhost | changed 2026-03-06 00:07:11.109581 | 2026-03-06 00:07:11.109660 | PLAY [all:!appliance*] 2026-03-06 00:07:11.127999 | 2026-03-06 00:07:11.128095 | TASK [include_role : start-zuul-console] 2026-03-06 00:07:11.150269 | controller | ok 2026-03-06 00:07:11.164808 | 2026-03-06 00:07:11.164888 | TASK [start-zuul-console : Start zuul_console daemon.] 2026-03-06 00:07:11.542511 | controller | ok 2026-03-06 00:07:11.560514 | 2026-03-06 00:07:11.560626 | TASK [use-our-mirror : Retrieve the IP address] 2026-03-06 00:07:13.003878 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2026-03-06 00:07:13.017852 | 2026-03-06 00:07:13.018159 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2026-03-06 00:07:13.573504 | controller | skipping: Conditional result was False 2026-03-06 00:07:13.580600 | 2026-03-06 00:07:13.580680 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2026-03-06 00:07:13.605300 | controller | skipping: Conditional result was False 2026-03-06 00:07:13.612067 | 2026-03-06 00:07:13.612137 | TASK [use-our-mirror : Create the podman configuration directory] 2026-03-06 00:07:13.626315 | controller | skipping: Conditional result was False 2026-03-06 00:07:13.632774 | 2026-03-06 00:07:13.632840 | TASK [use-our-mirror : Copy the podman configuration] 2026-03-06 00:07:13.647124 | controller | skipping: Conditional result was False 2026-03-06 00:07:13.657207 | 2026-03-06 00:07:13.657352 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2026-03-06 00:07:13.685422 | controller | skipping: Conditional result was False 2026-03-06 00:07:13.693111 | 2026-03-06 00:07:13.693236 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2026-03-06 00:07:13.707466 | controller | skipping: Conditional result was False 2026-03-06 00:07:13.719039 | 2026-03-06 00:07:13.719120 | TASK [Disable Fedora Modular] 2026-03-06 00:07:13.961551 | controller | changed 2026-03-06 00:07:13.966987 | 2026-03-06 00:07:13.967071 | TASK [Enable EPEL] 2026-03-06 00:07:13.980570 | controller | skipping: Conditional result was False 2026-03-06 00:07:13.986369 | 2026-03-06 00:07:13.986440 | TASK [Register the RHEL node] 2026-03-06 00:07:14.531690 | 2026-03-06 00:07:14.531968 | TASK [Show the subscription-manager status] 2026-03-06 00:07:15.113612 | controller | skipping: Conditional result was False 2026-03-06 00:07:15.120484 | 2026-03-06 00:07:15.120548 | TASK [Enable EPEL on RHEL] 2026-03-06 00:07:15.692494 | controller | skipping: Conditional result was False 2026-03-06 00:07:15.699366 | 2026-03-06 00:07:15.699437 | TASK [Install git and tox] 2026-03-06 00:08:41.397900 | controller | changed 2026-03-06 00:08:41.405560 | 2026-03-06 00:08:41.405635 | TASK [include_role : prepare-workspace] 2026-03-06 00:08:41.432777 | controller | ok 2026-03-06 00:08:41.466339 | 2026-03-06 00:08:41.466500 | TASK [prepare-workspace : Start zuul_console daemon.] 2026-03-06 00:08:41.736342 | controller | ok 2026-03-06 00:08:41.755901 | 2026-03-06 00:08:41.756163 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2026-03-06 00:14:13.426304 | controller | Output suppressed because no_log was given 2026-03-06 00:14:13.450190 | 2026-03-06 00:14:13.450410 | TASK [include_role : prepare-workspace-openshift] 2026-03-06 00:14:13.477472 | controller | skipping: Conditional result was False 2026-03-06 00:14:13.509903 | 2026-03-06 00:14:13.510008 | PLAY [all:!appliance] 2026-03-06 00:14:13.532241 | 2026-03-06 00:14:13.532367 | TASK [Run add-build-sshkey role (RSA)] 2026-03-06 00:14:13.564115 | controller | ok 2026-03-06 00:14:13.581440 | 2026-03-06 00:14:13.581568 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-03-06 00:14:13.839560 | controller -> localhost | ok 2026-03-06 00:14:13.846781 | 2026-03-06 00:14:13.846849 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-03-06 00:14:13.884009 | controller | ok 2026-03-06 00:14:13.911563 | controller | included: /var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-03-06 00:14:13.920419 | 2026-03-06 00:14:13.920510 | TASK [add-build-sshkey : Create Temp SSH key] 2026-03-06 00:14:14.511812 | controller -> localhost | Generating public/private rsa key pair. 2026-03-06 00:14:14.512212 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/work/4951d689f16148c58743c9f654cf4312_id_rsa. 2026-03-06 00:14:14.512278 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/work/4951d689f16148c58743c9f654cf4312_id_rsa.pub. 2026-03-06 00:14:14.512326 | controller -> localhost | The key fingerprint is: 2026-03-06 00:14:14.512372 | controller -> localhost | SHA256:Q+Qt2KM+th55lhCJKZVp+IHlJFHapTqHktyZe23jTwc zuul-build-sshkey 2026-03-06 00:14:14.512417 | controller -> localhost | The key's randomart image is: 2026-03-06 00:14:14.512459 | controller -> localhost | +---[RSA 2048]----+ 2026-03-06 00:14:14.512501 | controller -> localhost | | o*=o. . | 2026-03-06 00:14:14.512555 | controller -> localhost | | oB== * . | 2026-03-06 00:14:14.512623 | controller -> localhost | | oo*.+ * . | 2026-03-06 00:14:14.512702 | controller -> localhost | |...++ + o | 2026-03-06 00:14:14.512774 | controller -> localhost | |o.++. o SE | 2026-03-06 00:14:14.512846 | controller -> localhost | | . o...o o. | 2026-03-06 00:14:14.512902 | controller -> localhost | | . .*++. . | 2026-03-06 00:14:14.512950 | controller -> localhost | | ..o*o . | 2026-03-06 00:14:14.512993 | controller -> localhost | | .o... | 2026-03-06 00:14:14.513105 | controller -> localhost | +----[SHA256]-----+ 2026-03-06 00:14:14.513214 | controller -> localhost | ok: Runtime: 0:00:00.166413 2026-03-06 00:14:14.528488 | 2026-03-06 00:14:14.528679 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-03-06 00:14:14.575757 | controller | ok 2026-03-06 00:14:14.591527 | controller | included: /var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-03-06 00:14:14.605006 | 2026-03-06 00:14:14.605154 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-03-06 00:14:14.630791 | controller | skipping: Conditional result was False 2026-03-06 00:14:14.640867 | 2026-03-06 00:14:14.640983 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-03-06 00:14:15.283536 | controller | changed 2026-03-06 00:14:15.296990 | 2026-03-06 00:14:15.297227 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-03-06 00:14:15.538804 | controller | ok 2026-03-06 00:14:15.546783 | 2026-03-06 00:14:15.546906 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-03-06 00:14:16.188675 | controller | changed 2026-03-06 00:14:16.201427 | 2026-03-06 00:14:16.201583 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-03-06 00:14:16.856835 | controller | changed 2026-03-06 00:14:16.869988 | 2026-03-06 00:14:16.870174 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-03-06 00:14:16.897996 | controller | skipping: Conditional result was False 2026-03-06 00:14:16.913539 | 2026-03-06 00:14:16.913731 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-03-06 00:14:17.350203 | controller -> localhost | changed 2026-03-06 00:14:17.364165 | 2026-03-06 00:14:17.364309 | TASK [add-build-sshkey : Add back temp key] 2026-03-06 00:14:17.685578 | controller -> localhost | Identity added: /var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/work/4951d689f16148c58743c9f654cf4312_id_rsa (zuul-build-sshkey) 2026-03-06 00:14:17.685858 | controller -> localhost | ok: Runtime: 0:00:00.010593 2026-03-06 00:14:17.695504 | 2026-03-06 00:14:17.695661 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-03-06 00:14:18.068467 | controller | ok 2026-03-06 00:14:18.076466 | 2026-03-06 00:14:18.076590 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-03-06 00:14:18.112072 | controller | skipping: Conditional result was False 2026-03-06 00:14:18.125857 | 2026-03-06 00:14:18.125983 | TASK [Run add-build-sshkey role (ECDSA)] 2026-03-06 00:14:18.148185 | controller | ok 2026-03-06 00:14:18.172594 | 2026-03-06 00:14:18.172829 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2026-03-06 00:14:18.411793 | controller -> localhost | ok 2026-03-06 00:14:18.419370 | 2026-03-06 00:14:18.419487 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2026-03-06 00:14:18.442244 | controller | ok 2026-03-06 00:14:18.455099 | controller | included: /var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2026-03-06 00:14:18.461877 | 2026-03-06 00:14:18.462111 | TASK [add-build-sshkey : Create Temp SSH key] 2026-03-06 00:14:18.784125 | controller -> localhost | Generating public/private ecdsa key pair. 2026-03-06 00:14:18.784346 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/work/4951d689f16148c58743c9f654cf4312_id_ecdsa. 2026-03-06 00:14:18.784377 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/work/4951d689f16148c58743c9f654cf4312_id_ecdsa.pub. 2026-03-06 00:14:18.784407 | controller -> localhost | The key fingerprint is: 2026-03-06 00:14:18.784427 | controller -> localhost | SHA256:FJLUZ3gLvQlbBib+mBLuVEMn0jZ/dTJAq/+4x3L73LU zuul-build-sshkey 2026-03-06 00:14:18.784446 | controller -> localhost | The key's randomart image is: 2026-03-06 00:14:18.784464 | controller -> localhost | +---[ECDSA 521]---+ 2026-03-06 00:14:18.784483 | controller -> localhost | | .o*o==o. | 2026-03-06 00:14:18.784500 | controller -> localhost | | +=*=.B.+ . | 2026-03-06 00:14:18.784517 | controller -> localhost | | ..+o.X.= + | 2026-03-06 00:14:18.784535 | controller -> localhost | | . o *o.= | 2026-03-06 00:14:18.784552 | controller -> localhost | | + o S. | 2026-03-06 00:14:18.784569 | controller -> localhost | | o . . | 2026-03-06 00:14:18.784585 | controller -> localhost | | . .. .| 2026-03-06 00:14:18.784602 | controller -> localhost | | .o+. .o| 2026-03-06 00:14:18.784619 | controller -> localhost | | o=oooE.| 2026-03-06 00:14:18.784636 | controller -> localhost | +----[SHA256]-----+ 2026-03-06 00:14:18.784692 | controller -> localhost | ok: Runtime: 0:00:00.013909 2026-03-06 00:14:18.791533 | 2026-03-06 00:14:18.791643 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2026-03-06 00:14:18.821631 | controller | ok 2026-03-06 00:14:18.829011 | controller | included: /var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2026-03-06 00:14:18.838256 | 2026-03-06 00:14:18.838320 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2026-03-06 00:14:18.863576 | controller | skipping: Conditional result was False 2026-03-06 00:14:18.871360 | 2026-03-06 00:14:18.871456 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2026-03-06 00:14:19.153377 | controller | changed 2026-03-06 00:14:19.167320 | 2026-03-06 00:14:19.167470 | TASK [add-build-sshkey : Make sure user has a .ssh] 2026-03-06 00:14:19.422483 | controller | ok 2026-03-06 00:14:19.437874 | 2026-03-06 00:14:19.438243 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2026-03-06 00:14:20.111353 | controller | changed 2026-03-06 00:14:20.121248 | 2026-03-06 00:14:20.121378 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2026-03-06 00:14:20.784589 | controller | changed 2026-03-06 00:14:20.799123 | 2026-03-06 00:14:20.799289 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2026-03-06 00:14:20.817296 | controller | skipping: Conditional result was False 2026-03-06 00:14:20.874679 | 2026-03-06 00:14:20.874834 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2026-03-06 00:14:21.166861 | controller -> localhost | changed 2026-03-06 00:14:21.193897 | 2026-03-06 00:14:21.194089 | TASK [add-build-sshkey : Add back temp key] 2026-03-06 00:14:21.499916 | controller -> localhost | Identity added: /var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/work/4951d689f16148c58743c9f654cf4312_id_ecdsa (zuul-build-sshkey) 2026-03-06 00:14:21.500580 | controller -> localhost | ok: Runtime: 0:00:00.013810 2026-03-06 00:14:21.518621 | 2026-03-06 00:14:21.519072 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2026-03-06 00:14:21.729910 | controller | ok 2026-03-06 00:14:21.739832 | 2026-03-06 00:14:21.739970 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2026-03-06 00:14:21.776568 | controller | skipping: Conditional result was False 2026-03-06 00:14:21.795694 | 2026-03-06 00:14:21.796010 | TASK [include_role : remove-zuul-sshkey] 2026-03-06 00:14:21.812919 | controller | skipping: Conditional result was False 2026-03-06 00:14:21.823760 | 2026-03-06 00:14:21.823896 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2026-03-06 00:14:22.063437 | controller | ok: "logs" 2026-03-06 00:14:22.063670 | controller | ok: All items complete 2026-03-06 00:14:22.063697 | 2026-03-06 00:14:22.258295 | controller | ok: "artifacts" 2026-03-06 00:14:22.442980 | controller | ok: "docs" 2026-03-06 00:14:22.461782 | 2026-03-06 00:14:22.461924 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2026-03-06 00:14:22.683592 | controller | changed: "logs" 2026-03-06 00:14:22.873653 | controller | changed: "artifacts" 2026-03-06 00:14:23.061180 | controller | changed: "docs" 2026-03-06 00:14:23.098850 | 2026-03-06 00:14:23.098983 | PLAY RECAP 2026-03-06 00:14:23.099044 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2026-03-06 00:14:23.099077 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2026-03-06 00:14:23.099096 | 2026-03-06 00:14:23.222971 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2026-03-06 00:14:23.224368 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-03-06 00:14:23.856883 | 2026-03-06 00:14:23.857031 | PLAY [all] 2026-03-06 00:14:23.883687 | 2026-03-06 00:14:23.883843 | TASK [Install binary dependencies] 2026-03-06 00:14:23.935253 | controller | ok 2026-03-06 00:14:23.964116 | 2026-03-06 00:14:23.964302 | TASK [bindep : Include find tasks] 2026-03-06 00:14:23.996066 | controller | ok 2026-03-06 00:14:24.006380 | controller | included: /var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2026-03-06 00:14:24.014127 | 2026-03-06 00:14:24.014258 | TASK [bindep : Look for bindep.txt] 2026-03-06 00:14:24.781611 | controller | ok 2026-03-06 00:14:24.787689 | 2026-03-06 00:14:24.787796 | TASK [bindep : Define bindep_file fact] 2026-03-06 00:14:24.813138 | controller | skipping: Conditional result was False 2026-03-06 00:14:24.820444 | 2026-03-06 00:14:24.820565 | TASK [bindep : Look for other-requirements.txt] 2026-03-06 00:14:25.038721 | controller | ok 2026-03-06 00:14:25.047377 | 2026-03-06 00:14:25.047527 | TASK [bindep : Define bindep_file fact] 2026-03-06 00:14:25.084382 | controller | skipping: Conditional result was False 2026-03-06 00:14:25.101970 | 2026-03-06 00:14:25.102211 | TASK [bindep : Look for bindep fallback file] 2026-03-06 00:14:25.130527 | controller | skipping: Conditional result was False 2026-03-06 00:14:25.145114 | 2026-03-06 00:14:25.145307 | TASK [bindep : Define bindep_file fact] 2026-03-06 00:14:25.183671 | controller | skipping: Conditional result was False 2026-03-06 00:14:25.198453 | 2026-03-06 00:14:25.198652 | TASK [bindep : Include bindep tasks] 2026-03-06 00:14:25.236837 | controller | skipping: Conditional result was False 2026-03-06 00:14:25.250817 | 2026-03-06 00:14:25.251007 | TASK [bindep : Include install tasks] 2026-03-06 00:14:25.279270 | controller | skipping: Conditional result was False 2026-03-06 00:14:25.293309 | 2026-03-06 00:14:25.293509 | LOOP [bindep : Include package tasks] 2026-03-06 00:14:25.356032 | 2026-03-06 00:14:25.356233 | TASK [Run test-setup role] 2026-03-06 00:14:25.378785 | controller | ok 2026-03-06 00:14:25.404770 | 2026-03-06 00:14:25.404919 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2026-03-06 00:14:25.614273 | controller | ok 2026-03-06 00:14:25.625227 | 2026-03-06 00:14:25.625374 | TASK [test-setup : Run tools/test-setup.sh] 2026-03-06 00:14:26.169452 | controller | skipping: Conditional result was False 2026-03-06 00:14:26.226850 | 2026-03-06 00:14:26.226964 | PLAY RECAP 2026-03-06 00:14:26.227038 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-03-06 00:14:26.227076 | 2026-03-06 00:14:26.335811 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2026-03-06 00:14:26.336681 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-03-06 00:14:26.944424 | 2026-03-06 00:14:26.944568 | PLAY [controller] 2026-03-06 00:14:26.970624 | 2026-03-06 00:14:26.970792 | TASK [Create the /root directory] 2026-03-06 00:14:27.510639 | controller | ok 2026-03-06 00:14:27.524946 | 2026-03-06 00:14:27.525192 | TASK [Install glibc-langpack-en] 2026-03-06 00:14:31.574328 | controller | ok: Nothing to do 2026-03-06 00:14:31.587646 | 2026-03-06 00:14:31.587794 | TASK [Ensure controller directory exists] 2026-03-06 00:14:31.813987 | controller | changed 2026-03-06 00:14:31.827562 | 2026-03-06 00:14:31.827708 | TASK [Install container runtime] 2026-03-06 00:14:31.907994 | controller | ok 2026-03-06 00:14:31.966883 | 2026-03-06 00:14:31.967025 | LOOP [ensure-podman : Find distribution installation] 2026-03-06 00:14:31.997692 | controller | ok: "/var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2026-03-06 00:14:32.016257 | controller | included: /var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2026-03-06 00:14:32.027721 | 2026-03-06 00:14:32.027875 | TASK [ensure-podman : Install podman (RedHat)] 2026-03-06 00:15:43.850791 | controller | changed 2026-03-06 00:15:43.858267 | 2026-03-06 00:15:43.858355 | TASK [ensure-podman : Fetch podman version] 2026-03-06 00:15:44.407152 | controller | Client: Podman Engine 2026-03-06 00:15:44.434788 | controller | Version: 4.6.2 2026-03-06 00:15:44.434827 | controller | API Version: 4.6.2 2026-03-06 00:15:44.434840 | controller | Go Version: go1.19.12 2026-03-06 00:15:44.434861 | controller | Built: Mon Aug 28 19:38:31 2023 2026-03-06 00:15:44.434873 | controller | OS/Arch: linux/amd64 2026-03-06 00:15:44.889715 | controller | ok: Runtime: 0:00:00.192183 2026-03-06 00:15:44.896528 | 2026-03-06 00:15:44.896638 | TASK [ensure-podman : Print podman version installed] 2026-03-06 00:15:44.947439 | Podman version: Client: Podman Engine 2026-03-06 00:15:44.947725 | Version: 4.6.2 2026-03-06 00:15:44.947815 | API Version: 4.6.2 2026-03-06 00:15:44.947883 | Go Version: go1.19.12 2026-03-06 00:15:44.947931 | Built: Mon Aug 28 19:38:31 2023 2026-03-06 00:15:44.947982 | OS/Arch: linux/amd64 2026-03-06 00:15:44.962489 | 2026-03-06 00:15:44.962662 | TASK [ensure-podman : Validate podman engine] 2026-03-06 00:15:45.508048 | controller | skipping: Conditional result was False 2026-03-06 00:15:45.520584 | 2026-03-06 00:15:45.520724 | TASK [ensure-podman : Set up docker compatability socket] 2026-03-06 00:15:45.535408 | controller | skipping: Conditional result was False 2026-03-06 00:15:45.547573 | 2026-03-06 00:15:45.547696 | TASK [Ensure python3.8 is present] 2026-03-06 00:15:45.562465 | controller | skipping: Conditional result was False 2026-03-06 00:15:45.572339 | 2026-03-06 00:15:45.572468 | TASK [Run our-ensure-python role (Fedora only for now)] 2026-03-06 00:15:45.595195 | controller | ok 2026-03-06 00:15:45.625959 | 2026-03-06 00:15:45.626134 | TASK [our-ensure-python : Install the right Python version (rpm)] 2026-03-06 00:15:47.255172 | controller | ok: Nothing to do 2026-03-06 00:15:47.270612 | 2026-03-06 00:15:47.270814 | TASK [our-ensure-python : Also install python3-devel] 2026-03-06 00:15:56.345429 | controller | changed 2026-03-06 00:15:56.370258 | 2026-03-06 00:15:56.371064 | TASK [Run ensure-virtualenv role] 2026-03-06 00:15:56.396072 | controller | ok 2026-03-06 00:15:56.427484 | 2026-03-06 00:15:56.427937 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2026-03-06 00:15:56.647205 | controller | /usr/bin/virtualenv 2026-03-06 00:15:56.963487 | controller | ok: Runtime: 0:00:00.005503 2026-03-06 00:15:56.973552 | 2026-03-06 00:15:56.973684 | LOOP [ensure-virtualenv : Install virtualenv package] 2026-03-06 00:15:56.995569 | controller | skipping: Conditional result was False 2026-03-06 00:15:56.995806 | controller | ok: All items complete 2026-03-06 00:15:56.995835 | 2026-03-06 00:15:57.016873 | 2026-03-06 00:15:57.017058 | TASK [Find the full path of the Python interpreter] 2026-03-06 00:15:57.248290 | controller | /usr/bin/python3 2026-03-06 00:15:57.561931 | controller | ok 2026-03-06 00:15:57.567785 | 2026-03-06 00:15:57.567861 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2026-03-06 00:15:58.383812 | controller | created virtual environment CPython3.11.0.final.0-64 in 467ms 2026-03-06 00:15:58.408523 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2026-03-06 00:15:58.408852 | controller | seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv) 2026-03-06 00:15:58.408866 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2026-03-06 00:15:58.408882 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2026-03-06 00:15:58.606136 | controller | changed 2026-03-06 00:15:58.616710 | 2026-03-06 00:15:58.616851 | TASK [Set selinux package] 2026-03-06 00:15:58.653500 | controller | ok 2026-03-06 00:15:58.661857 | 2026-03-06 00:15:58.661990 | TASK [Set selinux package (Fedora)] 2026-03-06 00:15:58.705411 | controller | ok 2026-03-06 00:15:58.712892 | 2026-03-06 00:15:58.712984 | TASK [Install selinux into virtualenv] 2026-03-06 00:16:36.128660 | controller | Collecting selinux-please-lie-to-me 2026-03-06 00:16:48.417236 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2026-03-06 00:16:48.746951 | controller | Collecting setuptools<50.0.0 2026-03-06 00:16:48.761711 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2026-03-06 00:16:48.802505 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 22.8 MB/s eta 0:00:00 2026-03-06 00:16:48.890167 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2026-03-06 00:16:48.890311 | controller | Attempting uninstall: setuptools 2026-03-06 00:16:48.892785 | controller | Found existing installation: setuptools 62.6.0 2026-03-06 00:16:48.954607 | controller | Uninstalling setuptools-62.6.0: 2026-03-06 00:16:48.962600 | controller | Successfully uninstalled setuptools-62.6.0 2026-03-06 00:16:49.320528 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2026-03-06 00:17:00.770344 | controller | 2026-03-06 00:17:00.853831 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-03-06 00:17:00.853867 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-03-06 00:17:01.291287 | controller | ok: Runtime: 0:01:01.933731 2026-03-06 00:17:01.308623 | 2026-03-06 00:17:01.308912 | TASK [Install pytest-forked into virtualenv] 2026-03-06 00:17:13.008391 | controller | Collecting pytest-forked 2026-03-06 00:17:25.516763 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2026-03-06 00:17:25.563120 | controller | Collecting py 2026-03-06 00:17:25.736043 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2026-03-06 00:17:25.782875 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 2.2 MB/s eta 0:00:00 2026-03-06 00:17:25.899449 | controller | Collecting pytest>=3.10 2026-03-06 00:17:26.026959 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2026-03-06 00:17:26.043155 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 29.2 MB/s eta 0:00:00 2026-03-06 00:17:26.128040 | controller | Collecting iniconfig>=1.0.1 2026-03-06 00:17:26.197685 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2026-03-06 00:17:26.249007 | controller | Collecting packaging>=22 2026-03-06 00:17:26.317843 | controller | Downloading packaging-26.0-py3-none-any.whl (74 kB) 2026-03-06 00:17:26.329367 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 8.0 MB/s eta 0:00:00 2026-03-06 00:17:26.361294 | controller | Collecting pluggy<2,>=1.5 2026-03-06 00:17:26.411729 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2026-03-06 00:17:26.464595 | controller | Collecting pygments>=2.7.2 2026-03-06 00:17:26.507025 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2026-03-06 00:17:26.533454 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 53.2 MB/s eta 0:00:00 2026-03-06 00:17:26.606418 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2026-03-06 00:17:27.721165 | controller | Successfully installed iniconfig-2.3.0 packaging-26.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0 2026-03-06 00:17:27.731076 | controller | 2026-03-06 00:17:27.803815 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1 2026-03-06 00:17:27.803848 | controller | [notice] To update, run: python -m pip install --upgrade pip 2026-03-06 00:17:27.879863 | controller | ok: Runtime: 0:00:26.241664 2026-03-06 00:17:27.893259 | 2026-03-06 00:17:27.893435 | TASK [Update pip] 2026-03-06 00:17:28.456723 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2026-03-06 00:17:40.907622 | controller | Collecting pip 2026-03-06 00:17:53.225181 | controller | Downloading pip-26.0.1-py3-none-any.whl (1.8 MB) 2026-03-06 00:17:53.276484 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 39.0 MB/s eta 0:00:00 2026-03-06 00:17:53.340675 | controller | Installing collected packages: pip 2026-03-06 00:17:53.340822 | controller | Attempting uninstall: pip 2026-03-06 00:17:53.342937 | controller | Found existing installation: pip 22.2.2 2026-03-06 00:17:53.479957 | controller | Uninstalling pip-22.2.2: 2026-03-06 00:17:53.494779 | controller | Successfully uninstalled pip-22.2.2 2026-03-06 00:17:54.320789 | controller | Successfully installed pip-26.0.1 2026-03-06 00:17:54.479281 | controller | ok: Runtime: 0:00:26.241434 2026-03-06 00:17:54.491658 | 2026-03-06 00:17:54.491805 | TASK [Ensure pip temp directory exists in /var/tmp] 2026-03-06 00:17:54.715685 | controller | changed 2026-03-06 00:17:54.727623 | 2026-03-06 00:17:54.727872 | TASK [Install ansible into virtualenv] 2026-03-06 00:17:55.235430 | controller | Processing ./src/github.com/ansible/ansible 2026-03-06 00:17:55.237880 | controller | Installing build dependencies: started 2026-03-06 00:18:18.151515 | controller | Installing build dependencies: finished with status 'done' 2026-03-06 00:18:18.152700 | controller | Getting requirements to build wheel: started 2026-03-06 00:18:18.920304 | controller | Getting requirements to build wheel: finished with status 'done' 2026-03-06 00:18:18.921749 | controller | Preparing metadata (pyproject.toml): started 2026-03-06 00:18:19.403653 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2026-03-06 00:18:19.406651 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while. 2026-03-06 00:18:19.410010 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2026-03-06 00:18:19.794384 | controller | ERROR 2026-03-06 00:18:19.794632 | controller | { 2026-03-06 00:18:19.794769 | controller | "delta": "0:00:24.523623", 2026-03-06 00:18:19.795039 | controller | "end": "2026-03-06 00:18:19.469738", 2026-03-06 00:18:19.795157 | controller | "msg": "non-zero return code", 2026-03-06 00:18:19.795225 | controller | "rc": 1, 2026-03-06 00:18:19.795266 | controller | "start": "2026-03-06 00:17:54.946115" 2026-03-06 00:18:19.795302 | controller | } failure 2026-03-06 00:18:19.798178 | 2026-03-06 00:18:19.798278 | PLAY RECAP 2026-03-06 00:18:19.798369 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2026-03-06 00:18:19.798414 | 2026-03-06 00:18:19.930121 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2026-03-06 00:18:19.931999 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-03-06 00:18:20.529325 | 2026-03-06 00:18:20.529437 | PLAY [all] 2026-03-06 00:18:20.553215 | 2026-03-06 00:18:20.553355 | TASK [fetch-subunit-output : Find stestr or testr executable] 2026-03-06 00:18:21.004998 | controller | changed: non-zero return code 2026-03-06 00:18:21.011477 | 2026-03-06 00:18:21.011556 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2026-03-06 00:18:21.035758 | controller | skipping: Conditional result was False 2026-03-06 00:18:21.050264 | 2026-03-06 00:18:21.050414 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2026-03-06 00:18:21.087050 | 2026-03-06 00:18:21.087263 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2026-03-06 00:18:21.122070 | 2026-03-06 00:18:21.122422 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2026-03-06 00:18:21.147973 | controller | skipping: Conditional result was False 2026-03-06 00:18:21.165196 | 2026-03-06 00:18:21.165393 | LOOP [fetch-subunit-output : Generate subunit file] 2026-03-06 00:18:21.201328 | 2026-03-06 00:18:21.201541 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2026-03-06 00:18:21.226830 | controller | skipping: Conditional result was False 2026-03-06 00:18:21.236265 | 2026-03-06 00:18:21.236439 | TASK [fetch-subunit-output : Remove the temporary file] 2026-03-06 00:18:21.261865 | controller | skipping: Conditional result was False 2026-03-06 00:18:21.270725 | 2026-03-06 00:18:21.270808 | TASK [fetch-subunit-output : Process and fetch subunit results] 2026-03-06 00:18:21.296205 | controller | skipping: Conditional result was False 2026-03-06 00:18:21.337795 | 2026-03-06 00:18:21.337921 | PLAY RECAP 2026-03-06 00:18:21.337990 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2026-03-06 00:18:21.338071 | 2026-03-06 00:18:21.501987 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2026-03-06 00:18:21.503192 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2026-03-06 00:18:22.152736 | 2026-03-06 00:18:22.152851 | PLAY [all:!appliance*] 2026-03-06 00:18:22.174321 | 2026-03-06 00:18:22.174426 | TASK [unregister the node] 2026-03-06 00:18:22.705852 | controller | skipping: Conditional result was False 2026-03-06 00:18:22.714433 | 2026-03-06 00:18:22.714542 | TASK [include_role : fetch-output] 2026-03-06 00:18:22.758325 | controller | ok 2026-03-06 00:18:22.789542 | 2026-03-06 00:18:22.789684 | TASK [fetch-output : Set log path for multiple nodes] 2026-03-06 00:18:22.856648 | controller | skipping: Conditional result was False 2026-03-06 00:18:22.870119 | 2026-03-06 00:18:22.870271 | TASK [fetch-output : Set log path for single node] 2026-03-06 00:18:22.915054 | controller | ok 2026-03-06 00:18:22.922434 | 2026-03-06 00:18:22.922519 | LOOP [fetch-output : Ensure local output dirs] 2026-03-06 00:18:23.336353 | controller -> localhost | ok: "/var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/work/logs" 2026-03-06 00:18:23.606986 | controller -> localhost | changed: "/var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/work/artifacts" 2026-03-06 00:18:23.866477 | controller -> localhost | changed: "/var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/work/docs" 2026-03-06 00:18:23.881993 | 2026-03-06 00:18:23.882156 | LOOP [fetch-output : Collect logs, artifacts and docs] 2026-03-06 00:18:24.506898 | controller | changed: 2026-03-06 00:18:24.507288 | controller | .d..t...... ./ 2026-03-06 00:18:24.507355 | controller | cd+++++++++ controller/ 2026-03-06 00:18:24.507429 | controller | changed: All items complete 2026-03-06 00:18:24.507476 | 2026-03-06 00:18:25.000881 | controller | changed: .d..t...... ./ 2026-03-06 00:18:25.550047 | controller | changed: .d..t...... ./ 2026-03-06 00:18:25.577943 | 2026-03-06 00:18:25.578153 | TASK [include_role : fetch-output-openshift] 2026-03-06 00:18:25.603740 | controller | skipping: Conditional result was False 2026-03-06 00:18:25.616368 | 2026-03-06 00:18:25.616497 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2026-03-06 00:18:25.653539 | controller | skipping: Conditional result was False 2026-03-06 00:18:25.666241 | controller | skipping: Conditional result was False 2026-03-06 00:18:25.723653 | 2026-03-06 00:18:25.723772 | PLAY [localhost] 2026-03-06 00:18:25.740561 | 2026-03-06 00:18:25.740647 | TASK [Run Zuul manifest role] 2026-03-06 00:18:25.760080 | localhost | ok 2026-03-06 00:18:25.780766 | 2026-03-06 00:18:25.780891 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2026-03-06 00:18:26.176142 | localhost | changed 2026-03-06 00:18:26.182279 | 2026-03-06 00:18:26.182363 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2026-03-06 00:18:26.220930 | localhost | ok 2026-03-06 00:18:26.229315 | 2026-03-06 00:18:26.229380 | TASK [Set zuul-log-path fact] 2026-03-06 00:18:26.247347 | localhost | ok 2026-03-06 00:18:26.262654 | 2026-03-06 00:18:26.262740 | TASK [set-zuul-log-path-fact : Set log path for a build] 2026-03-06 00:18:26.301735 | localhost | ok 2026-03-06 00:18:26.310593 | 2026-03-06 00:18:26.310661 | LOOP [Set zuul_log_targets (Swift with random Rackspace region)] 2026-03-06 00:18:26.355203 | localhost | ok: 2026-03-06 00:18:26.355620 | localhost | { 2026-03-06 00:18:26.355677 | localhost | "auth": { 2026-03-06 00:18:26.355727 | localhost | "password": "IonWCwcuOFib&&<}wp^:[2G/", 2026-03-06 00:18:26.355767 | localhost | "username": "9LF91O0RK7JU" 2026-03-06 00:18:26.355804 | localhost | }, 2026-03-06 00:18:26.355840 | localhost | "profile": "rackspace", 2026-03-06 00:18:26.355876 | localhost | "region_name": "ORD" 2026-03-06 00:18:26.355911 | localhost | } 2026-03-06 00:18:26.355966 | 2026-03-06 00:18:26.363808 | 2026-03-06 00:18:26.363931 | TASK [Run upload-logs-failover role (S3 then Swift)] 2026-03-06 00:18:26.383098 | localhost | Output suppressed because no_log was given 2026-03-06 00:18:26.398070 | 2026-03-06 00:18:26.398170 | TASK [upload-logs-failover : Initialize control vars] 2026-03-06 00:18:26.427084 | localhost | ok 2026-03-06 00:18:26.433558 | 2026-03-06 00:18:26.433687 | LOOP [upload-logs-failover : Perform log upload] 2026-03-06 00:18:26.478703 | localhost | Output suppressed because no_log was given 2026-03-06 00:18:26.511305 | localhost | included: /var/lib/zuul/builds/4951d689f16148c58743c9f654cf4312/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/upload-logs-failover/tasks/upload.yaml 2026-03-06 00:18:26.517949 | 2026-03-06 00:18:26.518068 | LOOP [upload-logs-failover : Unpack vars for swift upload] 2026-03-06 00:18:26.635760 | localhost | Output suppressed because no_log was given 2026-03-06 00:18:26.643596 | 2026-03-06 00:18:26.643738 | TASK [Upload logs to swift] 2026-03-06 00:18:26.677578 | localhost | ok 2026-03-06 00:18:26.722218 | 2026-03-06 00:18:26.722408 | TASK [Set zuul-log-path fact] 2026-03-06 00:18:26.749804 | localhost | skipping: Conditional result was False 2026-03-06 00:18:26.759446 | 2026-03-06 00:18:26.759551 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2026-03-06 00:18:27.216213 | localhost -> localhost | ok: Runtime: 0:00:00.010680 2026-03-06 00:18:27.229936 | 2026-03-06 00:18:27.230127 | TASK [upload-logs-swift : Upload logs to swift]