2025-12-26 00:21:18.514593 | Job console starting...
2025-12-26 00:21:18.526534 | Updating repositories
2025-12-26 00:21:18.658606 | Preparing job workspace
2025-12-26 00:21:22.017278 | Running Ansible setup...
2025-12-26 00:21:27.046469 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-26 00:21:27.656407 | 
2025-12-26 00:21:27.656594 | PLAY [localhost]
2025-12-26 00:21:27.665705 | 
2025-12-26 00:21:27.665810 | TASK [Gathering Facts]
2025-12-26 00:21:28.692799 | localhost | ok
2025-12-26 00:21:28.707817 | 
2025-12-26 00:21:28.707937 | TASK [Setup log path fact]
2025-12-26 00:21:28.726170 | localhost | ok
2025-12-26 00:21:28.738784 | 
2025-12-26 00:21:28.738890 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-26 00:21:28.766830 | localhost | ok
2025-12-26 00:21:28.776583 | 
2025-12-26 00:21:28.776718 | TASK [emit-job-header : Print job information]
2025-12-26 00:21:28.805623 | # Job Information
2025-12-26 00:21:28.805812 | Ansible Version: 2.15.12
2025-12-26 00:21:28.805848 | Job: ansible-test-sanity-docker-devel
2025-12-26 00:21:28.805871 | Pipeline: periodic
2025-12-26 00:21:28.805889 | Executor: ze03.softwarefactory-project.io
2025-12-26 00:21:28.805907 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-12-26 00:21:28.805927 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/6d8/ansible/6d86ce6562c2478d9750595947409e44/
2025-12-26 00:21:28.805946 | Event ID: 251d181dbd134356bcf2e7a38c8ef353
2025-12-26 00:21:28.809964 | 
2025-12-26 00:21:28.810027 | LOOP [emit-job-header : Print node information]
2025-12-26 00:21:28.921778 | localhost | ok:
2025-12-26 00:21:28.921979 | localhost | # Node Information
2025-12-26 00:21:28.922011 | localhost | Inventory Hostname: controller
2025-12-26 00:21:28.922035 | localhost | Hostname: np0005570841
2025-12-26 00:21:28.922058 | localhost | Username: zuul
2025-12-26 00:21:28.922086 | localhost | Distro: Fedora 37
2025-12-26 00:21:28.922111 | localhost | Provider: ansible-vexxhost-ca-ymq-1
2025-12-26 00:21:28.922133 | localhost | Region: ca-ymq-1
2025-12-26 00:21:28.922154 | localhost | Label: ansible-fedora-37-1vcpu
2025-12-26 00:21:28.922175 | localhost | Product Name: OpenStack Nova
2025-12-26 00:21:28.922195 | localhost | Interface IP: 162.253.55.209
2025-12-26 00:21:28.933233 | 
2025-12-26 00:21:28.933360 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-26 00:21:29.314231 | localhost -> localhost | changed
2025-12-26 00:21:29.322099 | 
2025-12-26 00:21:29.322259 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-26 00:21:30.246792 | localhost -> localhost | changed
2025-12-26 00:21:30.273336 | 
2025-12-26 00:21:30.273510 | PLAY [all:!appliance*]
2025-12-26 00:21:30.294454 | 
2025-12-26 00:21:30.294630 | TASK [include_role : start-zuul-console]
2025-12-26 00:21:30.317210 | controller | ok
2025-12-26 00:21:30.336101 | 
2025-12-26 00:21:30.336222 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-26 00:21:30.776253 | controller | ok
2025-12-26 00:21:30.801684 | 
2025-12-26 00:21:30.801885 | TASK [use-our-mirror : Retrieve the IP address]
2025-12-26 00:21:31.840277 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-12-26 00:21:31.850075 | 
2025-12-26 00:21:31.850217 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-12-26 00:21:32.406646 | controller | skipping: Conditional result was False
2025-12-26 00:21:32.424849 | 
2025-12-26 00:21:32.425037 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-12-26 00:21:32.452844 | controller | skipping: Conditional result was False
2025-12-26 00:21:32.471953 | 
2025-12-26 00:21:32.472163 | TASK [use-our-mirror : Create the podman configuration directory]
2025-12-26 00:21:32.499958 | controller | skipping: Conditional result was False
2025-12-26 00:21:32.515848 | 
2025-12-26 00:21:32.516028 | TASK [use-our-mirror : Copy the podman configuration]
2025-12-26 00:21:32.543822 | controller | skipping: Conditional result was False
2025-12-26 00:21:32.551074 | 
2025-12-26 00:21:32.551177 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-12-26 00:21:32.575153 | controller | skipping: Conditional result was False
2025-12-26 00:21:32.582017 | 
2025-12-26 00:21:32.582140 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-12-26 00:21:32.606049 | controller | skipping: Conditional result was False
2025-12-26 00:21:32.619403 | 
2025-12-26 00:21:32.619511 | TASK [Disable Fedora Modular]
2025-12-26 00:21:32.870009 | controller | changed
2025-12-26 00:21:32.883116 | 
2025-12-26 00:21:32.883271 | TASK [Enable EPEL]
2025-12-26 00:21:32.911328 | controller | skipping: Conditional result was False
2025-12-26 00:21:32.927577 | 
2025-12-26 00:21:32.927792 | TASK [Register the RHEL node]
2025-12-26 00:21:33.495500 | 
2025-12-26 00:21:33.496092 | TASK [Show the subscription-manager status]
2025-12-26 00:21:34.087377 | controller | skipping: Conditional result was False
2025-12-26 00:21:34.097956 | 
2025-12-26 00:21:34.098125 | TASK [Enable EPEL on RHEL]
2025-12-26 00:21:34.647798 | controller | skipping: Conditional result was False
2025-12-26 00:21:34.657091 | 
2025-12-26 00:21:34.657222 | TASK [Install git and tox]
2025-12-26 00:23:19.466982 | controller | changed
2025-12-26 00:23:19.473677 | 
2025-12-26 00:23:19.473775 | TASK [include_role : prepare-workspace]
2025-12-26 00:23:19.508217 | controller | ok
2025-12-26 00:23:19.531041 | 
2025-12-26 00:23:19.531196 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-26 00:23:19.788888 | controller | ok
2025-12-26 00:23:19.797704 | 
2025-12-26 00:23:19.797923 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-26 00:23:34.685116 | controller | Output suppressed because no_log was given
2025-12-26 00:23:34.697256 | 
2025-12-26 00:23:34.697396 | TASK [include_role : prepare-workspace-openshift]
2025-12-26 00:23:34.722629 | controller | skipping: Conditional result was False
2025-12-26 00:23:34.751224 | 
2025-12-26 00:23:34.751366 | PLAY [all:!appliance]
2025-12-26 00:23:34.786763 | 
2025-12-26 00:23:34.786953 | TASK [Run add-build-sshkey role (RSA)]
2025-12-26 00:23:34.818986 | controller | ok
2025-12-26 00:23:34.838596 | 
2025-12-26 00:23:34.838809 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-26 00:23:35.184304 | controller -> localhost | ok
2025-12-26 00:23:35.191081 | 
2025-12-26 00:23:35.191157 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-26 00:23:35.221692 | controller | ok
2025-12-26 00:23:35.235680 | controller | included: /var/lib/zuul/builds/6d86ce6562c2478d9750595947409e44/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-26 00:23:35.241877 | 
2025-12-26 00:23:35.241939 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-26 00:23:35.860131 | controller -> localhost | Generating public/private rsa key pair.
2025-12-26 00:23:35.860410 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/6d86ce6562c2478d9750595947409e44/work/6d86ce6562c2478d9750595947409e44_id_rsa.
2025-12-26 00:23:35.860453 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/6d86ce6562c2478d9750595947409e44/work/6d86ce6562c2478d9750595947409e44_id_rsa.pub.
2025-12-26 00:23:35.860484 | controller -> localhost | The key fingerprint is:
2025-12-26 00:23:35.860514 | controller -> localhost | SHA256:xFpcjYdLpdlCgErEdsb7M+8aaofF2u7p+foIk7fuPUM zuul-build-sshkey
2025-12-26 00:23:35.860573 | controller -> localhost | The key's randomart image is:
2025-12-26 00:23:35.860604 | controller -> localhost | +---[RSA 2048]----+
2025-12-26 00:23:35.860633 | controller -> localhost | |   o.. ...o=.    |
2025-12-26 00:23:35.860662 | controller -> localhost | |    + =o o++o    |
2025-12-26 00:23:35.860689 | controller -> localhost | |   o + .=.+o.    |
2025-12-26 00:23:35.860717 | controller -> localhost | |    . .+  ..     |
2025-12-26 00:23:35.860795 | controller -> localhost | |      .oS        |
2025-12-26 00:23:35.860839 | controller -> localhost | |       .* E      |
2025-12-26 00:23:35.860876 | controller -> localhost | |      +=o=       |
2025-12-26 00:23:35.860905 | controller -> localhost | |      +=oB+      |
2025-12-26 00:23:35.860933 | controller -> localhost | |     ..B&*=o     |
2025-12-26 00:23:35.860963 | controller -> localhost | +----[SHA256]-----+
2025-12-26 00:23:35.861028 | controller -> localhost | ok: Runtime: 0:00:00.169205
2025-12-26 00:23:35.882361 | 
2025-12-26 00:23:35.882518 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-26 00:23:35.909679 | controller | ok
2025-12-26 00:23:35.924473 | controller | included: /var/lib/zuul/builds/6d86ce6562c2478d9750595947409e44/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-26 00:23:35.936491 | 
2025-12-26 00:23:35.936582 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-26 00:23:35.963992 | controller | skipping: Conditional result was False
2025-12-26 00:23:35.971996 | 
2025-12-26 00:23:35.972060 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-26 00:23:36.473264 | controller | changed
2025-12-26 00:23:36.481524 | 
2025-12-26 00:23:36.481596 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-26 00:23:36.730035 | controller | ok
2025-12-26 00:23:36.747024 | 
2025-12-26 00:23:36.747238 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-26 00:23:37.436359 | controller | changed
2025-12-26 00:23:37.448347 | 
2025-12-26 00:23:37.448523 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-26 00:23:38.126676 | controller | changed
2025-12-26 00:23:38.134550 | 
2025-12-26 00:23:38.134629 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-26 00:23:38.162333 | controller | skipping: Conditional result was False
2025-12-26 00:23:38.171645 | 
2025-12-26 00:23:38.171757 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-26 00:23:38.628252 | controller -> localhost | changed
2025-12-26 00:23:38.650552 | 
2025-12-26 00:23:38.650708 | TASK [add-build-sshkey : Add back temp key]
2025-12-26 00:23:38.980275 | controller -> localhost | Identity added: /var/lib/zuul/builds/6d86ce6562c2478d9750595947409e44/work/6d86ce6562c2478d9750595947409e44_id_rsa (zuul-build-sshkey)
2025-12-26 00:23:38.980597 | controller -> localhost | ok: Runtime: 0:00:00.011175
2025-12-26 00:23:38.990764 | 
2025-12-26 00:23:38.990867 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-26 00:23:39.356357 | controller | ok
2025-12-26 00:23:39.369429 | 
2025-12-26 00:23:39.369611 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-26 00:23:39.417091 | controller | skipping: Conditional result was False
2025-12-26 00:23:39.437456 | 
2025-12-26 00:23:39.437593 | TASK [Run add-build-sshkey role (ECDSA)]
2025-12-26 00:23:39.469127 | controller | ok
2025-12-26 00:23:39.491362 | 
2025-12-26 00:23:39.491537 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-26 00:23:39.742472 | controller -> localhost | ok
2025-12-26 00:23:39.756363 | 
2025-12-26 00:23:39.756558 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-26 00:23:39.790212 | controller | ok
2025-12-26 00:23:39.810352 | controller | included: /var/lib/zuul/builds/6d86ce6562c2478d9750595947409e44/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-26 00:23:39.822057 | 
2025-12-26 00:23:39.822231 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-26 00:23:40.117125 | controller -> localhost | Generating public/private ecdsa key pair.
2025-12-26 00:23:40.117406 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/6d86ce6562c2478d9750595947409e44/work/6d86ce6562c2478d9750595947409e44_id_ecdsa.
2025-12-26 00:23:40.117446 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/6d86ce6562c2478d9750595947409e44/work/6d86ce6562c2478d9750595947409e44_id_ecdsa.pub.
2025-12-26 00:23:40.117489 | controller -> localhost | The key fingerprint is:
2025-12-26 00:23:40.117517 | controller -> localhost | SHA256:39HLaTh+kACrNtv2b5DUr3S34ud6NBU4a6kvqlnHaug zuul-build-sshkey
2025-12-26 00:23:40.117544 | controller -> localhost | The key's randomart image is:
2025-12-26 00:23:40.117570 | controller -> localhost | +---[ECDSA 521]---+
2025-12-26 00:23:40.117596 | controller -> localhost | |              .  |
2025-12-26 00:23:40.117621 | controller -> localhost | |        .    o . |
2025-12-26 00:23:40.117646 | controller -> localhost | |         o .  + .|
2025-12-26 00:23:40.117671 | controller -> localhost | |        . o .=  .|
2025-12-26 00:23:40.117694 | controller -> localhost | |       .S. o+o. .|
2025-12-26 00:23:40.117719 | controller -> localhost | |      +  .+o++o=.|
2025-12-26 00:23:40.117766 | controller -> localhost | |     . +...==+*.o|
2025-12-26 00:23:40.117792 | controller -> localhost | |      ..=.ooo=.+ |
2025-12-26 00:23:40.117817 | controller -> localhost | |      .Eo+oo=+*. |
2025-12-26 00:23:40.117841 | controller -> localhost | +----[SHA256]-----+
2025-12-26 00:23:40.117903 | controller -> localhost | ok: Runtime: 0:00:00.013972
2025-12-26 00:23:40.131382 | 
2025-12-26 00:23:40.131563 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-26 00:23:40.168016 | controller | ok
2025-12-26 00:23:40.177714 | controller | included: /var/lib/zuul/builds/6d86ce6562c2478d9750595947409e44/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-26 00:23:40.190331 | 
2025-12-26 00:23:40.190442 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-26 00:23:40.217682 | controller | skipping: Conditional result was False
2025-12-26 00:23:40.227069 | 
2025-12-26 00:23:40.227157 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-26 00:23:40.524197 | controller | changed
2025-12-26 00:23:40.537980 | 
2025-12-26 00:23:40.538127 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-26 00:23:40.813883 | controller | ok
2025-12-26 00:23:40.825812 | 
2025-12-26 00:23:40.825986 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-26 00:23:41.513752 | controller | changed
2025-12-26 00:23:41.525055 | 
2025-12-26 00:23:41.525249 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-26 00:23:42.241938 | controller | changed
2025-12-26 00:23:42.303490 | 
2025-12-26 00:23:42.303675 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-26 00:23:42.338498 | controller | skipping: Conditional result was False
2025-12-26 00:23:42.345445 | 
2025-12-26 00:23:42.345553 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-26 00:23:42.652482 | controller -> localhost | changed
2025-12-26 00:23:42.672747 | 
2025-12-26 00:23:42.672931 | TASK [add-build-sshkey : Add back temp key]
2025-12-26 00:23:42.976602 | controller -> localhost | Identity added: /var/lib/zuul/builds/6d86ce6562c2478d9750595947409e44/work/6d86ce6562c2478d9750595947409e44_id_ecdsa (zuul-build-sshkey)
2025-12-26 00:23:42.977151 | controller -> localhost | ok: Runtime: 0:00:00.011430
2025-12-26 00:23:42.994281 | 
2025-12-26 00:23:42.994557 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-26 00:23:43.233626 | controller | ok
2025-12-26 00:23:43.248576 | 
2025-12-26 00:23:43.248786 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-26 00:23:43.275792 | controller | skipping: Conditional result was False
2025-12-26 00:23:43.294587 | 
2025-12-26 00:23:43.294777 | TASK [include_role : remove-zuul-sshkey]
2025-12-26 00:23:43.320930 | controller | skipping: Conditional result was False
2025-12-26 00:23:43.331880 | 
2025-12-26 00:23:43.332047 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-26 00:23:43.561905 | controller | ok: "logs"
2025-12-26 00:23:43.562223 | controller | ok: All items complete
2025-12-26 00:23:43.562263 | 
2025-12-26 00:23:43.786970 | controller | ok: "artifacts"
2025-12-26 00:23:43.994248 | controller | ok: "docs"
2025-12-26 00:23:44.007704 | 
2025-12-26 00:23:44.007965 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-26 00:23:44.263990 | controller | changed: "logs"
2025-12-26 00:23:44.478383 | controller | changed: "artifacts"
2025-12-26 00:23:44.684615 | controller | changed: "docs"
2025-12-26 00:23:44.719321 | 
2025-12-26 00:23:44.719431 | PLAY RECAP
2025-12-26 00:23:44.719481 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-12-26 00:23:44.719507 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-26 00:23:44.719526 | 
2025-12-26 00:23:44.869294 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-12-26 00:23:44.871111 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-26 00:23:45.477633 | 
2025-12-26 00:23:45.477851 | PLAY [all]
2025-12-26 00:23:45.502503 | 
2025-12-26 00:23:45.502636 | TASK [Install binary dependencies]
2025-12-26 00:23:45.563109 | controller | ok
2025-12-26 00:23:45.586494 | 
2025-12-26 00:23:45.586764 | TASK [bindep : Include find tasks]
2025-12-26 00:23:45.620608 | controller | ok
2025-12-26 00:23:45.632331 | controller | included: /var/lib/zuul/builds/6d86ce6562c2478d9750595947409e44/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-26 00:23:45.642174 | 
2025-12-26 00:23:45.642375 | TASK [bindep : Look for bindep.txt]
2025-12-26 00:23:46.021923 | controller | ok
2025-12-26 00:23:46.035416 | 
2025-12-26 00:23:46.035636 | TASK [bindep : Define bindep_file fact]
2025-12-26 00:23:46.063143 | controller | skipping: Conditional result was False
2025-12-26 00:23:46.074351 | 
2025-12-26 00:23:46.074522 | TASK [bindep : Look for other-requirements.txt]
2025-12-26 00:23:46.290806 | controller | ok
2025-12-26 00:23:46.296748 | 
2025-12-26 00:23:46.296855 | TASK [bindep : Define bindep_file fact]
2025-12-26 00:23:46.321766 | controller | skipping: Conditional result was False
2025-12-26 00:23:46.328475 | 
2025-12-26 00:23:46.328556 | TASK [bindep : Look for bindep fallback file]
2025-12-26 00:23:46.352840 | controller | skipping: Conditional result was False
2025-12-26 00:23:46.360890 | 
2025-12-26 00:23:46.361004 | TASK [bindep : Define bindep_file fact]
2025-12-26 00:23:46.385211 | controller | skipping: Conditional result was False
2025-12-26 00:23:46.393363 | 
2025-12-26 00:23:46.393497 | TASK [bindep : Include bindep tasks]
2025-12-26 00:23:46.418909 | controller | skipping: Conditional result was False
2025-12-26 00:23:46.427394 | 
2025-12-26 00:23:46.427544 | TASK [bindep : Include install tasks]
2025-12-26 00:23:46.472397 | controller | skipping: Conditional result was False
2025-12-26 00:23:46.480231 | 
2025-12-26 00:23:46.480382 | LOOP [bindep : Include package tasks]
2025-12-26 00:23:46.541183 | 
2025-12-26 00:23:46.541384 | TASK [Run test-setup role]
2025-12-26 00:23:46.571178 | controller | ok
2025-12-26 00:23:46.595377 | 
2025-12-26 00:23:46.595569 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-26 00:23:46.808976 | controller | ok
2025-12-26 00:23:46.824397 | 
2025-12-26 00:23:46.824590 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-26 00:23:47.379783 | controller | skipping: Conditional result was False
2025-12-26 00:23:47.415550 | 
2025-12-26 00:23:47.416002 | PLAY RECAP
2025-12-26 00:23:47.416091 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-26 00:23:47.416130 | 
2025-12-26 00:23:47.594117 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-26 00:23:47.595280 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-26 00:23:48.364992 | 
2025-12-26 00:23:48.365150 | PLAY [controller]
2025-12-26 00:23:48.387303 | 
2025-12-26 00:23:48.387500 | TASK [Create the /root directory]
2025-12-26 00:23:48.807506 | controller | ok
2025-12-26 00:23:48.813636 | 
2025-12-26 00:23:48.813787 | TASK [Install glibc-langpack-en]
2025-12-26 00:23:52.761476 | controller | ok: Nothing to do
2025-12-26 00:23:52.771354 | 
2025-12-26 00:23:52.771534 | TASK [Ensure controller directory exists]
2025-12-26 00:23:52.982273 | controller | changed
2025-12-26 00:23:52.996955 | 
2025-12-26 00:23:52.997119 | TASK [Install container runtime]
2025-12-26 00:23:53.060170 | controller | ok
2025-12-26 00:23:53.107156 | 
2025-12-26 00:23:53.107311 | LOOP [ensure-podman : Find distribution installation]
2025-12-26 00:23:53.144890 | controller | ok: "/var/lib/zuul/builds/6d86ce6562c2478d9750595947409e44/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-12-26 00:23:53.151614 | controller | included: /var/lib/zuul/builds/6d86ce6562c2478d9750595947409e44/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-12-26 00:23:53.158068 | 
2025-12-26 00:23:53.158135 | TASK [ensure-podman : Install podman (RedHat)]
2025-12-26 00:25:02.300169 | controller | changed
2025-12-26 00:25:02.317431 | 
2025-12-26 00:25:02.317606 | TASK [ensure-podman : Fetch podman version]
2025-12-26 00:25:02.875398 | controller | Client:       Podman Engine
2025-12-26 00:25:02.898868 | controller | Version:      4.6.2
2025-12-26 00:25:02.898894 | controller | API Version:  4.6.2
2025-12-26 00:25:02.898903 | controller | Go Version:   go1.19.12
2025-12-26 00:25:02.898921 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-12-26 00:25:02.898930 | controller | OS/Arch:      linux/amd64
2025-12-26 00:25:03.365980 | controller | ok: Runtime: 0:00:00.178469
2025-12-26 00:25:03.373534 | 
2025-12-26 00:25:03.373632 | TASK [ensure-podman : Print podman version installed]
2025-12-26 00:25:03.406809 | Podman version: Client:       Podman Engine
2025-12-26 00:25:03.407058 | Version:      4.6.2
2025-12-26 00:25:03.407102 | API Version:  4.6.2
2025-12-26 00:25:03.407133 | Go Version:   go1.19.12
2025-12-26 00:25:03.407164 | Built:        Mon Aug 28 19:38:31 2023
2025-12-26 00:25:03.407197 | OS/Arch:      linux/amd64
2025-12-26 00:25:03.415653 | 
2025-12-26 00:25:03.415802 | TASK [ensure-podman : Validate podman engine]
2025-12-26 00:25:03.953275 | controller | skipping: Conditional result was False
2025-12-26 00:25:03.963879 | 
2025-12-26 00:25:03.964016 | TASK [ensure-podman : Set up docker compatability socket]
2025-12-26 00:25:03.990287 | controller | skipping: Conditional result was False
2025-12-26 00:25:04.008895 | 
2025-12-26 00:25:04.009063 | TASK [Ensure python3.8 is present]
2025-12-26 00:25:04.034762 | controller | skipping: Conditional result was False
2025-12-26 00:25:04.044101 | 
2025-12-26 00:25:04.044249 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-12-26 00:25:04.070699 | controller | ok
2025-12-26 00:25:04.102644 | 
2025-12-26 00:25:04.102808 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-12-26 00:25:05.652318 | controller | ok: Nothing to do
2025-12-26 00:25:05.663354 | 
2025-12-26 00:25:05.663532 | TASK [our-ensure-python : Also install python3-devel]
2025-12-26 00:25:15.489002 | controller | changed
2025-12-26 00:25:15.516596 | 
2025-12-26 00:25:15.516838 | TASK [Run ensure-virtualenv role]
2025-12-26 00:25:15.543209 | controller | ok
2025-12-26 00:25:15.575178 | 
2025-12-26 00:25:15.575402 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-12-26 00:25:15.861095 | controller | /usr/bin/virtualenv
2025-12-26 00:25:16.179219 | controller | ok: Runtime: 0:00:00.005137
2025-12-26 00:25:16.186672 | 
2025-12-26 00:25:16.186786 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-12-26 00:25:16.220875 | controller | skipping: Conditional result was False
2025-12-26 00:25:16.221204 | controller | ok: All items complete
2025-12-26 00:25:16.221235 | 
2025-12-26 00:25:16.236823 | 
2025-12-26 00:25:16.236978 | TASK [Find the full path of the Python interpreter]
2025-12-26 00:25:16.464914 | controller | /usr/bin/python3
2025-12-26 00:25:16.771437 | controller | ok
2025-12-26 00:25:16.781297 | 
2025-12-26 00:25:16.781473 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-12-26 00:25:17.604013 | controller | created virtual environment CPython3.11.0.final.0-64 in 492ms
2025-12-26 00:25:17.629959 | controller |   creator CPython3Posix(dest=/home/zuul/venv, clear=False, no_vcs_ignore=False, global=False)
2025-12-26 00:25:17.630387 | controller |   seeder FromAppData(extra_search_dir=/usr/share/python-wheels,download=False, pip=bundle, setuptools=bundle, wheel=bundle, via=copy, app_data_dir=/home/zuul/.local/share/virtualenv)
2025-12-26 00:25:17.630667 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-12-26 00:25:17.630917 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-12-26 00:25:17.824465 | controller | changed
2025-12-26 00:25:17.841661 | 
2025-12-26 00:25:17.841909 | TASK [Set selinux package]
2025-12-26 00:25:17.883466 | controller | ok
2025-12-26 00:25:17.898606 | 
2025-12-26 00:25:17.898809 | TASK [Set selinux package (Fedora)]
2025-12-26 00:25:17.951238 | controller | ok
2025-12-26 00:25:17.956575 | 
2025-12-26 00:25:17.956638 | TASK [Install selinux into virtualenv]
2025-12-26 00:25:55.339269 | controller | Collecting selinux-please-lie-to-me
2025-12-26 00:26:07.599359 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-12-26 00:26:07.920728 | controller | Collecting setuptools<50.0.0
2025-12-26 00:26:07.928652 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-12-26 00:26:07.990821 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 13.9 MB/s eta 0:00:00
2025-12-26 00:26:08.072137 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-12-26 00:26:08.072355 | controller |   Attempting uninstall: setuptools
2025-12-26 00:26:08.074845 | controller |     Found existing installation: setuptools 62.6.0
2025-12-26 00:26:08.138120 | controller |     Uninstalling setuptools-62.6.0:
2025-12-26 00:26:08.146546 | controller |       Successfully uninstalled setuptools-62.6.0
2025-12-26 00:26:08.493059 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-12-26 00:26:23.873080 | controller |
2025-12-26 00:26:23.955618 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-26 00:26:23.955666 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-26 00:26:24.234998 | controller | ok: Runtime: 0:01:05.799968
2025-12-26 00:26:24.248178 | 
2025-12-26 00:26:24.248359 | TASK [Install pytest-forked into virtualenv]
2025-12-26 00:26:36.122059 | controller | Collecting pytest-forked
2025-12-26 00:26:48.364950 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-12-26 00:26:48.406942 | controller | Collecting py
2025-12-26 00:26:48.411623 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-12-26 00:26:48.428771 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 6.1 MB/s eta 0:00:00
2025-12-26 00:26:48.529820 | controller | Collecting pytest>=3.10
2025-12-26 00:26:48.534553 | controller |   Downloading pytest-9.0.2-py3-none-any.whl (374 kB)
2025-12-26 00:26:48.552125 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 374.8/374.8 kB 23.7 MB/s eta 0:00:00
2025-12-26 00:26:48.583077 | controller | Collecting iniconfig>=1.0.1
2025-12-26 00:26:48.586587 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-12-26 00:26:48.626566 | controller | Collecting packaging>=22
2025-12-26 00:26:48.629935 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-12-26 00:26:48.635522 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 18.5 MB/s eta 0:00:00
2025-12-26 00:26:48.667072 | controller | Collecting pluggy<2,>=1.5
2025-12-26 00:26:48.670521 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-12-26 00:26:48.716685 | controller | Collecting pygments>=2.7.2
2025-12-26 00:26:48.724727 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-12-26 00:26:48.769409 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 30.9 MB/s eta 0:00:00
2025-12-26 00:26:48.836876 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-12-26 00:26:49.895317 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-9.0.2 pytest-forked-1.6.0
2025-12-26 00:26:49.904663 | controller |
2025-12-26 00:26:49.991895 | controller | [notice] A new release of pip available: 22.2.2 -> 25.3
2025-12-26 00:26:49.991937 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-12-26 00:26:50.316820 | controller | ok: Runtime: 0:00:25.500943
2025-12-26 00:26:50.325956 | 
2025-12-26 00:26:50.326053 | TASK [Update pip]
2025-12-26 00:26:50.837157 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-12-26 00:27:15.211224 | controller | Collecting pip
2025-12-26 00:27:27.420107 | controller |   Downloading pip-25.3-py3-none-any.whl (1.8 MB)
2025-12-26 00:27:27.479728 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 33.9 MB/s eta 0:00:00
2025-12-26 00:27:27.546965 | controller | Installing collected packages: pip
2025-12-26 00:27:27.547224 | controller |   Attempting uninstall: pip
2025-12-26 00:27:27.549458 | controller |     Found existing installation: pip 22.2.2
2025-12-26 00:27:27.705329 | controller |     Uninstalling pip-22.2.2:
2025-12-26 00:27:27.725734 | controller |       Successfully uninstalled pip-22.2.2
2025-12-26 00:27:28.605944 | controller | Successfully installed pip-25.3
2025-12-26 00:27:28.885825 | controller | ok: Runtime: 0:00:38.169768
2025-12-26 00:27:28.895945 | 
2025-12-26 00:27:28.896121 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-12-26 00:27:29.144666 | controller | changed
2025-12-26 00:27:29.152881 | 
2025-12-26 00:27:29.153093 | TASK [Install ansible into virtualenv]
2025-12-26 00:27:29.703156 | controller | Processing ./src/github.com/ansible/ansible
2025-12-26 00:27:29.706774 | controller |   Installing build dependencies: started
2025-12-26 00:28:18.883007 | controller |   Installing build dependencies: finished with status 'done'
2025-12-26 00:28:18.883495 | controller |   Getting requirements to build wheel: started
2025-12-26 00:28:19.627774 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-12-26 00:28:19.628750 | controller |   Preparing metadata (pyproject.toml): started
2025-12-26 00:28:20.089713 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-12-26 00:28:20.095675 | controller | INFO: pip is looking at multiple versions of ansible-core to determine which version is compatible with other requirements. This could take a while.
2025-12-26 00:28:20.100498 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-12-26 00:28:20.261199 | controller | ERROR
2025-12-26 00:28:20.261491 | controller | {
2025-12-26 00:28:20.261532 | controller |   "delta": "0:00:50.778770",
2025-12-26 00:28:20.261560 | controller |   "end": "2025-12-26 00:28:20.196011",
2025-12-26 00:28:20.261584 | controller |   "msg": "non-zero return code",
2025-12-26 00:28:20.261620 | controller |   "rc": 1,
2025-12-26 00:28:20.261645 | controller |   "start": "2025-12-26 00:27:29.417241"
2025-12-26 00:28:20.261667 | controller | }
failure
2025-12-26 00:28:20.263953 | 
2025-12-26 00:28:20.264006 | PLAY RECAP
2025-12-26 00:28:20.264064 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-12-26 00:28:20.264094 | 
2025-12-26 00:28:20.405606 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-12-26 00:28:20.406596 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-26 00:28:21.052599 | 
2025-12-26 00:28:21.052786 | PLAY [all]
2025-12-26 00:28:21.075354 | 
2025-12-26 00:28:21.075446 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-26 00:28:21.331289 | controller | changed: non-zero return code
2025-12-26 00:28:21.337268 | 
2025-12-26 00:28:21.337395 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-26 00:28:21.352773 | controller | skipping: Conditional result was False
2025-12-26 00:28:21.360070 | 
2025-12-26 00:28:21.360157 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-26 00:28:21.397202 | 
2025-12-26 00:28:21.397372 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-26 00:28:21.428513 | 
2025-12-26 00:28:21.428682 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-26 00:28:21.453598 | controller | skipping: Conditional result was False
2025-12-26 00:28:21.462783 | 
2025-12-26 00:28:21.462876 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-26 00:28:21.494980 | 
2025-12-26 00:28:21.495202 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-26 00:28:21.512055 | controller | skipping: Conditional result was False
2025-12-26 00:28:21.519249 | 
2025-12-26 00:28:21.519331 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-26 00:28:21.534230 | controller | skipping: Conditional result was False
2025-12-26 00:28:21.540941 | 
2025-12-26 00:28:21.541005 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-26 00:28:21.557064 | controller | skipping: Conditional result was False
2025-12-26 00:28:21.586333 | 
2025-12-26 00:28:21.586467 | PLAY RECAP
2025-12-26 00:28:21.586514 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-26 00:28:21.586535 | 
2025-12-26 00:28:21.731070 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-26 00:28:21.732236 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-12-26 00:28:22.391045 | 
2025-12-26 00:28:22.391284 | PLAY [all:!appliance*]
2025-12-26 00:28:22.423906 | 
2025-12-26 00:28:22.424097 | TASK [unregister the node]
2025-12-26 00:28:22.963179 | controller | skipping: Conditional result was False
2025-12-26 00:28:22.976263 | 
2025-12-26 00:28:22.976446 | TASK [include_role : fetch-output]
2025-12-26 00:28:23.010766 | controller | ok
2025-12-26 00:28:23.045909 | 
2025-12-26 00:28:23.046025 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-26 00:28:23.122599 | controller | skipping: Conditional result was False
2025-12-26 00:28:23.134798 | 
2025-12-26 00:28:23.134929 | TASK [fetch-output : Set log path for single node]
2025-12-26 00:28:23.178980 | controller | ok
2025-12-26 00:28:23.188801 | 
2025-12-26 00:28:23.188947 | LOOP [fetch-output : Ensure local output dirs]
2025-12-26 00:28:23.667663 | controller -> localhost | ok: "/var/lib/zuul/builds/6d86ce6562c2478d9750595947409e44/work/logs"
2025-12-26 00:28:23.907793 | controller -> localhost | changed: "/var/lib/zuul/builds/6d86ce6562c2478d9750595947409e44/work/artifacts"
2025-12-26 00:28:24.147804 | controller -> localhost | changed: "/var/lib/zuul/builds/6d86ce6562c2478d9750595947409e44/work/docs"
2025-12-26 00:28:24.166176 | 
2025-12-26 00:28:24.166342 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-26 00:28:24.917145 | controller | changed:
2025-12-26 00:28:24.917368 | controller | .d..t...... ./
2025-12-26 00:28:24.917397 | controller | cd+++++++++ controller/
2025-12-26 00:28:24.917429 | controller | changed: All items complete
2025-12-26 00:28:24.917449 | 
2025-12-26 00:28:25.478278 | controller | changed: .d..t...... ./
2025-12-26 00:28:25.972186 | controller | changed: .d..t...... ./
2025-12-26 00:28:26.005646 | 
2025-12-26 00:28:26.005909 | TASK [include_role : fetch-output-openshift]
2025-12-26 00:28:26.033266 | controller | skipping: Conditional result was False
2025-12-26 00:28:26.048632 | 
2025-12-26 00:28:26.048843 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-26 00:28:26.085003 | controller | skipping: Conditional result was False
2025-12-26 00:28:26.102996 | controller | skipping: Conditional result was False
2025-12-26 00:28:26.137155 | 
2025-12-26 00:28:26.137286 | PLAY [localhost]
2025-12-26 00:28:26.149973 | 
2025-12-26 00:28:26.150055 | TASK [Run Zuul manifest role]
2025-12-26 00:28:26.170080 | localhost | ok
2025-12-26 00:28:26.186220 | 
2025-12-26 00:28:26.186363 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-26 00:28:26.639149 | localhost | changed
2025-12-26 00:28:26.650360 | 
2025-12-26 00:28:26.650530 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-26 00:28:26.694134 | localhost | ok
2025-12-26 00:28:26.705511 | 
2025-12-26 00:28:26.705660 | TASK [Set zuul-log-path fact]
2025-12-26 00:28:26.728397 | localhost | ok
2025-12-26 00:28:26.747201 | 
2025-12-26 00:28:26.747363 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-26 00:28:26.788402 | localhost | ok
2025-12-26 00:28:26.800868 | 
2025-12-26 00:28:26.801020 | LOOP [Run upload-logs-swift role]
2025-12-26 00:28:26.837314 | localhost | Output suppressed because no_log was given
2025-12-26 00:28:26.866396 | 
2025-12-26 00:28:26.866512 | TASK [Set zuul-log-path fact]
2025-12-26 00:28:26.902474 | localhost | skipping: Conditional result was False
2025-12-26 00:28:26.911313 | 
2025-12-26 00:28:26.911495 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-12-26 00:28:27.373552 | localhost -> localhost | ok: Runtime: 0:00:00.009169
2025-12-26 00:28:27.430040 | 
2025-12-26 00:28:27.430230 | TASK [upload-logs-swift : Upload logs to swift]