2025-12-04 12:37:28.758159 | Job console starting...
2025-12-04 12:37:28.773958 | Updating repositories
2025-12-04 12:37:28.821346 | Preparing job workspace
2025-12-04 12:37:33.215163 | Running Ansible setup...
2025-12-04 12:37:36.736266 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-04 12:37:37.335757 | 
2025-12-04 12:37:37.335930 | PLAY [localhost]
2025-12-04 12:37:37.344457 | 
2025-12-04 12:37:37.344524 | TASK [Gathering Facts]
2025-12-04 12:37:38.381136 | localhost | ok
2025-12-04 12:37:38.402279 | 
2025-12-04 12:37:38.402464 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-04 12:37:38.816983 | localhost -> localhost | changed
2025-12-04 12:37:38.823025 | 
2025-12-04 12:37:38.823098 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-04 12:37:39.745075 | localhost -> localhost | changed
2025-12-04 12:37:39.753567 | 
2025-12-04 12:37:39.753634 | TASK [Setup log path fact]
2025-12-04 12:37:39.771174 | localhost | ok
2025-12-04 12:37:39.782918 | 
2025-12-04 12:37:39.783006 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-04 12:37:39.820660 | localhost | ok
2025-12-04 12:37:39.829342 | 
2025-12-04 12:37:39.829422 | TASK [emit-job-header : Print job information]
2025-12-04 12:37:39.857591 | # Job Information
2025-12-04 12:37:39.857717 | Ansible Version: 2.15.12
2025-12-04 12:37:39.857761 | Job: cifmw-molecule-fdp_update_edpm
2025-12-04 12:37:39.857782 | Pipeline: github-check
2025-12-04 12:37:39.857800 | Executor: ze03.softwarefactory-project.io
2025-12-04 12:37:39.857817 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3467
2025-12-04 12:37:39.857835 | Log URL (when completed): https://logserver.rdoproject.org/587/rdoproject.org/5875b4400a95438c88cad4f754c85c65/
2025-12-04 12:37:39.857853 | Event ID: d55ff0e0-d10d-11f0-8a78-6f59b748a432
2025-12-04 12:37:39.861459 | 
2025-12-04 12:37:39.861521 | LOOP [emit-job-header : Print node information]
2025-12-04 12:37:39.955352 | localhost | ok:
2025-12-04 12:37:39.955626 | localhost | # Node Information
2025-12-04 12:37:39.955684 | localhost | Inventory Hostname: controller
2025-12-04 12:37:39.955762 | localhost | Hostname: np0005545622
2025-12-04 12:37:39.955814 | localhost | Username: zuul
2025-12-04 12:37:39.955859 | localhost | Distro: CentOS 9
2025-12-04 12:37:39.955898 | localhost | Provider: vexxhost-nodepool-tripleo
2025-12-04 12:37:39.955935 | localhost | Region: RegionOne
2025-12-04 12:37:39.955971 | localhost | Label: cloud-centos-9-stream-tripleo
2025-12-04 12:37:39.956007 | localhost | Product Name: OpenStack Nova
2025-12-04 12:37:39.956041 | localhost | Interface IP: 38.102.83.58
2025-12-04 12:37:39.976752 | 
2025-12-04 12:37:39.976847 | PLAY [all]
2025-12-04 12:37:39.983457 | 
2025-12-04 12:37:39.983519 | TASK [Gather network facts]
2025-12-04 12:37:40.539884 | controller | ok
2025-12-04 12:37:40.554623 | 
2025-12-04 12:37:40.554683 | TASK [include_role : start-zuul-console]
2025-12-04 12:37:40.584372 | controller | ok
2025-12-04 12:37:40.596121 | 
2025-12-04 12:37:40.596236 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-04 12:37:41.026950 | controller | ok
2025-12-04 12:37:41.047092 | 
2025-12-04 12:37:41.047242 | TASK [include_role : add-build-sshkey]
2025-12-04 12:37:41.083978 | controller | ok
2025-12-04 12:37:41.110949 | 
2025-12-04 12:37:41.111060 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-04 12:37:41.451034 | controller -> localhost | ok
2025-12-04 12:37:41.457122 | 
2025-12-04 12:37:41.457193 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-04 12:37:41.501512 | controller | ok
2025-12-04 12:37:41.523142 | controller | included: /var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-04 12:37:41.528895 | 
2025-12-04 12:37:41.528957 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-04 12:37:42.580442 | controller -> localhost | Generating public/private rsa key pair.
2025-12-04 12:37:42.580959 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/work/5875b4400a95438c88cad4f754c85c65_id_rsa.
2025-12-04 12:37:42.581056 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/work/5875b4400a95438c88cad4f754c85c65_id_rsa.pub.
2025-12-04 12:37:42.581126 | controller -> localhost | The key fingerprint is:
2025-12-04 12:37:42.581188 | controller -> localhost | SHA256:tEQsa8uByCz6EwDn4mhRPFbrp2rO8ZNi0qht7UV7rqo zuul-build-sshkey
2025-12-04 12:37:42.581246 | controller -> localhost | The key's randomart image is:
2025-12-04 12:37:42.581308 | controller -> localhost | +---[RSA 3072]----+
2025-12-04 12:37:42.581373 | controller -> localhost | |  . .. ..        |
2025-12-04 12:37:42.581440 | controller -> localhost | |. .=  o..        |
2025-12-04 12:37:42.581509 | controller -> localhost | |.=o..o oo        |
2025-12-04 12:37:42.581568 | controller -> localhost | |+.= o +o .       |
2025-12-04 12:37:42.581614 | controller -> localhost | |++.  +.+S        |
2025-12-04 12:37:42.581656 | controller -> localhost | |oo.  .=.         |
2025-12-04 12:37:42.581697 | controller -> localhost | |..o+ .+ .        |
2025-12-04 12:37:42.582047 | controller -> localhost | | +===+ o         |
2025-12-04 12:37:42.582105 | controller -> localhost | |o.EB+oo..        |
2025-12-04 12:37:42.582148 | controller -> localhost | +----[SHA256]-----+
2025-12-04 12:37:42.582239 | controller -> localhost | ok: Runtime: 0:00:00.620721
2025-12-04 12:37:42.599999 | 
2025-12-04 12:37:42.600148 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-04 12:37:42.648370 | controller | ok
2025-12-04 12:37:42.662214 | controller | included: /var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-04 12:37:42.674249 | 
2025-12-04 12:37:42.674346 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-04 12:37:42.699306 | controller | skipping: Conditional result was False
2025-12-04 12:37:42.705445 | 
2025-12-04 12:37:42.705523 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-04 12:37:43.219529 | controller | changed
2025-12-04 12:37:43.227544 | 
2025-12-04 12:37:43.227659 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-04 12:37:43.516076 | controller | ok
2025-12-04 12:37:43.529018 | 
2025-12-04 12:37:43.529189 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-04 12:37:44.351142 | controller | changed
2025-12-04 12:37:44.369165 | 
2025-12-04 12:37:44.370160 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-04 12:37:45.240071 | controller | changed
2025-12-04 12:37:45.247538 | 
2025-12-04 12:37:45.247625 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-04 12:37:45.282776 | controller | skipping: Conditional result was False
2025-12-04 12:37:45.290802 | 
2025-12-04 12:37:45.290895 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-04 12:37:45.715836 | controller -> localhost | changed
2025-12-04 12:37:45.730237 | 
2025-12-04 12:37:45.730444 | TASK [add-build-sshkey : Add back temp key]
2025-12-04 12:37:46.054130 | controller -> localhost | Identity added: /var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/work/5875b4400a95438c88cad4f754c85c65_id_rsa (zuul-build-sshkey)
2025-12-04 12:37:46.054382 | controller -> localhost | ok: Runtime: 0:00:00.017609
2025-12-04 12:37:46.060694 | 
2025-12-04 12:37:46.060817 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-04 12:37:46.492408 | controller | ok
2025-12-04 12:37:46.502600 | 
2025-12-04 12:37:46.502770 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-04 12:37:46.539878 | controller | skipping: Conditional result was False
2025-12-04 12:37:46.560404 | 
2025-12-04 12:37:46.560553 | TASK [include_role : validate-host]
2025-12-04 12:37:46.594444 | controller | ok
2025-12-04 12:37:46.622310 | 
2025-12-04 12:37:46.622444 | TASK [validate-host : Define zuul_info_dir fact]
2025-12-04 12:37:46.663377 | controller | ok
2025-12-04 12:37:46.669826 | 
2025-12-04 12:37:46.669946 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-12-04 12:37:46.937940 | controller -> localhost | ok
2025-12-04 12:37:46.944880 | 
2025-12-04 12:37:46.944947 | TASK [validate-host : Collect information about the host]
2025-12-04 12:37:47.762954 | controller | ok
2025-12-04 12:37:47.778976 | 
2025-12-04 12:37:47.779221 | TASK [validate-host : Sanitize hostname]
2025-12-04 12:37:47.858967 | controller | ok
2025-12-04 12:37:47.867446 | 
2025-12-04 12:37:47.867514 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-12-04 12:37:48.291211 | controller -> localhost | changed
2025-12-04 12:37:48.301086 | 
2025-12-04 12:37:48.301216 | TASK [validate-host : Collect information about zuul worker]
2025-12-04 12:37:48.676560 | controller | ok
2025-12-04 12:37:48.687008 | 
2025-12-04 12:37:48.687130 | TASK [validate-host : Write out all zuul information for each host]
2025-12-04 12:37:49.235237 | controller -> localhost | changed
2025-12-04 12:37:49.256039 | 
2025-12-04 12:37:49.256215 | TASK [include_role : prepare-workspace-openshift]
2025-12-04 12:37:49.293070 | controller | skipping: Conditional result was False
2025-12-04 12:37:49.306044 | 
2025-12-04 12:37:49.306607 | TASK [include_role : remove-zuul-sshkey]
2025-12-04 12:37:49.334289 | controller | skipping: Conditional result was False
2025-12-04 12:37:49.347515 | 
2025-12-04 12:37:49.347678 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-04 12:37:49.626816 | controller | ok: "logs"
2025-12-04 12:37:49.627059 | controller | ok: All items complete
2025-12-04 12:37:49.627087 | 
2025-12-04 12:37:49.873473 | controller | ok: "artifacts"
2025-12-04 12:37:50.077338 | controller | ok: "docs"
2025-12-04 12:37:50.094747 | 
2025-12-04 12:37:50.094873 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-04 12:37:50.361033 | controller | changed: "logs"
2025-12-04 12:37:50.588129 | controller | changed: "artifacts"
2025-12-04 12:37:50.832989 | controller | changed: "docs"
2025-12-04 12:37:50.892522 | 
2025-12-04 12:37:50.892601 | PLAY RECAP
2025-12-04 12:37:50.892768 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-04 12:37:50.892812 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-04 12:37:50.892838 | 
2025-12-04 12:37:50.998929 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-04 12:37:50.999758 | PRE-RUN START: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-04 12:37:51.557137 | 
2025-12-04 12:37:51.557252 | PLAY [localhost]
2025-12-04 12:37:51.573809 | 
2025-12-04 12:37:51.573886 | TASK [configure-ssh-config-fips : Ensure ssh config directory]
2025-12-04 12:37:51.985120 | localhost | ok
2025-12-04 12:37:51.995517 | 
2025-12-04 12:37:51.995621 | TASK [configure-ssh-config-fips : Setup ssh config]
2025-12-04 12:37:52.637485 | localhost | changed
2025-12-04 12:37:52.657257 | 
2025-12-04 12:37:52.657316 | PLAY [all]
2025-12-04 12:37:52.672131 | 
2025-12-04 12:37:52.672192 | TASK [include_role : prepare-workspace]
2025-12-04 12:37:52.701629 | controller | ok
2025-12-04 12:37:52.715565 | 
2025-12-04 12:37:52.715626 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-04 12:37:53.146080 | controller | ok
2025-12-04 12:37:53.158914 | 
2025-12-04 12:37:53.159060 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-04 12:37:54.981058 | controller | Output suppressed because no_log was given
2025-12-04 12:37:54.999649 | 
2025-12-04 12:37:54.999793 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-04 12:37:55.282912 | controller | changed: "logs"
2025-12-04 12:37:55.557532 | controller | changed: "artifacts"
2025-12-04 12:37:55.769141 | controller | changed: "docs"
2025-12-04 12:37:55.779769 | 
2025-12-04 12:37:55.779958 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-04 12:37:56.110811 | controller | changed: "logs"
2025-12-04 12:37:56.111368 | controller | changed: All items complete
2025-12-04 12:37:56.111466 | 
2025-12-04 12:37:56.354626 | controller | changed: "artifacts"
2025-12-04 12:37:56.595560 | controller | changed: "docs"
2025-12-04 12:37:56.615137 | 
2025-12-04 12:37:56.615329 | TASK [Check if worker can sudo]
2025-12-04 12:37:57.153756 | controller | ok: Runtime: 0:00:00.031961
2025-12-04 12:37:57.171135 | 
2025-12-04 12:37:57.171254 | TASK [configure-mirrors : Gather needed facts]
2025-12-04 12:37:57.217119 | controller | skipping: Conditional result was False
2025-12-04 12:37:57.234456 | 
2025-12-04 12:37:57.234627 | TASK [configure-mirrors : Set up infrastructure mirrors]
2025-12-04 12:37:57.330506 | controller | ok
2025-12-04 12:37:57.339921 | controller | included: /var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror.yaml
2025-12-04 12:37:57.379259 | 
2025-12-04 12:37:57.379371 | TASK [configure-mirrors : Remove .pydistutils.cfg configuration in homedir]
2025-12-04 12:37:57.646969 | controller | ok
2025-12-04 12:37:57.662694 | 
2025-12-04 12:37:57.662906 | LOOP [configure-mirrors : Include OS-specific variables]
2025-12-04 12:37:57.758572 | controller | ok: "/var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/vars/CentOS-9.yaml"
2025-12-04 12:37:57.780122 | 
2025-12-04 12:37:57.780320 | TASK [configure-mirrors : Install /etc/pip.conf configuration]
2025-12-04 12:37:58.597159 | controller | changed
2025-12-04 12:37:58.609289 | 
2025-12-04 12:37:58.609419 | LOOP [configure-mirrors : Setup distribution specific packaging mirrors]
2025-12-04 12:37:58.696080 | controller | ok: "/var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml"
2025-12-04 12:37:58.696244 | controller | ok: All items complete
2025-12-04 12:37:58.696269 | 
2025-12-04 12:37:58.769476 | controller | included: /var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/configure-mirrors/tasks/mirror/CentOS-9.yaml
2025-12-04 12:37:58.776149 | 
2025-12-04 12:37:58.776215 | LOOP [configure-mirrors : Install CentOS 9 repository files]
2025-12-04 12:37:59.725973 | controller | changed: "etc/yum.repos.d/centos.repo"
2025-12-04 12:38:00.557838 | controller | changed: "etc/yum.repos.d/centos-addons.repo"
2025-12-04 12:38:00.578353 | 
2025-12-04 12:38:00.578613 | TASK [configure-mirrors : Disable deltrarpm]
2025-12-04 12:38:01.133654 | controller | changed: section and option added
2025-12-04 12:38:01.173205 | 
2025-12-04 12:38:01.173319 | LOOP [configure-mirrors : Update yum/dnf cache]
2025-12-04 12:38:01.828079 | controller | 29 files removed
2025-12-04 12:38:01.832003 | controller | ok: Item: dnf clean all Runtime: 0:00:00.300067
2025-12-04 12:38:01.832117 | controller | changed: All items complete
2025-12-04 12:38:01.832166 | 
2025-12-04 12:38:13.284160 | controller | Loaded plugins: builddep, changelog, config-manager, copr, debug, debuginfo-install, download, generate_completion_cache, groups-manager, needs-restarting, playground, repoclosure, repodiff, repograph, repomanage, reposync, system-upgrade
2025-12-04 12:38:13.284340 | controller | DNF version: 4.14.0
2025-12-04 12:38:13.284394 | controller | cachedir: /var/cache/dnf
2025-12-04 12:38:13.284435 | controller | Making cache files for all metadata files.
2025-12-04 12:38:13.284474 | controller | baseos: has expired and will be refreshed.
2025-12-04 12:38:13.284511 | controller | appstream: has expired and will be refreshed.
2025-12-04 12:38:13.284547 | controller | crb: has expired and will be refreshed.
2025-12-04 12:38:13.284597 | controller | extras-common: has expired and will be refreshed.
2025-12-04 12:38:13.284634 | controller | repo: downloading from remote: baseos
2025-12-04 12:38:13.284668 | controller | CentOS Stream 9 - BaseOS                         63 MB/s | 8.8 MB     00:00
2025-12-04 12:38:13.284702 | controller | baseos: using metadata from Mon 01 Dec 2025 12:58:39 PM EST.
2025-12-04 12:38:13.288776 | controller | repo: downloading from remote: appstream
2025-12-04 12:38:13.288862 | controller | CentOS Stream 9 - AppStream                      90 MB/s |  25 MB     00:00
2025-12-04 12:38:13.288906 | controller | appstream: using metadata from Mon 01 Dec 2025 01:01:55 PM EST.
2025-12-04 12:38:13.288945 | controller | repo: downloading from remote: crb
2025-12-04 12:38:13.288981 | controller | CentOS Stream 9 - CRB                            82 MB/s | 7.3 MB     00:00
2025-12-04 12:38:13.289018 | controller | crb: using metadata from Mon 01 Dec 2025 01:06:07 PM EST.
2025-12-04 12:38:13.289053 | controller | repo: downloading from remote: extras-common
2025-12-04 12:38:13.289089 | controller | CentOS Stream 9 - Extras packages                62 kB/s |  20 kB     00:00
2025-12-04 12:38:13.289124 | controller | extras-common: using metadata from Thu 30 Oct 2025 09:20:08 AM EDT.
2025-12-04 12:38:13.289158 | controller | User-Agent: constructed: 'libdnf (CentOS Stream 9; generic; Linux.x86_64)'
2025-12-04 12:38:13.289192 | controller | Completion plugin: Generating completion cache...
2025-12-04 12:38:13.289227 | controller | Metadata cache created.
2025-12-04 12:38:13.289282 | controller | ok: Item: dnf makecache -v Runtime: 0:00:11.099974
2025-12-04 12:38:13.311923 | 
2025-12-04 12:38:13.311987 | PLAY RECAP
2025-12-04 12:38:13.312040 | controller | ok: 13 changed: 7 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-12-04 12:38:13.312075 | localhost | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-04 12:38:13.312101 | 
2025-12-04 12:38:13.431690 | PRE-RUN END RESULT_NORMAL: [untrusted : review.rdoproject.org/rdo-jobs/playbooks/base/pre.yaml@master]
2025-12-04 12:38:13.432517 | PRE-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-04 12:38:14.126199 | 
2025-12-04 12:38:14.126387 | PLAY [all]
2025-12-04 12:38:14.150061 | 
2025-12-04 12:38:14.150224 | TASK [Install binary dependencies]
2025-12-04 12:38:14.202149 | controller | ok
2025-12-04 12:38:14.223977 | 
2025-12-04 12:38:14.224106 | TASK [bindep : Include find tasks]
2025-12-04 12:38:14.255613 | controller | ok
2025-12-04 12:38:14.264067 | controller | included: /var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find.yaml
2025-12-04 12:38:14.270200 | 
2025-12-04 12:38:14.270277 | TASK [bindep : Look for bindep.txt]
2025-12-04 12:38:14.730518 | controller | ok
2025-12-04 12:38:14.745989 | 
2025-12-04 12:38:14.746151 | TASK [bindep : Define bindep_file fact]
2025-12-04 12:38:14.787127 | controller | ok
2025-12-04 12:38:14.799231 | 
2025-12-04 12:38:14.799376 | TASK [bindep : Look for other-requirements.txt]
2025-12-04 12:38:14.845034 | controller | skipping: Conditional result was False
2025-12-04 12:38:14.873895 | 
2025-12-04 12:38:14.874308 | TASK [bindep : Define bindep_file fact]
2025-12-04 12:38:14.926049 | controller | skipping: Conditional result was False
2025-12-04 12:38:14.944170 | 
2025-12-04 12:38:14.944375 | TASK [bindep : Look for bindep fallback file]
2025-12-04 12:38:14.980424 | controller | skipping: Conditional result was False
2025-12-04 12:38:14.986857 | 
2025-12-04 12:38:14.986932 | TASK [bindep : Define bindep_file fact]
2025-12-04 12:38:15.013663 | controller | skipping: Conditional result was False
2025-12-04 12:38:15.021318 | 
2025-12-04 12:38:15.021397 | TASK [bindep : Include bindep tasks]
2025-12-04 12:38:15.065927 | controller | ok
2025-12-04 12:38:15.072535 | controller | included: /var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/find-bindep.yaml
2025-12-04 12:38:15.080228 | 
2025-12-04 12:38:15.080290 | TASK [bindep : Look for bindep command]
2025-12-04 12:38:15.108090 | controller | skipping: Conditional result was False
2025-12-04 12:38:15.115408 | 
2025-12-04 12:38:15.115479 | TASK [bindep : Check for system bindep]
2025-12-04 12:38:15.651555 | controller | ok: Runtime: 0:00:00.006066
2025-12-04 12:38:15.665056 | 
2025-12-04 12:38:15.665235 | TASK [bindep : Define bindep_command fact]
2025-12-04 12:38:15.703314 | controller | skipping: Conditional result was False
2025-12-04 12:38:15.720162 | 
2025-12-04 12:38:15.720341 | TASK [bindep : Include install tasks]
2025-12-04 12:38:15.771478 | controller | ok
2025-12-04 12:38:15.790090 | controller | included: /var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/install.yaml
2025-12-04 12:38:15.802906 | 
2025-12-04 12:38:15.803009 | TASK [bindep : Create temp dir for bindep]
2025-12-04 12:38:16.249663 | controller | changed
2025-12-04 12:38:16.262065 | 
2025-12-04 12:38:16.262195 | TASK [Ensure we have pip dependencies]
2025-12-04 12:38:16.293204 | controller | ok
2025-12-04 12:38:16.329107 | 
2025-12-04 12:38:16.329199 | TASK [ensure-pip : Check if pip is installed]
2025-12-04 07:38:16.584742 | controller | /usr/bin/pip3
2025-12-04 07:38:16.607356 | controller | /usr/bin/python3: No module named wheel
2025-12-04 12:38:16.858120 | controller | ok: Runtime: 0:00:00.031768
2025-12-04 12:38:16.871717 | 
2025-12-04 12:38:16.871890 | LOOP [ensure-pip : Install pip from packages]
2025-12-04 12:38:16.928452 | controller | ok: "/var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml"
2025-12-04 12:38:16.946611 | controller | included: /var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/ensure-pip/tasks/RedHat.yaml
2025-12-04 12:38:16.962981 | 
2025-12-04 12:38:16.963066 | TASK [ensure-pip : Install Python 3 pip]
2025-12-04 12:38:19.175616 | controller | changed
2025-12-04 12:38:19.187621 | 
2025-12-04 12:38:19.187776 | TASK [ensure-pip : Check for EPEL repository]
2025-12-04 12:38:19.253456 | controller | skipping: Conditional result was False
2025-12-04 12:38:19.261506 | 
2025-12-04 12:38:19.261580 | TASK [ensure-pip : Fail with instructions when EPEL is not installed]
2025-12-04 12:38:19.328576 | controller | skipping: Conditional result was False
2025-12-04 12:38:19.342801 | 
2025-12-04 12:38:19.342944 | TASK [ensure-pip : Install Python 2 pip]
2025-12-04 12:38:19.411340 | controller | skipping: Conditional result was False
2025-12-04 12:38:19.425913 | 
2025-12-04 12:38:19.426063 | TASK [ensure-pip : Ensure setuptools]
2025-12-04 12:38:19.454065 | controller | skipping: Conditional result was False
2025-12-04 12:38:19.466500 | 
2025-12-04 12:38:19.466635 | TASK [ensure-pip : Check for ensurepip module]
2025-12-04 12:38:20.015348 | controller | skipping: Conditional result was False
2025-12-04 12:38:20.028522 | 
2025-12-04 12:38:20.028674 | TASK [ensure-pip : Ensure python3-venv]
2025-12-04 12:38:20.066679 | controller | skipping: Conditional result was False
2025-12-04 12:38:20.080015 | 
2025-12-04 12:38:20.080267 | TASK [ensure-pip : Install pip from source]
2025-12-04 12:38:20.109070 | controller | skipping: Conditional result was False
2025-12-04 12:38:20.121570 | 
2025-12-04 12:38:20.121705 | TASK [ensure-pip : Probe for venv python full path]
2025-12-04 07:38:20.409833 | controller | /usr/bin/python3
2025-12-04 12:38:20.667997 | controller | ok: Runtime: 0:00:00.007393
2025-12-04 12:38:20.681193 | 
2025-12-04 12:38:20.681426 | TASK [ensure-pip : Set host default]
2025-12-04 12:38:20.768324 | controller | ok
2025-12-04 12:38:20.776634 | 
2025-12-04 12:38:20.776721 | TASK [ensure-pip : Set ensure_pip_virtualenv_command]
2025-12-04 12:38:20.861399 | controller | ok
2025-12-04 12:38:20.875442 | 
2025-12-04 12:38:20.875527 | TASK [bindep : Install bindep into temporary venv]
2025-12-04 12:38:25.169983 | controller | changed
2025-12-04 12:38:25.182851 | 
2025-12-04 12:38:25.183014 | TASK [bindep : Define bindep_command]
2025-12-04 12:38:25.226660 | controller | ok
2025-12-04 12:38:25.241931 | 
2025-12-04 12:38:25.242137 | LOOP [bindep : Include package tasks]
2025-12-04 12:38:25.304148 | controller | ok: "src/github.com/openstack-k8s-operators/ci-framework/bindep.txt"
2025-12-04 12:38:25.304326 | controller | ok: All items complete
2025-12-04 12:38:25.304350 | 
2025-12-04 12:38:25.323408 | controller | included: /var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/untrusted/project_2/opendev.org/zuul/zuul-jobs/roles/bindep/tasks/packages.yaml
2025-12-04 12:38:25.337085 | 
2025-12-04 12:38:25.337215 | TASK [bindep : Define bindep_run fact]
2025-12-04 12:38:25.361858 | controller | ok
2025-12-04 12:38:25.367213 | 
2025-12-04 12:38:25.367301 | TASK [bindep : Get list of packages to install from bindep]
2025-12-04 07:38:26.822825 | controller | podman
2025-12-04 07:38:26.857619 | controller | python3-jmespath
2025-12-04 07:38:26.857752 | controller | python3-libvirt
2025-12-04 07:38:26.857765 | controller | python3-lxml
2025-12-04 07:38:26.857773 | controller | python3-netaddr
2025-12-04 12:38:26.912843 | controller | ok: Runtime: 0:00:01.236332
2025-12-04 12:38:26.921133 | 
2025-12-04 12:38:26.921220 | TASK [bindep : Install distro packages from bindep]
2025-12-04 12:39:32.001433 | controller | changed
2025-12-04 12:39:32.014143 | 
2025-12-04 12:39:32.014286 | TASK [bindep : Check that packages are installed]
2025-12-04 12:39:33.565160 | controller | ok: Runtime: 0:00:01.100635
2025-12-04 12:39:33.579627 | 
2025-12-04 12:39:33.579833 | TASK [bindep : Fail if we cannot install all packages]
2025-12-04 12:39:33.619701 | controller | skipping: Conditional result was False
2025-12-04 12:39:33.646515 | 
2025-12-04 12:39:33.646692 | TASK [Run test-setup role]
2025-12-04 12:39:33.680484 | controller | ok
2025-12-04 12:39:33.715428 | 
2025-12-04 12:39:33.715565 | TASK [test-setup : Check if project's tools/test-setup.sh exists]
2025-12-04 12:39:33.969050 | controller | ok
2025-12-04 12:39:33.981193 | 
2025-12-04 12:39:33.981335 | TASK [test-setup : Run tools/test-setup.sh]
2025-12-04 12:39:34.534520 | controller | skipping: Conditional result was False
2025-12-04 12:39:34.579564 | 
2025-12-04 12:39:34.579832 | TASK [bindep : Remove bindep temp dir]
2025-12-04 12:39:34.987431 | controller | ok
2025-12-04 12:39:35.013082 | 
2025-12-04 12:39:35.013287 | PLAY RECAP
2025-12-04 12:39:35.013374 | controller | ok: 22 changed: 6 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0
2025-12-04 12:39:35.013417 | 
2025-12-04 12:39:35.212074 | PRE-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/pre.yaml@master]
2025-12-04 12:39:35.213442 | RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-04 12:39:35.786531 | 
2025-12-04 12:39:35.786658 | PLAY [all]
2025-12-04 12:39:35.806649 | 
2025-12-04 12:39:35.806773 | TASK [Abort when test_command variable is undefined]
2025-12-04 12:39:35.841968 | controller | skipping: Conditional result was False
2025-12-04 12:39:35.850022 | 
2025-12-04 12:39:35.850116 | TASK [Convert test_command to list]
2025-12-04 12:39:35.916470 | controller | skipping: Conditional result was False
2025-12-04 12:39:35.929832 | 
2025-12-04 12:39:35.929973 | TASK [Use test_command list]
2025-12-04 12:39:36.006426 | controller | ok
2025-12-04 12:39:36.013859 | 
2025-12-04 12:39:36.013943 | LOOP [Run test_command]
2025-12-04 12:39:36.429816 | controller | no check to run
2025-12-04 12:39:36.430159 | controller | ok: Item: echo 'no check to run' Runtime: 0:00:00.004784
2025-12-04 12:39:36.479658 | 
2025-12-04 12:39:36.479918 | PLAY RECAP
2025-12-04 12:39:36.480037 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-04 12:39:36.480119 | 
2025-12-04 12:39:36.606467 | RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/run-test-command/run.yaml@master]
2025-12-04 12:39:36.607352 | POST-RUN START: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-04 12:39:37.216334 | 
2025-12-04 12:39:37.216453 | PLAY [all]
2025-12-04 12:39:37.236703 | 
2025-12-04 12:39:37.236821 | TASK [fetch-subunit-output : Find stestr or testr executable]
2025-12-04 12:39:37.612230 | controller | changed: non-zero return code
2025-12-04 12:39:37.624444 | 
2025-12-04 12:39:37.624631 | TASK [fetch-subunit-output : Get the list of directories with subunit files]
2025-12-04 12:39:37.652041 | controller | skipping: Conditional result was False
2025-12-04 12:39:37.657983 | 
2025-12-04 12:39:37.658060 | LOOP [fetch-subunit-output : Find any inflight partial subunit files]
2025-12-04 12:39:37.696776 | 
2025-12-04 12:39:37.697054 | LOOP [fetch-subunit-output : Copy any inflight subunit files]
2025-12-04 12:39:37.727622 | 
2025-12-04 12:39:37.727924 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream]
2025-12-04 12:39:37.745596 | controller | skipping: Conditional result was False
2025-12-04 12:39:37.758926 | 
2025-12-04 12:39:37.759086 | LOOP [fetch-subunit-output : Generate subunit file]
2025-12-04 12:39:37.784027 | 
2025-12-04 12:39:37.784279 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory]
2025-12-04 12:39:37.809632 | controller | skipping: Conditional result was False
2025-12-04 12:39:37.819699 | 
2025-12-04 12:39:37.819842 | TASK [fetch-subunit-output : Remove the temporary file]
2025-12-04 12:39:37.845014 | controller | skipping: Conditional result was False
2025-12-04 12:39:37.853078 | 
2025-12-04 12:39:37.853176 | TASK [fetch-subunit-output : Process and fetch subunit results]
2025-12-04 12:39:37.877411 | controller | skipping: Conditional result was False
2025-12-04 12:39:37.917483 | 
2025-12-04 12:39:37.917598 | PLAY RECAP
2025-12-04 12:39:37.917641 | controller | ok: 1 changed: 1 unreachable: 0 failed: 0 skipped: 8 rescued: 0 ignored: 0
2025-12-04 12:39:37.917661 | 
2025-12-04 12:39:38.017411 | POST-RUN END RESULT_NORMAL: [untrusted : opendev.org/zuul/zuul-jobs/playbooks/unittests/post.yaml@master]
2025-12-04 12:39:38.019036 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-04 12:39:38.628291 | 
2025-12-04 12:39:38.628420 | PLAY [all]
2025-12-04 12:39:38.648975 | 
2025-12-04 12:39:38.649085 | TASK [include_role : fetch-output]
2025-12-04 12:39:38.689117 | controller | ok
2025-12-04 12:39:38.705826 | 
2025-12-04 12:39:38.705903 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-04 12:39:38.782038 | controller | skipping: Conditional result was False
2025-12-04 12:39:38.788740 | 
2025-12-04 12:39:38.788814 | TASK [fetch-output : Set log path for single node]
2025-12-04 12:39:38.831832 | controller | ok
2025-12-04 12:39:38.841962 | 
2025-12-04 12:39:38.842097 | LOOP [fetch-output : Ensure local output dirs]
2025-12-04 12:39:39.282374 | controller -> localhost | ok: "/var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/work/logs"
2025-12-04 12:39:39.520236 | controller -> localhost | changed: "/var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/work/artifacts"
2025-12-04 12:39:39.766492 | controller -> localhost | changed: "/var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/work/docs"
2025-12-04 12:39:39.790544 | 
2025-12-04 12:39:39.790690 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-04 12:39:40.471238 | controller | changed: .d..t...... ./
2025-12-04 12:39:40.471598 | controller | changed: All items complete
2025-12-04 12:39:40.471659 | 
2025-12-04 12:39:41.054513 | controller | changed: .d..t...... ./
2025-12-04 12:39:41.594382 | controller | changed: .d..t...... ./
2025-12-04 12:39:41.619856 | 
2025-12-04 12:39:41.620044 | TASK [include_role : fetch-output-openshift]
2025-12-04 12:39:41.635409 | controller | skipping: Conditional result was False
2025-12-04 12:39:41.645090 | 
2025-12-04 12:39:41.645200 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-04 12:39:42.114494 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.014103
2025-12-04 12:39:42.391104 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.012538
2025-12-04 12:39:42.433486 | 
2025-12-04 12:39:42.433678 | PLAY [all]
2025-12-04 12:39:42.455844 | 
2025-12-04 12:39:42.455981 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-12-04 12:39:42.940204 | controller | changed
2025-12-04 12:39:42.992704 | 
2025-12-04 12:39:42.992893 | PLAY RECAP
2025-12-04 12:39:42.992954 | controller | ok: 5 changed: 4 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-04 12:39:42.992991 | 
2025-12-04 12:39:43.122082 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-04 12:39:43.122924 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-12-04 12:39:43.738970 | 
2025-12-04 12:39:43.739080 | PLAY [localhost]
2025-12-04 12:39:43.756605 | 
2025-12-04 12:39:43.756691 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-04 12:39:44.150776 | localhost | changed
2025-12-04 12:39:44.155553 | 
2025-12-04 12:39:44.155629 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-04 12:39:44.190577 | localhost | ok
2025-12-04 12:39:44.206007 | 
2025-12-04 12:39:44.206101 | TASK [add-fileserver : Create SSH private key tempfile]
2025-12-04 12:39:44.657254 | localhost | changed
2025-12-04 12:39:44.669177 | 
2025-12-04 12:39:44.669319 | TASK [add-fileserver : Create SSH private key from secret]
2025-12-04 12:39:45.412696 | localhost | changed
2025-12-04 12:39:45.418200 | 
2025-12-04 12:39:45.418266 | TASK [add-fileserver : Add fileserver ssh key]
2025-12-04 12:39:45.934320 | localhost | Identity added: /var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/work/tmp/ansible.6yo39g_g (/var/lib/zuul/builds/5875b4400a95438c88cad4f754c85c65/work/tmp/ansible.6yo39g_g)
2025-12-04 12:39:45.934693 | localhost | ok: Runtime: 0:00:00.014092
2025-12-04 12:39:45.945825 | 
2025-12-04 12:39:45.945984 | TASK [add-fileserver : Remove SSH private key from disk]
2025-12-04 12:39:46.291716 | localhost | ok: Runtime: 0:00:00.008984
2025-12-04 12:39:46.302440 | 
2025-12-04 12:39:46.302579 | TASK [add-fileserver : Add fileserver to inventory]
2025-12-04 12:39:46.387948 | localhost | changed
2025-12-04 12:39:46.393775 | 
2025-12-04 12:39:46.393867 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-12-04 12:39:46.857339 | localhost | changed
2025-12-04 12:39:46.895678 | 
2025-12-04 12:39:46.895826 | PLAY [localhost]
2025-12-04 12:39:46.912669 | 
2025-12-04 12:39:46.912772 | TASK [Generate bulk log download script]
2025-12-04 12:39:46.934205 | localhost | ok
2025-12-04 12:39:46.950350 | 
2025-12-04 12:39:46.950437 | TASK [local-log-download : Check API endpoint is defined]
2025-12-04 12:39:47.004161 | localhost | ok: All assertions passed
2025-12-04 12:39:47.014646 | 
2025-12-04 12:39:47.014835 | TASK [local-log-download : Create download script]
2025-12-04 12:39:47.458623 | localhost -> localhost | changed
2025-12-04 12:39:47.480321 | 
2025-12-04 12:39:47.480456 | TASK [Register quick-download link]
2025-12-04 12:39:47.517008 | localhost | ok
2025-12-04 12:39:47.591951 | 
2025-12-04 12:39:47.592113 | PLAY [logserver.rdoproject.org]
2025-12-04 12:39:47.613891 | 
2025-12-04 12:39:47.614025 | TASK [Set zuul-log-path fact]
2025-12-04 12:39:47.637230 | logserver.rdoproject.org | ok
2025-12-04 12:39:47.657789 | 
2025-12-04 12:39:47.657973 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-04 12:39:47.696525 | logserver.rdoproject.org | ok
2025-12-04 12:39:47.704461 | 
2025-12-04 12:39:47.704573 | TASK [upload-logs : Create log directories]
2025-12-04 12:39:48.570708 | logserver.rdoproject.org | changed
2025-12-04 12:39:48.574889 | 
2025-12-04 12:39:48.574968 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-12-04 12:39:48.928672 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009879
2025-12-04 12:39:48.935484 | 
2025-12-04 12:39:48.935566 | TASK [upload-logs : Upload logs to log server]
2025-12-04 12:39:49.712189 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-12-04 12:39:49.721061 | 
2025-12-04 12:39:49.721189 | LOOP [upload-logs : Compress console log and json output]
2025-12-04 12:39:49.792031 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-04 12:39:49.803571 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-04 12:39:49.817344 | 
2025-12-04 12:39:49.817579 | LOOP [upload-logs : Upload compressed console log and json output]
2025-12-04 12:39:49.870156 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-04 12:39:49.870663 | 
2025-12-04 12:39:49.873428 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-04 12:39:49.883207 | 
2025-12-04 12:39:49.883415 | LOOP [upload-logs : Upload console log and json output]