2025-12-27 00:14:40.648350 | Job console starting... 2025-12-27 00:14:40.661689 | Updating repositories 2025-12-27 00:14:40.764185 | Preparing job workspace 2025-12-27 00:14:44.628554 | Running Ansible setup... 2025-12-27 00:14:49.478255 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-27 00:14:50.109415 | 2025-12-27 00:14:50.109599 | PLAY [localhost] 2025-12-27 00:14:50.121069 | 2025-12-27 00:14:50.121191 | TASK [Gathering Facts] 2025-12-27 00:14:51.163256 | localhost | ok 2025-12-27 00:14:51.181692 | 2025-12-27 00:14:51.181805 | TASK [Setup log path fact] 2025-12-27 00:14:51.212689 | localhost | ok 2025-12-27 00:14:51.232175 | 2025-12-27 00:14:51.232281 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-27 00:14:51.263008 | localhost | ok 2025-12-27 00:14:51.275627 | 2025-12-27 00:14:51.275925 | TASK [emit-job-header : Print job information] 2025-12-27 00:14:51.368400 | # Job Information 2025-12-27 00:14:51.368594 | Ansible Version: 2.15.12 2025-12-27 00:14:51.368663 | Job: ansible-test-sanity-docker-milestone 2025-12-27 00:14:51.368700 | Pipeline: periodic 2025-12-27 00:14:51.368727 | Executor: ze01.softwarefactory-project.io 2025-12-27 00:14:51.368752 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-12-27 00:14:51.368782 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/0c4/ansible/0c4e9540231c48718a34f77b4481b091/ 2025-12-27 00:14:51.368809 | Event ID: 88cebac4610b4a578de9ac934b821521 2025-12-27 00:14:51.374396 | 2025-12-27 00:14:51.374500 | LOOP [emit-job-header : Print node information] 2025-12-27 00:14:51.542560 | localhost | ok: 2025-12-27 00:14:51.542843 | localhost | # Node Information 2025-12-27 00:14:51.542903 | localhost | Inventory Hostname: controller 2025-12-27 00:14:51.542947 | localhost | Hostname: np0005571272 2025-12-27 00:14:51.542989 | localhost | Username: zuul 2025-12-27 00:14:51.543108 | localhost | Distro: Fedora 37 2025-12-27 00:14:51.543166 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2025-12-27 00:14:51.543222 | localhost | Region: ca-ymq-1 2025-12-27 00:14:51.543272 | localhost | Label: ansible-fedora-37-1vcpu 2025-12-27 00:14:51.543319 | localhost | Product Name: OpenStack Nova 2025-12-27 00:14:51.543367 | localhost | Interface IP: 162.253.55.42 2025-12-27 00:14:51.564123 | 2025-12-27 00:14:51.564336 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-27 00:14:51.992221 | localhost -> localhost | changed 2025-12-27 00:14:52.000336 | 2025-12-27 00:14:52.000458 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-27 00:14:53.054162 | localhost -> localhost | changed 2025-12-27 00:14:53.076177 | 2025-12-27 00:14:53.076295 | PLAY [all:!appliance*] 2025-12-27 00:14:53.096519 | 2025-12-27 00:14:53.096672 | TASK [include_role : start-zuul-console] 2025-12-27 00:14:53.117629 | controller | ok 2025-12-27 00:14:53.134500 | 2025-12-27 00:14:53.134749 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-27 00:14:53.551801 | controller | ok 2025-12-27 00:14:53.577890 | 2025-12-27 00:14:53.578207 | TASK [use-our-mirror : Retrieve the IP address] 2025-12-27 00:15:16.275860 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-12-27 00:15:16.283916 | 2025-12-27 00:15:16.284051 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-12-27 00:15:16.818172 | controller | skipping: Conditional result was False 2025-12-27 00:15:16.835507 | 2025-12-27 00:15:16.835683 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-12-27 00:15:16.871890 | controller | skipping: Conditional result was False 2025-12-27 00:15:16.880829 | 2025-12-27 00:15:16.880951 | TASK [use-our-mirror : Create the podman configuration directory] 2025-12-27 00:15:16.915865 | controller | skipping: Conditional result was False 2025-12-27 00:15:16.925777 | 2025-12-27 00:15:16.925951 | TASK [use-our-mirror : Copy the podman configuration] 2025-12-27 00:15:16.961803 | controller | skipping: Conditional result was False 2025-12-27 00:15:16.972227 | 2025-12-27 00:15:16.972353 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-12-27 00:15:16.997248 | controller | skipping: Conditional result was False 2025-12-27 00:15:17.007730 | 2025-12-27 00:15:17.007854 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-12-27 00:15:17.022913 | controller | skipping: Conditional result was False 2025-12-27 00:15:17.043663 | 2025-12-27 00:15:17.043809 | TASK [Disable Fedora Modular] 2025-12-27 00:15:17.306827 | controller | changed 2025-12-27 00:15:17.322102 | 2025-12-27 00:15:17.322305 | TASK [Enable EPEL] 2025-12-27 00:15:17.349668 | controller | skipping: Conditional result was False 2025-12-27 00:15:17.363775 | 2025-12-27 00:15:17.364065 | TASK [Register the RHEL node] 2025-12-27 00:15:17.935408 | 2025-12-27 00:15:17.936075 | TASK [Show the subscription-manager status] 2025-12-27 00:15:18.488895 | controller | skipping: Conditional result was False 2025-12-27 00:15:18.497646 | 2025-12-27 00:15:18.497768 | TASK [Enable EPEL on RHEL] 2025-12-27 00:15:19.053585 | controller | skipping: Conditional result was False 2025-12-27 00:15:19.061624 | 2025-12-27 00:15:19.061724 | TASK [Install git and tox] 2025-12-27 00:16:03.243684 | controller | changed 2025-12-27 00:16:03.253455 | 2025-12-27 00:16:03.253557 | TASK [include_role : prepare-workspace] 2025-12-27 00:16:03.285409 | controller | ok 2025-12-27 00:16:03.309428 | 2025-12-27 00:16:03.309549 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-27 00:16:03.575640 | controller | ok 2025-12-27 00:16:03.583594 | 2025-12-27 00:16:03.583698 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-27 00:16:15.985050 | controller | Output suppressed because no_log was given 2025-12-27 00:16:15.996080 | 2025-12-27 00:16:15.996144 | TASK [include_role : prepare-workspace-openshift] 2025-12-27 00:16:16.020229 | controller | skipping: Conditional result was False 2025-12-27 00:16:16.046278 | 2025-12-27 00:16:16.046377 | PLAY [all:!appliance] 2025-12-27 00:16:16.065038 | 2025-12-27 00:16:16.065165 | TASK [Run add-build-sshkey role (RSA)] 2025-12-27 00:16:16.130305 | controller | ok 2025-12-27 00:16:16.145458 | 2025-12-27 00:16:16.145627 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-27 00:16:16.385385 | controller -> localhost | ok 2025-12-27 00:16:16.395396 | 2025-12-27 00:16:16.395552 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-27 00:16:16.431794 | controller | ok 2025-12-27 00:16:16.455590 | controller | included: /var/lib/zuul/builds/0c4e9540231c48718a34f77b4481b091/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-27 00:16:16.466293 | 2025-12-27 00:16:16.466451 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-27 00:16:16.951043 | controller -> localhost | Generating public/private rsa key pair. 2025-12-27 00:16:16.951292 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0c4e9540231c48718a34f77b4481b091/work/0c4e9540231c48718a34f77b4481b091_id_rsa. 2025-12-27 00:16:16.951330 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0c4e9540231c48718a34f77b4481b091/work/0c4e9540231c48718a34f77b4481b091_id_rsa.pub. 2025-12-27 00:16:16.951358 | controller -> localhost | The key fingerprint is: 2025-12-27 00:16:16.951385 | controller -> localhost | SHA256:6ylbnZ1iidvq25ErRxMowARYcKaQrFXDTzhsUvCxyxY zuul-build-sshkey 2025-12-27 00:16:16.951411 | controller -> localhost | The key's randomart image is: 2025-12-27 00:16:16.951437 | controller -> localhost | +---[RSA 2048]----+ 2025-12-27 00:16:16.951472 | controller -> localhost | |+=*X*. | 2025-12-27 00:16:16.951498 | controller -> localhost | |+=o.O+. | 2025-12-27 00:16:16.951524 | controller -> localhost | |o. oE= . | 2025-12-27 00:16:16.951548 | controller -> localhost | |. . oo . . | 2025-12-27 00:16:16.951572 | controller -> localhost | | + .S . | 2025-12-27 00:16:16.951608 | controller -> localhost | | . +o= . | 2025-12-27 00:16:16.951641 | controller -> localhost | | +.O.o | 2025-12-27 00:16:16.951692 | controller -> localhost | | .o.*.+ | 2025-12-27 00:16:16.951722 | controller -> localhost | | .+B=+ | 2025-12-27 00:16:16.951751 | controller -> localhost | +----[SHA256]-----+ 2025-12-27 00:16:16.951831 | controller -> localhost | ok: Runtime: 0:00:00.106786 2025-12-27 00:16:16.962158 | 2025-12-27 00:16:16.962301 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-27 00:16:16.996044 | controller | ok 2025-12-27 00:16:17.010305 | controller | included: /var/lib/zuul/builds/0c4e9540231c48718a34f77b4481b091/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-27 00:16:17.025701 | 2025-12-27 00:16:17.025858 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-27 00:16:17.051612 | controller | skipping: Conditional result was False 2025-12-27 00:16:17.061726 | 2025-12-27 00:16:17.061861 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-27 00:16:17.506898 | controller | changed 2025-12-27 00:16:17.516320 | 2025-12-27 00:16:17.516482 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-27 00:16:17.747501 | controller | ok 2025-12-27 00:16:17.756348 | 2025-12-27 00:16:17.756501 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-27 00:16:18.384430 | controller | changed 2025-12-27 00:16:18.395820 | 2025-12-27 00:16:18.396151 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-27 00:16:19.029280 | controller | changed 2025-12-27 00:16:19.045278 | 2025-12-27 00:16:19.045368 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-27 00:16:19.080309 | controller | skipping: Conditional result was False 2025-12-27 00:16:19.087262 | 2025-12-27 00:16:19.087333 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-27 00:16:19.521327 | controller -> localhost | changed 2025-12-27 00:16:19.543839 | 2025-12-27 00:16:19.544055 | TASK [add-build-sshkey : Add back temp key] 2025-12-27 00:16:19.848451 | controller -> localhost | Identity added: /var/lib/zuul/builds/0c4e9540231c48718a34f77b4481b091/work/0c4e9540231c48718a34f77b4481b091_id_rsa (zuul-build-sshkey) 2025-12-27 00:16:19.848673 | controller -> localhost | ok: Runtime: 0:00:00.009678 2025-12-27 00:16:19.855184 | 2025-12-27 00:16:19.855296 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-27 00:16:20.209158 | controller | ok 2025-12-27 00:16:20.215960 | 2025-12-27 00:16:20.216077 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-27 00:16:20.241330 | controller | skipping: Conditional result was False 2025-12-27 00:16:20.266100 | 2025-12-27 00:16:20.266225 | TASK [Run add-build-sshkey role (ECDSA)] 2025-12-27 00:16:20.303872 | controller | ok 2025-12-27 00:16:20.328302 | 2025-12-27 00:16:20.328418 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-27 00:16:20.589939 | controller -> localhost | ok 2025-12-27 00:16:20.597653 | 2025-12-27 00:16:20.598220 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-27 00:16:20.619800 | controller | ok 2025-12-27 00:16:20.632260 | controller | included: /var/lib/zuul/builds/0c4e9540231c48718a34f77b4481b091/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-27 00:16:20.641078 | 2025-12-27 00:16:20.641173 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-27 00:16:20.910279 | controller -> localhost | Generating public/private ecdsa key pair. 2025-12-27 00:16:20.910685 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0c4e9540231c48718a34f77b4481b091/work/0c4e9540231c48718a34f77b4481b091_id_ecdsa. 2025-12-27 00:16:20.910728 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0c4e9540231c48718a34f77b4481b091/work/0c4e9540231c48718a34f77b4481b091_id_ecdsa.pub. 2025-12-27 00:16:20.910767 | controller -> localhost | The key fingerprint is: 2025-12-27 00:16:20.910797 | controller -> localhost | SHA256:JatbKBx+TcyXKZ5BbvwVZsJkIJqVzqyDQQYe47cVNjs zuul-build-sshkey 2025-12-27 00:16:20.910827 | controller -> localhost | The key's randomart image is: 2025-12-27 00:16:20.910854 | controller -> localhost | +---[ECDSA 521]---+ 2025-12-27 00:16:20.910880 | controller -> localhost | |.+ +o...o | 2025-12-27 00:16:20.910906 | controller -> localhost | |o = .+=. + | 2025-12-27 00:16:20.910932 | controller -> localhost | | = .oE o + + | 2025-12-27 00:16:20.910957 | controller -> localhost | | o o =* + * . | 2025-12-27 00:16:20.910983 | controller -> localhost | | +.. S + . | 2025-12-27 00:16:20.911008 | controller -> localhost | | .oo. B * . | 2025-12-27 00:16:20.911062 | controller -> localhost | | +.+ = . | 2025-12-27 00:16:20.911090 | controller -> localhost | | o o | 2025-12-27 00:16:20.911117 | controller -> localhost | | . | 2025-12-27 00:16:20.911157 | controller -> localhost | +----[SHA256]-----+ 2025-12-27 00:16:20.911237 | controller -> localhost | ok: Runtime: 0:00:00.012803 2025-12-27 00:16:20.925706 | 2025-12-27 00:16:20.926587 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-27 00:16:20.952959 | controller | ok 2025-12-27 00:16:20.970041 | controller | included: /var/lib/zuul/builds/0c4e9540231c48718a34f77b4481b091/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-27 00:16:20.990042 | 2025-12-27 00:16:20.990388 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-27 00:16:21.025540 | controller | skipping: Conditional result was False 2025-12-27 00:16:21.034327 | 2025-12-27 00:16:21.034436 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-27 00:16:21.315740 | controller | changed 2025-12-27 00:16:21.325873 | 2025-12-27 00:16:21.326102 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-27 00:16:21.545907 | controller | ok 2025-12-27 00:16:21.553405 | 2025-12-27 00:16:21.553476 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-27 00:16:22.194036 | controller | changed 2025-12-27 00:16:22.201426 | 2025-12-27 00:16:22.201507 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-27 00:16:22.829376 | controller | changed 2025-12-27 00:16:22.835285 | 2025-12-27 00:16:22.835351 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-27 00:16:22.858944 | controller | skipping: Conditional result was False 2025-12-27 00:16:22.865505 | 2025-12-27 00:16:22.865586 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-27 00:16:23.153981 | controller -> localhost | changed 2025-12-27 00:16:23.167192 | 2025-12-27 00:16:23.167290 | TASK [add-build-sshkey : Add back temp key] 2025-12-27 00:16:23.469518 | controller -> localhost | Identity added: /var/lib/zuul/builds/0c4e9540231c48718a34f77b4481b091/work/0c4e9540231c48718a34f77b4481b091_id_ecdsa (zuul-build-sshkey) 2025-12-27 00:16:23.469732 | controller -> localhost | ok: Runtime: 0:00:00.019753 2025-12-27 00:16:23.477061 | 2025-12-27 00:16:23.477155 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-27 00:16:23.681382 | controller | ok 2025-12-27 00:16:23.687744 | 2025-12-27 00:16:23.687869 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-27 00:16:23.725326 | controller | skipping: Conditional result was False 2025-12-27 00:16:23.790179 | 2025-12-27 00:16:23.790357 | TASK [include_role : remove-zuul-sshkey] 2025-12-27 00:16:23.816277 | controller | skipping: Conditional result was False 2025-12-27 00:16:23.826104 | 2025-12-27 00:16:23.826209 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-27 00:16:24.062728 | controller | ok: "logs" 2025-12-27 00:16:24.063319 | controller | ok: All items complete 2025-12-27 00:16:24.063361 | 2025-12-27 00:16:24.264180 | controller | ok: "artifacts" 2025-12-27 00:16:24.464873 | controller | ok: "docs" 2025-12-27 00:16:24.483541 | 2025-12-27 00:16:24.483700 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-27 00:16:24.725587 | controller | changed: "logs" 2025-12-27 00:16:24.912208 | controller | changed: "artifacts" 2025-12-27 00:16:25.113513 | controller | changed: "docs" 2025-12-27 00:16:25.147422 | 2025-12-27 00:16:25.147553 | PLAY RECAP 2025-12-27 00:16:25.147600 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-12-27 00:16:25.147626 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-27 00:16:25.147644 | 2025-12-27 00:16:27.500932 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-27 00:16:27.501975 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-27 00:16:28.088287 | 2025-12-27 00:16:28.088474 | PLAY [all] 2025-12-27 00:16:28.143608 | 2025-12-27 00:16:28.143744 | TASK [Install binary dependencies] 2025-12-27 00:16:28.209497 | controller | ok 2025-12-27 00:16:28.276356 | 2025-12-27 00:16:28.276541 | TASK [bindep : Include find tasks] 2025-12-27 00:16:28.310161 | controller | ok 2025-12-27 00:16:28.330919 | controller | included: /var/lib/zuul/builds/0c4e9540231c48718a34f77b4481b091/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-27 00:16:28.341856 | 2025-12-27 00:16:28.342036 | TASK [bindep : Look for bindep.txt] 2025-12-27 00:16:28.715583 | controller | ok 2025-12-27 00:16:28.725666 | 2025-12-27 00:16:28.725819 | TASK [bindep : Define bindep_file fact] 2025-12-27 00:16:28.755538 | controller | skipping: Conditional result was False 2025-12-27 00:16:28.763881 | 2025-12-27 00:16:28.764215 | TASK [bindep : Look for other-requirements.txt] 2025-12-27 00:16:28.984954 | controller | ok 2025-12-27 00:16:28.992339 | 2025-12-27 00:16:28.992459 | TASK [bindep : Define bindep_file fact] 2025-12-27 00:16:29.013640 | controller | skipping: Conditional result was False 2025-12-27 00:16:29.021093 | 2025-12-27 00:16:29.021226 | TASK [bindep : Look for bindep fallback file] 2025-12-27 00:16:29.045212 | controller | skipping: Conditional result was False 2025-12-27 00:16:29.054575 | 2025-12-27 00:16:29.054701 | TASK [bindep : Define bindep_file fact] 2025-12-27 00:16:29.078561 | controller | skipping: Conditional result was False 2025-12-27 00:16:29.084937 | 2025-12-27 00:16:29.085305 | TASK [bindep : Include bindep tasks] 2025-12-27 00:16:29.109107 | controller | skipping: Conditional result was False 2025-12-27 00:16:29.115445 | 2025-12-27 00:16:29.115545 | TASK [bindep : Include install tasks] 2025-12-27 00:16:29.142415 | controller | skipping: Conditional result was False 2025-12-27 00:16:29.150803 | 2025-12-27 00:16:29.150911 | LOOP [bindep : Include package tasks] 2025-12-27 00:16:29.252270 | 2025-12-27 00:16:29.252703 | TASK [Run test-setup role] 2025-12-27 00:16:29.300201 | controller | ok 2025-12-27 00:16:29.349358 | 2025-12-27 00:16:29.349552 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-27 00:16:29.594816 | controller | ok 2025-12-27 00:16:29.609428 | 2025-12-27 00:16:29.609614 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-27 00:16:30.161492 | controller | skipping: Conditional result was False 2025-12-27 00:16:30.191976 | 2025-12-27 00:16:30.192108 | PLAY RECAP 2025-12-27 00:16:30.192150 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-27 00:16:30.192171 | 2025-12-27 00:16:30.322117 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-27 00:16:30.323850 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-27 00:16:31.020397 | 2025-12-27 00:16:31.020562 | PLAY [controller] 2025-12-27 00:16:31.042169 | 2025-12-27 00:16:31.042257 | TASK [Create the /root directory] 2025-12-27 00:16:31.426793 | controller | ok 2025-12-27 00:16:31.440134 | 2025-12-27 00:16:31.440337 | TASK [Install glibc-langpack-en] 2025-12-27 00:16:35.458449 | controller | ok: Nothing to do 2025-12-27 00:16:35.467594 | 2025-12-27 00:16:35.467729 | TASK [Ensure controller directory exists] 2025-12-27 00:16:35.698376 | controller | changed 2025-12-27 00:16:35.717466 | 2025-12-27 00:16:35.717646 | TASK [Install container runtime] 2025-12-27 00:16:35.782052 | controller | ok 2025-12-27 00:16:35.823742 | 2025-12-27 00:16:35.823850 | LOOP [ensure-podman : Find distribution installation] 2025-12-27 00:16:35.851951 | controller | ok: "/var/lib/zuul/builds/0c4e9540231c48718a34f77b4481b091/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2025-12-27 00:16:35.905652 | controller | included: /var/lib/zuul/builds/0c4e9540231c48718a34f77b4481b091/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2025-12-27 00:16:35.912448 | 2025-12-27 00:16:35.912545 | TASK [ensure-podman : Install podman (RedHat)] 2025-12-27 00:17:40.890202 | controller | changed 2025-12-27 00:17:40.902283 | 2025-12-27 00:17:40.902430 | TASK [ensure-podman : Fetch podman version] 2025-12-27 00:17:41.471927 | controller | Client: Podman Engine 2025-12-27 00:17:41.508276 | controller | Version: 4.6.2 2025-12-27 00:17:41.508347 | controller | API Version: 4.6.2 2025-12-27 00:17:41.508355 | controller | Go Version: go1.19.12 2025-12-27 00:17:41.508378 | controller | Built: Mon Aug 28 19:38:31 2023 2025-12-27 00:17:41.508385 | controller | OS/Arch: linux/amd64 2025-12-27 00:17:41.949121 | controller | ok: Runtime: 0:00:00.218486 2025-12-27 00:17:41.958318 | 2025-12-27 00:17:41.958428 | TASK [ensure-podman : Print podman version installed] 2025-12-27 00:17:41.990341 | Podman version: Client: Podman Engine 2025-12-27 00:17:41.990531 | Version: 4.6.2 2025-12-27 00:17:41.990564 | API Version: 4.6.2 2025-12-27 00:17:41.990585 | Go Version: go1.19.12 2025-12-27 00:17:41.990609 | Built: Mon Aug 28 19:38:31 2023 2025-12-27 00:17:41.990639 | OS/Arch: linux/amd64 2025-12-27 00:17:41.997450 | 2025-12-27 00:17:41.997527 | TASK [ensure-podman : Validate podman engine] 2025-12-27 00:17:42.539050 | controller | skipping: Conditional result was False 2025-12-27 00:17:42.547459 | 2025-12-27 00:17:42.547573 | TASK [ensure-podman : Set up docker compatability socket] 2025-12-27 00:17:42.572690 | controller | skipping: Conditional result was False 2025-12-27 00:17:42.587889 | 2025-12-27 00:17:42.588031 | TASK [Ensure python3.8 is present] 2025-12-27 00:17:42.612940 | controller | skipping: Conditional result was False 2025-12-27 00:17:42.621374 | 2025-12-27 00:17:42.621487 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-12-27 00:17:42.643944 | controller | ok 2025-12-27 00:17:42.672670 | 2025-12-27 00:17:42.672809 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-12-27 00:17:44.269565 | controller | ok: Nothing to do 2025-12-27 00:17:44.277428 | 2025-12-27 00:17:44.277541 | TASK [our-ensure-python : Also install python3-devel] 2025-12-27 00:17:53.278613 | controller | changed 2025-12-27 00:17:53.298938 | 2025-12-27 00:17:53.299163 | TASK [Run ensure-virtualenv role] 2025-12-27 00:17:53.328377 | controller | ok 2025-12-27 00:17:53.385636 | 2025-12-27 00:17:53.385772 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-12-27 00:17:53.638293 | controller | /usr/bin/virtualenv 2025-12-27 00:17:53.956273 | controller | ok: Runtime: 0:00:00.003424 2025-12-27 00:17:53.970124 | 2025-12-27 00:17:53.970268 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-12-27 00:17:54.007373 | controller | skipping: Conditional result was False 2025-12-27 00:17:54.007831 | controller | ok: All items complete 2025-12-27 00:17:54.007868 | 2025-12-27 00:17:54.043786 | 2025-12-27 00:17:54.043980 | TASK [Find the full path of the Python interpreter] 2025-12-27 00:17:54.306822 | controller | /usr/bin/python3 2025-12-27 00:17:54.592679 | controller | ok 2025-12-27 00:17:54.605348 | 2025-12-27 00:17:54.605495 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-12-27 00:17:55.589271 | controller | created virtual environment CPython3.11.0.final.0-64 in 594ms 2025-12-27 00:17:55.642498 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-12-27 00:17:55.642869 | 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) 2025-12-27 00:17:55.642884 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-12-27 00:17:55.642900 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-12-27 00:17:55.690683 | controller | changed 2025-12-27 00:17:55.704548 | 2025-12-27 00:17:55.704682 | TASK [Set selinux package] 2025-12-27 00:17:55.744847 | controller | ok 2025-12-27 00:17:55.757657 | 2025-12-27 00:17:55.757807 | TASK [Set selinux package (Fedora)] 2025-12-27 00:17:55.792590 | controller | ok 2025-12-27 00:17:55.801322 | 2025-12-27 00:17:55.801446 | TASK [Install selinux into virtualenv] 2025-12-27 00:18:21.421869 | controller | Collecting selinux-please-lie-to-me 2025-12-27 00:18:33.680458 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-12-27 00:18:34.021803 | controller | Collecting setuptools<50.0.0 2025-12-27 00:18:34.027454 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-12-27 00:18:34.070306 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 21.7 MB/s eta 0:00:00 2025-12-27 00:18:34.150364 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-12-27 00:18:34.150507 | controller | Attempting uninstall: setuptools 2025-12-27 00:18:34.152985 | controller | Found existing installation: setuptools 62.6.0 2025-12-27 00:18:34.213398 | controller | Uninstalling setuptools-62.6.0: 2025-12-27 00:18:34.222103 | controller | Successfully uninstalled setuptools-62.6.0 2025-12-27 00:18:34.591434 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-12-27 00:18:46.045648 | controller | 2025-12-27 00:18:46.154705 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-27 00:18:46.154760 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-27 00:18:46.398649 | controller | ok: Runtime: 0:00:50.113074 2025-12-27 00:18:46.413494 | 2025-12-27 00:18:46.413678 | TASK [Install pytest-forked into virtualenv] 2025-12-27 00:19:11.280304 | controller | Collecting pytest-forked 2025-12-27 00:19:23.545553 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-12-27 00:19:23.597279 | controller | Collecting py 2025-12-27 00:19:23.601662 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-12-27 00:19:23.627543 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.9 MB/s eta 0:00:00 2025-12-27 00:19:23.733589 | controller | Collecting pytest>=3.10 2025-12-27 00:19:23.740096 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2025-12-27 00:19:23.756878 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 28.0 MB/s eta 0:00:00 2025-12-27 00:19:23.800905 | controller | Collecting iniconfig>=1.0.1 2025-12-27 00:19:23.805214 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2025-12-27 00:19:23.848192 | controller | Collecting packaging>=22 2025-12-27 00:19:23.851660 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-12-27 00:19:23.857796 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 17.2 MB/s eta 0:00:00 2025-12-27 00:19:23.892709 | controller | Collecting pluggy<2,>=1.5 2025-12-27 00:19:23.896490 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-12-27 00:19:23.945711 | controller | Collecting pygments>=2.7.2 2025-12-27 00:19:23.952636 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-12-27 00:19:23.980103 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 57.3 MB/s eta 0:00:00 2025-12-27 00:19:24.052920 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2025-12-27 00:19:25.193971 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0 2025-12-27 00:19:25.203043 | controller | 2025-12-27 00:19:25.281807 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-27 00:19:25.281838 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-27 00:19:25.491071 | controller | ok: Runtime: 0:00:38.631399 2025-12-27 00:19:25.499716 | 2025-12-27 00:19:25.499855 | TASK [Update pip] 2025-12-27 00:19:26.002458 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2025-12-27 00:19:59.785301 | controller | Collecting pip 2025-12-27 00:20:12.102953 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2025-12-27 00:20:12.178382 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 25.4 MB/s eta 0:00:00 2025-12-27 00:20:12.241700 | controller | Installing collected packages: pip 2025-12-27 00:20:12.241875 | controller | Attempting uninstall: pip 2025-12-27 00:20:12.244018 | controller | Found existing installation: pip 22.2.2 2025-12-27 00:20:12.381885 | controller | Uninstalling pip-22.2.2: 2025-12-27 00:20:12.396895 | controller | Successfully uninstalled pip-22.2.2 2025-12-27 00:20:13.181239 | controller | Successfully installed pip-25.3 2025-12-27 00:20:13.561913 | controller | ok: Runtime: 0:00:47.549025 2025-12-27 00:20:13.576119 | 2025-12-27 00:20:13.576304 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-12-27 00:20:13.795386 | controller | changed 2025-12-27 00:20:13.808946 | 2025-12-27 00:20:13.809165 | TASK [Install ansible into virtualenv] 2025-12-27 00:20:14.370841 | controller | Processing ./src/github.com/ansible/ansible 2025-12-27 00:20:14.380687 | controller | Installing build dependencies: started 2025-12-27 00:20:37.080353 | controller | Installing build dependencies: finished with status 'done' 2025-12-27 00:20:37.081508 | controller | Getting requirements to build wheel: started 2025-12-27 00:20:37.802465 | controller | Getting requirements to build wheel: finished with status 'done' 2025-12-27 00:20:37.803446 | controller | Preparing metadata (pyproject.toml): started 2025-12-27 00:20:38.260349 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2025-12-27 00:20:38.266179 | 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. 2025-12-27 00:20:38.269771 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2025-12-27 00:20:38.438426 | controller | ERROR 2025-12-27 00:20:38.438681 | controller | { 2025-12-27 00:20:38.438941 | controller | "delta": "0:00:24.254683", 2025-12-27 00:20:38.438999 | controller | "end": "2025-12-27 00:20:38.342833", 2025-12-27 00:20:38.439078 | controller | "msg": "non-zero return code", 2025-12-27 00:20:38.439141 | controller | "rc": 1, 2025-12-27 00:20:38.439178 | controller | "start": "2025-12-27 00:20:14.088150" 2025-12-27 00:20:38.439212 | controller | } failure 2025-12-27 00:20:38.442054 | 2025-12-27 00:20:38.442166 | PLAY RECAP 2025-12-27 00:20:38.442249 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2025-12-27 00:20:38.442294 | 2025-12-27 00:20:38.577388 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-27 00:20:38.579432 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-27 00:20:39.199949 | 2025-12-27 00:20:39.200103 | PLAY [all] 2025-12-27 00:20:39.222954 | 2025-12-27 00:20:39.223139 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-27 00:20:39.481944 | controller | changed: non-zero return code 2025-12-27 00:20:39.488599 | 2025-12-27 00:20:39.488683 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-27 00:20:39.503508 | controller | skipping: Conditional result was False 2025-12-27 00:20:39.511413 | 2025-12-27 00:20:39.511547 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-27 00:20:39.545996 | 2025-12-27 00:20:39.546228 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-27 00:20:39.573833 | 2025-12-27 00:20:39.574202 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-27 00:20:39.601334 | controller | skipping: Conditional result was False 2025-12-27 00:20:39.608997 | 2025-12-27 00:20:39.609117 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-27 00:20:39.639808 | 2025-12-27 00:20:39.639997 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-27 00:20:39.653966 | controller | skipping: Conditional result was False 2025-12-27 00:20:39.660490 | 2025-12-27 00:20:39.660560 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-27 00:20:39.674393 | controller | skipping: Conditional result was False 2025-12-27 00:20:39.683002 | 2025-12-27 00:20:39.683099 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-27 00:20:39.698623 | controller | skipping: Conditional result was False 2025-12-27 00:20:39.733950 | 2025-12-27 00:20:39.734068 | PLAY RECAP 2025-12-27 00:20:39.734118 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-27 00:20:39.734145 | 2025-12-27 00:20:39.830570 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-27 00:20:39.831440 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-12-27 00:20:40.432244 | 2025-12-27 00:20:40.432590 | PLAY [all:!appliance*] 2025-12-27 00:20:40.457632 | 2025-12-27 00:20:40.457770 | TASK [unregister the node] 2025-12-27 00:20:40.992832 | controller | skipping: Conditional result was False 2025-12-27 00:20:41.001963 | 2025-12-27 00:20:41.002242 | TASK [include_role : fetch-output] 2025-12-27 00:20:41.035325 | controller | ok 2025-12-27 00:20:41.058411 | 2025-12-27 00:20:41.058565 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-27 00:20:41.113404 | controller | skipping: Conditional result was False 2025-12-27 00:20:41.121311 | 2025-12-27 00:20:41.121403 | TASK [fetch-output : Set log path for single node] 2025-12-27 00:20:41.173913 | controller | ok 2025-12-27 00:20:41.180955 | 2025-12-27 00:20:41.181051 | LOOP [fetch-output : Ensure local output dirs] 2025-12-27 00:20:41.605817 | controller -> localhost | ok: "/var/lib/zuul/builds/0c4e9540231c48718a34f77b4481b091/work/logs" 2025-12-27 00:20:41.841679 | controller -> localhost | changed: "/var/lib/zuul/builds/0c4e9540231c48718a34f77b4481b091/work/artifacts" 2025-12-27 00:20:42.071330 | controller -> localhost | changed: "/var/lib/zuul/builds/0c4e9540231c48718a34f77b4481b091/work/docs" 2025-12-27 00:20:42.081358 | 2025-12-27 00:20:42.081469 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-27 00:20:42.830192 | controller | changed: 2025-12-27 00:20:42.830403 | controller | .d..t...... ./ 2025-12-27 00:20:42.830430 | controller | cd+++++++++ controller/ 2025-12-27 00:20:42.830461 | controller | changed: All items complete 2025-12-27 00:20:42.830480 | 2025-12-27 00:20:43.310767 | controller | changed: .d..t...... ./ 2025-12-27 00:20:43.768130 | controller | changed: .d..t...... ./ 2025-12-27 00:20:43.789157 | 2025-12-27 00:20:43.789342 | TASK [include_role : fetch-output-openshift] 2025-12-27 00:20:43.815853 | controller | skipping: Conditional result was False 2025-12-27 00:20:43.826714 | 2025-12-27 00:20:43.826850 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-27 00:20:43.869258 | controller | skipping: Conditional result was False 2025-12-27 00:20:43.883337 | controller | skipping: Conditional result was False 2025-12-27 00:20:43.919639 | 2025-12-27 00:20:43.919765 | PLAY [localhost] 2025-12-27 00:20:43.933542 | 2025-12-27 00:20:43.933662 | TASK [Run Zuul manifest role] 2025-12-27 00:20:43.953206 | localhost | ok 2025-12-27 00:20:43.969126 | 2025-12-27 00:20:43.969221 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-27 00:20:44.409696 | localhost | changed 2025-12-27 00:20:44.417246 | 2025-12-27 00:20:44.417390 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-27 00:20:44.445542 | localhost | ok 2025-12-27 00:20:44.454074 | 2025-12-27 00:20:44.454175 | TASK [Set zuul-log-path fact] 2025-12-27 00:20:44.475168 | localhost | ok 2025-12-27 00:20:44.494009 | 2025-12-27 00:20:44.494157 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-27 00:20:44.524174 | localhost | ok 2025-12-27 00:20:44.534247 | 2025-12-27 00:20:44.534371 | LOOP [Run upload-logs-swift role] 2025-12-27 00:20:44.569901 | localhost | Output suppressed because no_log was given 2025-12-27 00:20:44.599010 | 2025-12-27 00:20:44.599145 | TASK [Set zuul-log-path fact] 2025-12-27 00:20:44.623191 | localhost | skipping: Conditional result was False 2025-12-27 00:20:44.628067 | 2025-12-27 00:20:44.628172 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-12-27 00:20:45.064248 | localhost -> localhost | ok: Runtime: 0:00:00.006278 2025-12-27 00:20:45.100362 | 2025-12-27 00:20:45.100514 | TASK [upload-logs-swift : Upload logs to swift]