2025-10-23 00:06:34.745586 | Job console starting...
2025-10-23 00:06:34.755054 | Updating repositories
2025-10-23 00:06:34.929819 | Preparing job workspace
2025-10-23 00:06:38.906900 | Running Ansible setup...
2025-10-23 00:06:44.825768 | PRE-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-23 00:06:45.460291 | 
2025-10-23 00:06:45.460410 | PLAY [localhost]
2025-10-23 00:06:45.479031 | 
2025-10-23 00:06:45.479124 | TASK [Gathering Facts]
2025-10-23 00:06:46.420917 | localhost | ok
2025-10-23 00:06:46.448303 | 
2025-10-23 00:06:46.448444 | TASK [Setup log path fact]
2025-10-23 00:06:46.466203 | localhost | ok
2025-10-23 00:06:46.478602 | 
2025-10-23 00:06:46.478726 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-23 00:06:46.506371 | localhost | ok
2025-10-23 00:06:46.514161 | 
2025-10-23 00:06:46.514237 | TASK [emit-job-header : Print job information]
2025-10-23 00:06:46.541605 | # Job Information
2025-10-23 00:06:46.541827 | Ansible Version: 2.15.12
2025-10-23 00:06:46.541864 | Job: ansible-test-sanity-docker-milestone
2025-10-23 00:06:46.541886 | Pipeline: periodic
2025-10-23 00:06:46.541905 | Executor: ze04.softwarefactory-project.io
2025-10-23 00:06:46.541924 | Triggered by: https://github.com/ansible-collections/ansible.network
2025-10-23 00:06:46.541945 | Log URL (when completed): https://ansible.softwarefactory-project.io/logs/b13/ansible/b13b681bb67a4a4e89d6e4c0bf0b089b/
2025-10-23 00:06:46.541969 | Event ID: 0b277d6fb2034b3eb017dadc7a95f30f
2025-10-23 00:06:46.545719 | 
2025-10-23 00:06:46.545794 | LOOP [emit-job-header : Print node information]
2025-10-23 00:06:46.649823 | localhost | ok:
2025-10-23 00:06:46.650017 | localhost | # Node Information
2025-10-23 00:06:46.650045 | localhost | Inventory Hostname: controller
2025-10-23 00:06:46.650065 | localhost | Hostname: ip-172-16-93-127
2025-10-23 00:06:46.650084 | localhost | Username: zuul-worker
2025-10-23 00:06:46.650104 | localhost | Distro: Fedora 37
2025-10-23 00:06:46.650126 | localhost | Provider: ansible-us-east-2
2025-10-23 00:06:46.650150 | localhost | Region: us-east-2
2025-10-23 00:06:46.650168 | localhost | Label: ansible-fedora-37-1vcpu
2025-10-23 00:06:46.650185 | localhost | Product Name: t3.small
2025-10-23 00:06:46.650202 | localhost | Interface IP: 18.118.115.236
2025-10-23 00:06:46.660114 | 
2025-10-23 00:06:46.660227 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-23 00:06:47.050885 | localhost -> localhost | changed
2025-10-23 00:06:47.056819 | 
2025-10-23 00:06:47.056898 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-23 00:06:47.809224 | localhost -> localhost | changed
2025-10-23 00:06:47.840894 | 
2025-10-23 00:06:47.841047 | PLAY [all:!appliance*]
2025-10-23 00:06:47.863470 | 
2025-10-23 00:06:47.863579 | TASK [include_role : start-zuul-console]
2025-10-23 00:06:47.882472 | controller | ok
2025-10-23 00:06:47.896250 | 
2025-10-23 00:06:47.896364 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-23 00:06:48.573720 | controller | ok
2025-10-23 00:06:48.593036 | 
2025-10-23 00:06:48.593152 | TASK [use-our-mirror : Retrieve the IP address]
2025-10-23 00:06:50.474619 | controller | ok: Status code was 404 and not [200]: HTTP Error 404: Not Found
2025-10-23 00:06:50.491863 | 
2025-10-23 00:06:50.492026 | TASK [use-our-mirror : Ensure the registry service is running on the mirror]
2025-10-23 00:06:50.647826 | controller | skipping: Conditional result was False
2025-10-23 00:06:50.658663 | 
2025-10-23 00:06:50.658863 | TASK [use-our-mirror : Write the IP in /etc/hosts]
2025-10-23 00:06:50.685210 | controller | skipping: Conditional result was False
2025-10-23 00:06:50.694375 | 
2025-10-23 00:06:50.694514 | TASK [use-our-mirror : Create the podman configuration directory]
2025-10-23 00:06:50.719602 | controller | skipping: Conditional result was False
2025-10-23 00:06:50.731834 | 
2025-10-23 00:06:50.732015 | TASK [use-our-mirror : Copy the podman configuration]
2025-10-23 00:06:50.757924 | controller | skipping: Conditional result was False
2025-10-23 00:06:50.778951 | 
2025-10-23 00:06:50.779077 | TASK [use-our-mirror : Copy the Yum configuration (main)]
2025-10-23 00:06:50.799832 | controller | skipping: Conditional result was False
2025-10-23 00:06:50.811249 | 
2025-10-23 00:06:50.811390 | TASK [use-our-mirror : Copy the Yum configuration (update)]
2025-10-23 00:06:50.825178 | controller | skipping: Conditional result was False
2025-10-23 00:06:50.842011 | 
2025-10-23 00:06:50.842098 | TASK [Disable Fedora Modular]
2025-10-23 00:06:51.595135 | controller | changed
2025-10-23 00:06:51.601262 | 
2025-10-23 00:06:51.601343 | TASK [Enable EPEL]
2025-10-23 00:06:51.626108 | controller | skipping: Conditional result was False
2025-10-23 00:06:51.632016 | 
2025-10-23 00:06:51.632087 | TASK [Register the RHEL node]
2025-10-23 00:06:51.792799 | 
2025-10-23 00:06:51.792990 | TASK [Show the subscription-manager status]
2025-10-23 00:06:51.980605 | controller | skipping: Conditional result was False
2025-10-23 00:06:51.987012 | 
2025-10-23 00:06:51.987087 | TASK [Enable EPEL on RHEL]
2025-10-23 00:06:52.146503 | controller | skipping: Conditional result was False
2025-10-23 00:06:52.153334 | 
2025-10-23 00:06:52.153417 | TASK [Install git and tox]
2025-10-23 00:08:25.613668 | controller | changed
2025-10-23 00:08:25.621945 | 
2025-10-23 00:08:25.622069 | TASK [include_role : prepare-workspace]
2025-10-23 00:08:25.653781 | controller | ok
2025-10-23 00:08:25.682537 | 
2025-10-23 00:08:25.682696 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-23 00:08:26.227170 | controller | ok
2025-10-23 00:08:26.243338 | 
2025-10-23 00:08:26.243490 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-23 00:08:42.837438 | controller | Output suppressed because no_log was given
2025-10-23 00:08:42.863461 | 
2025-10-23 00:08:42.863635 | TASK [include_role : prepare-workspace-openshift]
2025-10-23 00:08:42.889614 | controller | skipping: Conditional result was False
2025-10-23 00:08:42.926413 | 
2025-10-23 00:08:42.926537 | PLAY [all:!appliance]
2025-10-23 00:08:42.951810 | 
2025-10-23 00:08:42.952018 | TASK [Run add-build-sshkey role (RSA)]
2025-10-23 00:08:42.971954 | controller | ok
2025-10-23 00:08:42.987800 | 
2025-10-23 00:08:42.987888 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-23 00:08:43.224821 | controller -> localhost | ok
2025-10-23 00:08:43.231623 | 
2025-10-23 00:08:43.231710 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-23 00:08:43.293787 | controller | ok
2025-10-23 00:08:43.310405 | controller | included: /var/lib/zuul/builds/b13b681bb67a4a4e89d6e4c0bf0b089b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-23 00:08:43.317333 | 
2025-10-23 00:08:43.317421 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-23 00:08:43.790985 | controller -> localhost | Generating public/private rsa key pair.
2025-10-23 00:08:43.791282 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b13b681bb67a4a4e89d6e4c0bf0b089b/work/b13b681bb67a4a4e89d6e4c0bf0b089b_id_rsa.
2025-10-23 00:08:43.791324 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b13b681bb67a4a4e89d6e4c0bf0b089b/work/b13b681bb67a4a4e89d6e4c0bf0b089b_id_rsa.pub.
2025-10-23 00:08:43.791355 | controller -> localhost | The key fingerprint is:
2025-10-23 00:08:43.791384 | controller -> localhost | SHA256:TvAqNPd9GPo4hmXO0qmpPm4pw5Q/BjyP2JQGruNn8XY zuul-build-sshkey
2025-10-23 00:08:43.791412 | controller -> localhost | The key's randomart image is:
2025-10-23 00:08:43.791439 | controller -> localhost | +---[RSA 2048]----+
2025-10-23 00:08:43.791466 | controller -> localhost | |                 |
2025-10-23 00:08:43.791493 | controller -> localhost | |                 |
2025-10-23 00:08:43.791519 | controller -> localhost | |      .          |
2025-10-23 00:08:43.791545 | controller -> localhost | |.      o         |
2025-10-23 00:08:43.791572 | controller -> localhost | |.o oo . S .      |
2025-10-23 00:08:43.791614 | controller -> localhost | | .Xo o =oo o     |
2025-10-23 00:08:43.791650 | controller -> localhost | |.B *+..B+.o .    |
2025-10-23 00:08:43.791811 | controller -> localhost | |+ *oO+oEBo .     |
2025-10-23 00:08:43.791863 | controller -> localhost | |.ooB=+++...      |
2025-10-23 00:08:43.791897 | controller -> localhost | +----[SHA256]-----+
2025-10-23 00:08:43.791964 | controller -> localhost | ok: Runtime: 0:00:00.045367
2025-10-23 00:08:43.802819 | 
2025-10-23 00:08:43.802922 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-23 00:08:43.840498 | controller | ok
2025-10-23 00:08:43.854887 | controller | included: /var/lib/zuul/builds/b13b681bb67a4a4e89d6e4c0bf0b089b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-23 00:08:43.865559 | 
2025-10-23 00:08:43.865638 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-23 00:08:43.889739 | controller | skipping: Conditional result was False
2025-10-23 00:08:43.896304 | 
2025-10-23 00:08:43.896372 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-23 00:08:44.527160 | controller | changed
2025-10-23 00:08:44.541498 | 
2025-10-23 00:08:44.541756 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-23 00:08:44.889526 | controller | ok
2025-10-23 00:08:44.902825 | 
2025-10-23 00:08:44.903018 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-23 00:08:46.191630 | controller | changed
2025-10-23 00:08:46.205487 | 
2025-10-23 00:08:46.205649 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-23 00:08:47.761108 | controller | changed
2025-10-23 00:08:47.780921 | 
2025-10-23 00:08:47.781102 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-23 00:08:47.808063 | controller | skipping: Conditional result was False
2025-10-23 00:08:47.817202 | 
2025-10-23 00:08:47.817313 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-23 00:08:48.221825 | controller -> localhost | changed
2025-10-23 00:08:48.240071 | 
2025-10-23 00:08:48.240188 | TASK [add-build-sshkey : Add back temp key]
2025-10-23 00:08:48.512622 | controller -> localhost | Identity added: /var/lib/zuul/builds/b13b681bb67a4a4e89d6e4c0bf0b089b/work/b13b681bb67a4a4e89d6e4c0bf0b089b_id_rsa (zuul-build-sshkey)
2025-10-23 00:08:48.513217 | controller -> localhost | ok: Runtime: 0:00:00.009725
2025-10-23 00:08:48.523704 | 
2025-10-23 00:08:48.523837 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-23 00:08:48.995839 | controller | ok
2025-10-23 00:08:49.009642 | 
2025-10-23 00:08:49.009855 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-23 00:08:49.038912 | controller | skipping: Conditional result was False
2025-10-23 00:08:49.067622 | 
2025-10-23 00:08:49.069180 | TASK [Run add-build-sshkey role (ECDSA)]
2025-10-23 00:08:49.105099 | controller | ok
2025-10-23 00:08:49.135209 | 
2025-10-23 00:08:49.135470 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-23 00:08:49.477485 | controller -> localhost | ok
2025-10-23 00:08:49.485118 | 
2025-10-23 00:08:49.485207 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-23 00:08:49.512873 | controller | ok
2025-10-23 00:08:49.526416 | controller | included: /var/lib/zuul/builds/b13b681bb67a4a4e89d6e4c0bf0b089b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-23 00:08:49.534905 | 
2025-10-23 00:08:49.535003 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-23 00:08:49.871092 | controller -> localhost | Generating public/private ecdsa key pair.
2025-10-23 00:08:49.871430 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b13b681bb67a4a4e89d6e4c0bf0b089b/work/b13b681bb67a4a4e89d6e4c0bf0b089b_id_ecdsa.
2025-10-23 00:08:49.871477 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b13b681bb67a4a4e89d6e4c0bf0b089b/work/b13b681bb67a4a4e89d6e4c0bf0b089b_id_ecdsa.pub.
2025-10-23 00:08:49.871518 | controller -> localhost | The key fingerprint is:
2025-10-23 00:08:49.871547 | controller -> localhost | SHA256:+nuF7T1pKo21C4sm4hR/heYP/NehTLKhrKvPPW0u0u0 zuul-build-sshkey
2025-10-23 00:08:49.871574 | controller -> localhost | The key's randomart image is:
2025-10-23 00:08:49.871600 | controller -> localhost | +---[ECDSA 521]---+
2025-10-23 00:08:49.871626 | controller -> localhost | |                 |
2025-10-23 00:08:49.871650 | controller -> localhost | |                 |
2025-10-23 00:08:49.872066 | controller -> localhost | |                 |
2025-10-23 00:08:49.872137 | controller -> localhost | |         .       |
2025-10-23 00:08:49.872171 | controller -> localhost | |    .   S .o     |
2025-10-23 00:08:49.872210 | controller -> localhost | |     o = .+ = .  |
2025-10-23 00:08:49.872250 | controller -> localhost | |    . oo=+.% = o |
2025-10-23 00:08:49.872287 | controller -> localhost | |   ...o+B=OoB *  |
2025-10-23 00:08:49.872318 | controller -> localhost | |   .o+=*=OEoo+ . |
2025-10-23 00:08:49.872352 | controller -> localhost | +----[SHA256]-----+
2025-10-23 00:08:49.872431 | controller -> localhost | ok: Runtime: 0:00:00.028989
2025-10-23 00:08:49.883896 | 
2025-10-23 00:08:49.884028 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-23 00:08:49.919499 | controller | ok
2025-10-23 00:08:49.933473 | controller | included: /var/lib/zuul/builds/b13b681bb67a4a4e89d6e4c0bf0b089b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-23 00:08:49.949951 | 
2025-10-23 00:08:49.950092 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-23 00:08:49.976200 | controller | skipping: Conditional result was False
2025-10-23 00:08:49.983483 | 
2025-10-23 00:08:49.983575 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-23 00:08:50.450885 | controller | changed
2025-10-23 00:08:50.465156 | 
2025-10-23 00:08:50.465304 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-23 00:08:50.826392 | controller | ok
2025-10-23 00:08:50.844710 | 
2025-10-23 00:08:50.844916 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-23 00:08:52.115054 | controller | changed
2025-10-23 00:08:52.130419 | 
2025-10-23 00:08:52.130623 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-23 00:08:53.659878 | controller | changed
2025-10-23 00:08:53.675968 | 
2025-10-23 00:08:53.676127 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-23 00:08:53.704328 | controller | skipping: Conditional result was False
2025-10-23 00:08:53.718651 | 
2025-10-23 00:08:53.718841 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-23 00:08:54.001272 | controller -> localhost | changed
2025-10-23 00:08:54.012816 | 
2025-10-23 00:08:54.012999 | TASK [add-build-sshkey : Add back temp key]
2025-10-23 00:08:54.364187 | controller -> localhost | Identity added: /var/lib/zuul/builds/b13b681bb67a4a4e89d6e4c0bf0b089b/work/b13b681bb67a4a4e89d6e4c0bf0b089b_id_ecdsa (zuul-build-sshkey)
2025-10-23 00:08:54.364655 | controller -> localhost | ok: Runtime: 0:00:00.013196
2025-10-23 00:08:54.378261 | 
2025-10-23 00:08:54.378402 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-23 00:08:54.745200 | controller | ok
2025-10-23 00:08:54.762042 | 
2025-10-23 00:08:54.762266 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-23 00:08:54.802311 | controller | skipping: Conditional result was False
2025-10-23 00:08:54.828974 | 
2025-10-23 00:08:54.829157 | TASK [include_role : remove-zuul-sshkey]
2025-10-23 00:08:54.845998 | controller | skipping: Conditional result was False
2025-10-23 00:08:54.852931 | 
2025-10-23 00:08:54.853014 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-23 00:08:55.212300 | controller | ok: "logs"
2025-10-23 00:08:55.212830 | controller | ok: All items complete
2025-10-23 00:08:55.213017 | 
2025-10-23 00:08:55.488406 | controller | ok: "artifacts"
2025-10-23 00:08:55.844827 | controller | ok: "docs"
2025-10-23 00:08:55.861880 | 
2025-10-23 00:08:55.861986 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-23 00:08:56.233977 | controller | changed: "logs"
2025-10-23 00:08:56.947831 | controller | changed: "artifacts"
2025-10-23 00:08:57.257332 | controller | changed: "docs"
2025-10-23 00:08:57.299929 | 
2025-10-23 00:08:57.300048 | PLAY RECAP
2025-10-23 00:08:57.300104 | controller | ok: 30 changed: 16 unreachable: 0 failed: 0 skipped: 18 rescued: 0 ignored: 0
2025-10-23 00:08:57.300139 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-23 00:08:57.300163 | 
2025-10-23 00:08:57.443839 | PRE-RUN END RESULT_NORMAL: [trusted : github.com/ansible/zuul-config/playbooks/base/pre.yaml@master]
2025-10-23 00:08:57.445406 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-23 00:08:58.115525 | 
2025-10-23 00:08:58.115702 | PLAY [all]
2025-10-23 00:08:58.144036 | 
2025-10-23 00:08:58.144155 | TASK [Install binary dependencies]
2025-10-23 00:08:58.194825 | controller | ok
2025-10-23 00:08:58.222507 | 
2025-10-23 00:08:58.222665 | TASK [bindep : Include find tasks]
2025-10-23 00:08:58.274846 | controller | ok
2025-10-23 00:08:58.285623 | controller | included: /var/lib/zuul/builds/b13b681bb67a4a4e89d6e4c0bf0b089b/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-10-23 00:08:58.293806 | 
2025-10-23 00:08:58.293898 | TASK [bindep : Look for bindep.txt]
2025-10-23 00:08:58.828810 | controller | ok
2025-10-23 00:08:58.837260 | 
2025-10-23 00:08:58.837378 | TASK [bindep : Define bindep_file fact]
2025-10-23 00:08:58.870988 | controller | skipping: Conditional result was False
2025-10-23 00:08:58.878368 | 
2025-10-23 00:08:58.878484 | TASK [bindep : Look for other-requirements.txt]
2025-10-23 00:08:59.216049 | controller | ok
2025-10-23 00:08:59.228643 | 
2025-10-23 00:08:59.228849 | TASK [bindep : Define bindep_file fact]
2025-10-23 00:08:59.255492 | controller | skipping: Conditional result was False
2025-10-23 00:08:59.264487 | 
2025-10-23 00:08:59.264609 | TASK [bindep : Look for bindep fallback file]
2025-10-23 00:08:59.290205 | controller | skipping: Conditional result was False
2025-10-23 00:08:59.299815 | 
2025-10-23 00:08:59.299942 | TASK [bindep : Define bindep_file fact]
2025-10-23 00:08:59.324753 | controller | skipping: Conditional result was False
2025-10-23 00:08:59.333605 | 
2025-10-23 00:08:59.333774 | TASK [bindep : Include bindep tasks]
2025-10-23 00:08:59.358631 | controller | skipping: Conditional result was False
2025-10-23 00:08:59.373339 | 
2025-10-23 00:08:59.373506 | TASK [bindep : Include install tasks]
2025-10-23 00:08:59.399406 | controller | skipping: Conditional result was False
2025-10-23 00:08:59.407712 | 
2025-10-23 00:08:59.407819 | LOOP [bindep : Include package tasks]
2025-10-23 00:08:59.463247 | 
2025-10-23 00:08:59.463413 | TASK [Run test-setup role]
2025-10-23 00:08:59.482231 | controller | ok
2025-10-23 00:08:59.502942 | 
2025-10-23 00:08:59.503064 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-10-23 00:08:59.786232 | controller | ok
2025-10-23 00:08:59.791940 | 
2025-10-23 00:08:59.792009 | TASK [test-setup : Run tools/test-setup.sh]
2025-10-23 00:08:59.943060 | controller | skipping: Conditional result was False
2025-10-23 00:08:59.994822 | 
2025-10-23 00:08:59.995003 | PLAY RECAP
2025-10-23 00:08:59.995066 | controller | ok: 4 changed: 0 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-23 00:08:59.995096 | 
2025-10-23 00:09:00.113735 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-10-23 00:09:00.114854 | PRE-RUN START: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-23 00:09:00.816298 | 
2025-10-23 00:09:00.816434 | PLAY [controller]
2025-10-23 00:09:00.836191 | 
2025-10-23 00:09:00.836315 | TASK [Create the /root directory]
2025-10-23 00:09:01.868915 | controller | ok
2025-10-23 00:09:01.876966 | 
2025-10-23 00:09:01.877088 | TASK [Install glibc-langpack-en]
2025-10-23 00:09:10.334157 | controller | ok: Nothing to do
2025-10-23 00:09:10.341082 | 
2025-10-23 00:09:10.341149 | TASK [Ensure controller directory exists]
2025-10-23 00:09:10.772208 | controller | changed
2025-10-23 00:09:10.780011 | 
2025-10-23 00:09:10.780101 | TASK [Install container runtime]
2025-10-23 00:09:10.845733 | controller | ok
2025-10-23 00:09:10.897129 | 
2025-10-23 00:09:10.897284 | LOOP [ensure-podman : Find distribution installation]
2025-10-23 00:09:10.926671 | controller | ok: "/var/lib/zuul/builds/b13b681bb67a4a4e89d6e4c0bf0b089b/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml"
2025-10-23 00:09:10.945874 | controller | included: /var/lib/zuul/builds/b13b681bb67a4a4e89d6e4c0bf0b089b/untrusted/project_0/opendev.org/zuul/zuul-jobs/roles/ensure-podman/tasks/RedHat.yaml
2025-10-23 00:09:10.955065 | 
2025-10-23 00:09:10.955182 | TASK [ensure-podman : Install podman (RedHat)]
2025-10-23 00:10:27.648646 | controller | changed
2025-10-23 00:10:27.655788 | 
2025-10-23 00:10:27.655882 | TASK [ensure-podman : Fetch podman version]
2025-10-23 00:10:28.352898 | controller | Client:       Podman Engine
2025-10-23 00:10:28.378971 | controller | Version:      4.6.2
2025-10-23 00:10:28.379011 | controller | API Version:  4.6.2
2025-10-23 00:10:28.379018 | controller | Go Version:   go1.19.12
2025-10-23 00:10:28.379037 | controller | Built:        Mon Aug 28 19:38:31 2023
2025-10-23 00:10:28.379044 | controller | OS/Arch:      linux/amd64
2025-10-23 00:10:28.812125 | controller | ok: Runtime: 0:00:00.216192
2025-10-23 00:10:28.819341 | 
2025-10-23 00:10:28.819438 | TASK [ensure-podman : Print podman version installed]
2025-10-23 00:10:28.849311 | Podman version: Client:       Podman Engine
2025-10-23 00:10:28.849510 | Version:      4.6.2
2025-10-23 00:10:28.849540 | API Version:  4.6.2
2025-10-23 00:10:28.849560 | Go Version:   go1.19.12
2025-10-23 00:10:28.849578 | Built:        Mon Aug 28 19:38:31 2023
2025-10-23 00:10:28.849597 | OS/Arch:      linux/amd64
2025-10-23 00:10:28.854867 | 
2025-10-23 00:10:28.854929 | TASK [ensure-podman : Validate podman engine]
2025-10-23 00:10:28.996541 | controller | skipping: Conditional result was False
2025-10-23 00:10:29.006723 | 
2025-10-23 00:10:29.006847 | TASK [ensure-podman : Set up docker compatability socket]
2025-10-23 00:10:29.023853 | controller | skipping: Conditional result was False
2025-10-23 00:10:29.040327 | 
2025-10-23 00:10:29.040438 | TASK [Ensure python3.8 is present]
2025-10-23 00:10:29.066490 | controller | skipping: Conditional result was False
2025-10-23 00:10:29.075063 | 
2025-10-23 00:10:29.075154 | TASK [Run our-ensure-python role (Fedora only for now)]
2025-10-23 00:10:29.097811 | controller | ok
2025-10-23 00:10:29.126923 | 
2025-10-23 00:10:29.127061 | TASK [our-ensure-python : Install the right Python version (rpm)]
2025-10-23 00:10:32.764335 | controller | ok: Nothing to do
2025-10-23 00:10:32.769907 | 
2025-10-23 00:10:32.769975 | TASK [our-ensure-python : Also install python3-devel]
2025-10-23 00:10:46.375379 | controller | changed
2025-10-23 00:10:46.391079 | 
2025-10-23 00:10:46.391219 | TASK [Run ensure-virtualenv role]
2025-10-23 00:10:46.414712 | controller | ok
2025-10-23 00:10:46.446831 | 
2025-10-23 00:10:46.447001 | TASK [ensure-virtualenv : Check if virtualenv is installed]
2025-10-23 00:10:46.907560 | controller | /usr/bin/virtualenv
2025-10-23 00:10:47.135337 | controller | ok: Runtime: 0:00:00.004833
2025-10-23 00:10:47.145120 | 
2025-10-23 00:10:47.145347 | LOOP [ensure-virtualenv : Install virtualenv package]
2025-10-23 00:10:47.182573 | controller | skipping: Conditional result was False
2025-10-23 00:10:47.183044 | controller | ok: All items complete
2025-10-23 00:10:47.183093 | 
2025-10-23 00:10:47.210623 | 
2025-10-23 00:10:47.210811 | TASK [Find the full path of the Python interpreter]
2025-10-23 00:10:47.649836 | controller | /usr/bin/python3
2025-10-23 00:10:47.858493 | controller | ok
2025-10-23 00:10:47.870665 | 
2025-10-23 00:10:47.870883 | TASK [Create virtualenv for ansible-test with a specific interpreter]
2025-10-23 00:10:49.336131 | controller | created virtual environment CPython3.11.0.final.0-64 in 772ms
2025-10-23 00:10:49.391219 | controller |   creator CPython3Posix(dest=/home/zuul-worker/venv, clear=False, no_vcs_ignore=False, global=False)
2025-10-23 00:10:49.391281 | 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-worker/.local/share/virtualenv)
2025-10-23 00:10:49.391297 | controller |     added seed packages: pip==22.2.2, setuptools==62.6.0, wheel==0.37.1
2025-10-23 00:10:49.391320 | controller |   activators BashActivator,CShellActivator,FishActivator,NushellActivator,PowerShellActivator,PythonActivator
2025-10-23 00:10:49.546762 | controller | changed
2025-10-23 00:10:49.560924 | 
2025-10-23 00:10:49.561067 | TASK [Set selinux package]
2025-10-23 00:10:49.602049 | controller | ok
2025-10-23 00:10:49.616094 | 
2025-10-23 00:10:49.616518 | TASK [Set selinux package (Fedora)]
2025-10-23 00:10:49.660063 | controller | ok
2025-10-23 00:10:49.665783 | 
2025-10-23 00:10:49.665853 | TASK [Install selinux into virtualenv]
2025-10-23 00:10:52.246402 | controller | Collecting selinux-please-lie-to-me
2025-10-23 00:10:52.351382 | controller |   Downloading selinux_please_lie_to_me-1.0.1-py2.py3-none-any.whl (3.8 kB)
2025-10-23 00:10:52.883297 | controller | Collecting setuptools<50.0.0
2025-10-23 00:10:52.898773 | controller |   Downloading setuptools-49.6.0-py3-none-any.whl (803 kB)
2025-10-23 00:10:53.036895 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 803.3/803.3 kB 6.0 MB/s eta 0:00:00
2025-10-23 00:10:53.190066 | controller | Installing collected packages: setuptools, selinux-please-lie-to-me
2025-10-23 00:10:53.190498 | controller |   Attempting uninstall: setuptools
2025-10-23 00:10:53.195374 | controller |     Found existing installation: setuptools 62.6.0
2025-10-23 00:10:53.306556 | controller |     Uninstalling setuptools-62.6.0:
2025-10-23 00:10:53.321734 | controller |       Successfully uninstalled setuptools-62.6.0
2025-10-23 00:10:54.059470 | controller | Successfully installed selinux-please-lie-to-me-1.0.1 setuptools-49.6.0
2025-10-23 00:10:54.270227 | controller |
2025-10-23 00:10:54.484230 | controller | [notice] A new release of pip available: 22.2.2 -> 25.2
2025-10-23 00:10:54.484276 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-10-23 00:10:54.814470 | controller | ok: Runtime: 0:00:04.338870
2025-10-23 00:10:54.827784 | 
2025-10-23 00:10:54.827945 | TASK [Install pytest-forked into virtualenv]
2025-10-23 00:10:56.066785 | controller | Collecting pytest-forked
2025-10-23 00:10:56.154139 | controller |   Downloading pytest_forked-1.6.0-py3-none-any.whl (4.9 kB)
2025-10-23 00:10:56.213554 | controller | Collecting py
2025-10-23 00:10:56.225708 | controller |   Downloading py-1.11.0-py2.py3-none-any.whl (98 kB)
2025-10-23 00:10:56.259233 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.7/98.7 kB 3.3 MB/s eta 0:00:00
2025-10-23 00:10:56.435761 | controller | Collecting pytest>=3.10
2025-10-23 00:10:56.448400 | controller |   Downloading pytest-8.4.2-py3-none-any.whl (365 kB)
2025-10-23 00:10:56.500558 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 365.8/365.8 kB 7.6 MB/s eta 0:00:00
2025-10-23 00:10:56.559053 | controller | Collecting iniconfig>=1
2025-10-23 00:10:56.571555 | controller |   Downloading iniconfig-2.3.0-py3-none-any.whl (7.5 kB)
2025-10-23 00:10:56.639645 | controller | Collecting packaging>=20
2025-10-23 00:10:56.652287 | controller |   Downloading packaging-25.0-py3-none-any.whl (66 kB)
2025-10-23 00:10:56.662245 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 66.5/66.5 kB 9.1 MB/s eta 0:00:00
2025-10-23 00:10:56.709971 | controller | Collecting pluggy<2,>=1.5
2025-10-23 00:10:56.721947 | controller |   Downloading pluggy-1.6.0-py3-none-any.whl (20 kB)
2025-10-23 00:10:56.795271 | controller | Collecting pygments>=2.7.2
2025-10-23 00:10:56.807285 | controller |   Downloading pygments-2.19.2-py3-none-any.whl (1.2 MB)
2025-10-23 00:10:56.908288 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.2/1.2 MB 12.5 MB/s eta 0:00:00
2025-10-23 00:10:57.034625 | controller | Installing collected packages: pygments, py, pluggy, packaging, iniconfig, pytest, pytest-forked
2025-10-23 00:10:59.279472 | controller | Successfully installed iniconfig-2.3.0 packaging-25.0 pluggy-1.6.0 py-1.11.0 pygments-2.19.2 pytest-8.4.2 pytest-forked-1.6.0
2025-10-23 00:10:59.295343 | controller |
2025-10-23 00:10:59.472173 | controller | [notice] A new release of pip available: 22.2.2 -> 25.2
2025-10-23 00:10:59.472241 | controller | [notice] To update, run: python -m pip install --upgrade pip
2025-10-23 00:11:00.000031 | controller | ok: Runtime: 0:00:04.142483
2025-10-23 00:11:00.007017 | 
2025-10-23 00:11:00.007131 | TASK [Update pip]
2025-10-23 00:11:01.069801 | controller | Requirement already satisfied: pip in ./venv/lib/python3.11/site-packages (22.2.2)
2025-10-23 00:11:01.341683 | controller | Collecting pip
2025-10-23 00:11:01.449844 | controller |   Downloading pip-25.2-py3-none-any.whl (1.8 MB)
2025-10-23 00:11:01.546912 | controller |      ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.8/1.8 MB 18.9 MB/s eta 0:00:00
2025-10-23 00:11:01.671762 | controller | Installing collected packages: pip
2025-10-23 00:11:01.672167 | controller |   Attempting uninstall: pip
2025-10-23 00:11:01.676750 | controller |     Found existing installation: pip 22.2.2
2025-10-23 00:11:01.936666 | controller |     Uninstalling pip-22.2.2:
2025-10-23 00:11:01.966575 | controller |       Successfully uninstalled pip-22.2.2
2025-10-23 00:11:03.755715 | controller | Successfully installed pip-25.2
2025-10-23 00:11:04.145274 | controller | ok: Runtime: 0:00:03.482540
2025-10-23 00:11:04.159253 | 
2025-10-23 00:11:04.159389 | TASK [Ensure pip temp directory exists in /var/tmp]
2025-10-23 00:11:04.685221 | controller | changed
2025-10-23 00:11:04.692990 | 
2025-10-23 00:11:04.693076 | TASK [Install ansible into virtualenv]
2025-10-23 00:11:05.767925 | controller | Processing ./src/github.com/ansible/ansible
2025-10-23 00:11:05.774454 | controller |   Installing build dependencies: started
2025-10-23 00:11:07.647617 | controller |   Installing build dependencies: finished with status 'done'
2025-10-23 00:11:09.163240 | controller |   Getting requirements to build wheel: started
2025-10-23 00:11:09.163307 | controller |   Getting requirements to build wheel: finished with status 'done'
2025-10-23 00:11:09.164941 | controller |   Preparing metadata (pyproject.toml): started
2025-10-23 00:11:10.091260 | controller |   Preparing metadata (pyproject.toml): finished with status 'done'
2025-10-23 00:11:10.093746 | 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-10-23 00:11:10.098663 | controller | ERROR: Package 'ansible-core' requires a different Python: 3.11.0 not in '>=3.12'
2025-10-23 00:11:10.364253 | controller | ERROR
2025-10-23 00:11:10.364574 | controller | {
2025-10-23 00:11:10.364638 | controller |   "delta": "0:00:05.111584",
2025-10-23 00:11:10.364715 | controller |   "end": "2025-10-23 00:11:10.248534",
2025-10-23 00:11:10.364764 | controller |   "msg": "non-zero return code",
2025-10-23 00:11:10.364817 | controller |   "rc": 1,
2025-10-23 00:11:10.364854 | controller |   "start": "2025-10-23 00:11:05.136950"
2025-10-23 00:11:10.364890 | controller | }
failure
2025-10-23 00:11:10.367315 | 
2025-10-23 00:11:10.367427 | PLAY RECAP
2025-10-23 00:11:10.367526 | controller | ok: 18 changed: 10 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0
2025-10-23 00:11:10.367581 | 
2025-10-23 00:11:10.492617 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/ansible/ansible-zuul-jobs/playbooks/ansible-test-base/pre.yaml@master]
2025-10-23 00:11:10.493760 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-23 00:11:11.125537 | 
2025-10-23 00:11:11.125661 | PLAY [all]
2025-10-23 00:11:11.148349 | 
2025-10-23 00:11:11.148498 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-10-23 00:11:12.821657 | controller | changed: non-zero return code
2025-10-23 00:11:12.833643 | 
2025-10-23 00:11:12.833816 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-10-23 00:11:12.858390 | controller | skipping: Conditional result was False
2025-10-23 00:11:12.864658 | 
2025-10-23 00:11:12.864936 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-10-23 00:11:12.895706 | 
2025-10-23 00:11:12.895859 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-10-23 00:11:12.929866 | 
2025-10-23 00:11:12.930076 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-10-23 00:11:12.945255 | controller | skipping: Conditional result was False
2025-10-23 00:11:12.955408 | 
2025-10-23 00:11:12.955526 | LOOP [fetch-subunit-output : Generate subunit file]
2025-10-23 00:11:12.981515 | 
2025-10-23 00:11:12.981783 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-10-23 00:11:12.996667 | controller | skipping: Conditional result was False
2025-10-23 00:11:13.005636 | 
2025-10-23 00:11:13.005823 | TASK [fetch-subunit-output : Remove the temporary file]
2025-10-23 00:11:13.021155 | controller | skipping: Conditional result was False
2025-10-23 00:11:13.028376 | 
2025-10-23 00:11:13.028486 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-10-23 00:11:13.042259 | controller | skipping: Conditional result was False
2025-10-23 00:11:13.073825 | 
2025-10-23 00:11:13.073935 | PLAY RECAP
2025-10-23 00:11:13.073986 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-10-23 00:11:13.074014 | 
2025-10-23 00:11:13.175188 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-10-23 00:11:13.176416 | POST-RUN START: [trusted : github.com/ansible/zuul-config/playbooks/base/post.yaml@master]
2025-10-23 00:11:13.807796 | 
2025-10-23 00:11:13.807913 | PLAY [all:!appliance*]
2025-10-23 00:11:13.828628 | 
2025-10-23 00:11:13.828741 | TASK [unregister the node]
2025-10-23 00:11:13.975955 | controller | skipping: Conditional result was False
2025-10-23 00:11:13.988406 | 
2025-10-23 00:11:13.988572 | TASK [include_role : fetch-output]
2025-10-23 00:11:14.036269 | controller | ok
2025-10-23 00:11:14.077886 | 
2025-10-23 00:11:14.078151 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-23 00:11:14.146525 | controller | skipping: Conditional result was False
2025-10-23 00:11:14.154334 | 
2025-10-23 00:11:14.154467 | TASK [fetch-output : Set log path for single node]
2025-10-23 00:11:14.185848 | controller | ok
2025-10-23 00:11:14.191638 | 
2025-10-23 00:11:14.191759 | LOOP [fetch-output : Ensure local output dirs]
2025-10-23 00:11:14.587652 | controller -> localhost | ok: "/var/lib/zuul/builds/b13b681bb67a4a4e89d6e4c0bf0b089b/work/logs"
2025-10-23 00:11:14.825832 | controller -> localhost | changed: "/var/lib/zuul/builds/b13b681bb67a4a4e89d6e4c0bf0b089b/work/artifacts"
2025-10-23 00:11:15.051996 | controller -> localhost | changed: "/var/lib/zuul/builds/b13b681bb67a4a4e89d6e4c0bf0b089b/work/docs"
2025-10-23 00:11:15.065521 | 
2025-10-23 00:11:15.065661 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-23 00:11:16.358965 | controller | changed:
2025-10-23 00:11:16.359155 | controller | .d..t...... ./
2025-10-23 00:11:16.359183 | controller | cd+++++++++ controller/
2025-10-23 00:11:16.359217 | controller | changed: All items complete
2025-10-23 00:11:16.359238 | 
2025-10-23 00:11:17.496538 | controller | changed: .d..t...... ./
2025-10-23 00:11:18.582169 | controller | changed: .d..t...... ./
2025-10-23 00:11:18.618443 | 
2025-10-23 00:11:18.618667 | TASK [include_role : fetch-output-openshift]
2025-10-23 00:11:18.636033 | controller | skipping: Conditional result was False
2025-10-23 00:11:18.653452 | 
2025-10-23 00:11:18.653651 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-23 00:11:18.701320 | controller | skipping: Conditional result was False
2025-10-23 00:11:18.717105 | controller | skipping: Conditional result was False
2025-10-23 00:11:18.752789 | 
2025-10-23 00:11:18.752901 | PLAY [localhost]
2025-10-23 00:11:18.766270 | 
2025-10-23 00:11:18.766343 | TASK [Run Zuul manifest role]
2025-10-23 00:11:18.785083 | localhost | ok
2025-10-23 00:11:18.845440 | 
2025-10-23 00:11:18.845541 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-23 00:11:19.248387 | localhost | changed
2025-10-23 00:11:19.257996 | 
2025-10-23 00:11:19.258128 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-23 00:11:19.292495 | localhost | ok
2025-10-23 00:11:19.309527 | 
2025-10-23 00:11:19.309718 | TASK [Set zuul-log-path fact]
2025-10-23 00:11:19.333880 | localhost | ok
2025-10-23 00:11:19.360041 | 
2025-10-23 00:11:19.360144 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-23 00:11:19.400203 | localhost | ok
2025-10-23 00:11:19.412908 | 
2025-10-23 00:11:19.412995 | LOOP [Run upload-logs-swift role]
2025-10-23 00:11:19.450422 | localhost | Output suppressed because no_log was given
2025-10-23 00:11:19.477471 | 
2025-10-23 00:11:19.477559 | TASK [Set zuul-log-path fact]
2025-10-23 00:11:19.512034 | localhost | skipping: Conditional result was False
2025-10-23 00:11:19.517301 | 
2025-10-23 00:11:19.517412 | TASK [upload-logs-swift : Ensure logs are readable before uploading]
2025-10-23 00:11:19.930088 | localhost -> localhost | ok: Runtime: 0:00:00.004688
2025-10-23 00:11:19.935996 | 
2025-10-23 00:11:19.936064 | TASK [upload-logs-swift : Upload logs to swift]