2026-01-31 00:06:33.762642 | Job console starting...
2026-01-31 00:06:33.771801 | Updating repositories
2026-01-31 00:06:36.969222 | Preparing job workspace
2026-01-31 00:06:40.865846 | Running Ansible setup...
2026-01-31 00:06:47.469767 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-31 00:06:48.103049 | 
2026-01-31 00:06:48.103186 | PLAY [localhost]
2026-01-31 00:06:48.112408 | 
2026-01-31 00:06:48.112523 | TASK [Gathering Facts]
2026-01-31 00:06:49.088255 | localhost | ok
2026-01-31 00:06:49.114075 | 
2026-01-31 00:06:49.114354 | TASK [Setup log path fact]
2026-01-31 00:06:49.137252 | localhost | ok
2026-01-31 00:06:49.164218 | 
2026-01-31 00:06:49.164517 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-31 00:06:49.195713 | localhost | ok
2026-01-31 00:06:49.206265 | 
2026-01-31 00:06:49.206385 | TASK [emit-job-header : Print job information]
2026-01-31 00:06:49.245567 | # Job Information
2026-01-31 00:06:49.245721 | Ansible Version: 2.15.12
2026-01-31 00:06:49.245753 | Job: ansible-test-sanity-docker-milestone
2026-01-31 00:06:49.245776 | Pipeline: periodic
2026-01-31 00:06:49.245796 | Executor: ze01.softwarefactory-project.io
2026-01-31 00:06:49.245813 | Triggered by: https://github.com/ansible-collections/ansible.network
2026-01-31 00:06:49.245835 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/9e3/ansible/9e35bee9e60e40fda1886d661b138e46/
2026-01-31 00:06:49.245855 | Event ID: d2ac577d17c84cbe949600e8ba7c97bc
2026-01-31 00:06:49.249850 | 
2026-01-31 00:06:49.249919 | LOOP [emit-job-header : Print node information]
2026-01-31 00:06:49.351350 | localhost | ok:
2026-01-31 00:06:49.351510 | localhost | # Node Information
2026-01-31 00:06:49.351538 | localhost | Inventory Hostname: controller
2026-01-31 00:06:49.351558 | localhost | Hostname: np0005603402
2026-01-31 00:06:49.351577 | localhost | Username: zuul
2026-01-31 00:06:49.351598 | localhost | Distro: Fedora 37
2026-01-31 00:06:49.351617 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2026-01-31 00:06:49.351635 | localhost | Region: ca-ymq-1
2026-01-31 00:06:49.351653 | localhost | Label: ansible-fedora-37-1vcpu
2026-01-31 00:06:49.351670 | localhost | Product Name: OpenStack Nova
2026-01-31 00:06:49.351686 | localhost | Interface IP: 162.253.55.70
2026-01-31 00:06:49.363820 | 
2026-01-31 00:06:49.363994 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-31 00:06:49.836928 | localhost -> localhost | changed
2026-01-31 00:06:49.844949 | 
2026-01-31 00:06:49.845136 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-31 00:06:50.797457 | localhost -> localhost | changed
2026-01-31 00:06:50.829836 | 
2026-01-31 00:06:50.829948 | PLAY [all:!appliance*]
2026-01-31 00:06:50.849447 | 
2026-01-31 00:06:50.849567 | TASK [include_role : start-zuul-console]
2026-01-31 00:06:50.869088 | controller | ok
2026-01-31 00:06:50.888411 | 
2026-01-31 00:06:50.888519 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-31 00:06:51.260591 | controller | ok
2026-01-31 00:06:51.288741 | 
2026-01-31 00:06:51.288875 | TASK [use-our-mirror : Retrieve the IP address]
2026-01-31 00:06:52.050586 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2026-01-31 00:06:52.065677 | 
2026-01-31 00:06:52.065812 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2026-01-31 00:06:52.625721 | controller | skipping: Conditional result was False
2026-01-31 00:06:52.641855 | 
2026-01-31 00:06:52.642105 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2026-01-31 00:06:52.659604 | controller | skipping: Conditional result was False
2026-01-31 00:06:52.678775 | 
2026-01-31 00:06:52.679450 | TASK [use-our-mirror : Create the podman configuration directory]
2026-01-31 00:06:52.695463 | controller | skipping: Conditional result was False
2026-01-31 00:06:52.702960 | 
2026-01-31 00:06:52.703091 | TASK [use-our-mirror : Copy the podman configuration]
2026-01-31 00:06:52.718777 | controller | skipping: Conditional result was False
2026-01-31 00:06:52.726224 | 
2026-01-31 00:06:52.726317 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2026-01-31 00:06:52.741171 | controller | skipping: Conditional result was False
2026-01-31 00:06:52.748418 | 
2026-01-31 00:06:52.748507 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2026-01-31 00:06:52.763531 | controller | skipping: Conditional result was False
2026-01-31 00:06:52.778894 | 
2026-01-31 00:06:52.779010 | TASK [Disable Fedora Modular]
2026-01-31 00:06:53.045592 | controller | changed
2026-01-31 00:06:53.052112 | 
2026-01-31 00:06:53.052212 | TASK [Enable EPEL]
2026-01-31 00:06:53.083584 | controller | skipping: Conditional result was False
2026-01-31 00:06:53.092999 | 
2026-01-31 00:06:53.093172 | TASK [Register the RHEL node]
2026-01-31 00:06:53.652552 | 
2026-01-31 00:06:53.652746 | TASK [Show the subscription-manager status]
2026-01-31 00:06:54.292129 | controller | skipping: Conditional result was False
2026-01-31 00:06:54.298552 | 
2026-01-31 00:06:54.298619 | TASK [Enable EPEL on RHEL]
2026-01-31 00:06:54.839433 | controller | skipping: Conditional result was False
2026-01-31 00:06:54.846922 | 
2026-01-31 00:06:54.847083 | TASK [Install git and tox]
2026-01-31 00:08:15.189840 | controller | changed
2026-01-31 00:08:15.205128 | 
2026-01-31 00:08:15.205297 | TASK [include_role : prepare-workspace]
2026-01-31 00:08:15.244459 | controller | ok
2026-01-31 00:08:15.284279 | 
2026-01-31 00:08:15.284424 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-31 00:08:15.508251 | controller | ok
2026-01-31 00:08:15.515399 | 
2026-01-31 00:08:15.515496 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-31 00:08:30.138501 | controller | Output suppressed because no_log was given
2026-01-31 00:08:30.178942 | 
2026-01-31 00:08:30.179087 | TASK [include_role : prepare-workspace-openshift]
2026-01-31 00:08:30.203501 | controller | skipping: Conditional result was False
2026-01-31 00:08:30.225628 | 
2026-01-31 00:08:30.225711 | PLAY [all:!appliance]
2026-01-31 00:08:30.241759 | 
2026-01-31 00:08:30.241836 | TASK [Run add-build-sshkey role (RSA)]
2026-01-31 00:08:30.270986 | controller | ok
2026-01-31 00:08:30.286502 | 
2026-01-31 00:08:30.286595 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-31 00:08:30.514592 | controller -> localhost | ok
2026-01-31 00:08:30.521365 | 
2026-01-31 00:08:30.521442 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-31 00:08:30.562727 | controller | ok
2026-01-31 00:08:30.587972 | controller | included: /var/lib/zuul/builds/9e35bee9e60e40fda1886d661b138e46/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-31 00:08:30.597807 | 
2026-01-31 00:08:30.597915 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-31 00:08:31.086251 | controller -> localhost | Generating public/private rsa key pair.
2026-01-31 00:08:31.086453 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/9e35bee9e60e40fda1886d661b138e46/work/9e35bee9e60e40fda1886d661b138e46_id_rsa.
2026-01-31 00:08:31.086491 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/9e35bee9e60e40fda1886d661b138e46/work/9e35bee9e60e40fda1886d661b138e46_id_rsa.pub.
2026-01-31 00:08:31.086528 | controller -> localhost | The key fingerprint is:
2026-01-31 00:08:31.086549 | controller -> localhost | SHA256:Fg1AfNo/1A+e5BEItEleCnRS9DYH8ExUUTvlMZnWDxs zuul-build-sshkey
2026-01-31 00:08:31.086568 | controller -> localhost | The key's randomart image is:
2026-01-31 00:08:31.086586 | controller -> localhost | +---[RSA 2048]----+
2026-01-31 00:08:31.086604 | controller -> localhost | |     +*=X+=ooo.o=|
2026-01-31 00:08:31.086624 | controller -> localhost | |      .*.%... EB+|
2026-01-31 00:08:31.086643 | controller -> localhost | |       +* B...++o|
2026-01-31 00:08:31.086660 | controller -> localhost | |      . .o.o= ...|
2026-01-31 00:08:31.086678 | controller -> localhost | |        So + =   |
2026-01-31 00:08:31.086707 | controller -> localhost | |       .  o + .  |
2026-01-31 00:08:31.086733 | controller -> localhost | |           .     |
2026-01-31 00:08:31.086752 | controller -> localhost | |                 |
2026-01-31 00:08:31.086771 | controller -> localhost | |                 |
2026-01-31 00:08:31.086794 | controller -> localhost | +----[SHA256]-----+
2026-01-31 00:08:31.086839 | controller -> localhost | ok: Runtime: 0:00:00.085455
2026-01-31 00:08:31.094967 | 
2026-01-31 00:08:31.095110 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-31 00:08:31.120470 | controller | ok
2026-01-31 00:08:31.136431 | controller | included: /var/lib/zuul/builds/9e35bee9e60e40fda1886d661b138e46/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-31 00:08:31.149286 | 
2026-01-31 00:08:31.149412 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-31 00:08:31.164240 | controller | skipping: Conditional result was False
2026-01-31 00:08:31.173604 | 
2026-01-31 00:08:31.173727 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-31 00:08:31.645096 | controller | changed
2026-01-31 00:08:31.652852 | 
2026-01-31 00:08:31.652982 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-31 00:08:31.874457 | controller | ok
2026-01-31 00:08:31.885286 | 
2026-01-31 00:08:31.885417 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-31 00:08:32.459879 | controller | changed
2026-01-31 00:08:32.466712 | 
2026-01-31 00:08:32.466796 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-31 00:08:33.076087 | controller | changed
2026-01-31 00:08:33.086088 | 
2026-01-31 00:08:33.086285 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-31 00:08:33.122577 | controller | skipping: Conditional result was False
2026-01-31 00:08:33.131189 | 
2026-01-31 00:08:33.131314 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-31 00:08:33.557106 | controller -> localhost | changed
2026-01-31 00:08:33.574438 | 
2026-01-31 00:08:33.574684 | TASK [add-build-sshkey : Add back temp key]
2026-01-31 00:08:33.889545 | controller -> localhost | Identity added: /var/lib/zuul/builds/9e35bee9e60e40fda1886d661b138e46/work/9e35bee9e60e40fda1886d661b138e46_id_rsa (zuul-build-sshkey)
2026-01-31 00:08:33.889737 | controller -> localhost | ok: Runtime: 0:00:00.010866
2026-01-31 00:08:33.898901 | 
2026-01-31 00:08:33.898994 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-31 00:08:34.259011 | controller | ok
2026-01-31 00:08:34.268272 | 
2026-01-31 00:08:34.268437 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-31 00:08:34.315043 | controller | skipping: Conditional result was False
2026-01-31 00:08:34.346478 | 
2026-01-31 00:08:34.346661 | TASK [Run add-build-sshkey role (ECDSA)]
2026-01-31 00:08:34.381159 | controller | ok
2026-01-31 00:08:34.410330 | 
2026-01-31 00:08:34.410517 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-31 00:08:34.633758 | controller -> localhost | ok
2026-01-31 00:08:34.641603 | 
2026-01-31 00:08:34.641688 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-31 00:08:34.665212 | controller | ok
2026-01-31 00:08:34.678128 | controller | included: /var/lib/zuul/builds/9e35bee9e60e40fda1886d661b138e46/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-31 00:08:34.686985 | 
2026-01-31 00:08:34.687119 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-31 00:08:34.967813 | controller -> localhost | Generating public/private ecdsa key pair.
2026-01-31 00:08:34.968007 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/9e35bee9e60e40fda1886d661b138e46/work/9e35bee9e60e40fda1886d661b138e46_id_ecdsa.
2026-01-31 00:08:34.968050 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/9e35bee9e60e40fda1886d661b138e46/work/9e35bee9e60e40fda1886d661b138e46_id_ecdsa.pub.
2026-01-31 00:08:34.968086 | controller -> localhost | The key fingerprint is:
2026-01-31 00:08:34.968107 | controller -> localhost | SHA256:iWU7ht0EfTDddqf2mGZrTFvtlWFJOUJT79ws9qqBofA zuul-build-sshkey
2026-01-31 00:08:34.968125 | controller -> localhost | The key's randomart image is:
2026-01-31 00:08:34.968161 | controller -> localhost | +---[ECDSA 521]---+
2026-01-31 00:08:34.968181 | controller -> localhost | |        ..oo.+...|
2026-01-31 00:08:34.968199 | controller -> localhost | |         ...o.+++|
2026-01-31 00:08:34.968220 | controller -> localhost | |        o .. .oo=|
2026-01-31 00:08:34.968238 | controller -> localhost | |       * =    oB.|
2026-01-31 00:08:34.968255 | controller -> localhost | |      + S o  .++O|
2026-01-31 00:08:34.968272 | controller -> localhost | |       + o o .*+=|
2026-01-31 00:08:34.968289 | controller -> localhost | |        E . .= =o|
2026-01-31 00:08:34.968305 | controller -> localhost | |             .=..|
2026-01-31 00:08:34.968322 | controller -> localhost | |            .o.  |
2026-01-31 00:08:34.968339 | controller -> localhost | +----[SHA256]-----+
2026-01-31 00:08:34.968390 | controller -> localhost | ok: Runtime: 0:00:00.018693
2026-01-31 00:08:34.976524 | 
2026-01-31 00:08:34.976614 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-31 00:08:35.008694 | controller | ok
2026-01-31 00:08:35.017693 | controller | included: /var/lib/zuul/builds/9e35bee9e60e40fda1886d661b138e46/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-31 00:08:35.031547 | 
2026-01-31 00:08:35.031696 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-31 00:08:35.069934 | controller | skipping: Conditional result was False
2026-01-31 00:08:35.076998 | 
2026-01-31 00:08:35.077191 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-31 00:13:40.099156 | controller | ok
2026-01-31 00:13:40.105785 | 
2026-01-31 00:13:40.105887 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-31 00:13:40.334996 | controller | ok
2026-01-31 00:13:40.344422 | 
2026-01-31 00:13:40.344547 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-31 00:13:41.005398 | controller | changed
2026-01-31 00:13:41.013802 | 
2026-01-31 00:13:41.013926 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-31 00:13:41.698553 | controller | changed
2026-01-31 00:13:41.723189 | 
2026-01-31 00:13:41.723322 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-31 00:13:41.748875 | controller | skipping: Conditional result was False
2026-01-31 00:13:41.758476 | 
2026-01-31 00:13:41.758590 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-31 00:13:42.063302 | controller -> localhost | changed
2026-01-31 00:13:42.075293 | 
2026-01-31 00:13:42.075399 | TASK [add-build-sshkey : Add back temp key]
2026-01-31 00:13:42.401414 | controller -> localhost | Identity added: /var/lib/zuul/builds/9e35bee9e60e40fda1886d661b138e46/work/9e35bee9e60e40fda1886d661b138e46_id_ecdsa (zuul-build-sshkey)
2026-01-31 00:13:42.401620 | controller -> localhost | ok: Runtime: 0:00:00.008536
2026-01-31 00:13:42.409000 | 
2026-01-31 00:13:42.409122 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-31 00:13:42.604889 | controller | ok
2026-01-31 00:13:42.617723 | 
2026-01-31 00:13:42.617836 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-31 00:13:42.643990 | controller | skipping: Conditional result was False
2026-01-31 00:13:42.665879 | 
2026-01-31 00:13:42.666006 | TASK [include_role : remove-zuul-sshkey]
2026-01-31 00:13:42.679594 | controller | skipping: Conditional result was False
2026-01-31 00:13:42.691451 | 
2026-01-31 00:13:42.691621 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-31 00:13:42.920192 | controller | ok: "logs"
2026-01-31 00:13:42.920492 | controller | ok: All items complete
2026-01-31 00:13:42.920538 | 
2026-01-31 00:13:43.120128 | controller | ok: "artifacts"
2026-01-31 00:13:43.305817 | controller | ok: "docs"
2026-01-31 00:13:43.322194 | 
2026-01-31 00:13:43.322297 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-31 00:13:43.551372 | controller | changed: "logs"
2026-01-31 00:13:43.747320 | controller | changed: "artifacts"
2026-01-31 00:13:43.939435 | controller | changed: "docs"
2026-01-31 00:13:43.976011 | 
2026-01-31 00:13:43.976213 | PLAY RECAP
2026-01-31 00:13:43.976264 | controller | ok: 30 changed: 15 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2026-01-31 00:13:43.976293 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-31 00:13:43.976400 | 
2026-01-31 00:13:44.111619 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2026-01-31 00:13:44.112564 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-31 00:13:44.755654 | 
2026-01-31 00:13:44.755827 | PLAY [all]
2026-01-31 00:13:44.788471 | 
2026-01-31 00:13:44.788638 | TASK [Install binary dependencies]
2026-01-31 00:13:44.850263 | controller | ok
2026-01-31 00:13:44.873691 | 
2026-01-31 00:13:44.873814 | TASK [bindep : Include find tasks]
2026-01-31 00:13:44.903820 | controller | ok
2026-01-31 00:13:44.912633 | controller | included: /var/lib/zuul/builds/9e35bee9e60e40fda1886d661b138e46/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2026-01-31 00:13:44.919483 | 
2026-01-31 00:13:44.919554 | TASK [bindep : Look for bindep.txt]
2026-01-31 00:13:45.502857 | controller | ok
2026-01-31 00:13:45.518970 | 
2026-01-31 00:13:45.519218 | TASK [bindep : Define bindep_file fact]
2026-01-31 00:13:45.548251 | controller | skipping: Conditional result was False
2026-01-31 00:13:45.562807 | 
2026-01-31 00:13:45.563282 | TASK [bindep : Look for other-requirements.txt]
2026-01-31 00:13:45.800484 | controller | ok
2026-01-31 00:13:45.811770 | 
2026-01-31 00:13:45.811916 | TASK [bindep : Define bindep_file fact]
2026-01-31 00:13:45.848270 | controller | skipping: Conditional result was False
2026-01-31 00:13:45.858892 | 
2026-01-31 00:13:45.859093 | TASK [bindep : Look for bindep fallback file]
2026-01-31 00:13:45.885704 | controller | skipping: Conditional result was False
2026-01-31 00:13:45.893536 | 
2026-01-31 00:13:45.893668 | TASK [bindep : Define bindep_file fact]
2026-01-31 00:13:45.918302 | controller | skipping: Conditional result was False
2026-01-31 00:13:45.926182 | 
2026-01-31 00:13:45.926280 | TASK [bindep : Include bindep tasks]
2026-01-31 00:13:45.950412 | controller | skipping: Conditional result was False
2026-01-31 00:13:45.960325 | 
2026-01-31 00:13:45.960466 | TASK [bindep : Include install tasks]
2026-01-31 00:13:45.985525 | controller | skipping: Conditional result was False
2026-01-31 00:13:45.993361 | 
2026-01-31 00:13:45.993499 | LOOP [bindep : Include package tasks]
2026-01-31 00:13:46.051304 | 
2026-01-31 00:13:46.051470 | TASK [Run test-setup role]
2026-01-31 00:13:46.073139 | controller | ok
2026-01-31 00:13:46.093975 | 
2026-01-31 00:13:46.094111 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2026-01-31 00:13:46.314810 | controller | ok
2026-01-31 00:13:46.332190 | 
2026-01-31 00:13:46.332334 | TASK [test-setup : Run tools/test-setup.sh]
2026-01-31 00:13:46.874745 | controller | skipping: Conditional result was False
2026-01-31 00:13:46.914572 | 
2026-01-31 00:13:46.914678 | PLAY RECAP
2026-01-31 00:13:46.914721 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-31 00:13:46.914744 | 
2026-01-31 00:13:47.020079 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2026-01-31 00:13:47.021125 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-31 00:13:47.668462 | 
2026-01-31 00:13:47.668593 | PLAY [controller]
2026-01-31 00:13:47.690763 | 
2026-01-31 00:13:47.690885 | TASK [Create the /root directory]
2026-01-31 00:13:48.293298 | controller | ok
2026-01-31 00:13:48.305242 | 
2026-01-31 00:13:48.305348 | TASK [Install glibc-langpack-en]
2026-01-31 00:13:52.267749 | controller | ok: Nothing to do
2026-01-31 00:13:52.274530 | 
2026-01-31 00:13:52.274615 | TASK [Ensure controller directory exists]
2026-01-31 00:13:52.494035 | controller | changed
2026-01-31 00:13:52.522819 | 
2026-01-31 00:13:52.522923 | TASK [Install container runtime]
2026-01-31 00:13:52.587475 | controller | ok
2026-01-31 00:13:52.652254 | 
2026-01-31 00:13:52.652379 | LOOP [ensure-podman : Find distribution installation]
2026-01-31 00:13:52.677833 | controller | ok: "/var/lib/zuul/builds/9e35bee9e60e40fda1886d661b138e46/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2026-01-31 00:13:52.695317 | controller | included: /var/lib/zuul/builds/9e35bee9e60e40fda1886d661b138e46/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2026-01-31 00:13:52.702187 | 
2026-01-31 00:13:52.702295 | TASK [ensure-podman : Install podman (RedHat)]
2026-01-31 00:14:58.247421 | controller | changed
2026-01-31 00:14:58.257699 | 
2026-01-31 00:14:58.257834 | TASK [ensure-podman : Fetch podman version]
2026-01-31 00:14:58.789301 | controller | Client:       Podman Engine
2026-01-31 00:14:58.819995 | controller | Version:      4.6.2
2026-01-31 00:14:58.820020 | controller | API Version:  4.6.2
2026-01-31 00:14:58.820028 | controller | Go Version:   go1.19.12
2026-01-31 00:14:58.820046 | controller | Built:        Mon Aug 28 19:38:31 2023
2026-01-31 00:14:58.820054 | controller | OS/Arch:      linux/amd64
2026-01-31 00:14:59.296975 | controller | ok: Runtime: 0:00:00.195781
2026-01-31 00:14:59.310728 | 
2026-01-31 00:14:59.310890 | TASK [ensure-podman : Print podman version installed]
2026-01-31 00:14:59.347934 | Podman version: Client:       Podman Engine
2026-01-31 00:14:59.348187 | Version:      4.6.2
2026-01-31 00:14:59.348235 | API Version:  4.6.2
2026-01-31 00:14:59.348271 | Go Version:   go1.19.12
2026-01-31 00:14:59.348304 | Built:        Mon Aug 28 19:38:31 2023
2026-01-31 00:14:59.348338 | OS/Arch:      linux/amd64
2026-01-31 00:14:59.357870 | 
2026-01-31 00:14:59.358055 | TASK [ensure-podman : Validate podman engine]
2026-01-31 00:14:59.902076 | controller | skipping: Conditional result was False
2026-01-31 00:14:59.911535 | 
2026-01-31 00:14:59.911640 | TASK [ensure-podman : Set up docker compatability socket]
2026-01-31 00:14:59.943229 | controller | skipping: Conditional result was False
2026-01-31 00:14:59.955234 | 
2026-01-31 00:14:59.955338 | TASK [Ensure python3.8 is present]
2026-01-31 00:14:59.979741 | controller | skipping: Conditional result was False
2026-01-31 00:14:59.986427 | 
2026-01-31 00:14:59.986498 | TASK [Run our-ensure-python role (Fedora only for now)]
2026-01-31 00:15:00.007434 | controller | ok
2026-01-31 00:15:00.028480 | 
2026-01-31 00:15:00.028603 | TASK [our-ensure-python : Install the right Python version (rpm)]
2026-01-31 00:15:01.579552 | controller | ok: Nothing to do
2026-01-31 00:15:01.586163 | 
2026-01-31 00:15:01.586276 | TASK [our-ensure-python : Also install python3-devel]
2026-01-31 00:15:10.909303 | controller | changed
2026-01-31 00:15:10.921779 | 
2026-01-31 00:15:10.922033 | TASK [Run ensure-virtualenv role]
2026-01-31 00:15:10.941466 | controller | ok
2026-01-31 00:15:10.979261 | 
2026-01-31 00:15:10.979408 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2026-01-31 00:15:11.291085 | controller | /usr/bin/virtualenv
2026-01-31 00:15:11.570827 | controller | ok: Runtime: 0:00:00.002481
2026-01-31 00:15:11.578056 | 
2026-01-31 00:15:11.578178 | LOOP [ensure-virtualenv : Install virtualenv package]
2026-01-31 00:15:11.633920 | controller | skipping: Conditional result was False
2026-01-31 00:15:11.634191 | controller | ok: All items complete
2026-01-31 00:15:11.634220 | 
2026-01-31 00:15:11.650687 | 
2026-01-31 00:15:11.650814 | TASK [Find the full path of the Python interpreter]
2026-01-31 00:15:11.928645 | controller | /usr/bin/python3
2026-01-31 00:15:12.251976 | controller | ok
2026-01-31 00:15:12.258076 | 
2026-01-31 00:15:12.258188 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2026-01-31 00:15:13.172395 | controller | created virtual environment CPython3.11.0.final.0-64 in 453ms
2026-01-31 00:15:13.191039 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2026-01-31 00:15:13.191057 | 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-01-31 00:15:13.191074 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2026-01-31 00:15:13.191089 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2026-01-31 00:15:13.330107 | controller | changed
2026-01-31 00:15:13.336416 | 
2026-01-31 00:15:13.336490 | TASK [Set selinux package]
2026-01-31 00:15:13.396463 | controller | ok
2026-01-31 00:15:13.401704 | 
2026-01-31 00:15:13.401764 | TASK [Set selinux package (Fedora)]
2026-01-31 00:15:13.464740 | controller | ok
2026-01-31 00:15:13.473585 | 
2026-01-31 00:15:13.473698 | TASK [Install selinux into virtualenv]
2026-01-31 00:15:14.790618 | controller | Collecting selinux-please-lie-to-me
2026-01-31 00:15:14.826541 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2026-01-31 00:15:15.125641 | controller | Collecting setuptools<50.0.0
2026-01-31 00:15:15.131254 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2026-01-31 00:15:15.165997 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 25.9 MB/s eta 0:00:00
2026-01-31 00:15:15.245520 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2026-01-31 00:15:15.245737 | controller |   Attempting uninstall: setuptools
2026-01-31 00:15:15.248170 | controller |     Found existing installation: setuptools 62.6.0
2026-01-31 00:15:15.308024 | controller |     Uninstalling setuptools-62.6.0:
2026-01-31 00:15:15.315925 | controller |       Successfully uninstalled setuptools-62.6.0
2026-01-31 00:15:15.681825 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2026-01-31 00:15:15.799929 | controller |
2026-01-31 00:15:15.884249 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-31 00:15:15.884294 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-31 00:15:16.041856 | controller | ok: Runtime: 0:00:02.134253
2026-01-31 00:15:16.048630 | 
2026-01-31 00:15:16.048703 | TASK [Install pytest-forked into virtualenv]
2026-01-31 00:15:16.658142 | controller | Collecting pytest-forked
2026-01-31 00:15:16.692540 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2026-01-31 00:15:16.733630 | controller | Collecting py
2026-01-31 00:15:16.738385 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2026-01-31 00:15:16.758776 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.2 MB/s eta 0:00:00
2026-01-31 00:15:16.864086 | controller | Collecting pytest>=3.10
2026-01-31 00:15:16.869088 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2026-01-31 00:15:16.884601 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 29.0 MB/s eta 0:00:00
2026-01-31 00:15:16.927989 | controller | Collecting iniconfig>=1.0.1
2026-01-31 00:15:16.931506 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2026-01-31 00:15:16.977068 | controller | Collecting packaging>=22
2026-01-31 00:15:16.980441 | controller |   Downloading packaging-26.0-py3-none-any.whl (74 kB)
2026-01-31 00:15:16.988197 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.4/74.4 kB 10.9 MB/s eta 0:00:00
2026-01-31 00:15:17.019575 | controller | Collecting pluggy<2,>=1.5
2026-01-31 00:15:17.022976 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2026-01-31 00:15:17.073866 | controller | Collecting pygments>=2.7.2
2026-01-31 00:15:17.077051 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2026-01-31 00:15:17.096413 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 72.8 MB/s eta 0:00:00
2026-01-31 00:15:17.164966 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2026-01-31 00:15:18.311572 | 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-01-31 00:15:18.321072 | controller |
2026-01-31 00:15:18.389521 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2026-01-31 00:15:18.389565 | controller | [notice] To update, run: python -m pip install --upgrade pip
2026-01-31 00:15:18.601892 | controller | ok: Runtime: 0:00:02.124147
2026-01-31 00:15:18.615260 | 
2026-01-31 00:15:18.615416 | TASK [Update pip]
2026-01-31 00:15:19.156481 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2026-01-31 00:15:19.289962 | controller | Collecting pip
2026-01-31 00:15:19.325430 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2026-01-31 00:15:19.395230 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 26.7 MB/s eta 0:00:00
2026-01-31 00:15:19.458335 | controller | Installing collected packages: pip
2026-01-31 00:15:19.458556 | controller |   Attempting uninstall: pip
2026-01-31 00:15:19.460707 | controller |     Found existing installation: pip 22.2.2
2026-01-31 00:15:19.599603 | controller |     Uninstalling pip-22.2.2:
2026-01-31 00:15:19.614788 | controller |       Successfully uninstalled pip-22.2.2
2026-01-31 00:15:20.472250 | controller | Successfully installed pip-25.3
2026-01-31 00:15:20.699966 | controller | ok: Runtime: 0:00:01.684561
2026-01-31 00:15:20.713476 | 
2026-01-31 00:15:20.713619 | TASK [Ensure pip temp directory exists in /var/tmp]
2026-01-31 00:15:20.933393 | controller | changed
2026-01-31 00:15:20.942077 | 
2026-01-31 00:15:20.942184 | TASK [Install ansible into virtualenv]
2026-01-31 00:15:21.439184 | controller | Processing ./src/github.com/ansible/ansible
2026-01-31 00:15:21.442554 | controller |   Installing build dependencies: started
2026-01-31 00:15:22.412206 | controller |   Installing build dependencies: finished with status 'done'
2026-01-31 00:15:23.133625 | controller |   Getting requirements to build wheel: started
2026-01-31 00:15:23.133669 | controller |   Getting requirements to build wheel: finished with status 'done'
2026-01-31 00:15:23.134643 | controller |   Preparing metadata (pyproject.toml): started
2026-01-31 00:15:23.585883 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2026-01-31 00:15:23.643688 | 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-01-31 00:15:23.643735 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2026-01-31 00:15:24.004555 | controller | ERROR
2026-01-31 00:15:24.004768 | controller | {
2026-01-31 00:15:24.004799 | controller |   "delta": "0:00:02.480830",
2026-01-31 00:15:24.004818 | controller |   "end": "2026-01-31 00:15:23.644058",
2026-01-31 00:15:24.004836 | controller |   "msg": "non-zero return code",
2026-01-31 00:15:24.004866 | controller |   "rc": 1,
2026-01-31 00:15:24.004883 | controller |   "start": "2026-01-31 00:15:21.163228"
2026-01-31 00:15:24.004899 | controller | }
failure
2026-01-31 00:15:24.006592 | 
2026-01-31 00:15:24.006656 | PLAY RECAP
2026-01-31 00:15:24.006697 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2026-01-31 00:15:24.006717 | 
2026-01-31 00:15:24.132128 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2026-01-31 00:15:24.133225 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-31 00:15:24.757792 | 
2026-01-31 00:15:24.757912 | PLAY [all]
2026-01-31 00:15:24.780323 | 
2026-01-31 00:15:24.780443 | TASK [fetch-subunit-output : Find stestr or testr executable]
2026-01-31 00:15:25.236117 | controller | changed: non-zero return code
2026-01-31 00:15:25.244825 | 
2026-01-31 00:15:25.244942 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2026-01-31 00:15:25.270320 | controller | skipping: Conditional result was False
2026-01-31 00:15:25.279154 | 
2026-01-31 00:15:25.279296 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2026-01-31 00:15:25.324159 | 
2026-01-31 00:15:25.324357 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2026-01-31 00:15:25.357947 | 
2026-01-31 00:15:25.358162 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2026-01-31 00:15:25.382545 | controller | skipping: Conditional result was False
2026-01-31 00:15:25.389948 | 
2026-01-31 00:15:25.390044 | LOOP [fetch-subunit-output : Generate subunit file]
2026-01-31 00:15:25.432394 | 
2026-01-31 00:15:25.432621 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2026-01-31 00:15:25.457504 | controller | skipping: Conditional result was False
2026-01-31 00:15:25.469696 | 
2026-01-31 00:15:25.469830 | TASK [fetch-subunit-output : Remove the temporary file]
2026-01-31 00:15:25.503123 | controller | skipping: Conditional result was False
2026-01-31 00:15:25.513347 | 
2026-01-31 00:15:25.513469 | TASK [fetch-subunit-output : Process and fetch subunit results]
2026-01-31 00:15:25.539058 | controller | skipping: Conditional result was False
2026-01-31 00:15:25.577547 | 
2026-01-31 00:15:25.577663 | PLAY RECAP
2026-01-31 00:15:25.577720 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2026-01-31 00:15:25.577748 | 
2026-01-31 00:15:25.670986 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2026-01-31 00:15:25.671851 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2026-01-31 00:15:26.357985 | 
2026-01-31 00:15:26.358124 | PLAY [all:!appliance*]
2026-01-31 00:15:26.381915 | 
2026-01-31 00:15:26.382067 | TASK [unregister the node]
2026-01-31 00:15:26.919284 | controller | skipping: Conditional result was False
2026-01-31 00:15:26.929311 | 
2026-01-31 00:15:26.929415 | TASK [include_role : fetch-output]
2026-01-31 00:15:26.959925 | controller | ok
2026-01-31 00:15:26.983120 | 
2026-01-31 00:15:26.983379 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-31 00:15:27.029463 | controller | skipping: Conditional result was False
2026-01-31 00:15:27.038558 | 
2026-01-31 00:15:27.038658 | TASK [fetch-output : Set log path for single node]
2026-01-31 00:15:27.102519 | controller | ok
2026-01-31 00:15:27.110992 | 
2026-01-31 00:15:27.111120 | LOOP [fetch-output : Ensure local output dirs]
2026-01-31 00:15:27.539231 | controller -> localhost | ok: "/var/lib/zuul/builds/9e35bee9e60e40fda1886d661b138e46/work/logs"
2026-01-31 00:15:27.790445 | controller -> localhost | changed: "/var/lib/zuul/builds/9e35bee9e60e40fda1886d661b138e46/work/artifacts"
2026-01-31 00:15:28.046093 | controller -> localhost | changed: "/var/lib/zuul/builds/9e35bee9e60e40fda1886d661b138e46/work/docs"
2026-01-31 00:15:28.061065 | 
2026-01-31 00:15:28.061178 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-31 00:15:28.744673 | controller | changed:
2026-01-31 00:15:28.744935 | controller | .d..t...... ./
2026-01-31 00:15:28.744980 | controller | cd+++++++++ controller/
2026-01-31 00:15:28.745068 | controller | changed: All items complete
2026-01-31 00:15:28.745105 | 
2026-01-31 00:15:29.292864 | controller | changed: .d..t...... ./
2026-01-31 00:15:29.766904 | controller | changed: .d..t...... ./
2026-01-31 00:15:29.803297 | 
2026-01-31 00:15:29.803492 | TASK [include_role : fetch-output-openshift]
2026-01-31 00:15:29.831623 | controller | skipping: Conditional result was False
2026-01-31 00:15:29.841664 | 
2026-01-31 00:15:29.841775 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-31 00:15:29.884615 | controller | skipping: Conditional result was False
2026-01-31 00:15:29.893991 | controller | skipping: Conditional result was False
2026-01-31 00:15:29.933069 | 
2026-01-31 00:15:29.933156 | PLAY [localhost]
2026-01-31 00:15:29.946328 | 
2026-01-31 00:15:29.946434 | TASK [Run Zuul manifest role]
2026-01-31 00:15:29.964221 | localhost | ok
2026-01-31 00:15:29.979355 | 
2026-01-31 00:15:29.979457 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-31 00:15:30.412731 | localhost | changed
2026-01-31 00:15:30.421325 | 
2026-01-31 00:15:30.421453 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-31 00:15:30.450767 | localhost | ok
2026-01-31 00:15:30.458772 | 
2026-01-31 00:15:30.458841 | TASK [Set zuul-log-path fact]
2026-01-31 00:15:30.477260 | localhost | ok
2026-01-31 00:15:30.493568 | 
2026-01-31 00:15:30.493658 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-31 00:15:30.534801 | localhost | ok
2026-01-31 00:15:30.546690 | 
2026-01-31 00:15:30.546797 | LOOP [Run upload-logs-swift role]
2026-01-31 00:15:30.571919 | localhost | Output suppressed because no_log was given
2026-01-31 00:15:30.618869 | 
2026-01-31 00:15:30.619110 | TASK [Set zuul-log-path fact]
2026-01-31 00:15:30.644377 | localhost | skipping: Conditional result was False
2026-01-31 00:15:30.650113 | 
2026-01-31 00:15:30.650191 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2026-01-31 00:15:31.094880 | localhost -> localhost | ok: Runtime: 0:00:00.009961
2026-01-31 00:15:31.144274 | 
2026-01-31 00:15:31.144421 | TASK [upload-logs-swift : Upload logs to swift]