2025-11-11 00:07:27.131344 | Job console starting...
2025-11-11 00:07:27.140285 | Updating repositories
2025-11-11 00:07:27.253608 | Preparing job workspace
2025-11-11 00:07:33.058785 | Running Ansible setup...
2025-11-11 00:07:38.048904 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-11 00:07:38.663915 | 
2025-11-11 00:07:38.664060 | PLAY [localhost]
2025-11-11 00:07:38.675091 | 
2025-11-11 00:07:38.675298 | TASK [Gathering Facts]
2025-11-11 00:07:39.654739 | localhost | ok
2025-11-11 00:07:39.679960 | 
2025-11-11 00:07:39.680147 | TASK [Setup log path fact]
2025-11-11 00:07:39.704298 | localhost | ok
2025-11-11 00:07:39.727923 | 
2025-11-11 00:07:39.728634 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-11 00:07:39.764190 | localhost | ok
2025-11-11 00:07:39.777838 | 
2025-11-11 00:07:39.777980 | TASK [emit-job-header : Print job information]
2025-11-11 00:07:39.819478 | # Job Information
2025-11-11 00:07:39.819626 | Ansible Version: 2.15.12
2025-11-11 00:07:39.819658 | Job: ansible-test-sanity-docker-devel
2025-11-11 00:07:39.819680 | Pipeline: periodic
2025-11-11 00:07:39.819699 | Executor: ze01.softwarefactory-project.io
2025-11-11 00:07:39.819718 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-11-11 00:07:39.819739 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/49e/ansible/49ed0891d845456795308c4df84912ba/
2025-11-11 00:07:39.819776 | Event ID: 227e4e6828f94fb3a69b0e687d5dfdf5
2025-11-11 00:07:39.834610 | 
2025-11-11 00:07:39.834727 | LOOP [emit-job-header : Print node information]
2025-11-11 00:07:39.946945 | localhost | ok:
2025-11-11 00:07:39.947177 | localhost | # Node Information
2025-11-11 00:07:39.947208 | localhost | Inventory Hostname: controller
2025-11-11 00:07:39.947230 | localhost | Hostname: np0005517390
2025-11-11 00:07:39.947251 | localhost | Username: zuul
2025-11-11 00:07:39.947274 | localhost | Distro: Fedora 37
2025-11-11 00:07:39.947294 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-11-11 00:07:39.947313 | localhost | Region: ca-ymq-1
2025-11-11 00:07:39.947332 | localhost | Label: ansible-fedora-37-1vcpu
2025-11-11 00:07:39.947349 | localhost | Product Name: OpenStack Nova
2025-11-11 00:07:39.947368 | localhost | Interface IP: 162.253.55.221
2025-11-11 00:07:39.963460 | 
2025-11-11 00:07:39.963550 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-11-11 00:07:40.379610 | localhost -> localhost | changed
2025-11-11 00:07:40.391892 | 
2025-11-11 00:07:40.392087 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-11-11 00:07:41.330536 | localhost -> localhost | changed
2025-11-11 00:07:41.351481 | 
2025-11-11 00:07:41.351559 | PLAY [all:!appliance*]
2025-11-11 00:07:41.368462 | 
2025-11-11 00:07:41.368587 | TASK [include_role : start-zuul-console]
2025-11-11 00:07:41.387821 | controller | ok
2025-11-11 00:07:41.402844 | 
2025-11-11 00:07:41.402935 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-11-11 00:07:41.768733 | controller | ok
2025-11-11 00:07:41.780752 | 
2025-11-11 00:07:41.781283 | TASK [use-our-mirror : Retrieve the IP address]
2025-11-11 00:07:42.646823 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-11-11 00:07:42.661282 | 
2025-11-11 00:07:42.661415 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-11-11 00:07:43.209870 | controller | skipping: Conditional result was False
2025-11-11 00:07:43.223764 | 
2025-11-11 00:07:43.223919 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-11-11 00:07:43.252159 | controller | skipping: Conditional result was False
2025-11-11 00:07:43.267112 | 
2025-11-11 00:07:43.267845 | TASK [use-our-mirror : Create the podman configuration directory]
2025-11-11 00:07:43.284861 | controller | skipping: Conditional result was False
2025-11-11 00:07:43.298993 | 
2025-11-11 00:07:43.299167 | TASK [use-our-mirror : Copy the podman configuration]
2025-11-11 00:07:43.316484 | controller | skipping: Conditional result was False
2025-11-11 00:07:43.330114 | 
2025-11-11 00:07:43.330301 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-11-11 00:07:43.346674 | controller | skipping: Conditional result was False
2025-11-11 00:07:43.357255 | 
2025-11-11 00:07:43.357442 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-11-11 00:07:43.384265 | controller | skipping: Conditional result was False
2025-11-11 00:07:43.405886 | 
2025-11-11 00:07:43.406074 | TASK [Disable Fedora Modular]
2025-11-11 00:07:43.657693 | controller | changed
2025-11-11 00:07:43.669955 | 
2025-11-11 00:07:43.670130 | TASK [Enable EPEL]
2025-11-11 00:07:43.696122 | controller | skipping: Conditional result was False
2025-11-11 00:07:43.705238 | 
2025-11-11 00:07:43.705370 | TASK [Register the RHEL node]
2025-11-11 00:07:44.260839 | 
2025-11-11 00:07:44.261054 | TASK [Show the subscription-manager status]
2025-11-11 00:07:44.823612 | controller | skipping: Conditional result was False
2025-11-11 00:07:44.832891 | 
2025-11-11 00:07:44.833038 | TASK [Enable EPEL on RHEL]
2025-11-11 00:07:45.370512 | controller | skipping: Conditional result was False
2025-11-11 00:07:45.377295 | 
2025-11-11 00:07:45.377403 | TASK [Install git and tox]
2025-11-11 00:09:07.113603 | controller | changed
2025-11-11 00:09:07.122473 | 
2025-11-11 00:09:07.122572 | TASK [include_role : prepare-workspace]
2025-11-11 00:09:07.161733 | controller | ok
2025-11-11 00:09:07.194941 | 
2025-11-11 00:09:07.195127 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-11 00:09:07.445542 | controller | ok
2025-11-11 00:09:07.453267 | 
2025-11-11 00:09:07.453361 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-11 00:09:23.673065 | controller | Output suppressed because no_log was given
2025-11-11 00:09:23.688968 | 
2025-11-11 00:09:23.689108 | TASK [include_role : prepare-workspace-openshift]
2025-11-11 00:09:23.705397 | controller | skipping: Conditional result was False
2025-11-11 00:09:23.773575 | 
2025-11-11 00:09:23.773681 | PLAY [all:!appliance]
2025-11-11 00:09:23.789978 | 
2025-11-11 00:09:23.790105 | TASK [Run add-build-sshkey role (RSA)]
2025-11-11 00:09:23.819959 | controller | ok
2025-11-11 00:09:23.837513 | 
2025-11-11 00:09:23.837651 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-11 00:09:24.076329 | controller -> localhost | ok
2025-11-11 00:09:24.082965 | 
2025-11-11 00:09:24.083091 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-11 00:09:24.103483 | controller | ok
2025-11-11 00:09:24.122350 | controller | included: /var/lib/zuul/builds/49ed0891d845456795308c4df84912ba/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-11 00:09:24.133384 | 
2025-11-11 00:09:24.133559 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-11 00:09:24.638999 | controller -> localhost | Generating public/private rsa key pair.
2025-11-11 00:09:24.639256 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/49ed0891d845456795308c4df84912ba/work/49ed0891d845456795308c4df84912ba_id_rsa.
2025-11-11 00:09:24.639294 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/49ed0891d845456795308c4df84912ba/work/49ed0891d845456795308c4df84912ba_id_rsa.pub.
2025-11-11 00:09:24.639323 | controller -> localhost | The key fingerprint is:
2025-11-11 00:09:24.639347 | controller -> localhost | SHA256:BnckNghVtipKIz9szdWvjTxTnSDVq4SnCYL6gnw6l0E zuul-build-sshkey
2025-11-11 00:09:24.639376 | controller -> localhost | The key's randomart image is:
2025-11-11 00:09:24.639405 | controller -> localhost | +---[RSA 2048]----+
2025-11-11 00:09:24.639433 | controller -> localhost | |    .o.o* ..     |
2025-11-11 00:09:24.639464 | controller -> localhost | |      .o =. .    |
2025-11-11 00:09:24.639491 | controller -> localhost | |   .  . oo.  .   |
2025-11-11 00:09:24.639519 | controller -> localhost | |  .E. .=o.+ .    |
2025-11-11 00:09:24.639551 | controller -> localhost | |..+ ..o.S* + .   |
2025-11-11 00:09:24.639595 | controller -> localhost | |.= * o .o.o o    |
2025-11-11 00:09:24.639633 | controller -> localhost | |o.* =    ..      |
2025-11-11 00:09:24.639667 | controller -> localhost | |o+.=   .o+       |
2025-11-11 00:09:24.639697 | controller -> localhost | | o=     +o.      |
2025-11-11 00:09:24.639724 | controller -> localhost | +----[SHA256]-----+
2025-11-11 00:09:24.639781 | controller -> localhost | ok: Runtime: 0:00:00.149924
2025-11-11 00:09:24.647901 | 
2025-11-11 00:09:24.647995 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-11 00:09:24.670041 | controller | ok
2025-11-11 00:09:24.682128 | controller | included: /var/lib/zuul/builds/49ed0891d845456795308c4df84912ba/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-11 00:09:24.691667 | 
2025-11-11 00:09:24.691766 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-11 00:09:24.716165 | controller | skipping: Conditional result was False
2025-11-11 00:09:24.723678 | 
2025-11-11 00:09:24.723766 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-11 00:09:25.165365 | controller | changed
2025-11-11 00:09:25.175923 | 
2025-11-11 00:09:25.176135 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-11 00:09:25.392831 | controller | ok
2025-11-11 00:09:25.399748 | 
2025-11-11 00:09:25.399842 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-11 00:09:26.028467 | controller | changed
2025-11-11 00:09:26.034604 | 
2025-11-11 00:09:26.034678 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-11 00:09:26.662498 | controller | changed
2025-11-11 00:09:26.672457 | 
2025-11-11 00:09:26.672587 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-11 00:09:26.708547 | controller | skipping: Conditional result was False
2025-11-11 00:09:26.718241 | 
2025-11-11 00:09:26.718362 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-11 00:09:27.174303 | controller -> localhost | changed
2025-11-11 00:09:27.187120 | 
2025-11-11 00:09:27.187213 | TASK [add-build-sshkey : Add back temp key]
2025-11-11 00:09:27.467465 | controller -> localhost | Identity added: /var/lib/zuul/builds/49ed0891d845456795308c4df84912ba/work/49ed0891d845456795308c4df84912ba_id_rsa (zuul-build-sshkey)
2025-11-11 00:09:27.467668 | controller -> localhost | ok: Runtime: 0:00:00.009491
2025-11-11 00:09:27.476695 | 
2025-11-11 00:09:27.476829 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-11 00:09:27.838085 | controller | ok
2025-11-11 00:09:27.848434 | 
2025-11-11 00:09:27.848584 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-11 00:09:27.876907 | controller | skipping: Conditional result was False
2025-11-11 00:09:27.898190 | 
2025-11-11 00:09:27.898336 | TASK [Run add-build-sshkey role (ECDSA)]
2025-11-11 00:09:27.925134 | controller | ok
2025-11-11 00:09:27.952981 | 
2025-11-11 00:09:27.953149 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-11 00:09:28.197208 | controller -> localhost | ok
2025-11-11 00:09:28.209092 | 
2025-11-11 00:09:28.209230 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-11 00:09:28.251210 | controller | ok
2025-11-11 00:09:28.268882 | controller | included: /var/lib/zuul/builds/49ed0891d845456795308c4df84912ba/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-11 00:09:28.278805 | 
2025-11-11 00:09:28.278895 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-11 00:09:28.589114 | controller -> localhost | Generating public/private ecdsa key pair.
2025-11-11 00:09:28.589375 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/49ed0891d845456795308c4df84912ba/work/49ed0891d845456795308c4df84912ba_id_ecdsa.
2025-11-11 00:09:28.589411 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/49ed0891d845456795308c4df84912ba/work/49ed0891d845456795308c4df84912ba_id_ecdsa.pub.
2025-11-11 00:09:28.589440 | controller -> localhost | The key fingerprint is:
2025-11-11 00:09:28.589460 | controller -> localhost | SHA256:dHvSWC5Gzj1ZLAJ2ov57yEEaeY9kUR5BLG3LSp3Ori8 zuul-build-sshkey
2025-11-11 00:09:28.589478 | controller -> localhost | The key's randomart image is:
2025-11-11 00:09:28.589497 | controller -> localhost | +---[ECDSA 521]---+
2025-11-11 00:09:28.589514 | controller -> localhost | |        +=*.     |
2025-11-11 00:09:28.589531 | controller -> localhost | |       oo=+. .   |
2025-11-11 00:09:28.589548 | controller -> localhost | |      ...*=oo o  |
2025-11-11 00:09:28.589564 | controller -> localhost | |     .o.*==O +   |
2025-11-11 00:09:28.589579 | controller -> localhost | |      .OS*O B    |
2025-11-11 00:09:28.589596 | controller -> localhost | |      ..+.++ .   |
2025-11-11 00:09:28.589612 | controller -> localhost | |       ..+       |
2025-11-11 00:09:28.589627 | controller -> localhost | |        E.o      |
2025-11-11 00:09:28.589643 | controller -> localhost | |        o=.      |
2025-11-11 00:09:28.589660 | controller -> localhost | +----[SHA256]-----+
2025-11-11 00:09:28.589716 | controller -> localhost | ok: Runtime: 0:00:00.011491
2025-11-11 00:09:28.597209 | 
2025-11-11 00:09:28.597301 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-11 00:09:28.627957 | controller | ok
2025-11-11 00:09:28.636813 | controller | included: /var/lib/zuul/builds/49ed0891d845456795308c4df84912ba/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-11 00:09:28.645739 | 
2025-11-11 00:09:28.645817 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-11 00:09:28.669943 | controller | skipping: Conditional result was False
2025-11-11 00:09:28.676148 | 
2025-11-11 00:09:28.676218 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-11 00:09:28.940646 | controller | changed
2025-11-11 00:09:28.947395 | 
2025-11-11 00:09:28.947463 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-11 00:09:29.175317 | controller | ok
2025-11-11 00:09:29.184900 | 
2025-11-11 00:09:29.185035 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-11 00:09:29.800781 | controller | changed
2025-11-11 00:09:29.809181 | 
2025-11-11 00:09:29.809290 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-11 00:09:30.525672 | controller | changed
2025-11-11 00:09:30.531403 | 
2025-11-11 00:09:30.531500 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-11 00:09:30.577080 | controller | skipping: Conditional result was False
2025-11-11 00:09:30.587657 | 
2025-11-11 00:09:30.587802 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-11 00:09:30.899519 | controller -> localhost | changed
2025-11-11 00:09:30.911444 | 
2025-11-11 00:09:30.911544 | TASK [add-build-sshkey : Add back temp key]
2025-11-11 00:09:31.272939 | controller -> localhost | Identity added: /var/lib/zuul/builds/49ed0891d845456795308c4df84912ba/work/49ed0891d845456795308c4df84912ba_id_ecdsa (zuul-build-sshkey)
2025-11-11 00:09:31.273301 | controller -> localhost | ok: Runtime: 0:00:00.008599
2025-11-11 00:09:31.289160 | 
2025-11-11 00:09:31.289324 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-11 00:09:31.553059 | controller | ok
2025-11-11 00:09:31.559100 | 
2025-11-11 00:09:31.559201 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-11 00:09:31.583950 | controller | skipping: Conditional result was False
2025-11-11 00:09:31.599691 | 
2025-11-11 00:09:31.599833 | TASK [include_role : remove-zuul-sshkey]
2025-11-11 00:09:31.614760 | controller | skipping: Conditional result was False
2025-11-11 00:09:31.623735 | 
2025-11-11 00:09:31.623864 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-11 00:09:31.855537 | controller | ok: "logs"
2025-11-11 00:09:31.855902 | controller | ok: All items complete
2025-11-11 00:09:31.855943 | 
2025-11-11 00:09:32.045612 | controller | ok: "artifacts"
2025-11-11 00:09:32.232066 | controller | ok: "docs"
2025-11-11 00:09:32.243481 | 
2025-11-11 00:09:32.243630 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-11 00:09:32.497542 | controller | changed: "logs"
2025-11-11 00:09:32.695231 | controller | changed: "artifacts"
2025-11-11 00:09:32.897892 | controller | changed: "docs"
2025-11-11 00:09:32.929504 | 
2025-11-11 00:09:32.929692 | PLAY RECAP
2025-11-11 00:09:32.929740 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-11-11 00:09:32.929768 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-11 00:09:32.929788 | 
2025-11-11 00:09:33.045921 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-11-11 00:09:33.047098 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-11 00:09:33.682673 | 
2025-11-11 00:09:33.682818 | PLAY [all]
2025-11-11 00:09:33.716411 | 
2025-11-11 00:09:33.716572 | TASK [Install binary dependencies]
2025-11-11 00:09:33.767345 | controller | ok
2025-11-11 00:09:33.788133 | 
2025-11-11 00:09:33.788281 | TASK [bindep : Include find tasks]
2025-11-11 00:09:33.817884 | controller | ok
2025-11-11 00:09:33.825652 | controller | included: /var/lib/zuul/builds/49ed0891d845456795308c4df84912ba/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-11-11 00:09:33.832261 | 
2025-11-11 00:09:33.832386 | TASK [bindep : Look for bindep.txt]
2025-11-11 00:09:34.189361 | controller | ok
2025-11-11 00:09:34.202763 | 
2025-11-11 00:09:34.202956 | TASK [bindep : Define bindep_file fact]
2025-11-11 00:09:34.227765 | controller | skipping: Conditional result was False
2025-11-11 00:09:34.236913 | 
2025-11-11 00:09:34.237010 | TASK [bindep : Look for other-requirements.txt]
2025-11-11 00:09:34.471422 | controller | ok
2025-11-11 00:09:34.482229 | 
2025-11-11 00:09:34.482404 | TASK [bindep : Define bindep_file fact]
2025-11-11 00:09:34.508533 | controller | skipping: Conditional result was False
2025-11-11 00:09:34.518358 | 
2025-11-11 00:09:34.518712 | TASK [bindep : Look for bindep fallback file]
2025-11-11 00:09:34.553838 | controller | skipping: Conditional result was False
2025-11-11 00:09:34.564227 | 
2025-11-11 00:09:34.564377 | TASK [bindep : Define bindep_file fact]
2025-11-11 00:09:34.590135 | controller | skipping: Conditional result was False
2025-11-11 00:09:34.600235 | 
2025-11-11 00:09:34.600377 | TASK [bindep : Include bindep tasks]
2025-11-11 00:09:34.637615 | controller | skipping: Conditional result was False
2025-11-11 00:09:34.646530 | 
2025-11-11 00:09:34.646655 | TASK [bindep : Include install tasks]
2025-11-11 00:09:34.682087 | controller | skipping: Conditional result was False
2025-11-11 00:09:34.700658 | 
2025-11-11 00:09:34.700832 | LOOP [bindep : Include package tasks]
2025-11-11 00:09:34.770780 | 
2025-11-11 00:09:34.770957 | TASK [Run test-setup role]
2025-11-11 00:09:34.794420 | controller | ok
2025-11-11 00:09:34.818901 | 
2025-11-11 00:09:34.819087 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-11-11 00:09:35.039115 | controller | ok
2025-11-11 00:09:35.053308 | 
2025-11-11 00:09:35.053443 | TASK [test-setup : Run tools/test-setup.sh]
2025-11-11 00:09:35.599191 | controller | skipping: Conditional result was False
2025-11-11 00:09:35.635667 | 
2025-11-11 00:09:35.635783 | PLAY RECAP
2025-11-11 00:09:35.635838 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-11 00:09:35.635866 | 
2025-11-11 00:09:35.769923 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-11-11 00:09:35.770776 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-11 00:09:36.402964 | 
2025-11-11 00:09:36.403130 | PLAY [controller]
2025-11-11 00:09:36.424992 | 
2025-11-11 00:09:36.425137 | TASK [Create the /root directory]
2025-11-11 00:09:36.834554 | controller | ok
2025-11-11 00:09:36.842462 | 
2025-11-11 00:09:36.842608 | TASK [Install glibc-langpack-en]
2025-11-11 00:09:40.722079 | controller | ok: Nothing to do
2025-11-11 00:09:40.740903 | 
2025-11-11 00:09:40.741076 | TASK [Ensure controller directory exists]
2025-11-11 00:09:40.953803 | controller | changed
2025-11-11 00:09:40.975153 | 
2025-11-11 00:09:40.975334 | TASK [Install container runtime]
2025-11-11 00:09:41.056544 | controller | ok
2025-11-11 00:09:41.120451 | 
2025-11-11 00:09:41.120572 | LOOP [ensure-podman : Find distribution installation]
2025-11-11 00:09:41.149475 | controller | ok: "/var/lib/zuul/builds/49ed0891d845456795308c4df84912ba/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-11-11 00:09:41.163632 | controller | included: /var/lib/zuul/builds/49ed0891d845456795308c4df84912ba/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-11-11 00:09:41.171402 | 
2025-11-11 00:09:41.171478 | TASK [ensure-podman : Install podman (RedHat)]
2025-11-11 00:10:51.674650 | controller | changed
2025-11-11 00:10:51.683195 | 
2025-11-11 00:10:51.683325 | TASK [ensure-podman : Fetch podman version]
2025-11-11 00:10:52.234605 | controller | Client:       Podman Engine
2025-11-11 00:10:52.261101 | controller | Version:      4.6.2
2025-11-11 00:10:52.261155 | controller | API Version:  4.6.2
2025-11-11 00:10:52.261168 | controller | Go Version:   go1.19.12
2025-11-11 00:10:52.261192 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-11-11 00:10:52.261204 | controller | OS/Arch:      linux/amd64
2025-11-11 00:10:52.733481 | controller | ok: Runtime: 0:00:00.181579
2025-11-11 00:10:52.755882 | 
2025-11-11 00:10:52.756140 | TASK [ensure-podman : Print podman version installed]
2025-11-11 00:10:52.791686 | Podman version: Client:       Podman Engine
2025-11-11 00:10:52.791890 | Version:      4.6.2
2025-11-11 00:10:52.791930 | API Version:  4.6.2
2025-11-11 00:10:52.791959 | Go Version:   go1.19.12
2025-11-11 00:10:52.791985 | Built:        Mon Aug 28 19:38:31 2023
2025-11-11 00:10:52.792010 | OS/Arch:      linux/amd64
2025-11-11 00:10:52.800873 | 
2025-11-11 00:10:52.800980 | TASK [ensure-podman : Validate podman engine]
2025-11-11 00:10:53.347538 | controller | skipping: Conditional result was False
2025-11-11 00:10:53.354459 | 
2025-11-11 00:10:53.354535 | TASK [ensure-podman : Set up docker compatability socket]
2025-11-11 00:10:53.378271 | controller | skipping: Conditional result was False
2025-11-11 00:10:53.389942 | 
2025-11-11 00:10:53.390028 | TASK [Ensure python3.8 is present]
2025-11-11 00:10:53.414865 | controller | skipping: Conditional result was False
2025-11-11 00:10:53.421849 | 
2025-11-11 00:10:53.421923 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-11-11 00:10:53.443815 | controller | ok
2025-11-11 00:10:53.472683 | 
2025-11-11 00:10:53.472814 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-11-11 00:10:54.872882 | controller | ok: Nothing to do
2025-11-11 00:10:54.886059 | 
2025-11-11 00:10:54.886373 | TASK [our-ensure-python : Also install python3-devel]
2025-11-11 00:11:04.314552 | controller | changed
2025-11-11 00:11:04.335732 | 
2025-11-11 00:11:04.335918 | TASK [Run ensure-virtualenv role]
2025-11-11 00:11:04.360891 | controller | ok
2025-11-11 00:11:04.394544 | 
2025-11-11 00:11:04.394684 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-11-11 00:11:04.663598 | controller | /usr/bin/virtualenv
2025-11-11 00:11:04.981404 | controller | ok: Runtime: 0:00:00.005530
2025-11-11 00:11:04.989667 | 
2025-11-11 00:11:04.989771 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-11-11 00:11:05.019125 | controller | skipping: Conditional result was False
2025-11-11 00:11:05.019448 | controller | ok: All items complete
2025-11-11 00:11:05.019489 | 
2025-11-11 00:11:05.040310 | 
2025-11-11 00:11:05.040469 | TASK [Find the full path of the Python interpreter]
2025-11-11 00:11:05.249318 | controller | /usr/bin/python3
2025-11-11 00:11:05.579950 | controller | ok
2025-11-11 00:11:05.587842 | 
2025-11-11 00:11:05.587963 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-11-11 00:11:06.421670 | controller | created virtual environment CPython3.11.0.final.0-64 in 455ms
2025-11-11 00:11:06.437482 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-11-11 00:11:06.437518 | 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-11 00:11:06.437529 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-11-11 00:11:06.437543 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-11-11 00:11:06.629371 | controller | changed
2025-11-11 00:11:06.635581 | 
2025-11-11 00:11:06.635649 | TASK [Set selinux package]
2025-11-11 00:11:06.664888 | controller | ok
2025-11-11 00:11:06.686746 | 
2025-11-11 00:11:06.686889 | TASK [Set selinux package (Fedora)]
2025-11-11 00:11:06.728645 | controller | ok
2025-11-11 00:11:06.735244 | 
2025-11-11 00:11:06.735343 | TASK [Install selinux into virtualenv]
2025-11-11 00:11:20.302347 | controller | Collecting selinux-please-lie-to-me
2025-11-11 00:11:32.631572 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-11-11 00:11:32.934615 | controller | Collecting setuptools<50.0.0
2025-11-11 00:11:32.940295 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-11-11 00:11:32.981081 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 21.6 MB/s eta 0:00:00
2025-11-11 00:11:33.063393 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-11-11 00:11:33.063610 | controller |   Attempting uninstall: setuptools
2025-11-11 00:11:33.066023 | controller |     Found existing installation: setuptools 62.6.0
2025-11-11 00:11:33.125089 | controller |     Uninstalling setuptools-62.6.0:
2025-11-11 00:11:33.133116 | controller |       Successfully uninstalled setuptools-62.6.0
2025-11-11 00:11:33.485098 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-11-11 00:11:45.009562 | controller |
2025-11-11 00:11:45.096845 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-11-11 00:11:45.096897 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-11-11 00:11:45.302876 | controller | ok: Runtime: 0:00:38.150816
2025-11-11 00:11:45.317874 | 
2025-11-11 00:11:45.318106 | TASK [Install pytest-forked into virtualenv]
2025-11-11 00:11:57.246242 | controller | Collecting pytest-forked
2025-11-11 00:12:07.455512 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-11-11 00:12:07.506594 | controller | Collecting py
2025-11-11 00:12:07.510808 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-11-11 00:12:07.530593 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 5.4 MB/s eta 0:00:00
2025-11-11 00:12:07.641616 | controller | Collecting pytest>=3.10
2025-11-11 00:12:07.649190 | controller |   Downloading pytest-9.0.0-py3-none-any.whl (373 kB)
2025-11-11 00:12:07.664381 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 373.4/373.4 kB 29.9 MB/s eta 0:00:00
2025-11-11 00:12:07.704225 | controller | Collecting iniconfig>=1.0.1
2025-11-11 00:12:07.707787 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-11-11 00:12:07.748397 | controller | Collecting packaging>=22
2025-11-11 00:12:07.752759 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-11-11 00:12:07.757957 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 18.8 MB/s eta 0:00:00
2025-11-11 00:12:07.790275 | controller | Collecting pluggy<2,>=1.5
2025-11-11 00:12:07.794413 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-11-11 00:12:07.841442 | controller | Collecting pygments>=2.7.2
2025-11-11 00:12:07.845514 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-11-11 00:12:07.874936 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 51.3 MB/s eta 0:00:00
2025-11-11 00:12:07.944962 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-11-11 00:12:08.977923 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.0 pytest-forked-1.6.0
2025-11-11 00:12:08.986474 | controller |
2025-11-11 00:12:09.055814 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-11-11 00:12:09.055844 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-11-11 00:12:09.378084 | controller | ok: Runtime: 0:00:23.520554
2025-11-11 00:12:09.386996 | 
2025-11-11 00:12:09.387163 | TASK [Update pip]
2025-11-11 00:12:09.895577 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-11-11 00:12:22.323670 | controller | Collecting pip
2025-11-11 00:12:34.514986 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-11-11 00:12:34.569642 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 35.3 MB/s eta 0:00:00
2025-11-11 00:12:34.635497 | controller | Installing collected packages: pip
2025-11-11 00:12:34.635639 | controller |   Attempting uninstall: pip
2025-11-11 00:12:34.637730 | controller |     Found existing installation: pip 22.2.2
2025-11-11 00:12:34.773260 | controller |     Uninstalling pip-22.2.2:
2025-11-11 00:12:34.787864 | controller |       Successfully uninstalled pip-22.2.2
2025-11-11 00:12:35.546586 | controller | Successfully installed pip-25.3
2025-11-11 00:12:35.945618 | controller | ok: Runtime: 0:00:26.016700
2025-11-11 00:12:35.954710 | 
2025-11-11 00:12:35.954839 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-11-11 00:12:36.177207 | controller | changed
2025-11-11 00:12:36.187099 | 
2025-11-11 00:12:36.187242 | TASK [Install ansible into virtualenv]
2025-11-11 00:12:36.721506 | controller | Processing ./src/github.com/ansible/ansible
2025-11-11 00:12:36.724776 | controller |   Installing build dependencies: started
2025-11-11 00:13:01.967039 | controller |   Installing build dependencies: finished with status 'done'
2025-11-11 00:13:01.968151 | controller |   Getting requirements to build wheel: started
2025-11-11 00:13:02.705219 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-11-11 00:13:02.706469 | controller |   Preparing metadata (pyproject.toml): started
2025-11-11 00:13:03.186186 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-11-11 00:13:03.188904 | 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-11 00:13:03.191461 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-11-11 00:13:03.304715 | controller | ERROR
2025-11-11 00:13:03.304942 | controller | {
2025-11-11 00:13:03.304988 | controller |   "delta": "0:00:26.807198",
2025-11-11 00:13:03.305048 | controller |   "end": "2025-11-11 00:13:03.252808",
2025-11-11 00:13:03.305082 | controller |   "msg": "non-zero return code",
2025-11-11 00:13:03.305129 | controller |   "rc": 1,
2025-11-11 00:13:03.305154 | controller |   "start": "2025-11-11 00:12:36.445610"
2025-11-11 00:13:03.305178 | controller | }
failure
2025-11-11 00:13:03.311328 | 
2025-11-11 00:13:03.311405 | PLAY RECAP
2025-11-11 00:13:03.311467 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-11-11 00:13:03.311497 | 
2025-11-11 00:13:03.451559 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-11-11 00:13:03.452886 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-11 00:13:04.093099 | 
2025-11-11 00:13:04.093222 | PLAY [all]
2025-11-11 00:13:04.115932 | 
2025-11-11 00:13:04.116066 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-11-11 00:13:04.395547 | controller | changed: non-zero return code
2025-11-11 00:13:04.402111 | 
2025-11-11 00:13:04.402242 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-11-11 00:13:04.438041 | controller | skipping: Conditional result was False
2025-11-11 00:13:04.445010 | 
2025-11-11 00:13:04.445178 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-11-11 00:13:04.476908 | 
2025-11-11 00:13:04.477140 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-11-11 00:13:04.512008 | 
2025-11-11 00:13:04.512336 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-11-11 00:13:04.545296 | controller | skipping: Conditional result was False
2025-11-11 00:13:04.553648 | 
2025-11-11 00:13:04.553795 | LOOP [fetch-subunit-output : Generate subunit file]
2025-11-11 00:13:04.587042 | 
2025-11-11 00:13:04.587225 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-11-11 00:13:04.613448 | controller | skipping: Conditional result was False
2025-11-11 00:13:04.621886 | 
2025-11-11 00:13:04.622038 | TASK [fetch-subunit-output : Remove the temporary file]
2025-11-11 00:13:04.647462 | controller | skipping: Conditional result was False
2025-11-11 00:13:04.655763 | 
2025-11-11 00:13:04.655902 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-11-11 00:13:04.681338 | controller | skipping: Conditional result was False
2025-11-11 00:13:04.717282 | 
2025-11-11 00:13:04.717390 | PLAY RECAP
2025-11-11 00:13:04.717438 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-11-11 00:13:04.717462 | 
2025-11-11 00:13:04.856910 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-11-11 00:13:04.857942 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-11-11 00:13:05.510636 | 
2025-11-11 00:13:05.510757 | PLAY [all:!appliance*]
2025-11-11 00:13:05.533750 | 
2025-11-11 00:13:05.533933 | TASK [unregister the node]
2025-11-11 00:13:06.082992 | controller | skipping: Conditional result was False
2025-11-11 00:13:06.089794 | 
2025-11-11 00:13:06.089933 | TASK [include_role : fetch-output]
2025-11-11 00:13:06.159483 | controller | ok
2025-11-11 00:13:06.207915 | 
2025-11-11 00:13:06.208083 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-11 00:13:06.275858 | controller | skipping: Conditional result was False
2025-11-11 00:13:06.285341 | 
2025-11-11 00:13:06.285504 | TASK [fetch-output : Set log path for single node]
2025-11-11 00:13:06.341393 | controller | ok
2025-11-11 00:13:06.352631 | 
2025-11-11 00:13:06.352805 | LOOP [fetch-output : Ensure local output dirs]
2025-11-11 00:13:06.891256 | controller -> localhost | ok: "/var/lib/zuul/builds/49ed0891d845456795308c4df84912ba/work/logs"
2025-11-11 00:13:07.168881 | controller -> localhost | changed: "/var/lib/zuul/builds/49ed0891d845456795308c4df84912ba/work/artifacts"
2025-11-11 00:13:07.464892 | controller -> localhost | changed: "/var/lib/zuul/builds/49ed0891d845456795308c4df84912ba/work/docs"
2025-11-11 00:13:07.476134 | 
2025-11-11 00:13:07.476243 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-11 00:13:08.116895 | controller | changed:
2025-11-11 00:13:08.117205 | controller | .d..t...... ./
2025-11-11 00:13:08.117243 | controller | cd+++++++++ controller/
2025-11-11 00:13:08.117276 | controller | changed: All items complete
2025-11-11 00:13:08.117296 | 
2025-11-11 00:13:08.599130 | controller | changed: .d..t...... ./
2025-11-11 00:13:09.078081 | controller | changed: .d..t...... ./
2025-11-11 00:13:09.102846 | 
2025-11-11 00:13:09.102988 | TASK [include_role : fetch-output-openshift]
2025-11-11 00:13:09.120204 | controller | skipping: Conditional result was False
2025-11-11 00:13:09.135980 | 
2025-11-11 00:13:09.136976 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-11-11 00:13:09.174284 | controller | skipping: Conditional result was False
2025-11-11 00:13:09.178827 | controller | skipping: Conditional result was False
2025-11-11 00:13:09.236103 | 
2025-11-11 00:13:09.236235 | PLAY [localhost]
2025-11-11 00:13:09.263523 | 
2025-11-11 00:13:09.263674 | TASK [Run Zuul manifest role]
2025-11-11 00:13:09.287194 | localhost | ok
2025-11-11 00:13:09.307196 | 
2025-11-11 00:13:09.307319 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-11-11 00:13:09.724653 | localhost | changed
2025-11-11 00:13:09.730244 | 
2025-11-11 00:13:09.730311 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-11-11 00:13:09.758812 | localhost | ok
2025-11-11 00:13:09.769672 | 
2025-11-11 00:13:09.769772 | TASK [Set zuul-log-path fact]
2025-11-11 00:13:09.788546 | localhost | ok
2025-11-11 00:13:09.805197 | 
2025-11-11 00:13:09.805335 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-11 00:13:09.847559 | localhost | ok
2025-11-11 00:13:09.855935 | 
2025-11-11 00:13:09.856073 | LOOP [Run upload-logs-swift role]
2025-11-11 00:13:09.890740 | localhost | Output suppressed because no_log was given
2025-11-11 00:13:09.918821 | 
2025-11-11 00:13:09.918951 | TASK [Set zuul-log-path fact]
2025-11-11 00:13:09.964821 | localhost | skipping: Conditional result was False
2025-11-11 00:13:09.970381 | 
2025-11-11 00:13:09.970496 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-11-11 00:13:10.438355 | localhost -> localhost | ok: Runtime: 0:00:00.006340
2025-11-11 00:13:10.445616 | 
2025-11-11 00:13:10.445727 | TASK [upload-logs-swift : Upload logs to swift]