2025-11-02 00:12:06.552316 | Job console starting...
2025-11-02 00:12:06.561939 | Updating repositories
2025-11-02 00:12:06.702578 | Preparing job workspace
2025-11-02 00:12:10.481832 | Running Ansible setup...
2025-11-02 00:12:14.965799 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-02 00:12:15.760130 | 
2025-11-02 00:12:15.760293 | PLAY [localhost]
2025-11-02 00:12:15.769533 | 
2025-11-02 00:12:15.769618 | TASK [Gathering Facts]
2025-11-02 00:12:16.780959 | localhost | ok
2025-11-02 00:12:16.798264 | 
2025-11-02 00:12:16.798499 | TASK [Setup log path fact]
2025-11-02 00:12:16.818205 | localhost | ok
2025-11-02 00:12:16.836149 | 
2025-11-02 00:12:16.836286 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-02 00:12:16.865846 | localhost | ok
2025-11-02 00:12:16.874845 | 
2025-11-02 00:12:16.874936 | TASK [emit-job-header : Print job information]
2025-11-02 00:12:16.907907 | # Job Information
2025-11-02 00:12:16.908086 | Ansible Version: 2.15.12
2025-11-02 00:12:16.908122 | Job: ansible-test-sanity-docker-devel
2025-11-02 00:12:16.908163 | Pipeline: periodic
2025-11-02 00:12:16.908182 | Executor: ze04.softwarefactory-project.io
2025-11-02 00:12:16.908200 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-11-02 00:12:16.908758 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/af1/ansible/af18f3686d7e44558f5f891a789f2514/
2025-11-02 00:12:16.908799 | Event ID: ab268dade05340f0bccc28ef5656c369
2025-11-02 00:12:16.912889 | 
2025-11-02 00:12:16.912955 | LOOP [emit-job-header : Print node information]
2025-11-02 00:12:17.094299 | localhost | ok:
2025-11-02 00:12:17.094485 | localhost | # Node Information
2025-11-02 00:12:17.094512 | localhost | Inventory Hostname: controller
2025-11-02 00:12:17.094531 | localhost | Hostname: np0005509583
2025-11-02 00:12:17.094550 | localhost | Username: zuul
2025-11-02 00:12:17.094571 | localhost | Distro: Fedora 37
2025-11-02 00:12:17.094594 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-11-02 00:12:17.094611 | localhost | Region: ca-ymq-1
2025-11-02 00:12:17.094638 | localhost | Label: ansible-fedora-37-1vcpu
2025-11-02 00:12:17.094654 | localhost | Product Name: OpenStack Nova
2025-11-02 00:12:17.094671 | localhost | Interface IP: 162.253.55.209
2025-11-02 00:12:17.105778 | 
2025-11-02 00:12:17.105845 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-11-02 00:12:17.706420 | localhost -> localhost | changed
2025-11-02 00:12:17.714952 | 
2025-11-02 00:12:17.715041 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-11-02 00:12:18.658564 | localhost -> localhost | changed
2025-11-02 00:12:18.684884 | 
2025-11-02 00:12:18.684985 | PLAY [all:!appliance*]
2025-11-02 00:12:18.702248 | 
2025-11-02 00:12:18.702389 | TASK [include_role : start-zuul-console]
2025-11-02 00:12:18.734136 | controller | ok
2025-11-02 00:12:18.748070 | 
2025-11-02 00:12:18.748158 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-11-02 00:12:19.130914 | controller | ok
2025-11-02 00:12:19.142056 | 
2025-11-02 00:12:19.142188 | TASK [use-our-mirror : Retrieve the IP address]
2025-11-02 00:12:20.148219 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-11-02 00:12:20.164033 | 
2025-11-02 00:12:20.164202 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-11-02 00:12:20.721540 | controller | skipping: Conditional result was False
2025-11-02 00:12:20.739491 | 
2025-11-02 00:12:20.739653 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-11-02 00:12:20.769177 | controller | skipping: Conditional result was False
2025-11-02 00:12:20.776656 | 
2025-11-02 00:12:20.776779 | TASK [use-our-mirror : Create the podman configuration directory]
2025-11-02 00:12:20.803160 | controller | skipping: Conditional result was False
2025-11-02 00:12:20.810182 | 
2025-11-02 00:12:20.810267 | TASK [use-our-mirror : Copy the podman configuration]
2025-11-02 00:12:20.835813 | controller | skipping: Conditional result was False
2025-11-02 00:12:20.842890 | 
2025-11-02 00:12:20.843043 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-11-02 00:12:20.867904 | controller | skipping: Conditional result was False
2025-11-02 00:12:20.875917 | 
2025-11-02 00:12:20.876076 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-11-02 00:12:20.900704 | controller | skipping: Conditional result was False
2025-11-02 00:12:20.912946 | 
2025-11-02 00:12:20.913062 | TASK [Disable Fedora Modular]
2025-11-02 00:12:21.165731 | controller | changed
2025-11-02 00:12:21.178365 | 
2025-11-02 00:12:21.178531 | TASK [Enable EPEL]
2025-11-02 00:12:21.205982 | controller | skipping: Conditional result was False
2025-11-02 00:12:21.215976 | 
2025-11-02 00:12:21.216112 | TASK [Register the RHEL node]
2025-11-02 00:12:21.772869 | 
2025-11-02 00:12:21.773151 | TASK [Show the subscription-manager status]
2025-11-02 00:12:22.375307 | controller | skipping: Conditional result was False
2025-11-02 00:12:22.384773 | 
2025-11-02 00:12:22.384910 | TASK [Enable EPEL on RHEL]
2025-11-02 00:12:22.927305 | controller | skipping: Conditional result was False
2025-11-02 00:12:22.934917 | 
2025-11-02 00:12:22.935046 | TASK [Install git and tox]
2025-11-02 00:13:48.897289 | controller | changed
2025-11-02 00:13:48.906852 | 
2025-11-02 00:13:48.906958 | TASK [include_role : prepare-workspace]
2025-11-02 00:13:48.940214 | controller | ok
2025-11-02 00:13:48.972303 | 
2025-11-02 00:13:48.972431 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-02 00:13:49.219957 | controller | ok
2025-11-02 00:13:49.228955 | 
2025-11-02 00:13:49.229058 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-02 00:14:02.142344 | controller | Output suppressed because no_log was given
2025-11-02 00:14:02.156102 | 
2025-11-02 00:14:02.156267 | TASK [include_role : prepare-workspace-openshift]
2025-11-02 00:14:02.175599 | controller | skipping: Conditional result was False
2025-11-02 00:14:02.258581 | 
2025-11-02 00:14:02.258781 | PLAY [all:!appliance]
2025-11-02 00:14:02.301176 | 
2025-11-02 00:14:02.301353 | TASK [Run add-build-sshkey role (RSA)]
2025-11-02 00:14:02.332461 | controller | ok
2025-11-02 00:14:02.347836 | 
2025-11-02 00:14:02.347918 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-02 00:14:02.762336 | controller -> localhost | ok
2025-11-02 00:14:02.769567 | 
2025-11-02 00:14:02.769646 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-02 00:14:02.801169 | controller | ok
2025-11-02 00:14:02.814961 | controller | included: /var/lib/zuul/builds/af18f3686d7e44558f5f891a789f2514/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-02 00:14:02.820703 | 
2025-11-02 00:14:02.820768 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-02 00:14:03.329040 | controller -> localhost | Generating public/private rsa key pair.
2025-11-02 00:14:03.329315 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/af18f3686d7e44558f5f891a789f2514/work/af18f3686d7e44558f5f891a789f2514_id_rsa.
2025-11-02 00:14:03.329347 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/af18f3686d7e44558f5f891a789f2514/work/af18f3686d7e44558f5f891a789f2514_id_rsa.pub.
2025-11-02 00:14:03.329370 | controller -> localhost | The key fingerprint is:
2025-11-02 00:14:03.329391 | controller -> localhost | SHA256:9W8A7aoqWCyDMjltFeQdltqXnRr5xVIcbgtYCe+TYno zuul-build-sshkey
2025-11-02 00:14:03.329411 | controller -> localhost | The key's randomart image is:
2025-11-02 00:14:03.329431 | controller -> localhost | +---[RSA 2048]----+
2025-11-02 00:14:03.329451 | controller -> localhost | |   .. o....o..   |
2025-11-02 00:14:03.329471 | controller -> localhost | |   ..o.. +.oo    |
2025-11-02 00:14:03.329490 | controller -> localhost | |    .+. .+=++    |
2025-11-02 00:14:03.329509 | controller -> localhost | |    o . =o+Bo.   |
2025-11-02 00:14:03.329527 | controller -> localhost | | + o   .S++o=    |
2025-11-02 00:14:03.329555 | controller -> localhost | |* = o  o...o o   |
2025-11-02 00:14:03.329579 | controller -> localhost | |.+ =  . E .   o  |
2025-11-02 00:14:03.329601 | controller -> localhost | |  . .  . .   .   |
2025-11-02 00:14:03.329621 | controller -> localhost | |     ....        |
2025-11-02 00:14:03.329643 | controller -> localhost | +----[SHA256]-----+
2025-11-02 00:14:03.330583 | controller -> localhost | ok: Runtime: 0:00:00.105589
2025-11-02 00:14:03.337911 | 
2025-11-02 00:14:03.338035 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-02 00:14:03.370460 | controller | ok
2025-11-02 00:14:03.382393 | controller | included: /var/lib/zuul/builds/af18f3686d7e44558f5f891a789f2514/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-02 00:14:03.391503 | 
2025-11-02 00:14:03.391576 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-02 00:14:03.417206 | controller | skipping: Conditional result was False
2025-11-02 00:14:03.427340 | 
2025-11-02 00:14:03.427434 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-02 00:14:03.898727 | controller | changed
2025-11-02 00:14:03.904721 | 
2025-11-02 00:14:03.904803 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-02 00:14:04.147768 | controller | ok
2025-11-02 00:14:04.170155 | 
2025-11-02 00:14:04.170366 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-02 00:14:04.778391 | controller | changed
2025-11-02 00:14:04.787540 | 
2025-11-02 00:14:04.787652 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-02 00:14:05.428550 | controller | changed
2025-11-02 00:14:05.448658 | 
2025-11-02 00:14:05.448811 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-02 00:14:05.477729 | controller | skipping: Conditional result was False
2025-11-02 00:14:05.488602 | 
2025-11-02 00:14:05.488738 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-02 00:14:05.943128 | controller -> localhost | changed
2025-11-02 00:14:05.961110 | 
2025-11-02 00:14:05.961195 | TASK [add-build-sshkey : Add back temp key]
2025-11-02 00:14:06.305231 | controller -> localhost | Identity added: /var/lib/zuul/builds/af18f3686d7e44558f5f891a789f2514/work/af18f3686d7e44558f5f891a789f2514_id_rsa (zuul-build-sshkey)
2025-11-02 00:14:06.305973 | controller -> localhost | ok: Runtime: 0:00:00.021614
2025-11-02 00:14:06.314616 | 
2025-11-02 00:14:06.314766 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-02 00:14:06.682524 | controller | ok
2025-11-02 00:14:06.693185 | 
2025-11-02 00:14:06.693256 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-02 00:14:06.725771 | controller | skipping: Conditional result was False
2025-11-02 00:14:06.739388 | 
2025-11-02 00:14:06.739491 | TASK [Run add-build-sshkey role (ECDSA)]
2025-11-02 00:14:06.772829 | controller | ok
2025-11-02 00:14:06.793966 | 
2025-11-02 00:14:06.794107 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-02 00:14:07.067930 | controller -> localhost | ok
2025-11-02 00:14:07.077108 | 
2025-11-02 00:14:07.077219 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-02 00:14:07.111944 | controller | ok
2025-11-02 00:14:07.125048 | controller | included: /var/lib/zuul/builds/af18f3686d7e44558f5f891a789f2514/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-02 00:14:07.133280 | 
2025-11-02 00:14:07.133358 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-02 00:14:07.435948 | controller -> localhost | Generating public/private ecdsa key pair.
2025-11-02 00:14:07.436248 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/af18f3686d7e44558f5f891a789f2514/work/af18f3686d7e44558f5f891a789f2514_id_ecdsa.
2025-11-02 00:14:07.436315 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/af18f3686d7e44558f5f891a789f2514/work/af18f3686d7e44558f5f891a789f2514_id_ecdsa.pub.
2025-11-02 00:14:07.436375 | controller -> localhost | The key fingerprint is:
2025-11-02 00:14:07.436444 | controller -> localhost | SHA256:q/5kXR1dMVV4pacrneWSXlcNEJyPpTf/BQrqWeQJJgQ zuul-build-sshkey
2025-11-02 00:14:07.436484 | controller -> localhost | The key's randomart image is:
2025-11-02 00:14:07.436520 | controller -> localhost | +---[ECDSA 521]---+
2025-11-02 00:14:07.436556 | controller -> localhost | |    E.     .oo +X|
2025-11-02 00:14:07.436591 | controller -> localhost | |      .     o.oo+|
2025-11-02 00:14:07.436631 | controller -> localhost | |     .       =+.o|
2025-11-02 00:14:07.436672 | controller -> localhost | |      . o o o.==.|
2025-11-02 00:14:07.437441 | controller -> localhost | |       oS= o.oo++|
2025-11-02 00:14:07.437488 | controller -> localhost | |        .o+... *+|
2025-11-02 00:14:07.437524 | controller -> localhost | |       .+o. . * *|
2025-11-02 00:14:07.437573 | controller -> localhost | |       +o    o oo|
2025-11-02 00:14:07.437608 | controller -> localhost | |     .o..     .  |
2025-11-02 00:14:07.437643 | controller -> localhost | +----[SHA256]-----+
2025-11-02 00:14:07.437772 | controller -> localhost | ok: Runtime: 0:00:00.014851
2025-11-02 00:14:07.464983 | 
2025-11-02 00:14:07.465159 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-02 00:14:07.504174 | controller | ok
2025-11-02 00:14:07.513618 | controller | included: /var/lib/zuul/builds/af18f3686d7e44558f5f891a789f2514/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-02 00:14:07.528637 | 
2025-11-02 00:14:07.528797 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-02 00:14:07.555224 | controller | skipping: Conditional result was False
2025-11-02 00:14:07.564253 | 
2025-11-02 00:14:07.564404 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-02 00:14:07.849068 | controller | changed
2025-11-02 00:14:07.859169 | 
2025-11-02 00:14:07.859331 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-02 00:14:08.111619 | controller | ok
2025-11-02 00:14:08.122822 | 
2025-11-02 00:14:08.122991 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-02 00:14:08.751730 | controller | changed
2025-11-02 00:14:08.759402 | 
2025-11-02 00:14:08.759569 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-02 00:14:09.397922 | controller | changed
2025-11-02 00:14:09.411067 | 
2025-11-02 00:14:09.411137 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-02 00:14:09.438228 | controller | skipping: Conditional result was False
2025-11-02 00:14:09.449383 | 
2025-11-02 00:14:09.449487 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-02 00:14:09.754483 | controller -> localhost | changed
2025-11-02 00:14:09.840142 | 
2025-11-02 00:14:09.840303 | TASK [add-build-sshkey : Add back temp key]
2025-11-02 00:14:10.183702 | controller -> localhost | Identity added: /var/lib/zuul/builds/af18f3686d7e44558f5f891a789f2514/work/af18f3686d7e44558f5f891a789f2514_id_ecdsa (zuul-build-sshkey)
2025-11-02 00:14:10.183994 | controller -> localhost | ok: Runtime: 0:00:00.017960
2025-11-02 00:14:10.191534 | 
2025-11-02 00:14:10.191622 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-02 00:14:10.403570 | controller | ok
2025-11-02 00:14:10.416424 | 
2025-11-02 00:14:10.416574 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-02 00:14:10.457143 | controller | skipping: Conditional result was False
2025-11-02 00:14:10.474770 | 
2025-11-02 00:14:10.474877 | TASK [include_role : remove-zuul-sshkey]
2025-11-02 00:14:10.501604 | controller | skipping: Conditional result was False
2025-11-02 00:14:10.511014 | 
2025-11-02 00:14:10.511102 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-02 00:14:10.771673 | controller | ok: "logs"
2025-11-02 00:14:10.771979 | controller | ok: All items complete
2025-11-02 00:14:10.772037 | 
2025-11-02 00:14:10.948100 | controller | ok: "artifacts"
2025-11-02 00:14:11.149411 | controller | ok: "docs"
2025-11-02 00:14:11.162922 | 
2025-11-02 00:14:11.163081 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-02 00:14:11.394025 | controller | changed: "logs"
2025-11-02 00:14:11.609131 | controller | changed: "artifacts"
2025-11-02 00:14:11.825727 | controller | changed: "docs"
2025-11-02 00:14:11.875145 | 
2025-11-02 00:14:11.875289 | PLAY RECAP
2025-11-02 00:14:11.875343 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-11-02 00:14:11.875369 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-02 00:14:11.875387 | 
2025-11-02 00:14:12.047697 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-02 00:14:12.049139 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-02 00:14:12.693217 | 
2025-11-02 00:14:12.693381 | PLAY [all]
2025-11-02 00:14:12.718909 | 
2025-11-02 00:14:12.719053 | TASK [Install binary dependencies]
2025-11-02 00:14:12.774897 | controller | ok
2025-11-02 00:14:12.797464 | 
2025-11-02 00:14:12.797624 | TASK [bindep : Include find tasks]
2025-11-02 00:14:12.841776 | controller | ok
2025-11-02 00:14:12.851714 | controller | included: /var/lib/zuul/builds/af18f3686d7e44558f5f891a789f2514/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-11-02 00:14:12.858047 | 
2025-11-02 00:14:12.858112 | TASK [bindep : Look for bindep.txt]
2025-11-02 00:14:13.257796 | controller | ok
2025-11-02 00:14:13.273148 | 
2025-11-02 00:14:13.273368 | TASK [bindep : Define bindep_file fact]
2025-11-02 00:14:13.301928 | controller | skipping: Conditional result was False
2025-11-02 00:14:13.316984 | 
2025-11-02 00:14:13.317164 | TASK [bindep : Look for other-requirements.txt]
2025-11-02 00:14:13.572262 | controller | ok
2025-11-02 00:14:13.585945 | 
2025-11-02 00:14:13.586184 | TASK [bindep : Define bindep_file fact]
2025-11-02 00:14:13.624476 | controller | skipping: Conditional result was False
2025-11-02 00:14:13.640585 | 
2025-11-02 00:14:13.640848 | TASK [bindep : Look for bindep fallback file]
2025-11-02 00:14:13.668980 | controller | skipping: Conditional result was False
2025-11-02 00:14:13.687084 | 
2025-11-02 00:14:13.687253 | TASK [bindep : Define bindep_file fact]
2025-11-02 00:14:13.714594 | controller | skipping: Conditional result was False
2025-11-02 00:14:13.724037 | 
2025-11-02 00:14:13.724131 | TASK [bindep : Include bindep tasks]
2025-11-02 00:14:13.749991 | controller | skipping: Conditional result was False
2025-11-02 00:14:13.760009 | 
2025-11-02 00:14:13.760108 | TASK [bindep : Include install tasks]
2025-11-02 00:14:13.787664 | controller | skipping: Conditional result was False
2025-11-02 00:14:13.799085 | 
2025-11-02 00:14:13.799248 | LOOP [bindep : Include package tasks]
2025-11-02 00:14:13.893358 | 
2025-11-02 00:14:13.893738 | TASK [Run test-setup role]
2025-11-02 00:14:13.934591 | controller | ok
2025-11-02 00:14:13.961941 | 
2025-11-02 00:14:13.962030 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-11-02 00:14:14.188286 | controller | ok
2025-11-02 00:14:14.206039 | 
2025-11-02 00:14:14.206285 | TASK [test-setup : Run tools/test-setup.sh]
2025-11-02 00:14:14.757453 | controller | skipping: Conditional result was False
2025-11-02 00:14:14.818845 | 
2025-11-02 00:14:14.819015 | PLAY RECAP
2025-11-02 00:14:14.819160 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-02 00:14:14.819200 | 
2025-11-02 00:14:14.991300 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-02 00:14:14.992284 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-02 00:14:15.605433 | 
2025-11-02 00:14:15.605604 | PLAY [controller]
2025-11-02 00:14:15.627414 | 
2025-11-02 00:14:15.627566 | TASK [Create the /root directory]
2025-11-02 00:14:16.060820 | controller | ok
2025-11-02 00:14:16.069265 | 
2025-11-02 00:14:16.069427 | TASK [Install glibc-langpack-en]
2025-11-02 00:14:20.182579 | controller | ok: Nothing to do
2025-11-02 00:14:20.192957 | 
2025-11-02 00:14:20.193163 | TASK [Ensure controller directory exists]
2025-11-02 00:14:20.446603 | controller | changed
2025-11-02 00:14:20.461858 | 
2025-11-02 00:14:20.462088 | TASK [Install container runtime]
2025-11-02 00:14:20.537151 | controller | ok
2025-11-02 00:14:20.594269 | 
2025-11-02 00:14:20.594434 | LOOP [ensure-podman : Find distribution installation]
2025-11-02 00:14:20.636226 | controller | ok: "/var/lib/zuul/builds/af18f3686d7e44558f5f891a789f2514/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-11-02 00:14:20.648465 | controller | included: /var/lib/zuul/builds/af18f3686d7e44558f5f891a789f2514/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-11-02 00:14:20.657445 | 
2025-11-02 00:14:20.657537 | TASK [ensure-podman : Install podman (RedHat)]
2025-11-02 00:15:26.541134 | controller | changed
2025-11-02 00:15:26.551505 | 
2025-11-02 00:15:26.551633 | TASK [ensure-podman : Fetch podman version]
2025-11-02 00:15:27.132341 | controller | Client:       Podman Engine
2025-11-02 00:15:27.132432 | controller | Version:      4.6.2
2025-11-02 00:15:27.132478 | controller | API Version:  4.6.2
2025-11-02 00:15:27.132520 | controller | Go Version:   go1.19.12
2025-11-02 00:15:27.132572 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-11-02 00:15:27.132614 | controller | OS/Arch:      linux/amd64
2025-11-02 00:15:27.599948 | controller | ok: Runtime: 0:00:00.206056
2025-11-02 00:15:27.611355 | 
2025-11-02 00:15:27.611579 | TASK [ensure-podman : Print podman version installed]
2025-11-02 00:15:27.649453 | Podman version: Client:       Podman Engine
2025-11-02 00:15:27.649697 | Version:      4.6.2
2025-11-02 00:15:27.649755 | API Version:  4.6.2
2025-11-02 00:15:27.649800 | Go Version:   go1.19.12
2025-11-02 00:15:27.649838 | Built:        Mon Aug 28 19:38:31 2023
2025-11-02 00:15:27.649879 | OS/Arch:      linux/amd64
2025-11-02 00:15:27.658358 | 
2025-11-02 00:15:27.658449 | TASK [ensure-podman : Validate podman engine]
2025-11-02 00:15:28.207542 | controller | skipping: Conditional result was False
2025-11-02 00:15:28.218633 | 
2025-11-02 00:15:28.218800 | TASK [ensure-podman : Set up docker compatability socket]
2025-11-02 00:15:28.237130 | controller | skipping: Conditional result was False
2025-11-02 00:15:28.256537 | 
2025-11-02 00:15:28.256727 | TASK [Ensure python3.8 is present]
2025-11-02 00:15:28.282574 | controller | skipping: Conditional result was False
2025-11-02 00:15:28.293256 | 
2025-11-02 00:15:28.293403 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-11-02 00:15:28.321079 | controller | ok
2025-11-02 00:15:28.349516 | 
2025-11-02 00:15:28.349652 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-11-02 00:15:29.795305 | controller | ok: Nothing to do
2025-11-02 00:15:29.809751 | 
2025-11-02 00:15:29.809898 | TASK [our-ensure-python : Also install python3-devel]
2025-11-02 00:15:39.041080 | controller | changed
2025-11-02 00:15:39.070028 | 
2025-11-02 00:15:39.070265 | TASK [Run ensure-virtualenv role]
2025-11-02 00:15:39.096996 | controller | ok
2025-11-02 00:15:39.131520 | 
2025-11-02 00:15:39.131646 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-11-02 00:15:39.418410 | controller | /usr/bin/virtualenv
2025-11-02 00:15:39.713251 | controller | ok: Runtime: 0:00:00.005127
2025-11-02 00:15:39.730448 | 
2025-11-02 00:15:39.730624 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-11-02 00:15:39.773861 | controller | skipping: Conditional result was False
2025-11-02 00:15:39.774250 | controller | ok: All items complete
2025-11-02 00:15:39.774289 | 
2025-11-02 00:15:39.803907 | 
2025-11-02 00:15:39.804143 | TASK [Find the full path of the Python interpreter]
2025-11-02 00:15:40.037258 | controller | /usr/bin/python3
2025-11-02 00:15:40.350918 | controller | ok
2025-11-02 00:15:40.366223 | 
2025-11-02 00:15:40.366419 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-11-02 00:15:41.239829 | controller | created virtual environment CPython3.11.0.final.0-64 in 526ms
2025-11-02 00:15:41.262687 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-11-02 00:15:41.263160 | 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-11-02 00:15:41.263363 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-11-02 00:15:41.263605 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-11-02 00:15:41.430071 | controller | changed
2025-11-02 00:15:41.451317 | 
2025-11-02 00:15:41.451491 | TASK [Set selinux package]
2025-11-02 00:15:41.493095 | controller | ok
2025-11-02 00:15:41.502872 | 
2025-11-02 00:15:41.502961 | TASK [Set selinux package (Fedora)]
2025-11-02 00:15:41.557704 | controller | ok
2025-11-02 00:15:41.566670 | 
2025-11-02 00:15:41.566882 | TASK [Install selinux into virtualenv]
2025-11-02 00:15:55.126247 | controller | Collecting selinux-please-lie-to-me
2025-11-02 00:16:07.388438 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-11-02 00:16:07.694677 | controller | Collecting setuptools<50.0.0
2025-11-02 00:16:07.720441 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-11-02 00:16:07.787287 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 13.0 MB/s eta 0:00:00
2025-11-02 00:16:07.868288 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-11-02 00:16:07.868502 | controller |   Attempting uninstall: setuptools
2025-11-02 00:16:07.870890 | controller |     Found existing installation: setuptools 62.6.0
2025-11-02 00:16:07.932374 | controller |     Uninstalling setuptools-62.6.0:
2025-11-02 00:16:07.940355 | controller |       Successfully uninstalled setuptools-62.6.0
2025-11-02 00:16:08.283691 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-11-02 00:16:19.748878 | controller |
2025-11-02 00:16:19.830352 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-11-02 00:16:19.830394 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-11-02 00:16:20.128581 | controller | ok: Runtime: 0:00:38.046453
2025-11-02 00:16:20.144974 | 
2025-11-02 00:16:20.145232 | TASK [Install pytest-forked into virtualenv]
2025-11-02 00:16:32.007033 | controller | Collecting pytest-forked
2025-11-02 00:16:42.191747 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-11-02 00:16:42.239098 | controller | Collecting py
2025-11-02 00:16:42.244794 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-11-02 00:16:42.263228 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.9 MB/s eta 0:00:00
2025-11-02 00:16:42.388482 | controller | Collecting pytest>=3.10
2025-11-02 00:16:42.393565 | controller |   Downloading pytest-8.4.2-py3-none-any.whl (365 kB)
2025-11-02 00:16:42.411805 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 24.2 MB/s eta 0:00:00
2025-11-02 00:16:42.452608 | controller | Collecting iniconfig>=1
2025-11-02 00:16:42.456061 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-11-02 00:16:42.496770 | controller | Collecting packaging>=20
2025-11-02 00:16:42.500454 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-11-02 00:16:42.507635 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 11.4 MB/s eta 0:00:00
2025-11-02 00:16:42.541367 | controller | Collecting pluggy<2,>=1.5
2025-11-02 00:16:42.544791 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-11-02 00:16:42.590909 | controller | Collecting pygments>=2.7.2
2025-11-02 00:16:42.594351 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-11-02 00:16:42.642121 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 27.8 MB/s eta 0:00:00
2025-11-02 00:16:42.707850 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-11-02 00:16:43.743876 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-8.4.2 pytest-forked-1.6.0
2025-11-02 00:16:43.752550 | controller |
2025-11-02 00:16:43.825034 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-11-02 00:16:43.825287 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-11-02 00:16:44.212984 | controller | ok: Runtime: 0:00:23.443070
2025-11-02 00:16:44.225510 | 
2025-11-02 00:16:44.225705 | TASK [Update pip]
2025-11-02 00:16:44.752811 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-11-02 00:16:54.574311 | controller | Collecting pip
2025-11-02 00:17:06.766015 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-11-02 00:17:06.844241 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 24.4 MB/s eta 0:00:00
2025-11-02 00:17:06.910253 | controller | Installing collected packages: pip
2025-11-02 00:17:06.910401 | controller |   Attempting uninstall: pip
2025-11-02 00:17:06.912574 | controller |     Found existing installation: pip 22.2.2
2025-11-02 00:17:07.053033 | controller |     Uninstalling pip-22.2.2:
2025-11-02 00:17:07.068066 | controller |       Successfully uninstalled pip-22.2.2
2025-11-02 00:17:07.883999 | controller | Successfully installed pip-25.3
2025-11-02 00:17:08.288815 | controller | ok: Runtime: 0:00:23.494245
2025-11-02 00:17:08.296073 | 
2025-11-02 00:17:08.296187 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-11-02 00:17:08.533349 | controller | changed
2025-11-02 00:17:08.542074 | 
2025-11-02 00:17:08.542183 | TASK [Install ansible into virtualenv]
2025-11-02 00:17:09.170372 | controller | Processing ./src/github.com/ansible/ansible
2025-11-02 00:17:09.173561 | controller |   Installing build dependencies: started
2025-11-02 00:17:31.695243 | controller |   Installing build dependencies: finished with status 'done'
2025-11-02 00:17:31.695840 | controller |   Getting requirements to build wheel: started
2025-11-02 00:17:32.438361 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-11-02 00:17:32.439220 | controller |   Preparing metadata (pyproject.toml): started
2025-11-02 00:17:32.917641 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-11-02 00:17:32.923336 | 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-11-02 00:17:32.927103 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-11-02 00:17:33.145605 | controller | ERROR
2025-11-02 00:17:33.145876 | controller | {
2025-11-02 00:17:33.145927 | controller |   "delta": "0:00:24.112379",
2025-11-02 00:17:33.145956 | controller |   "end": "2025-11-02 00:17:32.985775",
2025-11-02 00:17:33.145981 | controller |   "msg": "non-zero return code",
2025-11-02 00:17:33.146016 | controller |   "rc": 1,
2025-11-02 00:17:33.146039 | controller |   "start": "2025-11-02 00:17:08.873396"
2025-11-02 00:17:33.146061 | controller | }
failure
2025-11-02 00:17:33.148704 | 
2025-11-02 00:17:33.148793 | PLAY RECAP
2025-11-02 00:17:33.148871 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-11-02 00:17:33.148908 | 
2025-11-02 00:17:33.330996 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-02 00:17:33.333110 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-02 00:17:33.960837 | 
2025-11-02 00:17:33.961017 | PLAY [all]
2025-11-02 00:17:33.992090 | 
2025-11-02 00:17:33.992288 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-11-02 00:17:34.270418 | controller | changed: non-zero return code
2025-11-02 00:17:34.280363 | 
2025-11-02 00:17:34.280551 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-11-02 00:17:34.311607 | controller | skipping: Conditional result was False
2025-11-02 00:17:34.321772 | 
2025-11-02 00:17:34.321905 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-11-02 00:17:34.365259 | 
2025-11-02 00:17:34.365500 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-11-02 00:17:34.411345 | 
2025-11-02 00:17:34.411549 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-11-02 00:17:34.437701 | controller | skipping: Conditional result was False
2025-11-02 00:17:34.449583 | 
2025-11-02 00:17:34.449744 | LOOP [fetch-subunit-output : Generate subunit file]
2025-11-02 00:17:34.485447 | 
2025-11-02 00:17:34.485752 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-11-02 00:17:34.513767 | controller | skipping: Conditional result was False
2025-11-02 00:17:34.523427 | 
2025-11-02 00:17:34.523541 | TASK [fetch-subunit-output : Remove the temporary file]
2025-11-02 00:17:34.549787 | controller | skipping: Conditional result was False
2025-11-02 00:17:34.559145 | 
2025-11-02 00:17:34.559246 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-11-02 00:17:34.585512 | controller | skipping: Conditional result was False
2025-11-02 00:17:34.626347 | 
2025-11-02 00:17:34.626486 | PLAY RECAP
2025-11-02 00:17:34.626555 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-02 00:17:34.626592 | 
2025-11-02 00:17:34.765795 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-02 00:17:34.766885 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-11-02 00:17:35.451235 | 
2025-11-02 00:17:35.451406 | PLAY [all:!appliance*]
2025-11-02 00:17:35.477150 | 
2025-11-02 00:17:35.477300 | TASK [unregister the node]
2025-11-02 00:17:36.012633 | controller | skipping: Conditional result was False
2025-11-02 00:17:36.024561 | 
2025-11-02 00:17:36.024723 | TASK [include_role : fetch-output]
2025-11-02 00:17:36.079318 | controller | ok
2025-11-02 00:17:36.121342 | 
2025-11-02 00:17:36.121599 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-02 00:17:36.200971 | controller | skipping: Conditional result was False
2025-11-02 00:17:36.211109 | 
2025-11-02 00:17:36.211225 | TASK [fetch-output : Set log path for single node]
2025-11-02 00:17:36.283373 | controller | ok
2025-11-02 00:17:36.296542 | 
2025-11-02 00:17:36.296751 | LOOP [fetch-output : Ensure local output dirs]
2025-11-02 00:17:36.816944 | controller -> localhost | ok: "/var/lib/zuul/builds/af18f3686d7e44558f5f891a789f2514/work/logs"
2025-11-02 00:17:37.065905 | controller -> localhost | changed: "/var/lib/zuul/builds/af18f3686d7e44558f5f891a789f2514/work/artifacts"
2025-11-02 00:17:37.371355 | controller -> localhost | changed: "/var/lib/zuul/builds/af18f3686d7e44558f5f891a789f2514/work/docs"
2025-11-02 00:17:37.389264 | 
2025-11-02 00:17:37.389414 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-02 00:17:38.108532 | controller | changed:
2025-11-02 00:17:38.108841 | controller | .d..t...... ./
2025-11-02 00:17:38.108876 | controller | cd+++++++++ controller/
2025-11-02 00:17:38.108921 | controller | changed: All items complete
2025-11-02 00:17:38.108950 | 
2025-11-02 00:17:38.693147 | controller | changed: .d..t...... ./
2025-11-02 00:17:39.190810 | controller | changed: .d..t...... ./
2025-11-02 00:17:39.209736 | 
2025-11-02 00:17:39.209894 | TASK [include_role : fetch-output-openshift]
2025-11-02 00:17:39.236053 | controller | skipping: Conditional result was False
2025-11-02 00:17:39.244108 | 
2025-11-02 00:17:39.244240 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-11-02 00:17:39.284610 | controller | skipping: Conditional result was False
2025-11-02 00:17:39.298355 | controller | skipping: Conditional result was False
2025-11-02 00:17:39.342912 | 
2025-11-02 00:17:39.343102 | PLAY [localhost]
2025-11-02 00:17:39.355847 | 
2025-11-02 00:17:39.355923 | TASK [Run Zuul manifest role]
2025-11-02 00:17:39.375340 | localhost | ok
2025-11-02 00:17:39.388052 | 
2025-11-02 00:17:39.388129 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-11-02 00:17:39.817331 | localhost | changed
2025-11-02 00:17:39.822338 | 
2025-11-02 00:17:39.822415 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-11-02 00:17:39.852099 | localhost | ok
2025-11-02 00:17:39.860247 | 
2025-11-02 00:17:39.860316 | TASK [Set zuul-log-path fact]
2025-11-02 00:17:39.879494 | localhost | ok
2025-11-02 00:17:39.894953 | 
2025-11-02 00:17:39.895092 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-02 00:17:39.924543 | localhost | ok
2025-11-02 00:17:39.933053 | 
2025-11-02 00:17:39.933130 | LOOP [Run upload-logs-swift role]
2025-11-02 00:17:39.957805 | localhost | Output suppressed because no_log was given
2025-11-02 00:17:39.984020 | 
2025-11-02 00:17:39.984163 | TASK [Set zuul-log-path fact]
2025-11-02 00:17:40.008737 | localhost | skipping: Conditional result was False
2025-11-02 00:17:40.015840 | 
2025-11-02 00:17:40.015978 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-11-02 00:17:40.465512 | localhost -> localhost | ok: Runtime: 0:00:00.005544
2025-11-02 00:17:40.476608 | 
2025-11-02 00:17:40.476829 | TASK [upload-logs-swift : Upload logs to swift]