2025-12-29 00:20:13.623941 | Job console starting... 2025-12-29 00:20:13.635484 | Updating repositories 2025-12-29 00:20:13.781242 | Preparing job workspace 2025-12-29 00:20:17.276046 | Running Ansible setup... 2025-12-29 00:20:22.134812 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-29 00:20:22.766007 | 2025-12-29 00:20:22.766137 | PLAY [localhost] 2025-12-29 00:20:22.775147 | 2025-12-29 00:20:22.775259 | TASK [Gathering Facts] 2025-12-29 00:20:23.782302 | localhost | ok 2025-12-29 00:20:23.813975 | 2025-12-29 00:20:23.814191 | TASK [Setup log path fact] 2025-12-29 00:20:23.836961 | localhost | ok 2025-12-29 00:20:23.857280 | 2025-12-29 00:20:23.857423 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-29 00:20:23.892162 | localhost | ok 2025-12-29 00:20:23.905864 | 2025-12-29 00:20:23.905983 | TASK [emit-job-header : Print job information] 2025-12-29 00:20:23.957630 | # Job Information 2025-12-29 00:20:23.957850 | Ansible Version: 2.15.12 2025-12-29 00:20:23.957896 | Job: ansible-test-sanity-docker-milestone 2025-12-29 00:20:23.957926 | Pipeline: periodic 2025-12-29 00:20:23.957952 | Executor: ze03.softwarefactory-project.io 2025-12-29 00:20:23.957978 | Triggered by: https://github.com/ansible-collections/ansible.network 2025-12-29 00:20:23.958007 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/3a6/ansible/3a6cccd9e22d48688357174cd07aae41/ 2025-12-29 00:20:23.958034 | Event ID: eb0a6e43c3504cb28144f028ea8b0113 2025-12-29 00:20:23.963430 | 2025-12-29 00:20:23.963521 | LOOP [emit-job-header : Print node information] 2025-12-29 00:20:24.101246 | localhost | ok: 2025-12-29 00:20:24.101613 | localhost | # Node Information 2025-12-29 00:20:24.101674 | localhost | Inventory Hostname: controller 2025-12-29 00:20:24.102125 | localhost | Hostname: np0005572014 2025-12-29 00:20:24.102210 | localhost | Username: zuul 2025-12-29 00:20:24.102270 | localhost | Distro: Fedora 37 2025-12-29 00:20:24.102313 | localhost | Provider: ansible-vexxhost-ca-ymq-1 2025-12-29 00:20:24.102353 | localhost | Region: ca-ymq-1 2025-12-29 00:20:24.102390 | localhost | Label: ansible-fedora-37-1vcpu 2025-12-29 00:20:24.102428 | localhost | Product Name: OpenStack Nova 2025-12-29 00:20:24.102465 | localhost | Interface IP: 162.253.55.52 2025-12-29 00:20:24.129427 | 2025-12-29 00:20:24.129637 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-29 00:20:24.555913 | localhost -> localhost | changed 2025-12-29 00:20:24.568391 | 2025-12-29 00:20:24.568524 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-29 00:20:25.459069 | localhost -> localhost | changed 2025-12-29 00:20:25.479096 | 2025-12-29 00:20:25.479163 | PLAY [all:!appliance*] 2025-12-29 00:20:25.495315 | 2025-12-29 00:20:25.495377 | TASK [include_role : start-zuul-console] 2025-12-29 00:20:25.514038 | controller | ok 2025-12-29 00:20:25.528430 | 2025-12-29 00:20:25.528510 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-29 00:20:25.913200 | controller | ok 2025-12-29 00:20:25.923869 | 2025-12-29 00:20:25.923991 | TASK [use-our-mirror : Retrieve the IP address] 2025-12-29 00:20:27.126951 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found 2025-12-29 00:20:27.142412 | 2025-12-29 00:20:27.142583 | TASK [use-our-mirror : Ensure the registry service is running on the mirror] 2025-12-29 00:20:27.687709 | controller | skipping: Conditional result was False 2025-12-29 00:20:27.702220 | 2025-12-29 00:20:27.702407 | TASK [use-our-mirror : Write the IP in /etc/hosts] 2025-12-29 00:20:27.730286 | controller | skipping: Conditional result was False 2025-12-29 00:20:27.745102 | 2025-12-29 00:20:27.745276 | TASK [use-our-mirror : Create the podman configuration directory] 2025-12-29 00:20:27.772976 | controller | skipping: Conditional result was False 2025-12-29 00:20:27.788825 | 2025-12-29 00:20:27.788977 | TASK [use-our-mirror : Copy the podman configuration] 2025-12-29 00:20:27.815983 | controller | skipping: Conditional result was False 2025-12-29 00:20:27.826592 | 2025-12-29 00:20:27.826746 | TASK [use-our-mirror : Copy the Yum configuration (main)] 2025-12-29 00:20:27.852039 | controller | skipping: Conditional result was False 2025-12-29 00:20:27.867478 | 2025-12-29 00:20:27.867637 | TASK [use-our-mirror : Copy the Yum configuration (update)] 2025-12-29 00:20:27.884836 | controller | skipping: Conditional result was False 2025-12-29 00:20:27.911294 | 2025-12-29 00:20:27.911401 | TASK [Disable Fedora Modular] 2025-12-29 00:20:28.171923 | controller | changed 2025-12-29 00:20:28.180539 | 2025-12-29 00:20:28.180656 | TASK [Enable EPEL] 2025-12-29 00:20:28.206481 | controller | skipping: Conditional result was False 2025-12-29 00:20:28.217555 | 2025-12-29 00:20:28.217685 | TASK [Register the RHEL node] 2025-12-29 00:20:28.776279 | 2025-12-29 00:20:28.776543 | TASK [Show the subscription-manager status] 2025-12-29 00:20:29.354250 | controller | skipping: Conditional result was False 2025-12-29 00:20:29.368710 | 2025-12-29 00:20:29.368947 | TASK [Enable EPEL on RHEL] 2025-12-29 00:20:29.926334 | controller | skipping: Conditional result was False 2025-12-29 00:20:29.939842 | 2025-12-29 00:20:29.939985 | TASK [Install git and tox] 2025-12-29 00:21:51.160166 | controller | changed 2025-12-29 00:21:51.173966 | 2025-12-29 00:21:51.174138 | TASK [include_role : prepare-workspace] 2025-12-29 00:21:51.207462 | controller | ok 2025-12-29 00:21:51.235832 | 2025-12-29 00:21:51.235946 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-29 00:21:51.504532 | controller | ok 2025-12-29 00:21:51.541531 | 2025-12-29 00:21:51.541660 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-29 00:22:06.096913 | controller | Output suppressed because no_log was given 2025-12-29 00:22:06.161126 | 2025-12-29 00:22:06.161245 | TASK [include_role : prepare-workspace-openshift] 2025-12-29 00:22:06.190510 | controller | skipping: Conditional result was False 2025-12-29 00:22:06.212765 | 2025-12-29 00:22:06.212822 | PLAY [all:!appliance] 2025-12-29 00:22:06.229453 | 2025-12-29 00:22:06.229541 | TASK [Run add-build-sshkey role (RSA)] 2025-12-29 00:22:06.260105 | controller | ok 2025-12-29 00:22:06.279562 | 2025-12-29 00:22:06.279626 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-29 00:22:06.581379 | controller -> localhost | ok 2025-12-29 00:22:06.595013 | 2025-12-29 00:22:06.595161 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-29 00:22:06.633505 | controller | ok 2025-12-29 00:22:06.666125 | controller | included: /var/lib/zuul/builds/3a6cccd9e22d48688357174cd07aae41/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-29 00:22:06.678616 | 2025-12-29 00:22:06.678702 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-29 00:22:07.184469 | controller -> localhost | Generating public/private rsa key pair. 2025-12-29 00:22:07.184760 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3a6cccd9e22d48688357174cd07aae41/work/3a6cccd9e22d48688357174cd07aae41_id_rsa. 2025-12-29 00:22:07.184804 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3a6cccd9e22d48688357174cd07aae41/work/3a6cccd9e22d48688357174cd07aae41_id_rsa.pub. 2025-12-29 00:22:07.184835 | controller -> localhost | The key fingerprint is: 2025-12-29 00:22:07.184861 | controller -> localhost | SHA256:Xw/99JL0yscXobe6F2kpquAzjtA20bKdpfpwxXumoSY zuul-build-sshkey 2025-12-29 00:22:07.184889 | controller -> localhost | The key's randomart image is: 2025-12-29 00:22:07.184910 | controller -> localhost | +---[RSA 2048]----+ 2025-12-29 00:22:07.184928 | controller -> localhost | | | 2025-12-29 00:22:07.184952 | controller -> localhost | | | 2025-12-29 00:22:07.184979 | controller -> localhost | | | 2025-12-29 00:22:07.185003 | controller -> localhost | | . . . . | 2025-12-29 00:22:07.185024 | controller -> localhost | | o .S+ o + =| 2025-12-29 00:22:07.185052 | controller -> localhost | | . = =... * %.| 2025-12-29 00:22:07.185074 | controller -> localhost | | . * * o.o. B.B| 2025-12-29 00:22:07.185094 | controller -> localhost | | oEB+o =. . =+| 2025-12-29 00:22:07.185112 | controller -> localhost | | o==oo. o*..| 2025-12-29 00:22:07.185131 | controller -> localhost | +----[SHA256]-----+ 2025-12-29 00:22:07.185181 | controller -> localhost | ok: Runtime: 0:00:00.059490 2025-12-29 00:22:07.195390 | 2025-12-29 00:22:07.195481 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-29 00:22:07.228873 | controller | ok 2025-12-29 00:22:07.243655 | controller | included: /var/lib/zuul/builds/3a6cccd9e22d48688357174cd07aae41/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-29 00:22:07.256562 | 2025-12-29 00:22:07.256652 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-29 00:22:07.281812 | controller | skipping: Conditional result was False 2025-12-29 00:22:07.290770 | 2025-12-29 00:22:07.290871 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-29 00:22:07.773369 | controller | changed 2025-12-29 00:22:07.779594 | 2025-12-29 00:22:07.779690 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-29 00:22:08.037513 | controller | ok 2025-12-29 00:22:08.043581 | 2025-12-29 00:22:08.043661 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-29 00:22:08.695199 | controller | changed 2025-12-29 00:22:08.702028 | 2025-12-29 00:22:08.702103 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-29 00:22:09.313365 | controller | changed 2025-12-29 00:22:09.322718 | 2025-12-29 00:22:09.322866 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-29 00:22:09.348219 | controller | skipping: Conditional result was False 2025-12-29 00:22:09.358328 | 2025-12-29 00:22:09.358427 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-29 00:22:09.760722 | controller -> localhost | changed 2025-12-29 00:22:09.773858 | 2025-12-29 00:22:09.773986 | TASK [add-build-sshkey : Add back temp key] 2025-12-29 00:22:10.098757 | controller -> localhost | Identity added: /var/lib/zuul/builds/3a6cccd9e22d48688357174cd07aae41/work/3a6cccd9e22d48688357174cd07aae41_id_rsa (zuul-build-sshkey) 2025-12-29 00:22:10.099106 | controller -> localhost | ok: Runtime: 0:00:00.009909 2025-12-29 00:22:10.114607 | 2025-12-29 00:22:10.114839 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-29 00:22:10.515823 | controller | ok 2025-12-29 00:22:10.541479 | 2025-12-29 00:22:10.541637 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-29 00:22:10.589445 | controller | skipping: Conditional result was False 2025-12-29 00:22:10.606447 | 2025-12-29 00:22:10.606541 | TASK [Run add-build-sshkey role (ECDSA)] 2025-12-29 00:22:10.644346 | controller | ok 2025-12-29 00:22:10.669872 | 2025-12-29 00:22:10.670028 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-29 00:22:10.950022 | controller -> localhost | ok 2025-12-29 00:22:10.958590 | 2025-12-29 00:22:10.959018 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-29 00:22:10.984146 | controller | ok 2025-12-29 00:22:10.998676 | controller | included: /var/lib/zuul/builds/3a6cccd9e22d48688357174cd07aae41/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-29 00:22:11.007106 | 2025-12-29 00:22:11.007200 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-29 00:22:11.308139 | controller -> localhost | Generating public/private ecdsa key pair. 2025-12-29 00:22:11.308326 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/3a6cccd9e22d48688357174cd07aae41/work/3a6cccd9e22d48688357174cd07aae41_id_ecdsa. 2025-12-29 00:22:11.308355 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/3a6cccd9e22d48688357174cd07aae41/work/3a6cccd9e22d48688357174cd07aae41_id_ecdsa.pub. 2025-12-29 00:22:11.308384 | controller -> localhost | The key fingerprint is: 2025-12-29 00:22:11.308405 | controller -> localhost | SHA256:yQiF7xAY9zrXNyBiFFpRR1HLDRLw270wcMVuqeRP6HI zuul-build-sshkey 2025-12-29 00:22:11.308425 | controller -> localhost | The key's randomart image is: 2025-12-29 00:22:11.308443 | controller -> localhost | +---[ECDSA 521]---+ 2025-12-29 00:22:11.308461 | controller -> localhost | | .o*=+o*+o.. | 2025-12-29 00:22:11.308478 | controller -> localhost | | .=oo o o =. | 2025-12-29 00:22:11.308496 | controller -> localhost | | . +oo + +... | 2025-12-29 00:22:11.308514 | controller -> localhost | | ..+.= B..+ | 2025-12-29 00:22:11.308532 | controller -> localhost | | ooo So*+. | 2025-12-29 00:22:11.308549 | controller -> localhost | | o. .++.. | 2025-12-29 00:22:11.308566 | controller -> localhost | | . o. | 2025-12-29 00:22:11.308584 | controller -> localhost | | . E . | 2025-12-29 00:22:11.308602 | controller -> localhost | | o | 2025-12-29 00:22:11.308619 | controller -> localhost | +----[SHA256]-----+ 2025-12-29 00:22:11.308666 | controller -> localhost | ok: Runtime: 0:00:00.013015 2025-12-29 00:22:11.316038 | 2025-12-29 00:22:11.316112 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-29 00:22:11.335441 | controller | ok 2025-12-29 00:22:11.343156 | controller | included: /var/lib/zuul/builds/3a6cccd9e22d48688357174cd07aae41/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-29 00:22:11.354551 | 2025-12-29 00:22:11.354680 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-29 00:22:11.379003 | controller | skipping: Conditional result was False 2025-12-29 00:22:11.385541 | 2025-12-29 00:22:11.385621 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-29 00:22:11.684576 | controller | changed 2025-12-29 00:22:11.692841 | 2025-12-29 00:22:11.692930 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-29 00:22:11.930160 | controller | ok 2025-12-29 00:22:11.939703 | 2025-12-29 00:22:11.939822 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-29 00:22:12.642619 | controller | changed 2025-12-29 00:22:12.648541 | 2025-12-29 00:22:12.648604 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-29 00:22:13.330379 | controller | changed 2025-12-29 00:22:13.337059 | 2025-12-29 00:22:13.337134 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-29 00:22:13.351829 | controller | skipping: Conditional result was False 2025-12-29 00:22:13.395447 | 2025-12-29 00:22:13.395608 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-29 00:22:13.635611 | controller -> localhost | changed 2025-12-29 00:22:13.647864 | 2025-12-29 00:22:13.647946 | TASK [add-build-sshkey : Add back temp key] 2025-12-29 00:22:13.950022 | controller -> localhost | Identity added: /var/lib/zuul/builds/3a6cccd9e22d48688357174cd07aae41/work/3a6cccd9e22d48688357174cd07aae41_id_ecdsa (zuul-build-sshkey) 2025-12-29 00:22:13.950315 | controller -> localhost | ok: Runtime: 0:00:00.010303 2025-12-29 00:22:13.959171 | 2025-12-29 00:22:13.959278 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-29 00:22:14.177592 | controller | ok 2025-12-29 00:22:14.186757 | 2025-12-29 00:22:14.186881 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-29 00:22:14.211853 | controller | skipping: Conditional result was False 2025-12-29 00:22:14.222908 | 2025-12-29 00:22:14.222977 | TASK [include_role : remove-zuul-sshkey] 2025-12-29 00:22:14.236009 | controller | skipping: Conditional result was False 2025-12-29 00:22:14.242150 | 2025-12-29 00:22:14.242213 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-29 00:22:14.487047 | controller | ok: "logs" 2025-12-29 00:22:14.487670 | controller | ok: All items complete 2025-12-29 00:22:14.487771 | 2025-12-29 00:22:14.699812 | controller | ok: "artifacts" 2025-12-29 00:22:14.919119 | controller | ok: "docs" 2025-12-29 00:22:14.935083 | 2025-12-29 00:22:14.935273 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-29 00:22:15.186814 | controller | changed: "logs" 2025-12-29 00:22:15.387063 | controller | changed: "artifacts" 2025-12-29 00:22:15.588005 | controller | changed: "docs" 2025-12-29 00:22:15.627021 | 2025-12-29 00:22:15.627136 | PLAY RECAP 2025-12-29 00:22:15.627182 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0 2025-12-29 00:22:15.627209 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-29 00:22:15.627226 | 2025-12-29 00:22:15.744383 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master] 2025-12-29 00:22:15.746133 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-29 00:22:16.406277 | 2025-12-29 00:22:16.406443 | PLAY [all] 2025-12-29 00:22:16.429401 | 2025-12-29 00:22:16.429505 | TASK [Install binary dependencies] 2025-12-29 00:22:16.500042 | controller | ok 2025-12-29 00:22:16.521932 | 2025-12-29 00:22:16.522083 | TASK [bindep : Include find tasks] 2025-12-29 00:22:16.552336 | controller | ok 2025-12-29 00:22:16.560769 | controller | included: /var/lib/zuul/builds/3a6cccd9e22d48688357174cd07aae41/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml 2025-12-29 00:22:16.567597 | 2025-12-29 00:22:16.567663 | TASK [bindep : Look for bindep.txt] 2025-12-29 00:22:16.925281 | controller | ok 2025-12-29 00:22:16.933164 | 2025-12-29 00:22:16.933263 | TASK [bindep : Define bindep_file fact] 2025-12-29 00:22:16.957744 | controller | skipping: Conditional result was False 2025-12-29 00:22:16.967061 | 2025-12-29 00:22:16.967201 | TASK [bindep : Look for other-requirements.txt] 2025-12-29 00:22:17.206172 | controller | ok 2025-12-29 00:22:17.218585 | 2025-12-29 00:22:17.218766 | TASK [bindep : Define bindep_file fact] 2025-12-29 00:22:17.245066 | controller | skipping: Conditional result was False 2025-12-29 00:22:17.258833 | 2025-12-29 00:22:17.258995 | TASK [bindep : Look for bindep fallback file] 2025-12-29 00:22:17.285705 | controller | skipping: Conditional result was False 2025-12-29 00:22:17.299767 | 2025-12-29 00:22:17.299948 | TASK [bindep : Define bindep_file fact] 2025-12-29 00:22:17.326262 | controller | skipping: Conditional result was False 2025-12-29 00:22:17.339128 | 2025-12-29 00:22:17.339289 | TASK [bindep : Include bindep tasks] 2025-12-29 00:22:17.365761 | controller | skipping: Conditional result was False 2025-12-29 00:22:17.379014 | 2025-12-29 00:22:17.379174 | TASK [bindep : Include install tasks] 2025-12-29 00:22:17.405469 | controller | skipping: Conditional result was False 2025-12-29 00:22:17.417837 | 2025-12-29 00:22:17.417991 | LOOP [bindep : Include package tasks] 2025-12-29 00:22:17.487806 | 2025-12-29 00:22:17.488078 | TASK [Run test-setup role] 2025-12-29 00:22:17.517146 | controller | ok 2025-12-29 00:22:17.547710 | 2025-12-29 00:22:17.547907 | TASK [test-setup : Check if project's tools/test-setup.sh exists] 2025-12-29 00:22:17.778554 | controller | ok 2025-12-29 00:22:17.791558 | 2025-12-29 00:22:17.791699 | TASK [test-setup : Run tools/test-setup.sh] 2025-12-29 00:22:18.345023 | controller | skipping: Conditional result was False 2025-12-29 00:22:18.402055 | 2025-12-29 00:22:18.402172 | PLAY RECAP 2025-12-29 00:22:18.402229 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-29 00:22:18.402258 | 2025-12-29 00:22:18.506604 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master] 2025-12-29 00:22:18.508408 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-29 00:22:19.120799 | 2025-12-29 00:22:19.120932 | PLAY [controller] 2025-12-29 00:22:19.141124 | 2025-12-29 00:22:19.141243 | TASK [Create the /root directory] 2025-12-29 00:22:19.535095 | controller | ok 2025-12-29 00:22:19.548194 | 2025-12-29 00:22:19.548375 | TASK [Install glibc-langpack-en] 2025-12-29 00:22:23.568873 | controller | ok: Nothing to do 2025-12-29 00:22:23.582971 | 2025-12-29 00:22:23.583239 | TASK [Ensure controller directory exists] 2025-12-29 00:22:23.815661 | controller | changed 2025-12-29 00:22:23.822376 | 2025-12-29 00:22:23.822446 | TASK [Install container runtime] 2025-12-29 00:22:23.899631 | controller | ok 2025-12-29 00:22:23.961893 | 2025-12-29 00:22:23.962032 | LOOP [ensure-podman : Find distribution installation] 2025-12-29 00:22:23.990785 | controller | ok: "/var/lib/zuul/builds/3a6cccd9e22d48688357174cd07aae41/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml" 2025-12-29 00:22:24.008659 | controller | included: /var/lib/zuul/builds/3a6cccd9e22d48688357174cd07aae41/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml 2025-12-29 00:22:24.017793 | 2025-12-29 00:22:24.017886 | TASK [ensure-podman : Install podman (RedHat)] 2025-12-29 00:23:28.010044 | controller | changed 2025-12-29 00:23:28.021483 | 2025-12-29 00:23:28.021594 | TASK [ensure-podman : Fetch podman version] 2025-12-29 00:23:28.570443 | controller | Client: Podman Engine 2025-12-29 00:23:28.593125 | controller | Version: 4.6.2 2025-12-29 00:23:28.593160 | controller | API Version: 4.6.2 2025-12-29 00:23:28.593169 | controller | Go Version: go1.19.12 2025-12-29 00:23:28.593186 | controller | Built: Mon Aug 28 19:38:31 2023 2025-12-29 00:23:28.593193 | controller | OS/Arch: linux/amd64 2025-12-29 00:23:29.066800 | controller | ok: Runtime: 0:00:00.192068 2025-12-29 00:23:29.080521 | 2025-12-29 00:23:29.080713 | TASK [ensure-podman : Print podman version installed] 2025-12-29 00:23:29.126373 | Podman version: Client: Podman Engine 2025-12-29 00:23:29.126580 | Version: 4.6.2 2025-12-29 00:23:29.126639 | API Version: 4.6.2 2025-12-29 00:23:29.126686 | Go Version: go1.19.12 2025-12-29 00:23:29.126774 | Built: Mon Aug 28 19:38:31 2023 2025-12-29 00:23:29.126823 | OS/Arch: linux/amd64 2025-12-29 00:23:29.135025 | 2025-12-29 00:23:29.135135 | TASK [ensure-podman : Validate podman engine] 2025-12-29 00:23:29.677921 | controller | skipping: Conditional result was False 2025-12-29 00:23:29.684609 | 2025-12-29 00:23:29.684698 | TASK [ensure-podman : Set up docker compatability socket] 2025-12-29 00:23:29.698699 | controller | skipping: Conditional result was False 2025-12-29 00:23:29.710464 | 2025-12-29 00:23:29.710545 | TASK [Ensure python3.8 is present] 2025-12-29 00:23:29.724492 | controller | skipping: Conditional result was False 2025-12-29 00:23:29.730635 | 2025-12-29 00:23:29.730702 | TASK [Run our-ensure-python role (Fedora only for now)] 2025-12-29 00:23:29.750163 | controller | ok 2025-12-29 00:23:29.773260 | 2025-12-29 00:23:29.773391 | TASK [our-ensure-python : Install the right Python version (rpm)] 2025-12-29 00:23:31.504923 | controller | ok: Nothing to do 2025-12-29 00:23:31.518084 | 2025-12-29 00:23:31.518251 | TASK [our-ensure-python : Also install python3-devel] 2025-12-29 00:23:40.022423 | controller | changed 2025-12-29 00:23:40.033367 | 2025-12-29 00:23:40.033435 | TASK [Run ensure-virtualenv role] 2025-12-29 00:23:40.053190 | controller | ok 2025-12-29 00:23:40.076205 | 2025-12-29 00:23:40.076277 | TASK [ensure-virtualenv : Check if virtualenv is installed] 2025-12-29 00:23:40.285723 | controller | /usr/bin/virtualenv 2025-12-29 00:23:40.606558 | controller | ok: Runtime: 0:00:00.005003 2025-12-29 00:23:40.695187 | 2025-12-29 00:23:40.695398 | LOOP [ensure-virtualenv : Install virtualenv package] 2025-12-29 00:23:40.732285 | controller | skipping: Conditional result was False 2025-12-29 00:23:40.733081 | controller | ok: All items complete 2025-12-29 00:23:40.733155 | 2025-12-29 00:23:40.770987 | 2025-12-29 00:23:40.771239 | TASK [Find the full path of the Python interpreter] 2025-12-29 00:23:40.991332 | controller | /usr/bin/python3 2025-12-29 00:23:41.319672 | controller | ok 2025-12-29 00:23:41.328603 | 2025-12-29 00:23:41.328717 | TASK [Create virtualenv for ansible-test with a specific interpreter] 2025-12-29 00:23:42.117179 | controller | created virtual environment CPython3.11.0.final.0-64 in 463ms 2025-12-29 00:23:42.134976 | controller | creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False) 2025-12-29 00:23:42.135019 | 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-29 00:23:42.135029 | controller | added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1 2025-12-29 00:23:42.135045 | controller | activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator 2025-12-29 00:23:42.375388 | controller | changed 2025-12-29 00:23:42.392025 | 2025-12-29 00:23:42.392186 | TASK [Set selinux package] 2025-12-29 00:23:42.439882 | controller | ok 2025-12-29 00:23:42.447334 | 2025-12-29 00:23:42.447423 | TASK [Set selinux package (Fedora)] 2025-12-29 00:23:42.491542 | controller | ok 2025-12-29 00:23:42.499701 | 2025-12-29 00:23:42.499856 | TASK [Install selinux into virtualenv] 2025-12-29 00:24:07.959328 | controller | Collecting selinux-please-lie-to-me 2025-12-29 00:24:32.160515 | controller | Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB) 2025-12-29 00:24:32.469191 | controller | Collecting setuptools<50.0.0 2025-12-29 00:24:32.473941 | controller | Downloading setuptools-49.6.0-py3-none-any.whl (803 kB) 2025-12-29 00:24:32.514523 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 22.8 MB/s eta 0:00:00 2025-12-29 00:24:32.595437 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me 2025-12-29 00:24:32.595678 | controller | Attempting uninstall: setuptools 2025-12-29 00:24:32.598102 | controller | Found existing installation: setuptools 62.6.0 2025-12-29 00:24:32.657834 | controller | Uninstalling setuptools-62.6.0: 2025-12-29 00:24:32.665954 | controller | Successfully uninstalled setuptools-62.6.0 2025-12-29 00:24:33.028341 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0 2025-12-29 00:24:49.317921 | controller | 2025-12-29 00:24:49.509955 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-29 00:24:49.510053 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-29 00:24:49.601494 | controller | ok: Runtime: 0:01:06.796386 2025-12-29 00:24:49.608312 | 2025-12-29 00:24:49.608375 | TASK [Install pytest-forked into virtualenv] 2025-12-29 00:25:01.581441 | controller | Collecting pytest-forked 2025-12-29 00:25:13.791328 | controller | Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB) 2025-12-29 00:25:13.839003 | controller | Collecting py 2025-12-29 00:25:13.844371 | controller | Downloading py-1.11.0-py2.py3-none-any.whl (98 kB) 2025-12-29 00:25:13.862663 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.0 MB/s eta 0:00:00 2025-12-29 00:25:13.970918 | controller | Collecting pytest>=3.10 2025-12-29 00:25:13.975928 | controller | Downloading pytest-9.0.2-py3-none-any.whl (374 kB) 2025-12-29 00:25:13.989545 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 34.4 MB/s eta 0:00:00 2025-12-29 00:25:14.025015 | controller | Collecting iniconfig>=1.0.1 2025-12-29 00:25:14.029098 | controller | Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB) 2025-12-29 00:25:14.074056 | controller | Collecting packaging>=22 2025-12-29 00:25:14.078533 | controller | Downloading packaging-25.0-py3-none-any.whl (66 kB) 2025-12-29 00:25:14.084924 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 17.5 MB/s eta 0:00:00 2025-12-29 00:25:14.117904 | controller | Collecting pluggy<2,>=1.5 2025-12-29 00:25:14.123960 | controller | Downloading pluggy-1.6.0-py3-none-any.whl (20 kB) 2025-12-29 00:25:14.171234 | controller | Collecting pygments>=2.7.2 2025-12-29 00:25:14.174679 | controller | Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB) 2025-12-29 00:25:14.201302 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 51.3 MB/s eta 0:00:00 2025-12-29 00:25:14.271405 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked 2025-12-29 00:25:15.377321 | 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-29 00:25:15.386582 | controller | 2025-12-29 00:25:15.506803 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3 2025-12-29 00:25:15.506866 | controller | [notice] To update, run: python -m pip install --upgrade pip 2025-12-29 00:25:15.674180 | controller | ok: Runtime: 0:00:25.670766 2025-12-29 00:25:15.681615 | 2025-12-29 00:25:15.681685 | TASK [Update pip] 2025-12-29 00:25:16.207020 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2) 2025-12-29 00:25:26.207914 | controller | Collecting pip 2025-12-29 00:25:38.379318 | controller | Downloading pip-25.3-py3-none-any.whl (1.8 MB) 2025-12-29 00:25:38.438172 | controller | ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 32.5 MB/s eta 0:00:00 2025-12-29 00:25:38.503745 | controller | Installing collected packages: pip 2025-12-29 00:25:38.503938 | controller | Attempting uninstall: pip 2025-12-29 00:25:38.506317 | controller | Found existing installation: pip 22.2.2 2025-12-29 00:25:38.651439 | controller | Uninstalling pip-22.2.2: 2025-12-29 00:25:38.667421 | controller | Successfully uninstalled pip-22.2.2 2025-12-29 00:25:39.499244 | controller | Successfully installed pip-25.3 2025-12-29 00:25:39.732091 | controller | ok: Runtime: 0:00:23.696696 2025-12-29 00:25:39.740455 | 2025-12-29 00:25:39.740563 | TASK [Ensure pip temp directory exists in /var/tmp] 2025-12-29 00:25:39.951401 | controller | changed 2025-12-29 00:25:39.964247 | 2025-12-29 00:25:39.964406 | TASK [Install ansible into virtualenv] 2025-12-29 00:25:40.541227 | controller | Processing ./src/github.com/ansible/ansible 2025-12-29 00:25:40.544824 | controller | Installing build dependencies: started 2025-12-29 00:26:17.763330 | controller | Installing build dependencies: finished with status 'done' 2025-12-29 00:26:17.764083 | controller | Getting requirements to build wheel: started 2025-12-29 00:26:18.540940 | controller | Getting requirements to build wheel: finished with status 'done' 2025-12-29 00:26:18.542424 | controller | Preparing metadata (pyproject.toml): started 2025-12-29 00:26:19.017723 | controller | Preparing metadata (pyproject.toml): finished with status 'done' 2025-12-29 00:26:19.022640 | 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-29 00:26:19.026446 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12' 2025-12-29 00:26:19.580990 | controller | ERROR 2025-12-29 00:26:19.581337 | controller | { 2025-12-29 00:26:19.581424 | controller | "delta": "0:00:38.849748", 2025-12-29 00:26:19.581472 | controller | "end": "2025-12-29 00:26:19.093060", 2025-12-29 00:26:19.581515 | controller | "msg": "non-zero return code", 2025-12-29 00:26:19.581595 | controller | "rc": 1, 2025-12-29 00:26:19.581654 | controller | "start": "2025-12-29 00:25:40.243312" 2025-12-29 00:26:19.581703 | controller | } failure 2025-12-29 00:26:19.584231 | 2025-12-29 00:26:19.584324 | PLAY RECAP 2025-12-29 00:26:19.584406 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2025-12-29 00:26:19.584449 | 2025-12-29 00:26:19.737843 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master] 2025-12-29 00:26:19.739903 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-29 00:26:20.363425 | 2025-12-29 00:26:20.363536 | PLAY [all] 2025-12-29 00:26:20.387176 | 2025-12-29 00:26:20.387266 | TASK [fetch-subunit-output : Find stestr or testr executable] 2025-12-29 00:26:20.690662 | controller | changed: non-zero return code 2025-12-29 00:26:20.704121 | 2025-12-29 00:26:20.704285 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2025-12-29 00:26:20.732376 | controller | skipping: Conditional result was False 2025-12-29 00:26:20.744612 | 2025-12-29 00:26:20.744689 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2025-12-29 00:26:20.775545 | 2025-12-29 00:26:20.775687 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2025-12-29 00:26:20.806439 | 2025-12-29 00:26:20.806576 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2025-12-29 00:26:20.831152 | controller | skipping: Conditional result was False 2025-12-29 00:26:20.847312 | 2025-12-29 00:26:20.847485 | LOOP [fetch-subunit-output : Generate subunit file] 2025-12-29 00:26:20.882963 | 2025-12-29 00:26:20.883185 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2025-12-29 00:26:20.908258 | controller | skipping: Conditional result was False 2025-12-29 00:26:20.923128 | 2025-12-29 00:26:20.923286 | TASK [fetch-subunit-output : Remove the temporary file] 2025-12-29 00:26:20.940706 | controller | skipping: Conditional result was False 2025-12-29 00:26:20.954516 | 2025-12-29 00:26:20.954623 | TASK [fetch-subunit-output : Process and fetch subunit results] 2025-12-29 00:26:20.969760 | controller | skipping: Conditional result was False 2025-12-29 00:26:21.008887 | 2025-12-29 00:26:21.009020 | PLAY RECAP 2025-12-29 00:26:21.009076 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0 2025-12-29 00:26:21.009105 | 2025-12-29 00:26:21.115412 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master] 2025-12-29 00:26:21.117711 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master] 2025-12-29 00:26:21.708659 | 2025-12-29 00:26:21.708818 | PLAY [all:!appliance*] 2025-12-29 00:26:21.730643 | 2025-12-29 00:26:21.730776 | TASK [unregister the node] 2025-12-29 00:26:22.265621 | controller | skipping: Conditional result was False 2025-12-29 00:26:22.284137 | 2025-12-29 00:26:22.284382 | TASK [include_role : fetch-output] 2025-12-29 00:26:22.341097 | controller | ok 2025-12-29 00:26:22.379475 | 2025-12-29 00:26:22.379610 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-29 00:26:22.455847 | controller | skipping: Conditional result was False 2025-12-29 00:26:22.465178 | 2025-12-29 00:26:22.465299 | TASK [fetch-output : Set log path for single node] 2025-12-29 00:26:22.506039 | controller | ok 2025-12-29 00:26:22.511899 | 2025-12-29 00:26:22.511973 | LOOP [fetch-output : Ensure local output dirs] 2025-12-29 00:26:22.903625 | controller -> localhost | ok: "/var/lib/zuul/builds/3a6cccd9e22d48688357174cd07aae41/work/logs" 2025-12-29 00:26:23.161682 | controller -> localhost | changed: "/var/lib/zuul/builds/3a6cccd9e22d48688357174cd07aae41/work/artifacts" 2025-12-29 00:26:23.407603 | controller -> localhost | changed: "/var/lib/zuul/builds/3a6cccd9e22d48688357174cd07aae41/work/docs" 2025-12-29 00:26:23.421142 | 2025-12-29 00:26:23.421257 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-29 00:26:24.146039 | controller | changed: 2025-12-29 00:26:24.146386 | controller | .d..t...... ./ 2025-12-29 00:26:24.146456 | controller | cd+++++++++ controller/ 2025-12-29 00:26:24.146534 | controller | changed: All items complete 2025-12-29 00:26:24.146587 | 2025-12-29 00:26:24.618757 | controller | changed: .d..t...... ./ 2025-12-29 00:26:25.165062 | controller | changed: .d..t...... ./ 2025-12-29 00:26:25.200266 | 2025-12-29 00:26:25.200472 | TASK [include_role : fetch-output-openshift] 2025-12-29 00:26:25.241384 | controller | skipping: Conditional result was False 2025-12-29 00:26:25.256928 | 2025-12-29 00:26:25.257102 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-29 00:26:25.294387 | controller | skipping: Conditional result was False 2025-12-29 00:26:25.317205 | controller | skipping: Conditional result was False 2025-12-29 00:26:25.387800 | 2025-12-29 00:26:25.387941 | PLAY [localhost] 2025-12-29 00:26:25.405562 | 2025-12-29 00:26:25.405676 | TASK [Run Zuul manifest role] 2025-12-29 00:26:25.432247 | localhost | ok 2025-12-29 00:26:25.481682 | 2025-12-29 00:26:25.481828 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-29 00:26:25.935865 | localhost | changed 2025-12-29 00:26:25.947423 | 2025-12-29 00:26:25.947583 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-29 00:26:25.995878 | localhost | ok 2025-12-29 00:26:26.015516 | 2025-12-29 00:26:26.015659 | TASK [Set zuul-log-path fact] 2025-12-29 00:26:26.042014 | localhost | ok 2025-12-29 00:26:26.064860 | 2025-12-29 00:26:26.064990 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-29 00:26:26.105548 | localhost | ok 2025-12-29 00:26:26.116481 | 2025-12-29 00:26:26.116562 | LOOP [Run upload-logs-swift role] 2025-12-29 00:26:26.161673 | localhost | Output suppressed because no_log was given 2025-12-29 00:26:26.200089 | 2025-12-29 00:26:26.200195 | TASK [Set zuul-log-path fact] 2025-12-29 00:26:26.235661 | localhost | skipping: Conditional result was False 2025-12-29 00:26:26.242458 | 2025-12-29 00:26:26.242547 | TASK [upload-logs-swift : Ensure logs are readable before uploading] 2025-12-29 00:26:26.692317 | localhost -> localhost | ok: Runtime: 0:00:00.009282 2025-12-29 00:26:26.741186 | 2025-12-29 00:26:26.741322 | TASK [upload-logs-swift : Upload logs to swift]