2026-02-09 00:28:08.094005 | Job console starting...
2026-02-09 00:28:08.110206 | Updating repositories
2026-02-09 00:28:08.255006 | Preparing job workspace
2026-02-09 00:28:12.535367 | Running Ansible setup...
2026-02-09 00:28:17.742006 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-09 00:28:18.413506 | 
2026-02-09 00:28:18.413692 | PLAY [localhost]
2026-02-09 00:28:18.424373 | 
2026-02-09 00:28:18.424519 | TASK [Gathering Facts]
2026-02-09 00:28:19.466695 | localhost | ok
2026-02-09 00:28:19.480466 | 
2026-02-09 00:28:19.480587 | TASK [Setup log path fact]
2026-02-09 00:28:19.500612 | localhost | ok
2026-02-09 00:28:19.514777 | 
2026-02-09 00:28:19.514898 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-09 00:28:19.546234 | localhost | ok
2026-02-09 00:28:19.557226 | 
2026-02-09 00:28:19.557368 | TASK [emit-job-header : Print job information]
2026-02-09 00:28:19.599833 | # Job Information
2026-02-09 00:28:19.600081 | Ansible Version: 2.15.12
2026-02-09 00:28:19.600156 | Job: ansible-test-sanity-docker-devel
2026-02-09 00:28:19.600182 | Pipeline: periodic
2026-02-09 00:28:19.600200 | Executor: ze01.softwarefactory-project.io
2026-02-09 00:28:19.600218 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-02-09 00:28:19.600238 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/b60/ansible/b60ba73a950e41e9ba87957f62b4b336/
2026-02-09 00:28:19.600256 | Event ID: 3991a479362c4ac7b1894c2bd5156053
2026-02-09 00:28:19.604298 | 
2026-02-09 00:28:19.604365 | LOOP [emit-job-header : Print node information]
2026-02-09 00:28:19.742682 | localhost | ok:
2026-02-09 00:28:19.742972 | localhost | # Node Information
2026-02-09 00:28:19.743012 | localhost | Inventory Hostname: controller
2026-02-09 00:28:19.743066 | localhost | Hostname: np0005613136
2026-02-09 00:28:19.743095 | localhost | Username: zuul
2026-02-09 00:28:19.743126 | localhost | Distro: Fedora 37
2026-02-09 00:28:19.743151 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-02-09 00:28:19.743175 | localhost | Region: ca-ymq-1
2026-02-09 00:28:19.743199 | localhost | Label: ansible-fedora-37-1vcpu
2026-02-09 00:28:19.743223 | localhost | Product Name: OpenStack Nova
2026-02-09 00:28:19.743247 | localhost | Interface IP: 162.253.55.212
2026-02-09 00:28:19.760332 | 
2026-02-09 00:28:19.760539 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-09 00:28:20.251896 | localhost -> localhost | changed
2026-02-09 00:28:20.259126 | 
2026-02-09 00:28:20.259283 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-09 00:28:21.257381 | localhost -> localhost | changed
2026-02-09 00:28:21.280180 | 
2026-02-09 00:28:21.280302 | PLAY [all:!appliance*]
2026-02-09 00:28:21.310680 | 
2026-02-09 00:28:21.310823 | TASK [include_role : start-zuul-console]
2026-02-09 00:28:21.333657 | controller | ok
2026-02-09 00:28:21.349060 | 
2026-02-09 00:28:21.349243 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-09 00:28:21.772814 | controller | ok
2026-02-09 00:28:21.789162 | 
2026-02-09 00:28:21.789325 | TASK [use-our-mirror : Retrieve the IP address]
2026-02-09 00:28:23.036663 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-02-09 00:28:23.051467 | 
2026-02-09 00:28:23.051664 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-02-09 00:28:23.608702 | controller | skipping: Conditional result was False
2026-02-09 00:28:23.619207 | 
2026-02-09 00:28:23.619367 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-02-09 00:28:23.655764 | controller | skipping: Conditional result was False
2026-02-09 00:28:23.665192 | 
2026-02-09 00:28:23.665309 | TASK [use-our-mirror : Create the podman configuration directory]
2026-02-09 00:28:23.691061 | controller | skipping: Conditional result was False
2026-02-09 00:28:23.701387 | 
2026-02-09 00:28:23.701509 | TASK [use-our-mirror : Copy the podman configuration]
2026-02-09 00:28:23.726442 | controller | skipping: Conditional result was False
2026-02-09 00:28:23.736070 | 
2026-02-09 00:28:23.736244 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-02-09 00:28:23.761804 | controller | skipping: Conditional result was False
2026-02-09 00:28:23.772209 | 
2026-02-09 00:28:23.772348 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-02-09 00:28:23.797330 | controller | skipping: Conditional result was False
2026-02-09 00:28:23.813725 | 
2026-02-09 00:28:23.813875 | TASK [Disable Fedora Modular]
2026-02-09 00:28:24.055652 | controller | changed
2026-02-09 00:28:24.068323 | 
2026-02-09 00:28:24.068488 | TASK [Enable EPEL]
2026-02-09 00:28:24.095986 | controller | skipping: Conditional result was False
2026-02-09 00:28:24.102457 | 
2026-02-09 00:28:24.102568 | TASK [Register the RHEL node]
2026-02-09 00:28:24.656375 | 
2026-02-09 00:28:24.656637 | TASK [Show the subscription-manager status]
2026-02-09 00:28:25.235608 | controller | skipping: Conditional result was False
2026-02-09 00:28:25.242979 | 
2026-02-09 00:28:25.243094 | TASK [Enable EPEL on RHEL]
2026-02-09 00:28:25.779352 | controller | skipping: Conditional result was False
2026-02-09 00:28:25.795169 | 
2026-02-09 00:28:25.795405 | TASK [Install git and tox]
2026-02-09 00:29:47.626388 | controller | changed
2026-02-09 00:29:47.638840 | 
2026-02-09 00:29:47.639106 | TASK [include_role : prepare-workspace]
2026-02-09 00:29:47.674291 | controller | ok
2026-02-09 00:29:47.699040 | 
2026-02-09 00:29:47.699226 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-09 00:29:47.916745 | controller | ok
2026-02-09 00:29:47.927833 | 
2026-02-09 00:29:47.928049 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-09 00:30:02.023780 | controller | Output suppressed because no_log was given
2026-02-09 00:30:02.035350 | 
2026-02-09 00:30:02.035435 | TASK [include_role : prepare-workspace-openshift]
2026-02-09 00:30:02.054985 | controller | skipping: Conditional result was False
2026-02-09 00:30:02.081602 | 
2026-02-09 00:30:02.081764 | PLAY [all:!appliance]
2026-02-09 00:30:02.103323 | 
2026-02-09 00:30:02.103507 | TASK [Run add-build-sshkey role (RSA)]
2026-02-09 00:30:02.135555 | controller | ok
2026-02-09 00:30:02.153041 | 
2026-02-09 00:30:02.153208 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-09 00:30:02.413425 | controller -> localhost | ok
2026-02-09 00:30:02.421356 | 
2026-02-09 00:30:02.421530 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-09 00:30:02.452808 | controller | ok
2026-02-09 00:30:02.469269 | controller | included: /var/lib/zuul/builds/b60ba73a950e41e9ba87957f62b4b336/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-09 00:30:02.476931 | 
2026-02-09 00:30:02.477076 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-09 00:30:02.962290 | controller -> localhost | Generating public/private rsa key pair.
2026-02-09 00:30:02.962540 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b60ba73a950e41e9ba87957f62b4b336/work/b60ba73a950e41e9ba87957f62b4b336_id_rsa.
2026-02-09 00:30:02.962571 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b60ba73a950e41e9ba87957f62b4b336/work/b60ba73a950e41e9ba87957f62b4b336_id_rsa.pub.
2026-02-09 00:30:02.962593 | controller -> localhost | The key fingerprint is:
2026-02-09 00:30:02.962613 | controller -> localhost | SHA256:vjakMgueOUgmPsK1yhvY2L7kT/l+9ZtcJBD/zXuBsJE zuul-build-sshkey
2026-02-09 00:30:02.962633 | controller -> localhost | The key's randomart image is:
2026-02-09 00:30:02.962652 | controller -> localhost | +---[RSA 2048]----+
2026-02-09 00:30:02.962671 | controller -> localhost | |          .      |
2026-02-09 00:30:02.962691 | controller -> localhost | |           o.    |
2026-02-09 00:30:02.962709 | controller -> localhost | |          .E.    |
2026-02-09 00:30:02.962728 | controller -> localhost | |           .+..o |
2026-02-09 00:30:02.962746 | controller -> localhost | |        S  ...o.o|
2026-02-09 00:30:02.962776 | controller -> localhost | |o* . . .. .  o  o|
2026-02-09 00:30:02.962803 | controller -> localhost | |Oo* +  o.. .  ...|
2026-02-09 00:30:02.962824 | controller -> localhost | |+Oo*o.. +. ..o  .|
2026-02-09 00:30:02.962843 | controller -> localhost | |.+@+o=oo..  +.   |
2026-02-09 00:30:02.962864 | controller -> localhost | +----[SHA256]-----+
2026-02-09 00:30:02.962913 | controller -> localhost | ok: Runtime: 0:00:00.097649
2026-02-09 00:30:02.970311 | 
2026-02-09 00:30:02.970412 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-09 00:30:03.001267 | controller | ok
2026-02-09 00:30:03.012539 | controller | included: /var/lib/zuul/builds/b60ba73a950e41e9ba87957f62b4b336/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-09 00:30:03.023159 | 
2026-02-09 00:30:03.023306 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-09 00:30:03.048309 | controller | skipping: Conditional result was False
2026-02-09 00:30:03.056491 | 
2026-02-09 00:30:03.056660 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-09 00:30:03.571746 | controller | changed
2026-02-09 00:30:03.578591 | 
2026-02-09 00:30:03.578676 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-09 00:30:03.793421 | controller | ok
2026-02-09 00:30:03.799585 | 
2026-02-09 00:30:03.799673 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-09 00:30:04.435596 | controller | changed
2026-02-09 00:30:04.443468 | 
2026-02-09 00:30:04.443578 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-09 00:30:05.122189 | controller | changed
2026-02-09 00:30:05.131524 | 
2026-02-09 00:30:05.131683 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-09 00:30:05.157335 | controller | skipping: Conditional result was False
2026-02-09 00:30:05.167478 | 
2026-02-09 00:30:05.167620 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-09 00:30:05.635521 | controller -> localhost | changed
2026-02-09 00:30:05.654584 | 
2026-02-09 00:30:05.654779 | TASK [add-build-sshkey : Add back temp key]
2026-02-09 00:30:06.009519 | controller -> localhost | Identity added: /var/lib/zuul/builds/b60ba73a950e41e9ba87957f62b4b336/work/b60ba73a950e41e9ba87957f62b4b336_id_rsa (zuul-build-sshkey)
2026-02-09 00:30:06.009890 | controller -> localhost | ok: Runtime: 0:00:00.009070
2026-02-09 00:30:06.020500 | 
2026-02-09 00:30:06.020677 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-09 00:30:06.383217 | controller | ok
2026-02-09 00:30:06.391299 | 
2026-02-09 00:30:06.391417 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-09 00:30:06.419435 | controller | skipping: Conditional result was False
2026-02-09 00:30:06.433689 | 
2026-02-09 00:30:06.433851 | TASK [Run add-build-sshkey role (ECDSA)]
2026-02-09 00:30:06.468619 | controller | ok
2026-02-09 00:30:06.495930 | 
2026-02-09 00:30:06.496144 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-09 00:30:06.821202 | controller -> localhost | ok
2026-02-09 00:30:06.829814 | 
2026-02-09 00:30:06.829921 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-09 00:30:06.861567 | controller | ok
2026-02-09 00:30:06.874054 | controller | included: /var/lib/zuul/builds/b60ba73a950e41e9ba87957f62b4b336/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-09 00:30:06.880722 | 
2026-02-09 00:30:06.880794 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-09 00:30:07.191623 | controller -> localhost | Generating public/private ecdsa key pair.
2026-02-09 00:30:07.191856 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b60ba73a950e41e9ba87957f62b4b336/work/b60ba73a950e41e9ba87957f62b4b336_id_ecdsa.
2026-02-09 00:30:07.191890 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b60ba73a950e41e9ba87957f62b4b336/work/b60ba73a950e41e9ba87957f62b4b336_id_ecdsa.pub.
2026-02-09 00:30:07.191923 | controller -> localhost | The key fingerprint is:
2026-02-09 00:30:07.191944 | controller -> localhost | SHA256:RBViwJezfUWV5ioagmPhF/xIq5APPX2p5zIV2jhHJJQ zuul-build-sshkey
2026-02-09 00:30:07.191992 | controller -> localhost | The key's randomart image is:
2026-02-09 00:30:07.192011 | controller -> localhost | +---[ECDSA 521]---+
2026-02-09 00:30:07.192079 | controller -> localhost | |     .oo=oo. ...o|
2026-02-09 00:30:07.192097 | controller -> localhost | |      .E+o    .o |
2026-02-09 00:30:07.192115 | controller -> localhost | |      ..++   .o  |
2026-02-09 00:30:07.192131 | controller -> localhost | |     . =.o. .  . |
2026-02-09 00:30:07.192148 | controller -> localhost | |    + = S o.  .  |
2026-02-09 00:30:07.192164 | controller -> localhost | |   + B X O . .   |
2026-02-09 00:30:07.192180 | controller -> localhost | |    = = B o .    |
2026-02-09 00:30:07.192196 | controller -> localhost | |     o + o       |
2026-02-09 00:30:07.192212 | controller -> localhost | |        =.       |
2026-02-09 00:30:07.192228 | controller -> localhost | +----[SHA256]-----+
2026-02-09 00:30:07.192296 | controller -> localhost | ok: Runtime: 0:00:00.009961
2026-02-09 00:30:07.199449 | 
2026-02-09 00:30:07.199578 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-09 00:30:07.230984 | controller | ok
2026-02-09 00:30:07.240245 | controller | included: /var/lib/zuul/builds/b60ba73a950e41e9ba87957f62b4b336/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-09 00:30:07.250726 | 
2026-02-09 00:30:07.250814 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-09 00:30:07.275400 | controller | skipping: Conditional result was False
2026-02-09 00:30:07.282858 | 
2026-02-09 00:30:07.283069 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-09 00:30:07.588527 | controller | changed
2026-02-09 00:30:07.602999 | 
2026-02-09 00:30:07.603222 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-09 00:30:07.862689 | controller | ok
2026-02-09 00:30:07.868665 | 
2026-02-09 00:30:07.868758 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-09 00:30:08.549443 | controller | changed
2026-02-09 00:30:08.563356 | 
2026-02-09 00:30:08.563645 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-09 00:30:09.247502 | controller | changed
2026-02-09 00:30:09.308038 | 
2026-02-09 00:30:09.308187 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-09 00:30:09.342998 | controller | skipping: Conditional result was False
2026-02-09 00:30:09.351004 | 
2026-02-09 00:30:09.351192 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-09 00:30:09.602834 | controller -> localhost | changed
2026-02-09 00:30:09.617959 | 
2026-02-09 00:30:09.618104 | TASK [add-build-sshkey : Add back temp key]
2026-02-09 00:30:09.902400 | controller -> localhost | Identity added: /var/lib/zuul/builds/b60ba73a950e41e9ba87957f62b4b336/work/b60ba73a950e41e9ba87957f62b4b336_id_ecdsa (zuul-build-sshkey)
2026-02-09 00:30:09.902914 | controller -> localhost | ok: Runtime: 0:00:00.008418
2026-02-09 00:30:09.921834 | 
2026-02-09 00:30:09.922179 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-09 00:30:10.163328 | controller | ok
2026-02-09 00:30:10.181167 | 
2026-02-09 00:30:10.181461 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-09 00:30:10.209442 | controller | skipping: Conditional result was False
2026-02-09 00:30:10.228722 | 
2026-02-09 00:30:10.228895 | TASK [include_role : remove-zuul-sshkey]
2026-02-09 00:30:10.245970 | controller | skipping: Conditional result was False
2026-02-09 00:30:10.257819 | 
2026-02-09 00:30:10.257964 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-09 00:30:10.502648 | controller | ok: "logs"
2026-02-09 00:30:10.503103 | controller | ok: All items complete
2026-02-09 00:30:10.503150 | 
2026-02-09 00:30:10.693092 | controller | ok: "artifacts"
2026-02-09 00:30:10.884071 | controller | ok: "docs"
2026-02-09 00:30:10.895673 | 
2026-02-09 00:30:10.895823 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-09 00:30:11.151605 | controller | changed: "logs"
2026-02-09 00:30:11.354355 | controller | changed: "artifacts"
2026-02-09 00:30:11.558123 | controller | changed: "docs"
2026-02-09 00:30:11.589899 | 
2026-02-09 00:30:11.590037 | PLAY RECAP
2026-02-09 00:30:11.590088 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-02-09 00:30:11.590116 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-09 00:30:11.590135 | 
2026-02-09 00:30:11.734520 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-02-09 00:30:11.735516 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-09 00:30:12.356726 | 
2026-02-09 00:30:12.356874 | PLAY [all]
2026-02-09 00:30:12.381693 | 
2026-02-09 00:30:12.381832 | TASK [Install binary dependencies]
2026-02-09 00:30:12.446290 | controller | ok
2026-02-09 00:30:12.478162 | 
2026-02-09 00:30:12.478405 | TASK [bindep : Include find tasks]
2026-02-09 00:30:12.511449 | controller | ok
2026-02-09 00:30:12.520811 | controller | included: /var/lib/zuul/builds/b60ba73a950e41e9ba87957f62b4b336/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-02-09 00:30:12.527990 | 
2026-02-09 00:30:12.528125 | TASK [bindep : Look for bindep.txt]
2026-02-09 00:30:12.899192 | controller | ok
2026-02-09 00:30:12.906835 | 
2026-02-09 00:30:12.906968 | TASK [bindep : Define bindep_file fact]
2026-02-09 00:30:12.934262 | controller | skipping: Conditional result was False
2026-02-09 00:30:12.942569 | 
2026-02-09 00:30:12.942705 | TASK [bindep : Look for other-requirements.txt]
2026-02-09 00:30:13.161906 | controller | ok
2026-02-09 00:30:13.171910 | 
2026-02-09 00:30:13.172231 | TASK [bindep : Define bindep_file fact]
2026-02-09 00:30:13.199060 | controller | skipping: Conditional result was False
2026-02-09 00:30:13.210894 | 
2026-02-09 00:30:13.211114 | TASK [bindep : Look for bindep fallback file]
2026-02-09 00:30:13.237870 | controller | skipping: Conditional result was False
2026-02-09 00:30:13.258841 | 
2026-02-09 00:30:13.259352 | TASK [bindep : Define bindep_file fact]
2026-02-09 00:30:13.285568 | controller | skipping: Conditional result was False
2026-02-09 00:30:13.295887 | 
2026-02-09 00:30:13.296069 | TASK [bindep : Include bindep tasks]
2026-02-09 00:30:13.322397 | controller | skipping: Conditional result was False
2026-02-09 00:30:13.333888 | 
2026-02-09 00:30:13.334094 | TASK [bindep : Include install tasks]
2026-02-09 00:30:13.360119 | controller | skipping: Conditional result was False
2026-02-09 00:30:13.367927 | 
2026-02-09 00:30:13.368033 | LOOP [bindep : Include package tasks]
2026-02-09 00:30:13.460341 | 
2026-02-09 00:30:13.460710 | TASK [Run test-setup role]
2026-02-09 00:30:13.492007 | controller | ok
2026-02-09 00:30:13.519155 | 
2026-02-09 00:30:13.519363 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-02-09 00:30:13.743280 | controller | ok
2026-02-09 00:30:13.752071 | 
2026-02-09 00:30:13.752238 | TASK [test-setup : Run tools/test-setup.sh]
2026-02-09 00:30:14.291680 | controller | skipping: Conditional result was False
2026-02-09 00:30:14.335731 | 
2026-02-09 00:30:14.335891 | PLAY RECAP
2026-02-09 00:30:14.335958 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-09 00:30:14.336008 | 
2026-02-09 00:30:14.469838 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-02-09 00:30:14.470901 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-09 00:30:15.275337 | 
2026-02-09 00:30:15.275538 | PLAY [controller]
2026-02-09 00:30:15.300794 | 
2026-02-09 00:30:15.301062 | TASK [Create the /root directory]
2026-02-09 00:30:15.757854 | controller | ok
2026-02-09 00:30:15.765161 | 
2026-02-09 00:30:15.765379 | TASK [Install glibc-langpack-en]
2026-02-09 00:30:19.793495 | controller | ok: Nothing to do
2026-02-09 00:30:19.810822 | 
2026-02-09 00:30:19.811098 | TASK [Ensure controller directory exists]
2026-02-09 00:30:20.051365 | controller | changed
2026-02-09 00:30:20.066351 | 
2026-02-09 00:30:20.066498 | TASK [Install container runtime]
2026-02-09 00:30:20.151172 | controller | ok
2026-02-09 00:30:20.216602 | 
2026-02-09 00:30:20.216763 | LOOP [ensure-podman : Find distribution installation]
2026-02-09 00:30:20.264283 | controller | ok: "/var/lib/zuul/builds/b60ba73a950e41e9ba87957f62b4b336/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-02-09 00:30:20.283735 | controller | included: /var/lib/zuul/builds/b60ba73a950e41e9ba87957f62b4b336/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-02-09 00:30:20.293204 | 
2026-02-09 00:30:20.293359 | TASK [ensure-podman : Install podman (RedHat)]
2026-02-09 00:31:26.711461 | controller | changed
2026-02-09 00:31:26.728146 | 
2026-02-09 00:31:26.728331 | TASK [ensure-podman : Fetch podman version]
2026-02-09 00:31:27.296801 | controller | Client:       Podman Engine
2026-02-09 00:31:27.325413 | controller | Version:      4.6.2
2026-02-09 00:31:27.325472 | controller | API Version:  4.6.2
2026-02-09 00:31:27.325485 | controller | Go Version:   go1.19.12
2026-02-09 00:31:27.325523 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-02-09 00:31:27.325537 | controller | OS/Arch:      linux/amd64
2026-02-09 00:31:27.774803 | controller | ok: Runtime: 0:00:00.210288
2026-02-09 00:31:27.781340 | 
2026-02-09 00:31:27.781444 | TASK [ensure-podman : Print podman version installed]
2026-02-09 00:31:27.811846 | Podman version: Client:       Podman Engine
2026-02-09 00:31:27.812015 | Version:      4.6.2
2026-02-09 00:31:27.812060 | API Version:  4.6.2
2026-02-09 00:31:27.812082 | Go Version:   go1.19.12
2026-02-09 00:31:27.812101 | Built:        Mon Aug 28 19:38:31 2023
2026-02-09 00:31:27.812120 | OS/Arch:      linux/amd64
2026-02-09 00:31:27.817761 | 
2026-02-09 00:31:27.817825 | TASK [ensure-podman : Validate podman engine]
2026-02-09 00:31:28.352208 | controller | skipping: Conditional result was False
2026-02-09 00:31:28.359778 | 
2026-02-09 00:31:28.359917 | TASK [ensure-podman : Set up docker compatability socket]
2026-02-09 00:31:28.384969 | controller | skipping: Conditional result was False
2026-02-09 00:31:28.401561 | 
2026-02-09 00:31:28.401721 | TASK [Ensure python3.8 is present]
2026-02-09 00:31:28.417430 | controller | skipping: Conditional result was False
2026-02-09 00:31:28.431531 | 
2026-02-09 00:31:28.431697 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-02-09 00:31:28.455922 | controller | ok
2026-02-09 00:31:28.485171 | 
2026-02-09 00:31:28.485325 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-02-09 00:31:29.895606 | controller | ok: Nothing to do
2026-02-09 00:31:29.902796 | 
2026-02-09 00:31:29.902936 | TASK [our-ensure-python : Also install python3-devel]
2026-02-09 00:31:38.838636 | controller | changed
2026-02-09 00:31:38.850993 | 
2026-02-09 00:31:38.851165 | TASK [Run ensure-virtualenv role]
2026-02-09 00:31:38.872722 | controller | ok
2026-02-09 00:31:38.896006 | 
2026-02-09 00:31:38.896198 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-02-09 00:31:39.175388 | controller | /usr/bin/virtualenv
2026-02-09 00:31:39.488393 | controller | ok: Runtime: 0:00:00.005451
2026-02-09 00:31:39.498039 | 
2026-02-09 00:31:39.498161 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-02-09 00:31:39.522704 | controller | skipping: Conditional result was False
2026-02-09 00:31:39.523074 | controller | ok: All items complete
2026-02-09 00:31:39.523107 | 
2026-02-09 00:31:39.544358 | 
2026-02-09 00:31:39.544618 | TASK [Find the full path of the Python interpreter]
2026-02-09 00:31:39.777339 | controller | /usr/bin/python3
2026-02-09 00:31:40.089586 | controller | ok
2026-02-09 00:31:40.096620 | 
2026-02-09 00:31:40.096707 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-02-09 00:31:40.892246 | controller | created virtual environment CPython3.11.0.final.0-64 in 477ms
2026-02-09 00:31:40.919877 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-02-09 00:31:40.920292 | 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-02-09 00:31:40.920481 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-02-09 00:31:40.920689 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-02-09 00:31:41.133425 | controller | changed
2026-02-09 00:31:41.149265 | 
2026-02-09 00:31:41.149504 | TASK [Set selinux package]
2026-02-09 00:31:41.200410 | controller | ok
2026-02-09 00:31:41.212229 | 
2026-02-09 00:31:41.212373 | TASK [Set selinux package (Fedora)]
2026-02-09 00:31:41.263690 | controller | ok
2026-02-09 00:31:41.276854 | 
2026-02-09 00:31:41.277113 | TASK [Install selinux into virtualenv]
2026-02-09 00:31:54.883519 | controller | Collecting selinux-please-lie-to-me
2026-02-09 00:32:07.097992 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-02-09 00:32:07.417519 | controller | Collecting setuptools<50.0.0
2026-02-09 00:32:07.422123 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-02-09 00:32:07.464862 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 21.3 MB/s eta 0:00:00
2026-02-09 00:32:07.550482 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-02-09 00:32:07.550698 | controller |   Attempting uninstall: setuptools
2026-02-09 00:32:07.553251 | controller |     Found existing installation: setuptools 62.6.0
2026-02-09 00:32:07.612878 | controller |     Uninstalling setuptools-62.6.0:
2026-02-09 00:32:07.620934 | controller |       Successfully uninstalled setuptools-62.6.0
2026-02-09 00:32:07.964852 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-02-09 00:32:19.479053 | controller |
2026-02-09 00:32:19.591430 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-09 00:32:19.591473 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-09 00:32:19.864345 | controller | ok: Runtime: 0:00:38.078426
2026-02-09 00:32:19.872852 | 
2026-02-09 00:32:19.872980 | TASK [Install pytest-forked into virtualenv]
2026-02-09 00:32:31.714597 | controller | Collecting pytest-forked
2026-02-09 00:32:43.969346 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-02-09 00:32:44.078045 | controller | Collecting py
2026-02-09 00:32:44.082835 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-02-09 00:32:44.107867 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 4.3 MB/s eta 0:00:00
2026-02-09 00:32:44.219944 | controller | Collecting pytest>=3.10
2026-02-09 00:32:44.223744 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-02-09 00:32:44.240955 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 27.8 MB/s eta 0:00:00
2026-02-09 00:32:44.292535 | controller | Collecting iniconfig>=1.0.1
2026-02-09 00:32:44.297405 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-02-09 00:32:44.340849 | controller | Collecting packaging>=22
2026-02-09 00:32:44.344216 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-02-09 00:32:44.353716 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 11.3 MB/s eta 0:00:00
2026-02-09 00:32:44.391242 | controller | Collecting pluggy<2,>=1.5
2026-02-09 00:32:44.394834 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-02-09 00:32:44.449619 | controller | Collecting pygments>=2.7.2
2026-02-09 00:32:44.453414 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-02-09 00:32:44.479836 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 54.8 MB/s eta 0:00:00
2026-02-09 00:32:44.551255 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-02-09 00:32:45.707932 | 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-02-09 00:32:45.720399 | controller |
2026-02-09 00:32:45.833031 | controller | [notice] A new release of pip available: 22.2.2 -> 26.0.1
2026-02-09 00:32:45.833100 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-02-09 00:32:45.923411 | controller | ok: Runtime: 0:00:25.748489
2026-02-09 00:32:45.940810 | 
2026-02-09 00:32:45.941062 | TASK [Update pip]
2026-02-09 00:32:46.558132 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-02-09 00:32:56.365425 | controller | Collecting pip
2026-02-09 00:33:08.551481 | controller |   Downloading pip-26.0.1-py3-none-any.whl (1.8 MB)
2026-02-09 00:33:08.622661 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 29.3 MB/s eta 0:00:00
2026-02-09 00:33:08.691344 | controller | Installing collected packages: pip
2026-02-09 00:33:08.691540 | controller |   Attempting uninstall: pip
2026-02-09 00:33:08.693895 | controller |     Found existing installation: pip 22.2.2
2026-02-09 00:33:08.841132 | controller |     Uninstalling pip-22.2.2:
2026-02-09 00:33:08.856986 | controller |       Successfully uninstalled pip-22.2.2
2026-02-09 00:33:09.703288 | controller | Successfully installed pip-26.0.1
2026-02-09 00:33:10.082579 | controller | ok: Runtime: 0:00:23.568569
2026-02-09 00:33:10.092929 | 
2026-02-09 00:33:10.093117 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-02-09 00:33:10.333076 | controller | changed
2026-02-09 00:33:10.340332 | 
2026-02-09 00:33:10.340448 | TASK [Install ansible into virtualenv]
2026-02-09 00:33:10.849389 | controller | Processing ./src/github.com/ansible/ansible
2026-02-09 00:33:10.851913 | controller |   Installing build dependencies: started
2026-02-09 00:33:33.848764 | controller |   Installing build dependencies: finished with status 'done'
2026-02-09 00:33:34.649846 | controller |   Getting requirements to build wheel: started
2026-02-09 00:33:34.649916 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-02-09 00:33:34.651440 | controller |   Preparing metadata (pyproject.toml): started
2026-02-09 00:33:35.123174 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-02-09 00:33:35.127406 | 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-02-09 00:33:35.130912 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-02-09 00:33:35.405541 | controller | ERROR
2026-02-09 00:33:35.406056 | controller | {
2026-02-09 00:33:35.406132 | controller |   "delta": "0:00:24.658820",
2026-02-09 00:33:35.406198 | controller |   "end": "2026-02-09 00:33:35.220534",
2026-02-09 00:33:35.406238 | controller |   "msg": "non-zero return code",
2026-02-09 00:33:35.406293 | controller |   "rc": 1,
2026-02-09 00:33:35.406329 | controller |   "start": "2026-02-09 00:33:10.561714"
2026-02-09 00:33:35.406361 | controller | }
failure
2026-02-09 00:33:35.409110 | 
2026-02-09 00:33:35.409202 | PLAY RECAP
2026-02-09 00:33:35.409276 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-02-09 00:33:35.409319 | 
2026-02-09 00:33:35.606541 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-02-09 00:33:35.607731 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-09 00:33:36.353623 | 
2026-02-09 00:33:36.353795 | PLAY [all]
2026-02-09 00:33:36.378856 | 
2026-02-09 00:33:36.379078 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-02-09 00:33:36.676106 | controller | changed: non-zero return code
2026-02-09 00:33:36.691369 | 
2026-02-09 00:33:36.691662 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-02-09 00:33:36.709736 | controller | skipping: Conditional result was False
2026-02-09 00:33:36.723827 | 
2026-02-09 00:33:36.724120 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-02-09 00:33:36.754427 | 
2026-02-09 00:33:36.754702 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-02-09 00:33:36.791181 | 
2026-02-09 00:33:36.791453 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-02-09 00:33:36.817915 | controller | skipping: Conditional result was False
2026-02-09 00:33:36.828079 | 
2026-02-09 00:33:36.828279 | LOOP [fetch-subunit-output : Generate subunit file]
2026-02-09 00:33:36.861556 | 
2026-02-09 00:33:36.861788 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-02-09 00:33:36.877080 | controller | skipping: Conditional result was False
2026-02-09 00:33:36.884904 | 
2026-02-09 00:33:36.885084 | TASK [fetch-subunit-output : Remove the temporary file]
2026-02-09 00:33:36.900967 | controller | skipping: Conditional result was False
2026-02-09 00:33:36.908306 | 
2026-02-09 00:33:36.908460 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-02-09 00:33:36.933792 | controller | skipping: Conditional result was False
2026-02-09 00:33:36.964666 | 
2026-02-09 00:33:36.964808 | PLAY RECAP
2026-02-09 00:33:36.964853 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-02-09 00:33:36.964874 | 
2026-02-09 00:33:37.121116 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-02-09 00:33:37.122115 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-02-09 00:33:37.818267 | 
2026-02-09 00:33:37.818442 | PLAY [all:!appliance*]
2026-02-09 00:33:37.854574 | 
2026-02-09 00:33:37.854771 | TASK [unregister the node]
2026-02-09 00:33:38.389206 | controller | skipping: Conditional result was False
2026-02-09 00:33:38.396590 | 
2026-02-09 00:33:38.396816 | TASK [include_role : fetch-output]
2026-02-09 00:33:38.431907 | controller | ok
2026-02-09 00:33:38.469144 | 
2026-02-09 00:33:38.469327 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-09 00:33:38.535504 | controller | skipping: Conditional result was False
2026-02-09 00:33:38.543450 | 
2026-02-09 00:33:38.543617 | TASK [fetch-output : Set log path for single node]
2026-02-09 00:33:38.598469 | controller | ok
2026-02-09 00:33:38.605268 | 
2026-02-09 00:33:38.605378 | LOOP [fetch-output : Ensure local output dirs]
2026-02-09 00:33:39.058743 | controller -> localhost | ok: "/var/lib/zuul/builds/b60ba73a950e41e9ba87957f62b4b336/work/logs"
2026-02-09 00:33:39.282042 | controller -> localhost | changed: "/var/lib/zuul/builds/b60ba73a950e41e9ba87957f62b4b336/work/artifacts"
2026-02-09 00:33:39.500944 | controller -> localhost | changed: "/var/lib/zuul/builds/b60ba73a950e41e9ba87957f62b4b336/work/docs"
2026-02-09 00:33:39.518302 | 
2026-02-09 00:33:39.518476 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-09 00:33:40.305331 | controller | changed:
2026-02-09 00:33:40.305563 | controller | .d..t...... ./
2026-02-09 00:33:40.305593 | controller | cd+++++++++ controller/
2026-02-09 00:33:40.305628 | controller | changed: All items complete
2026-02-09 00:33:40.305649 | 
2026-02-09 00:33:40.807489 | controller | changed: .d..t...... ./
2026-02-09 00:33:41.358525 | controller | changed: .d..t...... ./
2026-02-09 00:33:41.381835 | 
2026-02-09 00:33:41.382001 | TASK [include_role : fetch-output-openshift]
2026-02-09 00:33:41.406691 | controller | skipping: Conditional result was False
2026-02-09 00:33:41.414673 | 
2026-02-09 00:33:41.414838 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-09 00:33:41.454379 | controller | skipping: Conditional result was False
2026-02-09 00:33:41.468677 | controller | skipping: Conditional result was False
2026-02-09 00:33:41.517093 | 
2026-02-09 00:33:41.517278 | PLAY [localhost]
2026-02-09 00:33:41.548094 | 
2026-02-09 00:33:41.548216 | TASK [Run Zuul manifest role]
2026-02-09 00:33:41.567839 | localhost | ok
2026-02-09 00:33:41.590278 | 
2026-02-09 00:33:41.590463 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-09 00:33:42.006527 | localhost | changed
2026-02-09 00:33:42.012123 | 
2026-02-09 00:33:42.012277 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-09 00:33:42.042389 | localhost | ok
2026-02-09 00:33:42.050797 | 
2026-02-09 00:33:42.050886 | TASK [Set zuul-log-path fact]
2026-02-09 00:33:42.070038 | localhost | ok
2026-02-09 00:33:42.086152 | 
2026-02-09 00:33:42.086291 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-09 00:33:42.115489 | localhost | ok
2026-02-09 00:33:42.126149 | 
2026-02-09 00:33:42.126287 | LOOP [Run upload-logs-swift role]
2026-02-09 00:33:42.151580 | localhost | Output suppressed because no_log was given
2026-02-09 00:33:42.183563 | 
2026-02-09 00:33:42.183710 | TASK [Set zuul-log-path fact]
2026-02-09 00:33:42.208308 | localhost | skipping: Conditional result was False
2026-02-09 00:33:42.214342 | 
2026-02-09 00:33:42.214472 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-02-09 00:33:42.633361 | localhost -> localhost | ok: Runtime: 0:00:00.007453
2026-02-09 00:33:42.689393 | 
2026-02-09 00:33:42.689545 | TASK [upload-logs-swift : Upload logs to swift]