2025-10-13 16:18:02.899777 | Job console starting...
2025-10-13 16:18:03.139183 | Updating repositories
2025-10-13 16:18:03.902373 | Preparing job workspace
2025-10-13 16:18:14.052171 | Running Ansible setup...
2025-10-13 16:18:17.946024 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 16:18:18.497570 | 
2025-10-13 16:18:18.497661 | PLAY [localhost]
2025-10-13 16:18:18.506225 | 
2025-10-13 16:18:18.506298 | TASK [Gathering Facts]
2025-10-13 16:18:19.336088 | localhost | ok
2025-10-13 16:18:19.350157 | 
2025-10-13 16:18:19.350253 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-13 16:18:19.678799 | localhost -> localhost | changed
2025-10-13 16:18:19.684540 | 
2025-10-13 16:18:19.684613 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-13 16:18:20.474482 | localhost -> localhost | changed
2025-10-13 16:18:20.482827 | 
2025-10-13 16:18:20.482897 | TASK [Setup log path fact]
2025-10-13 16:18:20.522215 | localhost | ok
2025-10-13 16:18:20.541715 | 
2025-10-13 16:18:20.541855 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 16:18:20.571080 | localhost | ok
2025-10-13 16:18:20.582526 | 
2025-10-13 16:18:20.582599 | TASK [emit-job-header : Print job information]
2025-10-13 16:18:20.631821 | # Job Information
2025-10-13 16:18:20.631973 | Ansible Version: 2.15.12
2025-10-13 16:18:20.632005 | Job: cifmw-molecule-openshift_provisioner_node
2025-10-13 16:18:20.632029 | Pipeline: github-check
2025-10-13 16:18:20.632050 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-10-13 16:18:20.632072 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3402
2025-10-13 16:18:20.632094 | Log URL (when completed): https://logserver.rdoproject.org/f35/rdoproject.org/f351a4ad085742d68d019135ea0b3f59/
2025-10-13 16:18:20.632132 | Event ID: b0cb8a10-a84e-11f0-9fc4-7f703dfb38e8
2025-10-13 16:18:20.636009 | 
2025-10-13 16:18:20.636079 | LOOP [emit-job-header : Print node information]
2025-10-13 16:18:20.798357 | localhost | ok:
2025-10-13 16:18:20.798512 | localhost | # Node Information
2025-10-13 16:18:20.798542 | localhost | Inventory Hostname: controller
2025-10-13 16:18:20.798567 | localhost | Hostname: np0005485854
2025-10-13 16:18:20.798588 | localhost | Username: zuul
2025-10-13 16:18:20.798609 | localhost | Distro: CentOS 9
2025-10-13 16:18:20.798629 | localhost | Provider: ibm-bm4-nodepool
2025-10-13 16:18:20.798649 | localhost | Region: regionOne
2025-10-13 16:18:20.798668 | localhost | Label: centos-9-stream-crc-2-48-0-xl-ibm
2025-10-13 16:18:20.798686 | localhost | Product Name: OpenStack Compute
2025-10-13 16:18:20.798704 | localhost | Interface IP: 192.168.26.116
2025-10-13 16:18:20.841977 | 
2025-10-13 16:18:20.842090 | PLAY [all]
2025-10-13 16:18:20.852167 | 
2025-10-13 16:18:20.852231 | TASK [Gather network facts]
2025-10-13 16:18:21.301799 | controller | ok
2025-10-13 16:18:21.318257 | 
2025-10-13 16:18:21.318330 | TASK [include_role : start-zuul-console]
2025-10-13 16:18:21.337340 | controller | ok
2025-10-13 16:18:21.349146 | 
2025-10-13 16:18:21.349214 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-13 16:18:21.778848 | controller | ok
2025-10-13 16:18:21.796137 | 
2025-10-13 16:18:21.796248 | TASK [include_role : add-build-sshkey]
2025-10-13 16:18:21.836515 | controller | ok
2025-10-13 16:18:21.850840 | 
2025-10-13 16:18:21.851171 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-13 16:18:22.081249 | controller -> localhost | ok
2025-10-13 16:18:22.087020 | 
2025-10-13 16:18:22.087096 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-13 16:18:22.107137 | controller | ok
2025-10-13 16:18:22.121674 | controller | included: /var/lib/zuul/builds/f351a4ad085742d68d019135ea0b3f59/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-13 16:18:22.129618 | 
2025-10-13 16:18:22.129710 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-13 16:18:22.550614 | controller -> localhost | Generating public/private rsa key pair.
2025-10-13 16:18:22.550834 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/f351a4ad085742d68d019135ea0b3f59/work/f351a4ad085742d68d019135ea0b3f59_id_rsa.
2025-10-13 16:18:22.550872 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/f351a4ad085742d68d019135ea0b3f59/work/f351a4ad085742d68d019135ea0b3f59_id_rsa.pub.
2025-10-13 16:18:22.550898 | controller -> localhost | The key fingerprint is:
2025-10-13 16:18:22.550942 | controller -> localhost | SHA256:XNh+vHeat6MjL9EyHQH31jDWV/BE2Gnj8y9K8Xdt8FA zuul-build-sshkey
2025-10-13 16:18:22.550966 | controller -> localhost | The key's randomart image is:
2025-10-13 16:18:22.551005 | controller -> localhost | +---[RSA 3072]----+
2025-10-13 16:18:22.551026 | controller -> localhost | |           ...=**|
2025-10-13 16:18:22.551090 | controller -> localhost | |         o  .ooO=|
2025-10-13 16:18:22.551135 | controller -> localhost | |        . o   +oE|
2025-10-13 16:18:22.551160 | controller -> localhost | |       . o . ..+ |
2025-10-13 16:18:22.551179 | controller -> localhost | |        S . * + o|
2025-10-13 16:18:22.551198 | controller -> localhost | |           = * +o|
2025-10-13 16:18:22.551217 | controller -> localhost | |            * o O|
2025-10-13 16:18:22.551238 | controller -> localhost | |           + o.B+|
2025-10-13 16:18:22.551257 | controller -> localhost | |            =+=+o|
2025-10-13 16:18:22.551275 | controller -> localhost | +----[SHA256]-----+
2025-10-13 16:18:22.551320 | controller -> localhost | ok: Runtime: 0:00:00.064632
2025-10-13 16:18:22.558987 | 
2025-10-13 16:18:22.559055 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-13 16:18:22.581123 | controller | ok
2025-10-13 16:18:22.591698 | controller | included: /var/lib/zuul/builds/f351a4ad085742d68d019135ea0b3f59/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-13 16:18:22.601067 | 
2025-10-13 16:18:22.601147 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-13 16:18:22.615059 | controller | skipping: Conditional result was False
2025-10-13 16:18:22.621663 | 
2025-10-13 16:18:22.621733 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-13 16:18:23.108135 | controller | changed
2025-10-13 16:18:23.113544 | 
2025-10-13 16:18:23.113686 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-13 16:18:23.356190 | controller | ok
2025-10-13 16:18:23.361130 | 
2025-10-13 16:18:23.361198 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-13 16:18:24.403114 | controller | changed
2025-10-13 16:18:24.408404 | 
2025-10-13 16:18:24.408474 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-13 16:18:25.495396 | controller | changed
2025-10-13 16:18:25.501332 | 
2025-10-13 16:18:25.501400 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-13 16:18:25.539577 | controller | skipping: Conditional result was False
2025-10-13 16:18:25.545278 | 
2025-10-13 16:18:25.545346 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-13 16:18:25.866234 | controller -> localhost | changed
2025-10-13 16:18:25.878682 | 
2025-10-13 16:18:25.878772 | TASK [add-build-sshkey : Add back temp key]
2025-10-13 16:18:26.136492 | controller -> localhost | Identity added: /var/lib/zuul/builds/f351a4ad085742d68d019135ea0b3f59/work/f351a4ad085742d68d019135ea0b3f59_id_rsa (zuul-build-sshkey)
2025-10-13 16:18:26.136675 | controller -> localhost | ok: Runtime: 0:00:00.025332
2025-10-13 16:18:26.142490 | 
2025-10-13 16:18:26.142559 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-13 16:18:26.508194 | controller | ok
2025-10-13 16:18:26.513013 | 
2025-10-13 16:18:26.513085 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-13 16:18:26.537387 | controller | skipping: Conditional result was False
2025-10-13 16:18:26.547310 | 
2025-10-13 16:18:26.547384 | TASK [include_role : validate-host]
2025-10-13 16:18:26.566191 | controller | ok
2025-10-13 16:18:26.585651 | 
2025-10-13 16:18:26.585720 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-13 16:18:26.615031 | controller | ok
2025-10-13 16:18:26.620341 | 
2025-10-13 16:18:26.620422 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-13 16:18:26.846828 | controller -> localhost | ok
2025-10-13 16:18:26.852618 | 
2025-10-13 16:18:26.852688 | TASK [validate-host : Collect information about the host]
2025-10-13 16:18:27.628387 | controller | ok
2025-10-13 16:18:27.643015 | 
2025-10-13 16:18:27.643118 | TASK [validate-host : Sanitize hostname]
2025-10-13 16:18:27.701870 | controller | ok
2025-10-13 16:18:27.707049 | 
2025-10-13 16:18:27.707140 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-13 16:18:28.107903 | controller -> localhost | changed
2025-10-13 16:18:28.113891 | 
2025-10-13 16:18:28.114019 | TASK [validate-host : Collect information about zuul worker]
2025-10-13 16:18:28.509739 | controller | ok
2025-10-13 16:18:28.514841 | 
2025-10-13 16:18:28.514933 | TASK [validate-host : Write out all zuul information for each host]
2025-10-13 16:18:28.893242 | controller -> localhost | changed
2025-10-13 16:18:28.904180 | 
2025-10-13 16:18:28.904277 | TASK [include_role : prepare-workspace-openshift]
2025-10-13 16:18:28.917854 | controller | skipping: Conditional result was False
2025-10-13 16:18:28.923183 | 
2025-10-13 16:18:28.923247 | TASK [include_role : remove-zuul-sshkey]
2025-10-13 16:18:28.936673 | controller | skipping: Conditional result was False
2025-10-13 16:18:28.941694 | 
2025-10-13 16:18:28.941764 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-13 16:18:29.218850 | controller | ok: "logs"
2025-10-13 16:18:29.219111 | controller | ok: All items complete
2025-10-13 16:18:29.219144 | 
2025-10-13 16:18:29.462000 | controller | ok: "artifacts"
2025-10-13 16:18:29.723213 | controller | ok: "docs"
2025-10-13 16:18:29.735544 | 
2025-10-13 16:18:29.735640 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-13 16:18:30.027490 | controller | changed: "logs"
2025-10-13 16:18:30.283393 | controller | changed: "artifacts"
2025-10-13 16:18:30.532599 | controller | changed: "docs"
2025-10-13 16:18:30.555046 | 
2025-10-13 16:18:30.555147 | PLAY RECAP
2025-10-13 16:18:30.555194 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-13 16:18:30.555226 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 16:18:30.555247 | 
2025-10-13 16:18:30.646454 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-13 16:18:30.647239 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-13 16:18:31.253075 | 
2025-10-13 16:18:31.253189 | PLAY [all]
2025-10-13 16:18:31.279015 | 
2025-10-13 16:18:31.279089 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-13 16:18:31.330800 | controller | ok
2025-10-13 16:18:31.335799 | 
2025-10-13 16:18:31.335876 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-13 16:18:31.752297 | controller | changed
2025-10-13 16:18:31.758069 | 
2025-10-13 16:18:31.758157 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-13 16:18:33.072688 | controller | changed
2025-10-13 16:18:33.083178 | 
2025-10-13 16:18:33.083497 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-10-13 16:18:33.536383 | controller | changed:
2025-10-13 16:18:33.536557 | controller | {
2025-10-13 16:18:33.536597 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-10-13 16:18:33.536688 | controller | }
2025-10-13 16:18:33.824085 | controller | changed:
2025-10-13 16:18:33.824183 | controller | {
2025-10-13 16:18:33.824218 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-10-13 16:18:33.824243 | controller | }
2025-10-13 16:18:34.124008 | controller | changed:
2025-10-13 16:18:34.124090 | controller | {
2025-10-13 16:18:34.124131 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-10-13 16:18:34.124154 | controller | }
2025-10-13 16:18:34.416563 | controller | changed:
2025-10-13 16:18:34.417068 | controller | {
2025-10-13 16:18:34.417126 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-10-13 16:18:34.417152 | controller | }
2025-10-13 16:18:34.712500 | controller | changed:
2025-10-13 16:18:34.712582 | controller | {
2025-10-13 16:18:34.712609 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-10-13 16:18:34.712631 | controller | }
2025-10-13 16:18:35.010132 | controller | changed:
2025-10-13 16:18:35.010228 | controller | {
2025-10-13 16:18:35.010256 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-10-13 16:18:35.010278 | controller | }
2025-10-13 16:18:35.305585 | controller | changed:
2025-10-13 16:18:35.305686 | controller | {
2025-10-13 16:18:35.305714 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDLOQd4ZLtkZXQGY6UwAr/06ppWQK4fDO3HaqxPk98csyOCBXsliSKK39Bso828+5srIXiW7aI6aC9P5mwi4mUZlGPfJlQbfrcGvY+b/SocuvaGK+1RrHLoJCT52LBhwgrzlXio2jeksZeein8iaTrhsPrOAs7KggIL/rB9hEiB3NaOPWhhoCP4vlW6MEMExGcqB/1FVxXFBPnLkEyW0Lk7ycVflZl2ocRxbfjZi0+tI1Wlinp8PvSQSc/WVrAcDgKjc/mB4ODPOyYy3G8FHgfMsrXSDEyjBKgLKMsdCrAUcqJQWjkqXleXSYOV4q3pzL+9umK+q/e3P/bIoSFQzmJKTU1eDfuvPXmow9F5H54fii/Da7ezlMJ+wPGHJrRAkmzvMbALy7xwswLhZMkOGNtRcPqaKYRmIBKpw3o6bCTtcNUHOtOQnzwY8JzrM2eBWJBXAANYw+9/ho80JIiwhg29CFNpVBuHbql2YxJQNrnl90guN65rYNpDxdIluweyUf8= anbanerj@kaermorhen"
2025-10-13 16:18:35.305737 | controller | }
2025-10-13 16:18:35.597838 | controller | changed:
2025-10-13 16:18:35.597955 | controller | {
2025-10-13 16:18:35.597984 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC3VwV8Im9kRm49lt3tM36hj4Zv27FxGo4C1Q/0jqhzFmHY7RHbmeRr8ObhwWoHjXSozKWg8FL5ER0z3hTwL0W6lez3sL7hUaCmSuZmG5Hnl3x4vTSxDI9JZ/Y65rtYiiWQo2fC5xJhU/4+0e5e/pseCm8cKRSu+SaxhO+sd6FDojA2x1BzOzKiQRDy/1zWGp/cZkxcEuB1wHI5LMzN03c67vmbu+fhZRAUO4dQkvcnj2LrhQtpa+ytvnSjr8icMDosf1OsbSffwZFyHB/hfWGAfe0eIeSA2XPraxiPknXxiPKx2MJsaUTYbsZcm3EjFdHBBMumw5rBI74zLrMRvCO9GwBEmGT4rFng1nP+yw5DB8sn2zqpOsPg1LYRwCPOUveC13P6pgsZZPh812e8v5EKnETct+5XI3dVpdw6CnNiLwAyVAF15DJvBGT/u1k0Myg/bQn+Gv9k2MSj6LvQmf6WbZu2Wgjm30z3FyCneBqTL7mLF19YXzeC0ufHz5pnO1E= dasm@fedora"
2025-10-13 16:18:35.598006 | controller | }
2025-10-13 16:18:35.889483 | controller | changed:
2025-10-13 16:18:35.889733 | controller | {
2025-10-13 16:18:35.889772 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-10-13 16:18:35.889796 | controller | }
2025-10-13 16:18:36.212197 | controller | changed:
2025-10-13 16:18:36.212278 | controller | {
2025-10-13 16:18:36.212305 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-10-13 16:18:36.212327 | controller | }
2025-10-13 16:18:36.483411 | controller | changed:
2025-10-13 16:18:36.483594 | controller | {
2025-10-13 16:18:36.483631 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-10-13 16:18:36.483654 | controller | }
2025-10-13 16:18:36.770161 | controller | changed:
2025-10-13 16:18:36.770267 | controller | {
2025-10-13 16:18:36.770295 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-10-13 16:18:36.770317 | controller | }
2025-10-13 16:18:37.072393 | controller | changed:
2025-10-13 16:18:37.072497 | controller | {
2025-10-13 16:18:37.072530 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-10-13 16:18:37.072557 | controller | }
2025-10-13 16:18:37.376119 | controller | changed:
2025-10-13 16:18:37.376220 | controller | {
2025-10-13 16:18:37.376248 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-10-13 16:18:37.376269 | controller | }
2025-10-13 16:18:37.674928 | controller | changed:
2025-10-13 16:18:37.675022 | controller | {
2025-10-13 16:18:37.675050 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-10-13 16:18:37.675072 | controller | }
2025-10-13 16:18:37.969401 | controller | changed:
2025-10-13 16:18:37.969480 | controller | {
2025-10-13 16:18:37.969506 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-10-13 16:18:37.969527 | controller | }
2025-10-13 16:18:38.267937 | controller | changed:
2025-10-13 16:18:38.268032 | controller | {
2025-10-13 16:18:38.268061 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQCfNtF7NvKl915TGsGGoseUb06Hj8L/S4toWf0hExeY+F00woL6NvBlJD0nDct+P5a22I4EhvoQCRQ8reaPCm1lybR3uiRIJsj+8zkVvLwby9LXzfZorlNG9ofjd00FEmB09uW/YvTl6Q9XwwwX6tInzIOv3TMqTHHGOL74ibbj8J/FJR0cFEyj0z4WQRvtkh32xAHl83gbuINryMt0sqRI+clj2381NKL55DRLQrVw0gsfqqxiHAnXg21qWmc4J+b9e9kiuAFQjcjwTVkwJCcg3xbPwC/qokYRby/Y5S40UUd7/jEARGXT7RZgpzTuDd1oZiCVrnrqJNPaMNdVv5MLeFdf1B7iIe5aa/fGouX7AO4SdKhZUdnJmCFAGvjC6S3JMZ2wAcUl+OHnssfmdj7XL50cLo27vjuzMtLAgSqi6N99m92WCF2s8J9aVzszX7Xz9OKZCeGsiVJp3/NdABKzSEAyM9xBD/5Vho894Sav+otpySHe3p6RUTgbB5Zu8VyZRZ/UtB3ueXxyo764yrc6qWIDqrehm84Xm9g+/jpIBzGPl07NUNJpdt/6Sgf9RIKXw/7XypO5yZfUcuFNGTxLfqjTNrtgLZNcjfav6sSdVXVcMPL//XNuRdKmVFaO76eV/oGMQGr1fGcCD+N+CpI7+Q+fCNB6VFWG4nZFuI/Iuw== averdagu@redhat.com"
2025-10-13 16:18:38.268086 | controller | }
2025-10-13 16:18:38.564787 | controller | changed:
2025-10-13 16:18:38.564877 | controller | {
2025-10-13 16:18:38.564920 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDq8l27xI+QlQVdS4djp9ogSoyrNE2+Ox6vKPdhSNL1J3PE5w+WCSvMz9A5gnNuH810zwbekEApbxTze/gLQJwBHA52CChfURpXrFaxY7ePXRElwKAL3mJfzBWY/c5jnNL9TCVmFJTGZkFZP3Nh+BMgZvL6xBkt3WKm6Uq18qzd9XeKcZusrA+O+uLv1fVeQnadY9RIqOCyeFYCzLWrUfTyE8x/XG0hAWIM7qpnF2cALQS2h9n4hW5ybiUN790H08wf9hFwEf5nxY9Z9dVkPFQiTSGKNBzmnCXU9skxS/xhpFjJ5duGSZdtAHe9O+nGZm9c67hxgtf8e5PDuqAdXEv2cf6e3VBAt+Bz8EKI3yosTj0oZHfwr42Yzb1l/SKy14Rggsrc9KAQlrGXan6+u2jcQqqx7l+SWmnpFiWTV9u5cWj2IgOhApOitmRBPYqk9rE2usfO0hLn/Pj/R/Nau4803e1/EikdLE7Ps95s9mX5jRDjAoUa2JwFF5RsVFyL910= ashigupt@ashigupt.remote.csb"
2025-10-13 16:18:38.564960 | controller | }
2025-10-13 16:18:38.866796 | controller | changed:
2025-10-13 16:18:38.866889 | controller | {
2025-10-13 16:18:38.867049 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-10-13 16:18:38.867081 | controller | }
2025-10-13 16:18:39.173113 | controller | changed:
2025-10-13 16:18:39.173194 | controller | {
2025-10-13 16:18:39.173224 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-10-13 16:18:39.173247 | controller | }
2025-10-13 16:18:39.498078 | controller | changed:
2025-10-13 16:18:39.498189 | controller | {
2025-10-13 16:18:39.498218 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-10-13 16:18:39.498240 | controller | }
2025-10-13 16:18:39.800001 | controller | changed:
2025-10-13 16:18:39.800087 | controller | {
2025-10-13 16:18:39.800127 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-10-13 16:18:39.800149 | controller | }
2025-10-13 16:18:40.097826 | controller | changed:
2025-10-13 16:18:40.098017 | controller | {
2025-10-13 16:18:40.098057 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQDZdI7t1cxYx65heVI24HTV4F7oQLW1zyfxHreL2TIJKxjyrUUKIFEUmTutcBlJRLNT2Eoix6x1sOw9YrchloCLcn//SGfTElr9mSc5jbjb7QXEU+zJMhtxyEJ1Po3CUGnj7ckiIXw7wcawZtrEOAQ9pH3ExYCJcEMiyNjRQZCxT3tPK+S4B95EWh5Fsrz9CkwpjNRPPH7LigCeQTM3Wc7r97utAslBUUvYceDSLA7rMgkitJE38b7rZBeYzsGQ8YYUBjTCtehqQXxCRjizbHWaaZkBU+N3zkKB6n/iCNGIO690NK7A/qb6msTijiz1PeuM8ThOsi9qXnbX5v0PoTpcFSojV7NHAQ71f0XXuS43FhZctT+Dcx44dT8Fb5vJu2cJGrk+qF8ZgJYNpRS7gPg0EG2EqjK7JMf9ULdjSu0r+KlqIAyLvtzT4eOnQipoKlb/WG5D/0ohKv7OMQ352ggfkBFIQsRXyyTCT98Ft9juqPuahi3CAQmP4H9dyE+7+Kz437PEtsxLmfm6naNmWi7Ee1DqWPwS8rEajsm4sNM4wW9gdBboJQtc0uZw0DfLj1I9r3Mc8Ol0jYtz0yNQDSzVLrGCaJlC311trU70tZ+ZkAVV6Mn8lOhSbj1cK0lvSr6ZK4dgqGl3I1eTZJJhbLNdg7UOVaiRx9543+C/p/As7w== brjackma@redhat.com"
2025-10-13 16:18:40.098082 | controller | }
2025-10-13 16:18:40.400208 | controller | changed:
2025-10-13 16:18:40.400314 | controller | {
2025-10-13 16:18:40.400350 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-10-13 16:18:40.400377 | controller | }
2025-10-13 16:18:40.704954 | controller | changed:
2025-10-13 16:18:40.705053 | controller | {
2025-10-13 16:18:40.705082 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-10-13 16:18:40.705118 | controller | }
2025-10-13 16:18:40.999484 | controller | changed:
2025-10-13 16:18:40.999589 | controller | {
2025-10-13 16:18:40.999617 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-10-13 16:18:40.999637 | controller | }
2025-10-13 16:18:41.018200 | 
2025-10-13 16:18:41.018312 | TASK [Set timezone to UTC]
2025-10-13 16:18:41.529701 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-10-13 16:18:41.535082 | 
2025-10-13 16:18:41.535157 | TASK [Create nodepool directory]
2025-10-13 16:18:41.808821 | controller | changed
2025-10-13 16:18:41.814457 | 
2025-10-13 16:18:41.814531 | TASK [Create nodepool sub_nodes file]
2025-10-13 16:18:42.826456 | controller | changed
2025-10-13 16:18:42.831406 | 
2025-10-13 16:18:42.831479 | TASK [Create nodepool sub_nodes_private file]
2025-10-13 16:18:43.804244 | controller | changed
2025-10-13 16:18:43.809152 | 
2025-10-13 16:18:43.809213 | LOOP [Populate nodepool sub_nodes file]
2025-10-13 16:18:43.839278 | 
2025-10-13 16:18:43.839411 | LOOP [Populate nodepool sub_nodes_private file]
2025-10-13 16:18:43.879326 | 
2025-10-13 16:18:43.879475 | TASK [Create nodepool primary file]
2025-10-13 16:18:43.902486 | controller | skipping: Conditional result was False
2025-10-13 16:18:43.908925 | 
2025-10-13 16:18:43.909028 | TASK [Create nodepool node_private for this node]
2025-10-13 16:18:44.869324 | controller | changed
2025-10-13 16:18:44.874927 | 
2025-10-13 16:18:44.874997 | LOOP [Copy ssh keys to nodepool directory]
2025-10-13 16:18:45.286961 | controller | ok: Item: id_rsa Runtime: 0:00:00.004592
2025-10-13 16:18:45.287174 | 
2025-10-13 16:18:45.506261 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.005028
2025-10-13 16:18:45.521025 | 
2025-10-13 16:18:45.521132 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-10-13 16:18:46.453207 | controller | changed
2025-10-13 16:18:46.458621 | 
2025-10-13 16:18:46.458688 | TASK [Validate sudoers config after edits]
2025-10-13 16:18:46.734129 | controller | /etc/sudoers: parsed OK
2025-10-13 16:18:46.734183 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-10-13 16:18:46.734194 | controller | /etc/sudoers.d/zuul: parsed OK
2025-10-13 16:18:46.734201 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-10-13 16:18:46.987245 | controller | ok: Runtime: 0:00:00.005076
2025-10-13 16:18:46.992791 | 
2025-10-13 16:18:46.992857 | TASK [Show the environment passed in to job shell scripts]
2025-10-13 16:18:47.287477 | controller | SHELL=/bin/bash
2025-10-13 16:18:47.287530 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-10-13 16:18:47.287539 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-10-13 16:18:47.287547 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/04/3404/9f142a3066b32ef704ae4f0d5fc5f7189e41a1f8^openstack-k8s-operators/ci-framework:main:refs/changes/06/3406/3b7e5d87cb08f8ceea89c6e58502f20dfffec667^openstack-k8s-operators/ci-framework:main:refs/changes/02/3402/434cec7be124190dc47673724851485a6696e611
2025-10-13 16:18:47.287554 | controller | PWD=/home/zuul
2025-10-13 16:18:47.287559 | controller | ZUUL_PIPELINE=github-check
2025-10-13 16:18:47.287565 | controller | LOGNAME=zuul
2025-10-13 16:18:47.287609 | controller | XDG_SESSION_TYPE=tty
2025-10-13 16:18:47.287616 | controller | _=/usr/bin/env
2025-10-13 16:18:47.287622 | controller | MOTD_SHOWN=pam
2025-10-13 16:18:47.287627 | controller | HOME=/home/zuul
2025-10-13 16:18:47.287633 | controller | LANG=en_US.UTF-8
2025-10-13 16:18:47.287638 | controller | SSH_CONNECTION=192.168.26.12 47502 192.168.26.116 22
2025-10-13 16:18:47.287643 | controller | TOX_TESTENV_PASSENV=ZUUL_UUID ZUUL_PROJECT ZUUL_SHORT_PROJECT_NAME ZUUL_PIPELINE ZUUL_VOTING WORKSPACE BUILD_TIMEOUT ZUUL_BRANCH ZUUL_CHANGES ZUUL_CHANGE_IDS ZUUL_CHANGE ZUUL_PATCHSET
2025-10-13 16:18:47.287652 | controller | ZUUL_CHANGE_IDS=3404,9f142a3066b32ef704ae4f0d5fc5f7189e41a1f8 3406,3b7e5d87cb08f8ceea89c6e58502f20dfffec667 3402,434cec7be124190dc47673724851485a6696e611
2025-10-13 16:18:47.287658 | controller | WORKSPACE=/home/zuul/workspace
2025-10-13 16:18:47.287664 | controller | XDG_SESSION_CLASS=user
2025-10-13 16:18:47.287669 | controller | SELINUX_ROLE_REQUESTED=
2025-10-13 16:18:47.287674 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-10-13 16:18:47.287679 | controller | USER=zuul
2025-10-13 16:18:47.287685 | controller | ZUUL_VOTING=True
2025-10-13 16:18:47.287690 | controller | BUILD_TIMEOUT=1800000
2025-10-13 16:18:47.287695 | controller | SELINUX_USE_CURRENT_RANGE=
2025-10-13 16:18:47.287700 | controller | SHLVL=1
2025-10-13 16:18:47.287705 | controller | ZUUL_PATCHSET=434cec7be124190dc47673724851485a6696e611
2025-10-13 16:18:47.287711 | controller | XDG_SESSION_ID=1
2025-10-13 16:18:47.287716 | controller | ZUUL_BRANCH=main
2025-10-13 16:18:47.287721 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-10-13 16:18:47.287726 | controller | SSH_CLIENT=192.168.26.12 47502 22
2025-10-13 16:18:47.287732 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-10-13 16:18:47.287737 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-10-13 16:18:47.287744 | controller | which_declare=declare -f
2025-10-13 16:18:47.287750 | controller | PATH=/home/zuul/.crc/bin/oc:/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-10-13 16:18:47.287755 | controller | SELINUX_LEVEL_REQUESTED=
2025-10-13 16:18:47.287760 | controller | ZUUL_CHANGE=3402
2025-10-13 16:18:47.287765 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-10-13 16:18:47.287770 | controller | ZUUL_UUID=f351a4ad085742d68d019135ea0b3f59
2025-10-13 16:18:47.287776 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-10-13 16:18:47.287781 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-10-13 16:18:47.287787 | controller | }
2025-10-13 16:18:47.533549 | controller | ok: Runtime: 0:00:00.006062
2025-10-13 16:18:47.541605 | 
2025-10-13 16:18:47.541877 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-10-13 16:18:47.571482 | controller | skipping: Conditional result was False
2025-10-13 16:18:47.587376 | 
2025-10-13 16:18:47.587500 | TASK [Symlink /home/zuul-worker/workspace]
2025-10-13 16:18:48.137380 | controller | skipping: Conditional result was False
2025-10-13 16:18:48.143382 | 
2025-10-13 16:18:48.143454 | TASK [Ensure legacy workspace directory]
2025-10-13 16:18:48.384837 | controller | changed
2025-10-13 16:18:48.407617 | 
2025-10-13 16:18:48.407716 | PLAY RECAP
2025-10-13 16:18:48.407767 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-13 16:18:48.407791 | 
2025-10-13 16:18:48.492120 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-13 16:18:48.492841 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-13 16:18:49.008700 | 
2025-10-13 16:18:49.008819 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-10-13 16:18:49.029571 | 
2025-10-13 16:18:49.029682 | TASK [Create zuul-output directory]
2025-10-13 16:18:49.417496 | controller | changed
2025-10-13 16:18:49.422568 | 
2025-10-13 16:18:49.422645 | TASK [Slurp Zuul inventory test]
2025-10-13 16:18:49.710710 | controller -> localhost | ok
2025-10-13 16:18:49.716844 | 
2025-10-13 16:18:49.716943 | TASK [Save zuul inventory]
2025-10-13 16:18:50.849280 | controller | changed
2025-10-13 16:18:50.856146 | 
2025-10-13 16:18:50.856234 | TASK [Save zuul vars without the change_message]
2025-10-13 16:18:51.810560 | controller | changed
2025-10-13 16:18:51.828874 | 
2025-10-13 16:18:51.828982 | PLAY RECAP
2025-10-13 16:18:51.829032 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-13 16:18:51.829055 | 
2025-10-13 16:18:51.904852 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-13 16:18:51.905624 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-13 16:18:52.485495 | 
2025-10-13 16:18:52.485608 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-10-13 16:18:52.507803 | 
2025-10-13 16:18:52.507887 | TASK [Read group_vars]
2025-10-13 16:18:52.527349 | controller | ok
2025-10-13 16:18:52.545282 | 
2025-10-13 16:18:52.545376 | TASK [cifmw_helpers : Check directory is available]
2025-10-13 16:18:52.880649 | controller | ok
2025-10-13 16:18:52.885968 | 
2025-10-13 16:18:52.886046 | TASK [cifmw_helpers : Find yaml files]
2025-10-13 16:18:52.910611 | controller | skipping: Conditional result was False
2025-10-13 16:18:52.917408 | 
2025-10-13 16:18:52.917483 | TASK [cifmw_helpers : Print available yaml files]
2025-10-13 16:18:52.931606 | controller | skipping: Conditional result was False
2025-10-13 16:18:52.937235 | 
2025-10-13 16:18:52.937308 | LOOP [cifmw_helpers : Create files on localhost and use include_vars]
2025-10-13 16:18:52.963328 | 
2025-10-13 16:18:52.963456 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-10-13 16:18:52.987690 | controller | ok
2025-10-13 16:18:53.007833 | 
2025-10-13 16:18:53.007903 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-13 16:18:53.031772 | controller | skipping: Conditional result was False
2025-10-13 16:18:53.037889 | 
2025-10-13 16:18:53.037989 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-13 16:18:53.410052 | controller | ok
2025-10-13 16:18:53.417898 | 
2025-10-13 16:18:53.418006 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-13 16:18:54.182758 | controller | ok
2025-10-13 16:18:54.194656 | 
2025-10-13 16:18:54.194741 | TASK [Prepare workspace]
2025-10-13 16:18:54.212974 | controller | ok
2025-10-13 16:18:54.261401 | 
2025-10-13 16:18:54.261504 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-13 16:18:54.584962 | controller | ok
2025-10-13 16:18:54.591839 | 
2025-10-13 16:18:54.591950 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-13 16:18:56.986600 | controller | Output suppressed because no_log was given
2025-10-13 16:18:56.996110 | 
2025-10-13 16:18:56.996194 | LOOP [Create zuul-output directory]
2025-10-13 16:18:57.244596 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-10-13 16:18:57.244812 | 
2025-10-13 16:18:57.463703 | controller | ok: "/home/zuul/zuul-output/logs"
2025-10-13 16:18:57.471985 | 
2025-10-13 16:18:57.472102 | TASK [Install required packages]
2025-10-13 16:19:27.831886 | controller | ok: Nothing to do
2025-10-13 16:19:27.841411 | 
2025-10-13 16:19:27.841483 | TASK [Install venv]
2025-10-13 16:20:27.480004 | controller | changed
2025-10-13 16:20:27.516517 | 
2025-10-13 16:20:27.516598 | PLAY RECAP
2025-10-13 16:20:27.516643 | controller | ok: 8 changed: 3 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 0
2025-10-13 16:20:27.516668 | 
2025-10-13 16:20:27.599886 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-13 16:20:27.600718 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-13 16:20:28.136782 | 
2025-10-13 16:20:28.136896 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-10-13 16:20:28.158319 | 
2025-10-13 16:20:28.158416 | TASK [Gather required facts]
2025-10-13 16:20:28.755742 | controller | ok
2025-10-13 16:20:28.761301 | 
2025-10-13 16:20:28.761399 | TASK [Load environment var if instructed to]
2025-10-13 16:20:28.784951 | controller | skipping: Conditional result was False
2025-10-13 16:20:28.790580 | 
2025-10-13 16:20:28.790661 | TASK [Ensure group_vars dir exists]
2025-10-13 16:20:29.164018 | controller | ok
2025-10-13 16:20:29.169467 | 
2025-10-13 16:20:29.169537 | TASK [Run molecule]
2025-10-13 16:20:30.160437 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-10-13 16:20:30.230111 | controller | INFO     Performing prerun with role_name_check=0...
2025-10-13 16:20:49.788532 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/887b1e/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-13 16:20:49.788979 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/887b1e/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-13 16:20:49.789493 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/887b1e/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-13 16:20:49.789934 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/887b1e/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-13 16:20:49.790430 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+1932df63 was found installed in /home/zuul/.cache/ansible-compat/887b1e/collections/ansible_collections, only the first one will be used, 1.0.0+1932df63 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-13 16:20:49.790896 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/887b1e/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-13 16:20:49.791343 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/887b1e/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-13 16:20:49.791786 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/887b1e/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-13 16:20:49.792247 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/887b1e/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-13 16:20:49.792716 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/887b1e/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-13 16:20:49.793183 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/887b1e/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-13 16:20:49.793609 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/887b1e/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-13 16:20:49.794033 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/887b1e/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-13 16:20:49.794499 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/887b1e/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-13 16:20:49.794938 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/887b1e/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-13 16:20:49.805631 | controller | INFO     Running default > prepare
2025-10-13 16:20:50.541187 | controller |
2025-10-13 16:20:50.541244 | controller | PLAY [Prepare] *****************************************************************
2025-10-13 16:20:50.541359 | controller |
2025-10-13 16:20:50.541479 | controller | TASK [Gathering Facts] *********************************************************
2025-10-13 16:20:50.541584 | controller | Monday 13 October 2025  16:20:50 +0000 (0:00:00.029)       0:00:00.029 ********
2025-10-13 16:20:51.419570 | controller | ok: [instance]
2025-10-13 16:20:51.419642 | controller |
2025-10-13 16:20:51.419763 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-10-13 16:20:51.419869 | controller | Monday 13 October 2025  16:20:51 +0000 (0:00:00.879)       0:00:00.908 ********
2025-10-13 16:20:51.437994 | controller | skipping: [instance]
2025-10-13 16:20:51.438056 | controller |
2025-10-13 16:20:51.438179 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-10-13 16:20:51.438281 | controller | Monday 13 October 2025  16:20:51 +0000 (0:00:00.018)       0:00:00.927 ********
2025-10-13 16:20:51.481120 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-10-13 16:20:51.481197 | controller |
2025-10-13 16:20:51.481336 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-10-13 16:20:51.481419 | controller | Monday 13 October 2025  16:20:51 +0000 (0:00:00.042)       0:00:00.970 ********
2025-10-13 16:20:51.770188 | controller | ok: [instance]
2025-10-13 16:20:51.770288 | controller |
2025-10-13 16:20:51.770424 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-10-13 16:20:51.770537 | controller | Monday 13 October 2025  16:20:51 +0000 (0:00:00.289)       0:00:01.259 ********
2025-10-13 16:20:52.091584 | controller | ok: [instance]
2025-10-13 16:20:52.091691 | controller |
2025-10-13 16:20:52.091802 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-10-13 16:20:52.091910 | controller | Monday 13 October 2025  16:20:52 +0000 (0:00:00.321)       0:00:01.580 ********
2025-10-13 16:20:52.793716 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-10-13 16:20:52.793795 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-10-13 16:20:52.793899 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-10-13 16:20:52.793992 | controller |
2025-10-13 16:20:52.794101 | controller | TASK [Deploy repo-setup] *******************************************************
2025-10-13 16:20:52.794187 | controller | Monday 13 October 2025  16:20:52 +0000 (0:00:00.702)       0:00:02.282 ********
2025-10-13 16:20:52.854440 | controller |
2025-10-13 16:20:52.854524 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-10-13 16:20:52.854625 | controller | Monday 13 October 2025  16:20:52 +0000 (0:00:00.060)       0:00:02.343 ********
2025-10-13 16:20:53.420972 | controller | changed: [instance] => (item=tmp)
2025-10-13 16:20:53.421050 | controller | changed: [instance] => (item=artifacts/repositories)
2025-10-13 16:20:53.421161 | controller | changed: [instance] => (item=venv/repo_setup)
2025-10-13 16:20:53.421268 | controller |
2025-10-13 16:20:53.421356 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-10-13 16:20:53.421468 | controller | Monday 13 October 2025  16:20:53 +0000 (0:00:00.566)       0:00:02.910 ********
2025-10-13 16:20:54.240070 | controller | ok: [instance]
2025-10-13 16:20:54.240133 | controller |
2025-10-13 16:20:54.240405 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-10-13 16:20:55.382085 | controller | Monday 13 October 2025  16:20:54 +0000 (0:00:00.819)       0:00:03.729 ********
2025-10-13 16:20:55.382142 | controller | changed: [instance]
2025-10-13 16:21:03.403830 | controller |
2025-10-13 16:21:03.403868 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-10-13 16:21:03.403877 | controller | Monday 13 October 2025  16:20:55 +0000 (0:00:01.141)       0:00:04.870 ********
2025-10-13 16:21:03.403894 | controller | changed: [instance]
2025-10-13 16:21:04.147119 | controller |
2025-10-13 16:21:04.147160 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-10-13 16:21:04.147169 | controller | Monday 13 October 2025  16:21:03 +0000 (0:00:08.021)       0:00:12.892 ********
2025-10-13 16:21:04.147179 | controller | changed: [instance]
2025-10-13 16:21:04.169012 | controller |
2025-10-13 16:21:04.169037 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-10-13 16:21:04.169044 | controller | Monday 13 October 2025  16:21:04 +0000 (0:00:00.743)       0:00:13.635 ********
2025-10-13 16:21:04.169054 | controller | skipping: [instance]
2025-10-13 16:21:05.062517 | controller |
2025-10-13 16:21:05.062552 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-10-13 16:21:05.062561 | controller | Monday 13 October 2025  16:21:04 +0000 (0:00:00.022)       0:00:13.657 ********
2025-10-13 16:21:05.062572 | controller | changed: [instance]
2025-10-13 16:21:05.101082 | controller |
2025-10-13 16:21:05.101114 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-10-13 16:21:05.101123 | controller | Monday 13 October 2025  16:21:05 +0000 (0:00:00.893)       0:00:14.551 ********
2025-10-13 16:21:05.101132 | controller | skipping: [instance]
2025-10-13 16:21:05.142548 | controller |
2025-10-13 16:21:05.142594 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-10-13 16:21:05.142604 | controller | Monday 13 October 2025  16:21:05 +0000 (0:00:00.038)       0:00:14.589 ********
2025-10-13 16:21:05.142619 | controller | skipping: [instance]
2025-10-13 16:21:05.184343 | controller |
2025-10-13 16:21:05.184378 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-10-13 16:21:05.184386 | controller | Monday 13 October 2025  16:21:05 +0000 (0:00:00.041)       0:00:14.630 ********
2025-10-13 16:21:05.184418 | controller | skipping: [instance]
2025-10-13 16:21:05.771711 | controller |
2025-10-13 16:21:05.771745 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-10-13 16:21:05.771753 | controller | Monday 13 October 2025  16:21:05 +0000 (0:00:00.042)       0:00:14.673 ********
2025-10-13 16:21:05.771763 | controller | changed: [instance]
2025-10-13 16:21:06.216491 | controller |
2025-10-13 16:21:06.216525 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-10-13 16:21:06.216533 | controller | Monday 13 October 2025  16:21:05 +0000 (0:00:00.587)       0:00:15.260 ********
2025-10-13 16:21:06.216543 | controller | changed: [instance]
2025-10-13 16:21:06.247089 | controller |
2025-10-13 16:21:06.247124 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-10-13 16:21:06.247132 | controller | Monday 13 October 2025  16:21:06 +0000 (0:00:00.444)       0:00:15.705 ********
2025-10-13 16:21:06.247143 | controller | skipping: [instance]
2025-10-13 16:21:06.278492 | controller |
2025-10-13 16:21:06.278526 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-10-13 16:21:06.278534 | controller | Monday 13 October 2025  16:21:06 +0000 (0:00:00.030)       0:00:15.735 ********
2025-10-13 16:21:06.278548 | controller | skipping: [instance]
2025-10-13 16:21:06.309489 | controller |
2025-10-13 16:21:06.309523 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-10-13 16:21:06.309532 | controller | Monday 13 October 2025  16:21:06 +0000 (0:00:00.031)       0:00:15.767 ********
2025-10-13 16:21:06.309542 | controller | skipping: [instance]
2025-10-13 16:21:06.309761 | controller |
2025-10-13 16:21:06.309799 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-10-13 16:21:06.349538 | controller | Monday 13 October 2025  16:21:06 +0000 (0:00:00.031)       0:00:15.798 ********
2025-10-13 16:21:06.349576 | controller | ok: [instance]
2025-10-13 16:21:06.349603 | controller |
2025-10-13 16:21:06.349610 | controller | TASK [repo_setup : Create download directory] **********************************
2025-10-13 16:21:06.349618 | controller | Monday 13 October 2025  16:21:06 +0000 (0:00:00.040)       0:00:15.838 ********
2025-10-13 16:21:06.378497 | controller | skipping: [instance]
2025-10-13 16:21:06.378548 | controller |
2025-10-13 16:21:06.378746 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-10-13 16:21:06.406858 | controller | Monday 13 October 2025  16:21:06 +0000 (0:00:00.029)       0:00:15.867 ********
2025-10-13 16:21:06.406898 | controller | skipping: [instance]
2025-10-13 16:21:06.407048 | controller |
2025-10-13 16:21:06.407190 | controller | TASK [Download the RPM] ********************************************************
2025-10-13 16:21:06.407346 | controller | Monday 13 October 2025  16:21:06 +0000 (0:00:00.028)       0:00:15.896 ********
2025-10-13 16:21:06.434295 | controller | skipping: [instance]
2025-10-13 16:21:06.434497 | controller |
2025-10-13 16:21:06.434654 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-10-13 16:21:06.434796 | controller | Monday 13 October 2025  16:21:06 +0000 (0:00:00.027)       0:00:15.923 ********
2025-10-13 16:21:06.462615 | controller | skipping: [instance]
2025-10-13 16:21:06.462713 | controller |
2025-10-13 16:21:06.462810 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-10-13 16:21:06.462971 | controller | Monday 13 October 2025  16:21:06 +0000 (0:00:00.028)       0:00:15.951 ********
2025-10-13 16:21:06.490304 | controller | skipping: [instance]
2025-10-13 16:21:06.490414 | controller |
2025-10-13 16:21:06.490543 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-10-13 16:21:06.490667 | controller | Monday 13 October 2025  16:21:06 +0000 (0:00:00.027)       0:00:15.979 ********
2025-10-13 16:21:06.520349 | controller | skipping: [instance]
2025-10-13 16:21:06.520504 | controller |
2025-10-13 16:21:06.520666 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-10-13 16:21:06.520774 | controller | Monday 13 October 2025  16:21:06 +0000 (0:00:00.030)       0:00:16.009 ********
2025-10-13 16:21:06.549735 | controller | skipping: [instance]
2025-10-13 16:21:06.549852 | controller |
2025-10-13 16:21:06.549977 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-10-13 16:21:06.550098 | controller | Monday 13 October 2025  16:21:06 +0000 (0:00:00.029)       0:00:16.039 ********
2025-10-13 16:21:06.740248 | controller | ok: [instance]
2025-10-13 16:21:06.950534 | controller |
2025-10-13 16:21:06.950567 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-10-13 16:21:06.950576 | controller | Monday 13 October 2025  16:21:06 +0000 (0:00:00.189)       0:00:16.229 ********
2025-10-13 16:21:06.950587 | controller | changed: [instance]
2025-10-13 16:21:07.187536 | controller |
2025-10-13 16:21:07.187587 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-10-13 16:21:07.187596 | controller | Monday 13 October 2025  16:21:06 +0000 (0:00:00.209)       0:00:16.438 ********
2025-10-13 16:21:07.187608 | controller | changed: [instance]
2025-10-13 16:21:07.209281 | controller |
2025-10-13 16:21:07.209323 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-10-13 16:21:07.209332 | controller | Monday 13 October 2025  16:21:07 +0000 (0:00:00.237)       0:00:16.676 ********
2025-10-13 16:21:07.209345 | controller | skipping: [instance]
2025-10-13 16:21:07.233273 | controller |
2025-10-13 16:21:07.233312 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-10-13 16:21:07.233320 | controller | Monday 13 October 2025  16:21:07 +0000 (0:00:00.022)       0:00:16.698 ********
2025-10-13 16:21:07.233331 | controller | skipping: [instance]
2025-10-13 16:21:07.257541 | controller |
2025-10-13 16:21:07.257579 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-10-13 16:21:07.257588 | controller | Monday 13 October 2025  16:21:07 +0000 (0:00:00.024)       0:00:16.722 ********
2025-10-13 16:21:07.257605 | controller | skipping: [instance]
2025-10-13 16:21:07.282497 | controller |
2025-10-13 16:21:07.282591 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-10-13 16:21:07.282601 | controller | Monday 13 October 2025  16:21:07 +0000 (0:00:00.023)       0:00:16.746 ********
2025-10-13 16:21:07.282618 | controller | skipping: [instance]
2025-10-13 16:21:07.282656 | controller |
2025-10-13 16:21:07.282786 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-10-13 16:21:07.282798 | controller | Monday 13 October 2025  16:21:07 +0000 (0:00:00.025)       0:00:16.771 ********
2025-10-13 16:21:07.306761 | controller | skipping: [instance]
2025-10-13 16:21:07.306925 | controller |
2025-10-13 16:21:07.307072 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-10-13 16:21:07.307196 | controller | Monday 13 October 2025  16:21:07 +0000 (0:00:00.024)       0:00:16.795 ********
2025-10-13 16:21:07.331360 | controller | skipping: [instance]
2025-10-13 16:21:07.331515 | controller |
2025-10-13 16:21:07.331648 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-10-13 16:21:07.331767 | controller | Monday 13 October 2025  16:21:07 +0000 (0:00:00.023)       0:00:16.819 ********
2025-10-13 16:21:07.348153 | controller | skipping: [instance]
2025-10-13 16:21:07.348294 | controller |
2025-10-13 16:21:07.348446 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-10-13 16:21:07.348590 | controller | Monday 13 October 2025  16:21:07 +0000 (0:00:00.017)       0:00:16.837 ********
2025-10-13 16:21:07.377873 | controller | skipping: [instance]
2025-10-13 16:21:07.378015 | controller |
2025-10-13 16:21:07.378252 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-10-13 16:21:07.378302 | controller | Monday 13 October 2025  16:21:07 +0000 (0:00:00.029)       0:00:16.867 ********
2025-10-13 16:21:07.396631 | controller | skipping: [instance]
2025-10-13 16:21:07.396743 | controller |
2025-10-13 16:21:07.396859 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-10-13 16:21:07.396972 | controller | Monday 13 October 2025  16:21:07 +0000 (0:00:00.019)       0:00:16.886 ********
2025-10-13 16:21:07.420665 | controller | skipping: [instance]
2025-10-13 16:21:07.420810 | controller |
2025-10-13 16:21:07.420961 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-10-13 16:21:07.421093 | controller | Monday 13 October 2025  16:21:07 +0000 (0:00:00.023)       0:00:16.909 ********
2025-10-13 16:21:07.452954 | controller | skipping: [instance]
2025-10-13 16:21:07.453112 | controller |
2025-10-13 16:21:07.453253 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-10-13 16:21:07.453377 | controller | Monday 13 October 2025  16:21:07 +0000 (0:00:00.032)       0:00:16.941 ********
2025-10-13 16:21:07.483929 | controller | skipping: [instance]
2025-10-13 16:21:07.484049 | controller |
2025-10-13 16:21:07.484178 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-10-13 16:21:07.484312 | controller | Monday 13 October 2025  16:21:07 +0000 (0:00:00.031)       0:00:16.972 ********
2025-10-13 16:21:07.512711 | controller | skipping: [instance]
2025-10-13 16:21:07.512858 | controller |
2025-10-13 16:21:07.513022 | controller | TASK [test_deps : Install additional packages] *********************************
2025-10-13 16:21:07.513164 | controller | Monday 13 October 2025  16:21:07 +0000 (0:00:00.028)       0:00:17.001 ********
2025-10-13 16:21:07.543089 | controller | skipping: [instance]
2025-10-13 16:21:07.543215 | controller |
2025-10-13 16:21:07.543351 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-10-13 16:21:07.543492 | controller | Monday 13 October 2025  16:21:07 +0000 (0:00:00.030)       0:00:17.032 ********
2025-10-13 16:21:50.153026 | controller | ok: [instance]
2025-10-13 16:21:51.404966 | controller |
2025-10-13 16:21:51.404998 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-10-13 16:21:51.405006 | controller | Monday 13 October 2025  16:21:50 +0000 (0:00:42.609)       0:00:59.641 ********
2025-10-13 16:21:51.405016 | controller | ok: [instance]
2025-10-13 16:21:51.445620 | controller |
2025-10-13 16:21:51.445657 | controller | TASK [test_deps : Install extra packages] **************************************
2025-10-13 16:21:51.445666 | controller | Monday 13 October 2025  16:21:51 +0000 (0:00:01.251)       0:01:00.893 ********
2025-10-13 16:21:51.445677 | controller | skipping: [instance]
2025-10-13 16:21:51.498909 | controller |
2025-10-13 16:21:51.498940 | controller | TASK [ci_setup : Gather variables for each operating system] *******************
2025-10-13 16:21:51.498948 | controller | Monday 13 October 2025  16:21:51 +0000 (0:00:00.040)       0:01:00.934 ********
2025-10-13 16:21:51.498958 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/ci_setup/vars/redhat.yml)
2025-10-13 16:21:51.525791 | controller |
2025-10-13 16:21:51.525885 | controller | TASK [ci_setup : List packages to install] *************************************
2025-10-13 16:21:51.525895 | controller | Monday 13 October 2025  16:21:51 +0000 (0:00:00.053)       0:01:00.987 ********
2025-10-13 16:21:51.525948 | controller | ok: [instance] =>
2025-10-13 16:21:57.315937 | controller |   cifmw_ci_setup_packages:
2025-10-13 16:21:57.315970 | controller |   - bash-completion
2025-10-13 16:21:57.315978 | controller |   - ca-certificates
2025-10-13 16:21:57.315984 | controller |   - git-core
2025-10-13 16:21:57.315989 | controller |   - make
2025-10-13 16:21:57.315995 | controller |   - tar
2025-10-13 16:21:57.316000 | controller |   - tmux
2025-10-13 16:21:57.316005 | controller |   - python3-pip
2025-10-13 16:21:57.316011 | controller |
2025-10-13 16:21:57.316017 | controller | TASK [ci_setup : Install needed packages] **************************************
2025-10-13 16:21:57.316028 | controller | Monday 13 October 2025  16:21:51 +0000 (0:00:00.026)       0:01:01.013 ********
2025-10-13 16:21:57.316038 | controller | changed: [instance]
2025-10-13 16:21:57.892706 | controller |
2025-10-13 16:21:57.892739 | controller | TASK [ci_setup : Gather version of openshift client] ***************************
2025-10-13 16:21:57.892747 | controller | Monday 13 October 2025  16:21:57 +0000 (0:00:05.789)       0:01:06.803 ********
2025-10-13 16:21:57.892758 | controller | ok: [instance]
2025-10-13 16:21:57.892776 | controller |
2025-10-13 16:21:57.892873 | controller | TASK [ci_setup : Ensure openshift client install path is present] **************
2025-10-13 16:21:57.892958 | controller | Monday 13 October 2025  16:21:57 +0000 (0:00:00.578)       0:01:07.381 ********
2025-10-13 16:21:58.101065 | controller | changed: [instance]
2025-10-13 16:22:04.268623 | controller |
2025-10-13 16:22:04.268877 | controller | TASK [ci_setup : Install openshift client] *************************************
2025-10-13 16:22:04.268891 | controller | Monday 13 October 2025  16:21:58 +0000 (0:00:00.207)       0:01:07.589 ********
2025-10-13 16:22:04.268916 | controller | changed: [instance]
2025-10-13 16:22:04.317223 | controller |
2025-10-13 16:22:04.317266 | controller | TASK [ci_setup : Add the OC path to cifmw_path if needed] **********************
2025-10-13 16:22:04.317274 | controller | Monday 13 October 2025  16:22:04 +0000 (0:00:06.167)       0:01:13.757 ********
2025-10-13 16:22:04.317285 | controller | skipping: [instance]
2025-10-13 16:22:04.586079 | controller |
2025-10-13 16:22:04.586124 | controller | TASK [ci_setup : Create completion file] ***************************************
2025-10-13 16:22:04.586133 | controller | Monday 13 October 2025  16:22:04 +0000 (0:00:00.048)       0:01:13.806 ********
2025-10-13 16:22:04.586143 | controller | changed: [instance]
2025-10-13 16:22:04.866426 | controller |
2025-10-13 16:22:04.866459 | controller | TASK [ci_setup : Source completion from within .bashrc] ************************
2025-10-13 16:22:04.866467 | controller | Monday 13 October 2025  16:22:04 +0000 (0:00:00.268)       0:01:14.074 ********
2025-10-13 16:22:04.866476 | controller | changed: [instance]
2025-10-13 16:22:04.883932 | controller |
2025-10-13 16:22:04.883959 | controller | TASK [ci_setup : Check rhsm status] ********************************************
2025-10-13 16:22:04.883973 | controller | Monday 13 October 2025  16:22:04 +0000 (0:00:00.280)       0:01:14.355 ********
2025-10-13 16:22:04.883983 | controller | skipping: [instance]
2025-10-13 16:22:04.901539 | controller |
2025-10-13 16:22:04.901570 | controller | TASK [ci_setup : Gather the repos to be enabled] *******************************
2025-10-13 16:22:04.901578 | controller | Monday 13 October 2025  16:22:04 +0000 (0:00:00.017)       0:01:14.372 ********
2025-10-13 16:22:04.901589 | controller | skipping: [instance]
2025-10-13 16:22:04.919086 | controller |
2025-10-13 16:22:04.919133 | controller | TASK [ci_setup : Enabling the required repositories.] **************************
2025-10-13 16:22:04.919142 | controller | Monday 13 October 2025  16:22:04 +0000 (0:00:00.017)       0:01:14.390 ********
2025-10-13 16:22:04.919152 | controller | skipping: [instance]
2025-10-13 16:22:04.936467 | controller |
2025-10-13 16:22:04.936496 | controller | TASK [ci_setup : Get current /etc/redhat-release] ******************************
2025-10-13 16:22:04.936503 | controller | Monday 13 October 2025  16:22:04 +0000 (0:00:00.017)       0:01:14.408 ********
2025-10-13 16:22:04.936514 | controller | skipping: [instance]
2025-10-13 16:22:04.936624 | controller |
2025-10-13 16:22:04.936650 | controller | TASK [ci_setup : Print current /etc/redhat-release] ****************************
2025-10-13 16:22:04.936663 | controller | Monday 13 October 2025  16:22:04 +0000 (0:00:00.017)       0:01:14.425 ********
2025-10-13 16:22:04.955361 | controller | skipping: [instance]
2025-10-13 16:22:04.978586 | controller |
2025-10-13 16:22:04.978611 | controller | TASK [ci_setup : Ensure the repos are enabled in the system using yum] *********
2025-10-13 16:22:04.978628 | controller | Monday 13 October 2025  16:22:04 +0000 (0:00:00.018)       0:01:14.444 ********
2025-10-13 16:22:04.978640 | controller | skipping: [instance]
2025-10-13 16:22:04.978816 | controller |
2025-10-13 16:22:04.978989 | controller | TASK [ci_setup : Manage directories] *******************************************
2025-10-13 16:22:04.979159 | controller | Monday 13 October 2025  16:22:04 +0000 (0:00:00.023)       0:01:14.467 ********
2025-10-13 16:22:05.973026 | controller | changed: [instance] => (item=/home/zuul/ci-framework-data/artifacts/manifests/openstack/cr)
2025-10-13 16:22:06.169065 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/logs)
2025-10-13 16:22:06.169095 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/tmp)
2025-10-13 16:22:06.169116 | controller | changed: [instance] => (item=/home/zuul/ci-framework-data/volumes)
2025-10-13 16:22:06.169123 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/artifacts/parameters)
2025-10-13 16:22:06.169129 | controller |
2025-10-13 16:22:06.169134 | controller | TASK [libvirt_manager : Ensure output directory exists] ************************
2025-10-13 16:22:06.169139 | controller | Monday 13 October 2025  16:22:05 +0000 (0:00:00.993)       0:01:15.461 ********
2025-10-13 16:22:06.169149 | controller | ok: [instance]
2025-10-13 16:22:06.350842 | controller |
2025-10-13 16:22:06.350872 | controller | TASK [libvirt_manager : Get vmx/svm extensions from /proc/cpuinfo] *************
2025-10-13 16:22:06.350886 | controller | Monday 13 October 2025  16:22:06 +0000 (0:00:00.196)       0:01:15.658 ********
2025-10-13 16:22:06.350897 | controller | changed: [instance]
2025-10-13 16:22:06.537387 | controller |
2025-10-13 16:22:06.537435 | controller | TASK [libvirt_manager : Check if KVM is enabled] *******************************
2025-10-13 16:22:06.537443 | controller | Monday 13 October 2025  16:22:06 +0000 (0:00:00.181)       0:01:15.839 ********
2025-10-13 16:22:06.537453 | controller | ok: [instance]
2025-10-13 16:22:06.564575 | controller |
2025-10-13 16:22:06.564618 | controller | TASK [libvirt_manager : Fail if KVM not enabled] *******************************
2025-10-13 16:22:06.564628 | controller | Monday 13 October 2025  16:22:06 +0000 (0:00:00.186)       0:01:16.026 ********
2025-10-13 16:22:06.564642 | controller | skipping: [instance]
2025-10-13 16:22:06.564678 | controller |
2025-10-13 16:22:06.564688 | controller | TASK [libvirt_manager : Check if VMX virtualization] ***************************
2025-10-13 16:22:06.581183 | controller | Monday 13 October 2025  16:22:06 +0000 (0:00:00.027)       0:01:16.053 ********
2025-10-13 16:22:06.581214 | controller | skipping: [instance]
2025-10-13 16:22:06.600248 | controller |
2025-10-13 16:22:06.600268 | controller | TASK [libvirt_manager : Check if SVM virtualization] ***************************
2025-10-13 16:22:06.600275 | controller | Monday 13 October 2025  16:22:06 +0000 (0:00:00.016)       0:01:16.070 ********
2025-10-13 16:22:06.600285 | controller | ok: [instance]
2025-10-13 16:22:06.626088 | controller |
2025-10-13 16:22:06.626132 | controller | TASK [libvirt_manager : Enable VMX virtualization] *****************************
2025-10-13 16:22:06.626141 | controller | Monday 13 October 2025  16:22:06 +0000 (0:00:00.018)       0:01:16.089 ********
2025-10-13 16:22:06.626151 | controller | skipping: [instance]
2025-10-13 16:22:18.924838 | controller |
2025-10-13 16:22:18.924885 | controller | TASK [libvirt_manager : Install packages required for using KVM] ***************
2025-10-13 16:22:18.924894 | controller | Monday 13 October 2025  16:22:06 +0000 (0:00:00.025)       0:01:16.115 ********
2025-10-13 16:22:18.924907 | controller | changed: [instance]
2025-10-13 16:22:19.157251 | controller |
2025-10-13 16:22:19.157296 | controller | TASK [libvirt_manager : Create rules.d polkit folder] **************************
2025-10-13 16:22:19.157305 | controller | Monday 13 October 2025  16:22:18 +0000 (0:00:12.297)       0:01:28.413 ********
2025-10-13 16:22:19.157319 | controller | changed: [instance]
2025-10-13 16:22:19.579507 | controller |
2025-10-13 16:22:19.579552 | controller | TASK [libvirt_manager : Enable UNIX socket PolicyKit auth] *********************
2025-10-13 16:22:19.579560 | controller | Monday 13 October 2025  16:22:19 +0000 (0:00:00.232)       0:01:28.645 ********
2025-10-13 16:22:19.579572 | controller | changed: [instance]
2025-10-13 16:22:19.579604 | controller |
2025-10-13 16:22:19.579752 | controller | TASK [libvirt_manager : Restart service polkit service] ************************
2025-10-13 16:22:19.579866 | controller | Monday 13 October 2025  16:22:19 +0000 (0:00:00.422)       0:01:29.068 ********
2025-10-13 16:22:20.257575 | controller | changed: [instance]
2025-10-13 16:22:20.469887 | controller |
2025-10-13 16:22:20.469948 | controller | TASK [libvirt_manager : Remove directory for service override] *****************
2025-10-13 16:22:20.469957 | controller | Monday 13 October 2025  16:22:20 +0000 (0:00:00.677)       0:01:29.746 ********
2025-10-13 16:22:20.469970 | controller | ok: [instance]
2025-10-13 16:22:21.186213 | controller |
2025-10-13 16:22:21.186258 | controller | TASK [libvirt_manager : Reload systemctl and start/enable virtproxyd.service] ***
2025-10-13 16:22:21.186267 | controller | Monday 13 October 2025  16:22:20 +0000 (0:00:00.212)       0:01:29.958 ********
2025-10-13 16:22:21.186279 | controller | ok: [instance]
2025-10-13 16:22:22.212045 | controller |
2025-10-13 16:22:22.212101 | controller | TASK [libvirt_manager : Ensure firewalld service is up] ************************
2025-10-13 16:22:22.212112 | controller | Monday 13 October 2025  16:22:21 +0000 (0:00:00.716)       0:01:30.674 ********
2025-10-13 16:22:22.212129 | controller | changed: [instance]
2025-10-13 16:22:22.299570 | controller |
2025-10-13 16:22:22.299608 | controller | TASK [libvirt_manager : Ensure libvirt modular driver daemons are started.] ****
2025-10-13 16:22:22.299617 | controller | Monday 13 October 2025  16:22:22 +0000 (0:00:01.025)       0:01:31.700 ********
2025-10-13 16:22:22.299628 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=qemu)
2025-10-13 16:22:22.299671 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=interface)
2025-10-13 16:22:22.299679 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=network)
2025-10-13 16:22:22.299684 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nodedev)
2025-10-13 16:22:22.299692 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nwfilter)
2025-10-13 16:22:22.300224 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=secret)
2025-10-13 16:22:22.300251 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=storage)
2025-10-13 16:22:23.662960 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=proxy)
2025-10-13 16:22:23.663001 | controller |
2025-10-13 16:22:23.663009 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for qemu.] *********
2025-10-13 16:22:23.663015 | controller | Monday 13 October 2025  16:22:22 +0000 (0:00:00.088)       0:01:31.788 ********
2025-10-13 16:22:23.663026 | controller | ok: [instance]
2025-10-13 16:22:24.038276 | controller |
2025-10-13 16:22:24.038339 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for qemu.] **********
2025-10-13 16:22:24.038348 | controller | Monday 13 October 2025  16:22:23 +0000 (0:00:01.363)       0:01:33.151 ********
2025-10-13 16:22:24.038377 | controller | ok: [instance]
2025-10-13 16:22:24.404605 | controller |
2025-10-13 16:22:24.404696 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for qemu.] **************
2025-10-13 16:22:24.404706 | controller | Monday 13 October 2025  16:22:24 +0000 (0:00:00.374)       0:01:33.526 ********
2025-10-13 16:22:24.404725 | controller | ok: [instance]
2025-10-13 16:22:24.770575 | controller |
2025-10-13 16:22:24.770619 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for interface.] ****
2025-10-13 16:22:24.770627 | controller | Monday 13 October 2025  16:22:24 +0000 (0:00:00.366)       0:01:33.892 ********
2025-10-13 16:22:24.770639 | controller | ok: [instance]
2025-10-13 16:22:25.131481 | controller |
2025-10-13 16:22:25.131561 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for interface.] *****
2025-10-13 16:22:25.131570 | controller | Monday 13 October 2025  16:22:24 +0000 (0:00:00.366)       0:01:34.259 ********
2025-10-13 16:22:25.131588 | controller | ok: [instance]
2025-10-13 16:22:26.492976 | controller |
2025-10-13 16:22:26.493009 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for interface.] *********
2025-10-13 16:22:26.493017 | controller | Monday 13 October 2025  16:22:25 +0000 (0:00:00.360)       0:01:34.619 ********
2025-10-13 16:22:26.493027 | controller | ok: [instance]
2025-10-13 16:22:26.836482 | controller |
2025-10-13 16:22:26.836549 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for network.] ******
2025-10-13 16:22:26.836559 | controller | Monday 13 October 2025  16:22:26 +0000 (0:00:01.361)       0:01:35.981 ********
2025-10-13 16:22:26.836574 | controller | ok: [instance]
2025-10-13 16:22:26.836615 | controller |
2025-10-13 16:22:26.836624 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for network.] *******
2025-10-13 16:22:27.177481 | controller | Monday 13 October 2025  16:22:26 +0000 (0:00:00.343)       0:01:36.325 ********
2025-10-13 16:22:27.177539 | controller | ok: [instance]
2025-10-13 16:22:27.177781 | controller |
2025-10-13 16:22:27.177817 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for network.] ***********
2025-10-13 16:22:27.528553 | controller | Monday 13 October 2025  16:22:27 +0000 (0:00:00.341)       0:01:36.666 ********
2025-10-13 16:22:27.528598 | controller | ok: [instance]
2025-10-13 16:22:27.528629 | controller |
2025-10-13 16:22:27.528640 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nodedev.] ******
2025-10-13 16:22:27.528799 | controller | Monday 13 October 2025  16:22:27 +0000 (0:00:00.350)       0:01:37.017 ********
2025-10-13 16:22:27.860834 | controller | ok: [instance]
2025-10-13 16:22:28.193272 | controller |
2025-10-13 16:22:28.193303 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nodedev.] *******
2025-10-13 16:22:28.193311 | controller | Monday 13 October 2025  16:22:27 +0000 (0:00:00.332)       0:01:37.349 ********
2025-10-13 16:22:28.193322 | controller | ok: [instance]
2025-10-13 16:22:28.523039 | controller |
2025-10-13 16:22:28.523075 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nodedev.] ***********
2025-10-13 16:22:28.523084 | controller | Monday 13 October 2025  16:22:28 +0000 (0:00:00.332)       0:01:37.682 ********
2025-10-13 16:22:28.523096 | controller | ok: [instance]
2025-10-13 16:22:28.858119 | controller |
2025-10-13 16:22:28.858151 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nwfilter.] *****
2025-10-13 16:22:28.858159 | controller | Monday 13 October 2025  16:22:28 +0000 (0:00:00.329)       0:01:38.011 ********
2025-10-13 16:22:28.858169 | controller | ok: [instance]
2025-10-13 16:22:29.192526 | controller |
2025-10-13 16:22:29.192562 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nwfilter.] ******
2025-10-13 16:22:29.192573 | controller | Monday 13 October 2025  16:22:28 +0000 (0:00:00.335)       0:01:38.346 ********
2025-10-13 16:22:29.192585 | controller | ok: [instance]
2025-10-13 16:22:29.192614 | controller |
2025-10-13 16:22:29.192624 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nwfilter.] **********
2025-10-13 16:22:29.192694 | controller | Monday 13 October 2025  16:22:29 +0000 (0:00:00.334)       0:01:38.681 ********
2025-10-13 16:22:30.519006 | controller | ok: [instance]
2025-10-13 16:22:30.869654 | controller |
2025-10-13 16:22:30.869728 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for secret.] *******
2025-10-13 16:22:30.869738 | controller | Monday 13 October 2025  16:22:30 +0000 (0:00:01.326)       0:01:40.007 ********
2025-10-13 16:22:30.869752 | controller | ok: [instance]
2025-10-13 16:22:31.217131 | controller |
2025-10-13 16:22:31.217162 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for secret.] ********
2025-10-13 16:22:31.217170 | controller | Monday 13 October 2025  16:22:30 +0000 (0:00:00.350)       0:01:40.358 ********
2025-10-13 16:22:31.217179 | controller | ok: [instance]
2025-10-13 16:22:31.583556 | controller |
2025-10-13 16:22:31.583655 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for secret.] ************
2025-10-13 16:22:31.583702 | controller | Monday 13 October 2025  16:22:31 +0000 (0:00:00.347)       0:01:40.706 ********
2025-10-13 16:22:31.583725 | controller | ok: [instance]
2025-10-13 16:22:31.946541 | controller |
2025-10-13 16:22:31.946574 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for storage.] ******
2025-10-13 16:22:31.946582 | controller | Monday 13 October 2025  16:22:31 +0000 (0:00:00.366)       0:01:41.072 ********
2025-10-13 16:22:31.946602 | controller | ok: [instance]
2025-10-13 16:22:33.304493 | controller |
2025-10-13 16:22:33.304529 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for storage.] *******
2025-10-13 16:22:33.304537 | controller | Monday 13 October 2025  16:22:31 +0000 (0:00:00.363)       0:01:41.435 ********
2025-10-13 16:22:33.304547 | controller | ok: [instance]
2025-10-13 16:22:33.655284 | controller |
2025-10-13 16:22:33.655317 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for storage.] ***********
2025-10-13 16:22:33.655325 | controller | Monday 13 October 2025  16:22:33 +0000 (0:00:01.357)       0:01:42.793 ********
2025-10-13 16:22:33.655336 | controller | ok: [instance]
2025-10-13 16:22:34.005940 | controller |
2025-10-13 16:22:34.005972 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for proxy.] ********
2025-10-13 16:22:34.005980 | controller | Monday 13 October 2025  16:22:33 +0000 (0:00:00.350)       0:01:43.144 ********
2025-10-13 16:22:34.005991 | controller | ok: [instance]
2025-10-13 16:22:34.340641 | controller |
2025-10-13 16:22:34.340704 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for proxy.] *********
2025-10-13 16:22:34.340716 | controller | Monday 13 October 2025  16:22:34 +0000 (0:00:00.350)       0:01:43.494 ********
2025-10-13 16:22:34.340732 | controller | ok: [instance]
2025-10-13 16:22:34.340755 | controller |
2025-10-13 16:22:34.340765 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for proxy.] *************
2025-10-13 16:22:34.676940 | controller | Monday 13 October 2025  16:22:34 +0000 (0:00:00.334)       0:01:43.829 ********
2025-10-13 16:22:34.676983 | controller | ok: [instance]
2025-10-13 16:22:34.677003 | controller |
2025-10-13 16:22:34.677198 | controller | TASK [libvirt_manager : Manage service for older releases] *********************
2025-10-13 16:22:34.700016 | controller | Monday 13 October 2025  16:22:34 +0000 (0:00:00.336)       0:01:44.165 ********
2025-10-13 16:22:34.700047 | controller | skipping: [instance]
2025-10-13 16:22:34.993630 | controller |
2025-10-13 16:22:34.993667 | controller | TASK [libvirt_manager : Get libvirt group users] *******************************
2025-10-13 16:22:34.993676 | controller | Monday 13 October 2025  16:22:34 +0000 (0:00:00.022)       0:01:44.188 ********
2025-10-13 16:22:34.993688 | controller | ok: [instance]
2025-10-13 16:22:34.993717 | controller |
2025-10-13 16:22:34.993727 | controller | TASK [libvirt_manager : Add user if not exists in libvirt group] ***************
2025-10-13 16:22:34.993753 | controller | Monday 13 October 2025  16:22:34 +0000 (0:00:00.293)       0:01:44.482 ********
2025-10-13 16:22:35.394328 | controller | ok: [instance]
2025-10-13 16:22:35.722464 | controller |
2025-10-13 16:22:35.722499 | controller | TASK [libvirt_manager : Allow QEMU on home directory for the storage access] ***
2025-10-13 16:22:35.722507 | controller | Monday 13 October 2025  16:22:35 +0000 (0:00:00.400)       0:01:44.883 ********
2025-10-13 16:22:35.722518 | controller | changed: [instance]
2025-10-13 16:22:35.922564 | controller |
2025-10-13 16:22:35.922614 | controller | TASK [libvirt_manager : Inject system connection parameters in bashrc] *********
2025-10-13 16:22:35.922624 | controller | Monday 13 October 2025  16:22:35 +0000 (0:00:00.328)       0:01:45.211 ********
2025-10-13 16:22:35.922636 | controller | [WARNING]: Reset is not implemented for this connection
2025-10-13 16:22:35.944474 | controller | changed: [instance]
2025-10-13 16:22:35.945525 | controller |
2025-10-13 16:22:35.945557 | controller | TASK [libvirt_manager : Ensure we reload user env] *****************************
2025-10-13 16:22:35.945596 | controller | Monday 13 October 2025  16:22:35 +0000 (0:00:00.195)       0:01:45.406 ********
2025-10-13 16:22:35.945605 | controller |
2025-10-13 16:22:35.945612 | controller | PLAY RECAP *********************************************************************
2025-10-13 16:22:35.945618 | controller | instance                   : ok=75   changed=23   unreachable=0    failed=0    skipped=41   rescued=0    ignored=0
2025-10-13 16:22:35.945625 | controller |
2025-10-13 16:22:35.945632 | controller | Monday 13 October 2025  16:22:35 +0000 (0:00:00.026)       0:01:45.433 ********
2025-10-13 16:22:35.945638 | controller | ===============================================================================
2025-10-13 16:22:35.945645 | controller | test_deps : Install selinux python libs -------------------------------- 42.61s
2025-10-13 16:22:35.945651 | controller | libvirt_manager : Install packages required for using KVM -------------- 12.30s
2025-10-13 16:22:35.945660 | controller | repo_setup : Initialize python venv and install requirements ------------ 8.02s
2025-10-13 16:22:35.945700 | controller | ci_setup : Install openshift client ------------------------------------- 6.17s
2025-10-13 16:22:35.947085 | controller | ci_setup : Install needed packages -------------------------------------- 5.79s
2025-10-13 16:22:36.011792 | controller | libvirt_manager : Ensure read-write socket is enabled for qemu. --------- 1.36s
2025-10-13 16:22:36.011826 | controller | libvirt_manager : Ensure admin socket is enabled for interface. --------- 1.36s
2025-10-13 16:22:36.011833 | controller | libvirt_manager : Ensure read-only socket is enabled for storage. ------- 1.36s
2025-10-13 16:22:36.011838 | controller | libvirt_manager : Ensure admin socket is enabled for nwfilter. ---------- 1.33s
2025-10-13 16:22:36.011844 | controller | test_deps : Install python yaml libs ------------------------------------ 1.25s
2025-10-13 16:22:36.011849 | controller | repo_setup : Get repo-setup repository ---------------------------------- 1.14s
2025-10-13 16:22:36.011854 | controller | libvirt_manager : Ensure firewalld service is up ------------------------ 1.03s
2025-10-13 16:22:36.011859 | controller | ci_setup : Manage directories ------------------------------------------- 0.99s
2025-10-13 16:22:36.011864 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.89s
2025-10-13 16:22:36.011869 | controller | Gathering Facts --------------------------------------------------------- 0.88s
2025-10-13 16:22:36.011874 | controller | repo_setup : Make sure git-core package is installed -------------------- 0.82s
2025-10-13 16:22:36.011879 | controller | repo_setup : Install repo-setup package --------------------------------- 0.74s
2025-10-13 16:22:36.011884 | controller | libvirt_manager : Reload systemctl and start/enable virtproxyd.service --- 0.72s
2025-10-13 16:22:36.011889 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.70s
2025-10-13 16:22:36.011895 | controller | libvirt_manager : Restart service polkit service ------------------------ 0.68s
2025-10-13 16:22:36.011905 | controller | INFO     Running default > converge
2025-10-13 16:22:36.485432 | controller |
2025-10-13 16:22:36.485665 | controller | PLAY [Converge] ****************************************************************
2025-10-13 16:22:36.485814 | controller |
2025-10-13 16:22:36.485955 | controller | TASK [Gathering Facts] *********************************************************
2025-10-13 16:22:36.486093 | controller | Monday 13 October 2025  16:22:36 +0000 (0:00:00.015)       0:00:00.015 ********
2025-10-13 16:22:37.356947 | controller | ok: [instance]
2025-10-13 16:22:37.398510 | controller |
2025-10-13 16:22:37.398629 | controller | TASK [Including the openshift provisioner node role.] **************************
2025-10-13 16:22:37.398642 | controller | Monday 13 October 2025  16:22:37 +0000 (0:00:00.871)       0:00:00.886 ********
2025-10-13 16:22:37.398660 | controller |
2025-10-13 16:22:37.703122 | controller | TASK [openshift_provisioner_node : Create the artifacts directory] *************
2025-10-13 16:22:37.703160 | controller | Monday 13 October 2025  16:22:37 +0000 (0:00:00.041)       0:00:00.928 ********
2025-10-13 16:22:37.703172 | controller | ok: [instance -> localhost]
2025-10-13 16:22:38.103713 | controller |
2025-10-13 16:22:38.103746 | controller | TASK [openshift_provisioner_node : Adding user kni] ****************************
2025-10-13 16:22:38.103754 | controller | Monday 13 October 2025  16:22:37 +0000 (0:00:00.304)       0:00:01.233 ********
2025-10-13 16:22:38.103764 | controller | changed: [instance]
2025-10-13 16:22:38.474135 | controller |
2025-10-13 16:22:38.474168 | controller | TASK [openshift_provisioner_node : Generate SSH keys] **************************
2025-10-13 16:22:38.474176 | controller | Monday 13 October 2025  16:22:38 +0000 (0:00:00.400)       0:00:01.633 ********
2025-10-13 16:22:38.474186 | controller | changed: [instance -> localhost]
2025-10-13 16:22:38.867171 | controller |
2025-10-13 16:22:38.867202 | controller | TASK [openshift_provisioner_node : Enable passwordless access] *****************
2025-10-13 16:22:38.867210 | controller | Monday 13 October 2025  16:22:38 +0000 (0:00:00.370)       0:00:02.004 ********
2025-10-13 16:22:38.867220 | controller | changed: [instance]
2025-10-13 16:23:05.042808 | controller |
2025-10-13 16:23:05.042846 | controller | TASK [openshift_provisioner_node : Install required packages need to execute openshift installer] ***
2025-10-13 16:23:05.042855 | controller | Monday 13 October 2025  16:22:38 +0000 (0:00:00.392)       0:00:02.397 ********
2025-10-13 16:23:05.042875 | controller | changed: [instance]
2025-10-13 16:23:05.460130 | controller |
2025-10-13 16:23:05.460170 | controller | TASK [openshift_provisioner_node : Create the external network connection] *****
2025-10-13 16:23:05.460179 | controller | Monday 13 October 2025  16:23:05 +0000 (0:00:26.175)       0:00:28.572 ********
2025-10-13 16:23:05.460190 | controller | changed: [instance]
2025-10-13 16:23:05.460478 | controller |
2025-10-13 16:23:05.460504 | controller | TASK [openshift_provisioner_node : Verify external network interface is defined] ***
2025-10-13 16:23:05.492868 | controller | Monday 13 October 2025  16:23:05 +0000 (0:00:00.417)       0:00:28.990 ********
2025-10-13 16:23:05.492903 | controller | skipping: [instance]
2025-10-13 16:23:05.492929 | controller |
2025-10-13 16:23:05.493145 | controller | TASK [openshift_provisioner_node : Add iface to the external network connection] ***
2025-10-13 16:23:05.518591 | controller | Monday 13 October 2025  16:23:05 +0000 (0:00:00.032)       0:00:29.023 ********
2025-10-13 16:23:05.518621 | controller | skipping: [instance]
2025-10-13 16:23:05.518783 | controller |
2025-10-13 16:23:05.518802 | controller | TASK [openshift_provisioner_node : Create the provisioning network connection] ***
2025-10-13 16:23:05.548835 | controller | Monday 13 October 2025  16:23:05 +0000 (0:00:00.025)       0:00:29.049 ********
2025-10-13 16:23:05.548866 | controller | skipping: [instance]
2025-10-13 16:23:05.579239 | controller |
2025-10-13 16:23:05.579268 | controller | TASK [openshift_provisioner_node : Add iface to the provisioning network connection] ***
2025-10-13 16:23:05.579276 | controller | Monday 13 October 2025  16:23:05 +0000 (0:00:00.029)       0:00:29.079 ********
2025-10-13 16:23:05.579286 | controller | skipping: [instance]
2025-10-13 16:23:05.579308 | controller |
2025-10-13 16:23:05.579317 | controller | TASK [openshift_provisioner_node : Check required virtualization networks] *****
2025-10-13 16:23:05.579379 | controller | Monday 13 October 2025  16:23:05 +0000 (0:00:00.030)       0:00:29.109 ********
2025-10-13 16:23:05.615786 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/openshift_provisioner_node/tasks/add_virtual_network.yml for instance => (item=baremetal)
2025-10-13 16:23:05.615844 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/openshift_provisioner_node/tasks/add_virtual_network.yml for instance => (item=provisioning)
2025-10-13 16:23:05.615941 | controller |
2025-10-13 16:23:05.616183 | controller | TASK [openshift_provisioner_node : Define virtual network baremetal] ***********
2025-10-13 16:23:06.526304 | controller | Monday 13 October 2025  16:23:05 +0000 (0:00:00.036)       0:00:29.146 ********
2025-10-13 16:23:06.526367 | controller | changed: [instance]
2025-10-13 16:23:06.526433 | controller |
2025-10-13 16:23:06.526463 | controller | TASK [openshift_provisioner_node : Start the network - baremetal] **************
2025-10-13 16:23:06.526639 | controller | Monday 13 October 2025  16:23:06 +0000 (0:00:00.910)       0:00:30.056 ********
2025-10-13 16:23:06.768021 | controller | changed: [instance]
2025-10-13 16:23:06.998081 | controller |
2025-10-13 16:23:06.998602 | controller | TASK [openshift_provisioner_node : Enable network autostart for baremetal] *****
2025-10-13 16:23:06.998613 | controller | Monday 13 October 2025  16:23:06 +0000 (0:00:00.241)       0:00:30.298 ********
2025-10-13 16:23:06.998623 | controller | changed: [instance]
2025-10-13 16:23:07.235387 | controller |
2025-10-13 16:23:07.235438 | controller | TASK [openshift_provisioner_node : Define virtual network provisioning] ********
2025-10-13 16:23:07.235446 | controller | Monday 13 October 2025  16:23:06 +0000 (0:00:00.229)       0:00:30.528 ********
2025-10-13 16:23:07.235457 | controller | changed: [instance]
2025-10-13 16:23:07.464828 | controller |
2025-10-13 16:23:07.464864 | controller | TASK [openshift_provisioner_node : Start the network - provisioning] ***********
2025-10-13 16:23:07.464872 | controller | Monday 13 October 2025  16:23:07 +0000 (0:00:00.237)       0:00:30.765 ********
2025-10-13 16:23:07.464882 | controller | changed: [instance]
2025-10-13 16:23:07.693225 | controller |
2025-10-13 16:23:07.693258 | controller | TASK [openshift_provisioner_node : Enable network autostart for provisioning] ***
2025-10-13 16:23:07.693266 | controller | Monday 13 October 2025  16:23:07 +0000 (0:00:00.229)       0:00:30.994 ********
2025-10-13 16:23:07.693276 | controller | changed: [instance]
2025-10-13 16:23:07.742564 | controller |
2025-10-13 16:23:07.742616 | controller | TASK [openshift_provisioner_node : Cache the MAC addresses] ********************
2025-10-13 16:23:07.742626 | controller | Monday 13 October 2025  16:23:07 +0000 (0:00:00.228)       0:00:31.223 ********
2025-10-13 16:23:07.742639 | controller | ok: [instance]
2025-10-13 16:23:08.018977 | controller |
2025-10-13 16:23:08.019014 | controller | TASK [openshift_provisioner_node : Read host SSH fingerprint] ******************
2025-10-13 16:23:08.019022 | controller | Monday 13 October 2025  16:23:07 +0000 (0:00:00.049)       0:00:31.272 ********
2025-10-13 16:23:08.019036 | controller | ok: [instance]
2025-10-13 16:23:08.051373 | controller |
2025-10-13 16:23:08.051435 | controller | TASK [openshift_provisioner_node : Set the role output parameters] *************
2025-10-13 16:23:08.051444 | controller | Monday 13 October 2025  16:23:08 +0000 (0:00:00.276)       0:00:31.548 ********
2025-10-13 16:23:08.051455 | controller | ok: [instance]
2025-10-13 16:23:08.051670 | controller |
2025-10-13 16:23:08.051859 | controller | TASK [openshift_provisioner_node : Cache provisioning bridge name] *************
2025-10-13 16:23:08.052061 | controller | Monday 13 October 2025  16:23:08 +0000 (0:00:00.032)       0:00:31.581 ********
2025-10-13 16:23:08.086368 | controller | skipping: [instance]
2025-10-13 16:23:08.086608 | controller |
2025-10-13 16:23:08.086771 | controller | TASK [Verify user is created] **************************************************
2025-10-13 16:23:08.086917 | controller | Monday 13 October 2025  16:23:08 +0000 (0:00:00.034)       0:00:31.616 ********
2025-10-13 16:23:08.368503 | controller | ok: [instance]
2025-10-13 16:23:08.368705 | controller |
2025-10-13 16:23:08.368876 | controller | TASK [Verify external network bridge exists] ***********************************
2025-10-13 16:23:08.369048 | controller | Monday 13 October 2025  16:23:08 +0000 (0:00:00.282)       0:00:31.898 ********
2025-10-13 16:23:08.470115 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_000_verify_external_network.log
2025-10-13 16:23:08.505787 | controller | changed: [instance]
2025-10-13 16:23:08.505819 | controller |
2025-10-13 16:23:08.505828 | controller | TASK [Perform cleanup] *********************************************************
2025-10-13 16:23:08.505836 | controller | Monday 13 October 2025  16:23:08 +0000 (0:00:00.101)       0:00:32.000 ********
2025-10-13 16:23:08.505847 | controller |
2025-10-13 16:23:08.535166 | controller | TASK [openshift_provisioner_node : Cleaning up the virtual networks] ***********
2025-10-13 16:23:08.535191 | controller | Monday 13 October 2025  16:23:08 +0000 (0:00:00.035)       0:00:32.036 ********
2025-10-13 16:23:08.535202 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/openshift_provisioner_node/tasks/cleanup_virtual_network.yml for instance => (item=baremetal)
2025-10-13 16:23:08.759476 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/openshift_provisioner_node/tasks/cleanup_virtual_network.yml for instance => (item=provisioning)
2025-10-13 16:23:08.759507 | controller |
2025-10-13 16:23:08.759515 | controller | TASK [openshift_provisioner_node : Stopping virtual network baremetal] *********
2025-10-13 16:23:08.759521 | controller | Monday 13 October 2025  16:23:08 +0000 (0:00:00.029)       0:00:32.065 ********
2025-10-13 16:23:08.759530 | controller | ok: [instance]
2025-10-13 16:23:08.759733 | controller |
2025-10-13 16:23:08.759747 | controller | TASK [openshift_provisioner_node : Remove virtual network baremetal] ***********
2025-10-13 16:23:08.987324 | controller | Monday 13 October 2025  16:23:08 +0000 (0:00:00.224)       0:00:32.289 ********
2025-10-13 16:23:08.987361 | controller | ok: [instance]
2025-10-13 16:23:09.217148 | controller |
2025-10-13 16:23:09.217182 | controller | TASK [openshift_provisioner_node : Stopping virtual network provisioning] ******
2025-10-13 16:23:09.217190 | controller | Monday 13 October 2025  16:23:08 +0000 (0:00:00.227)       0:00:32.517 ********
2025-10-13 16:23:09.217200 | controller | ok: [instance]
2025-10-13 16:23:09.217370 | controller |
2025-10-13 16:23:09.217556 | controller | TASK [openshift_provisioner_node : Remove virtual network provisioning] ********
2025-10-13 16:23:09.217734 | controller | Monday 13 October 2025  16:23:09 +0000 (0:00:00.230)       0:00:32.747 ********
2025-10-13 16:23:09.444343 | controller | ok: [instance]
2025-10-13 16:23:09.444583 | controller |
2025-10-13 16:23:09.444773 | controller | TASK [openshift_provisioner_node : Remove provisioning network] ****************
2025-10-13 16:23:09.444977 | controller | Monday 13 October 2025  16:23:09 +0000 (0:00:00.227)       0:00:32.974 ********
2025-10-13 16:23:09.682883 | controller | ok: [instance]
2025-10-13 16:23:10.023956 | controller |
2025-10-13 16:23:10.023988 | controller | TASK [openshift_provisioner_node : Remove the user] ****************************
2025-10-13 16:23:10.023996 | controller | Monday 13 October 2025  16:23:09 +0000 (0:00:00.238)       0:00:33.212 ********
2025-10-13 16:23:10.024007 | controller | changed: [instance]
2025-10-13 16:23:10.109953 | controller |
2025-10-13 16:23:10.109987 | controller | PLAY RECAP *********************************************************************
2025-10-13 16:23:10.109996 | controller | instance                   : ok=28   changed=13   unreachable=0    failed=0    skipped=5    rescued=0    ignored=0
2025-10-13 16:23:10.110002 | controller |
2025-10-13 16:23:10.110007 | controller | Monday 13 October 2025  16:23:10 +0000 (0:00:00.338)       0:00:33.551 ********
2025-10-13 16:23:10.110013 | controller | ===============================================================================
2025-10-13 16:23:10.110018 | controller | openshift_provisioner_node : Install required packages need to execute openshift installer -- 26.18s
2025-10-13 16:23:10.110024 | controller | openshift_provisioner_node : Define virtual network baremetal ----------- 0.91s
2025-10-13 16:23:10.110029 | controller | Gathering Facts --------------------------------------------------------- 0.87s
2025-10-13 16:23:10.110035 | controller | openshift_provisioner_node : Create the external network connection ----- 0.42s
2025-10-13 16:23:10.110040 | controller | openshift_provisioner_node : Adding user kni ---------------------------- 0.40s
2025-10-13 16:23:10.110045 | controller | openshift_provisioner_node : Enable passwordless access ----------------- 0.39s
2025-10-13 16:23:10.110050 | controller | openshift_provisioner_node : Generate SSH keys -------------------------- 0.37s
2025-10-13 16:23:10.110056 | controller | openshift_provisioner_node : Remove the user ---------------------------- 0.34s
2025-10-13 16:23:10.110066 | controller | openshift_provisioner_node : Create the artifacts directory ------------- 0.30s
2025-10-13 16:23:10.110072 | controller | Verify user is created -------------------------------------------------- 0.28s
2025-10-13 16:23:10.110078 | controller | openshift_provisioner_node : Read host SSH fingerprint ------------------ 0.28s
2025-10-13 16:23:10.110083 | controller | openshift_provisioner_node : Start the network - baremetal -------------- 0.24s
2025-10-13 16:23:10.110088 | controller | openshift_provisioner_node : Remove provisioning network ---------------- 0.24s
2025-10-13 16:23:10.110093 | controller | openshift_provisioner_node : Define virtual network provisioning -------- 0.24s
2025-10-13 16:23:10.110098 | controller | openshift_provisioner_node : Stopping virtual network provisioning ------ 0.23s
2025-10-13 16:23:10.110103 | controller | openshift_provisioner_node : Enable network autostart for baremetal ----- 0.23s
2025-10-13 16:23:10.110109 | controller | openshift_provisioner_node : Start the network - provisioning ----------- 0.23s
2025-10-13 16:23:10.110114 | controller | openshift_provisioner_node : Enable network autostart for provisioning --- 0.23s
2025-10-13 16:23:10.110119 | controller | openshift_provisioner_node : Remove virtual network baremetal ----------- 0.23s
2025-10-13 16:23:10.110125 | controller | openshift_provisioner_node : Remove virtual network provisioning -------- 0.23s
2025-10-13 16:23:10.110135 | controller | INFO     Running default > cleanup
2025-10-13 16:23:10.110603 | controller | WARNING  Skipping, cleanup playbook not configured.
2025-10-13 16:23:10.111181 | controller | INFO     Writing /tmp/report.html report.
2025-10-13 16:23:10.397064 | [controller] Waiting on logger
2025-10-13 16:23:15.570303 | [controller] Waiting on logger
2025-10-13 16:23:26.002377 | [controller] Waiting on logger
2025-10-13 16:23:36.435332 | [controller] Waiting on logger
2025-10-13 16:23:40.187629 | [Zuul] Log Stream did not terminate
2025-10-13 16:23:40.187789 | controller | changed
2025-10-13 16:23:40.210368 | 
2025-10-13 16:23:40.210427 | PLAY RECAP
2025-10-13 16:23:40.210469 | controller | ok: 3 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-13 16:23:40.210494 | 
2025-10-13 16:23:40.285208 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-13 16:23:40.286000 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-13 16:23:40.842431 | 
2025-10-13 16:23:40.842549 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-10-13 16:23:40.863976 | 
2025-10-13 16:23:40.864087 | TASK [Filter out host if needed]
2025-10-13 16:23:40.873037 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-10-13 16:23:40.877706 | 
2025-10-13 16:23:40.877778 | TASK [Ensure file is present]
2025-10-13 16:23:41.335523 | controller | ok
2025-10-13 16:23:41.341343 | 
2025-10-13 16:23:41.341427 | TASK [Manage molecule report file]
2025-10-13 16:23:41.365644 | [controller] Waiting on logger
2025-10-13 16:23:50.707369 | [controller] Waiting on logger
2025-10-13 16:24:01.138509 | [controller] Waiting on logger
2025-10-13 16:24:10.518901 | [controller] Waiting on logger
2025-10-13 16:24:11.767864 | [Zuul] Log Stream did not terminate
2025-10-13 16:24:11.768078 | controller | changed
2025-10-13 16:24:11.773628 | 
2025-10-13 16:24:11.773692 | TASK [Check if we get ci-framework-data basedir]
2025-10-13 16:24:12.066656 | controller | ok
2025-10-13 16:24:12.072010 | 
2025-10-13 16:24:12.072079 | TASK [Create ci-framework-data log directory for zuul]
2025-10-13 16:24:12.466554 | controller | changed
2025-10-13 16:24:12.472672 | 
2025-10-13 16:24:12.472760 | TASK [Copy ci-framework interesting files]
2025-10-13 16:24:12.494776 | [controller] Waiting on logger
2025-10-13 16:24:22.898430 | [controller] Waiting on logger
2025-10-13 16:24:33.330386 | [controller] Waiting on logger
2025-10-13 16:24:42.674309 | [controller] Waiting on logger
2025-10-13 16:24:42.787287 | [Zuul] Log Stream did not terminate
2025-10-13 16:24:42.787454 | controller | changed
2025-10-13 16:24:42.792903 | 
2025-10-13 16:24:42.793007 | TASK [Get SELinux listing]
2025-10-13 16:24:43.826372 | [controller] Waiting on logger
2025-10-13 16:24:50.097115 | controller | changed
2025-10-13 16:24:50.103762 | 
2025-10-13 16:24:50.103851 | TASK [Generate log index]
2025-10-13 16:24:51.293565 | controller | changed
2025-10-13 16:24:51.305149 | 
2025-10-13 16:24:51.305325 | TASK [Get some env related data]
2025-10-13 16:24:55.154350 | [controller] Waiting on logger
2025-10-13 16:24:56.333128 | controller | changed
2025-10-13 16:24:56.338756 | 
2025-10-13 16:24:56.338836 | TASK [Generate list of logs to collect in home directory]
2025-10-13 16:24:56.741899 | controller | ok: All paths examined
2025-10-13 16:24:56.747685 | 
2025-10-13 16:24:56.747776 | LOOP [Copy logs from home directory]
2025-10-13 16:24:57.356436 | controller | changed:
2025-10-13 16:24:57.356624 | controller | {
2025-10-13 16:24:57.356654 | controller |   "atime": 1743544925.4788878,
2025-10-13 16:24:57.356676 | controller |   "ctime": 1743545329.1409318,
2025-10-13 16:24:57.356695 | controller |   "dev": 64513,
2025-10-13 16:24:57.356714 | controller |   "gid": 1000,
2025-10-13 16:24:57.356731 | controller |   "gr_name": "zuul",
2025-10-13 16:24:57.356748 | controller |   "inode": 4518807,
2025-10-13 16:24:57.356764 | controller |   "isblk": false,
2025-10-13 16:24:57.356780 | controller |   "ischr": false,
2025-10-13 16:24:57.356796 | controller |   "isdir": false,
2025-10-13 16:24:57.356819 | controller |   "isfifo": false,
2025-10-13 16:24:57.356838 | controller |   "isgid": false,
2025-10-13 16:24:57.356854 | controller |   "islnk": false,
2025-10-13 16:24:57.356871 | controller |   "isreg": true,
2025-10-13 16:24:57.356887 | controller |   "issock": false,
2025-10-13 16:24:57.356903 | controller |   "isuid": false,
2025-10-13 16:24:57.356945 | controller |   "mode": "0644",
2025-10-13 16:24:57.356965 | controller |   "mtime": 1743545329.1409318,
2025-10-13 16:24:57.357001 | controller |   "nlink": 1,
2025-10-13 16:24:57.357019 | controller |   "path": "/home/zuul/crc-setup.log",
2025-10-13 16:24:57.357036 | controller |   "pw_name": "zuul",
2025-10-13 16:24:57.357052 | controller |   "rgrp": true,
2025-10-13 16:24:57.357068 | controller |   "roth": true,
2025-10-13 16:24:57.357084 | controller |   "rusr": true,
2025-10-13 16:24:57.357099 | controller |   "size": 4108,
2025-10-13 16:24:57.357114 | controller |   "uid": 1000,
2025-10-13 16:24:57.357130 | controller |   "wgrp": false,
2025-10-13 16:24:57.357146 | controller |   "woth": false,
2025-10-13 16:24:57.357162 | controller |   "wusr": true,
2025-10-13 16:24:57.357178 | controller |   "xgrp": false,
2025-10-13 16:24:57.357193 | controller |   "xoth": false,
2025-10-13 16:24:57.357208 | controller |   "xusr": false
2025-10-13 16:24:57.357224 | controller | }
2025-10-13 16:24:57.931381 | controller | changed:
2025-10-13 16:24:57.931477 | controller | {
2025-10-13 16:24:57.931506 | controller |   "atime": 1743545331.0429637,
2025-10-13 16:24:57.931526 | controller |   "ctime": 1743545842.0111232,
2025-10-13 16:24:57.931543 | controller |   "dev": 64513,
2025-10-13 16:24:57.931560 | controller |   "gid": 1000,
2025-10-13 16:24:57.931576 | controller |   "gr_name": "zuul",
2025-10-13 16:24:57.931597 | controller |   "inode": 4194437,
2025-10-13 16:24:57.931613 | controller |   "isblk": false,
2025-10-13 16:24:57.931629 | controller |   "ischr": false,
2025-10-13 16:24:57.931644 | controller |   "isdir": false,
2025-10-13 16:24:57.931659 | controller |   "isfifo": false,
2025-10-13 16:24:57.931674 | controller |   "isgid": false,
2025-10-13 16:24:57.931688 | controller |   "islnk": false,
2025-10-13 16:24:57.931701 | controller |   "isreg": true,
2025-10-13 16:24:57.931715 | controller |   "issock": false,
2025-10-13 16:24:57.931728 | controller |   "isuid": false,
2025-10-13 16:24:57.931742 | controller |   "mode": "0644",
2025-10-13 16:24:57.931755 | controller |   "mtime": 1743545842.0111232,
2025-10-13 16:24:57.932141 | controller |   "nlink": 1,
2025-10-13 16:24:57.932763 | controller |   "path": "/home/zuul/crc-start.log",
2025-10-13 16:24:57.932878 | controller |   "pw_name": "zuul",
2025-10-13 16:24:57.932999 | controller |   "rgrp": true,
2025-10-13 16:24:57.933034 | controller |   "roth": true,
2025-10-13 16:24:57.933054 | controller |   "rusr": true,
2025-10-13 16:24:57.933072 | controller |   "size": 4023,
2025-10-13 16:24:57.933088 | controller |   "uid": 1000,
2025-10-13 16:24:57.933104 | controller |   "wgrp": false,
2025-10-13 16:24:57.933119 | controller |   "woth": false,
2025-10-13 16:24:57.933135 | controller |   "wusr": true,
2025-10-13 16:24:57.933149 | controller |   "xgrp": false,
2025-10-13 16:24:57.933162 | controller |   "xoth": false,
2025-10-13 16:24:57.933175 | controller |   "xusr": false
2025-10-13 16:24:57.933188 | controller | }
2025-10-13 16:24:58.517051 | controller | changed:
2025-10-13 16:24:58.517135 | controller | {
2025-10-13 16:24:58.517162 | controller |   "atime": 1760372410.6740675,
2025-10-13 16:24:58.517183 | controller |   "ctime": 1760372427.0704117,
2025-10-13 16:24:58.517201 | controller |   "dev": 64513,
2025-10-13 16:24:58.517219 | controller |   "gid": 1000,
2025-10-13 16:24:58.517236 | controller |   "gr_name": "zuul",
2025-10-13 16:24:58.517252 | controller |   "inode": 4340284,
2025-10-13 16:24:58.517268 | controller |   "isblk": false,
2025-10-13 16:24:58.517284 | controller |   "ischr": false,
2025-10-13 16:24:58.517299 | controller |   "isdir": false,
2025-10-13 16:24:58.517314 | controller |   "isfifo": false,
2025-10-13 16:24:58.517330 | controller |   "isgid": false,
2025-10-13 16:24:58.517345 | controller |   "islnk": false,
2025-10-13 16:24:58.517363 | controller |   "isreg": true,
2025-10-13 16:24:58.517378 | controller |   "issock": false,
2025-10-13 16:24:58.517394 | controller |   "isuid": false,
2025-10-13 16:24:58.517409 | controller |   "mode": "0644",
2025-10-13 16:24:58.517424 | controller |   "mtime": 1760372427.0704117,
2025-10-13 16:24:58.517440 | controller |   "nlink": 1,
2025-10-13 16:24:58.517455 | controller |   "path": "/home/zuul/ansible.log",
2025-10-13 16:24:58.517469 | controller |   "pw_name": "zuul",
2025-10-13 16:24:58.517484 | controller |   "rgrp": true,
2025-10-13 16:24:58.517498 | controller |   "roth": true,
2025-10-13 16:24:58.517513 | controller |   "rusr": true,
2025-10-13 16:24:58.517527 | controller |   "size": 6749,
2025-10-13 16:24:58.517541 | controller |   "uid": 1000,
2025-10-13 16:24:58.517557 | controller |   "wgrp": false,
2025-10-13 16:24:58.517573 | controller |   "woth": false,
2025-10-13 16:24:58.517588 | controller |   "wusr": true,
2025-10-13 16:24:58.517603 | controller |   "xgrp": false,
2025-10-13 16:24:58.517618 | controller |   "xoth": false,
2025-10-13 16:24:58.517633 | controller |   "xusr": false
2025-10-13 16:24:58.517648 | controller | }
2025-10-13 16:24:58.527489 | 
2025-10-13 16:24:58.527570 | TASK [Copy crio stats log file]
2025-10-13 16:24:58.543415 | controller | skipping: Conditional result was False
2025-10-13 16:24:58.549449 | 
2025-10-13 16:24:58.549538 | TASK [Get SELinux related data]
2025-10-13 16:24:58.573948 | [controller] Waiting on logger
2025-10-13 16:25:13.778457 | [controller] Waiting on logger
2025-10-13 16:25:17.170288 | [controller] Waiting on logger
2025-10-13 16:25:28.882659 | [Zuul] Log Stream did not terminate
2025-10-13 16:25:28.882858 | controller | ERROR
2025-10-13 16:25:28.883061 | controller | {
2025-10-13 16:25:28.883101 | controller |   "delta": "0:00:00.010685",
2025-10-13 16:25:28.883124 | controller |   "end": "2025-10-13 16:24:58.853483",
2025-10-13 16:25:28.883145 | controller |   "msg": "non-zero return code",
2025-10-13 16:25:28.883162 | controller |   "rc": 1,
2025-10-13 16:25:28.883181 | controller |   "start": "2025-10-13 16:24:58.842798"
2025-10-13 16:25:28.883199 | controller | }
2025-10-13 16:25:28.883223 | controller | ERROR: Ignoring Errors
2025-10-13 16:25:28.888542 | 
2025-10-13 16:25:28.888607 | TASK [Create system configuration directory]
2025-10-13 16:25:29.160076 | controller | changed
2025-10-13 16:25:29.166224 | 
2025-10-13 16:25:29.166353 | TASK [Get some of the system configurations]
2025-10-13 16:25:30.226360 | [controller] Waiting on logger
2025-10-13 16:25:39.570336 | [controller] Waiting on logger
2025-10-13 16:25:50.002429 | [controller] Waiting on logger
2025-10-13 16:25:59.497734 | [Zuul] Log Stream did not terminate
2025-10-13 16:25:59.497875 | controller | changed
2025-10-13 16:25:59.503516 | 
2025-10-13 16:25:59.503585 | TASK [Copy generated documentation if available]
2025-10-13 16:25:59.527784 | controller | skipping: Conditional result was False
2025-10-13 16:25:59.533179 | 
2025-10-13 16:25:59.533245 | TASK [Copy generated AsciiDoc documentation if available]
2025-10-13 16:25:59.546683 | controller | skipping: Conditional result was False
2025-10-13 16:25:59.552376 | 
2025-10-13 16:25:59.552440 | TASK [Compress logs bigger than 2MB]
2025-10-13 16:25:59.574741 | [controller] Waiting on logger
2025-10-13 16:26:00.434533 | [controller] Waiting on logger
2025-10-13 16:26:04.681137 | controller | changed
2025-10-13 16:26:04.686597 | 
2025-10-13 16:26:04.686678 | TASK [Copy files from workspace on node]
2025-10-13 16:26:04.704938 | controller | ok
2025-10-13 16:26:04.729358 | 
2025-10-13 16:26:04.729456 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-13 16:26:04.747083 | controller | skipping: Conditional result was False
2025-10-13 16:26:04.756416 | 
2025-10-13 16:26:04.756578 | TASK [fetch-output : Set log path for single node]
2025-10-13 16:26:04.785954 | controller | ok
2025-10-13 16:26:04.796376 | 
2025-10-13 16:26:04.796448 | LOOP [fetch-output : Ensure local output dirs]
2025-10-13 16:26:05.123856 | controller -> localhost | ok: "/var/lib/zuul/builds/f351a4ad085742d68d019135ea0b3f59/work/logs"
2025-10-13 16:26:05.124148 | controller -> localhost | changed: All items complete
2025-10-13 16:26:05.124180 | 
2025-10-13 16:26:05.338982 | controller -> localhost | changed: "/var/lib/zuul/builds/f351a4ad085742d68d019135ea0b3f59/work/artifacts"
2025-10-13 16:26:05.553620 | controller -> localhost | changed: "/var/lib/zuul/builds/f351a4ad085742d68d019135ea0b3f59/work/docs"
2025-10-13 16:26:05.563448 | 
2025-10-13 16:26:05.563523 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-13 16:26:06.243705 | controller | changed:
2025-10-13 16:26:06.243891 | controller | .d..t...... ./
2025-10-13 16:26:06.243942 | controller | >f+++++++++ README.html
2025-10-13 16:26:06.243979 | controller | >f+++++++++ ansible-execution.log
2025-10-13 16:26:06.244003 | controller | >f+++++++++ ansible.log
2025-10-13 16:26:06.244025 | controller | >f+++++++++ crc-setup.log
2025-10-13 16:26:06.244045 | controller | >f+++++++++ crc-start.log
2025-10-13 16:26:06.244064 | controller | >f+++++++++ dmesg.log
2025-10-13 16:26:06.244083 | controller | >f+++++++++ installed-pkgs.log
2025-10-13 16:26:06.244101 | controller | >f+++++++++ python.log
2025-10-13 16:26:06.244119 | controller | >f+++++++++ registries.conf
2025-10-13 16:26:06.244136 | controller | >f+++++++++ report.html
2025-10-13 16:26:06.244153 | controller | >f+++++++++ selinux-denials.log
2025-10-13 16:26:06.244169 | controller | >f+++++++++ selinux-listing.log
2025-10-13 16:26:06.244186 | controller | cd+++++++++ ci-framework-data/
2025-10-13 16:26:06.244202 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-10-13 16:26:06.244230 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_000_verify_external_network.sh
2025-10-13 16:26:06.244251 | controller | >f+++++++++ ci-framework-data/artifacts/kni_id_cifw
2025-10-13 16:26:06.244270 | controller | >f+++++++++ ci-framework-data/artifacts/kni_id_cifw.pub
2025-10-13 16:26:06.244288 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-10-13 16:26:06.244305 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/
2025-10-13 16:26:06.244322 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/openstack/
2025-10-13 16:26:06.244339 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/openstack/cr/
2025-10-13 16:26:06.244355 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-10-13 16:26:06.244373 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-10-13 16:26:06.244390 | controller | cd+++++++++ ci-framework-data/artifacts/repositories/
2025-10-13 16:26:06.244407 | controller | >f+++++++++ ci-framework-data/artifacts/repositories/delorean.repo.md5
2025-10-13 16:26:06.244424 | controller | cd+++++++++ ci-framework-data/logs/
2025-10-13 16:26:06.244440 | controller | >f+++++++++ ci-framework-data/logs/ci_script_000_verify_external_network.log
2025-10-13 16:26:06.244457 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-10-13 16:26:06.244473 | controller | cd+++++++++ registries.conf.d/
2025-10-13 16:26:06.244490 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-10-13 16:26:06.244508 | controller | cd+++++++++ system-config/
2025-10-13 16:26:06.244525 | controller | cd+++++++++ system-config/libvirt/
2025-10-13 16:26:06.244542 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-10-13 16:26:06.244559 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-10-13 16:26:06.244576 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf
2025-10-13 16:26:06.244592 | controller | >f+++++++++ system-config/libvirt/network.conf
2025-10-13 16:26:06.244608 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf
2025-10-13 16:26:06.244624 | controller | >f+++++++++ system-config/libvirt/qemu.conf
2025-10-13 16:26:06.244640 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf
2025-10-13 16:26:06.244655 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf
2025-10-13 16:26:06.244671 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf
2025-10-13 16:26:06.244686 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf
2025-10-13 16:26:06.244702 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf
2025-10-13 16:26:06.244717 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf
2025-10-13 16:26:06.244733 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf
2025-10-13 16:26:06.244750 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf
2025-10-13 16:26:06.244766 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf
2025-10-13 16:26:06.244783 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf
2025-10-13 16:26:06.764869 | controller | changed: .d..t...... ./
2025-10-13 16:26:07.252352 | controller | changed: .d..t...... ./
2025-10-13 16:26:07.280202 | 
2025-10-13 16:26:07.280301 | TASK [Return artifact to Zuul]
2025-10-13 16:26:07.309131 | controller | ok
2025-10-13 16:26:07.330986 | 
2025-10-13 16:26:07.331061 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-10-13 16:26:07.331163 | 
2025-10-13 16:26:07.331193 | PLAY RECAP
2025-10-13 16:26:07.331232 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-10-13 16:26:07.331254 | 
2025-10-13 16:26:07.421322 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-13 16:26:07.422100 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 16:26:08.028290 | 
2025-10-13 16:26:08.028385 | PLAY [all]
2025-10-13 16:26:08.068775 | 
2025-10-13 16:26:08.068888 | TASK [include_role : fetch-output]
2025-10-13 16:26:08.100138 | controller | ok
2025-10-13 16:26:08.119103 | 
2025-10-13 16:26:08.119212 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-13 16:26:08.163433 | controller | skipping: Conditional result was False
2025-10-13 16:26:08.169710 | 
2025-10-13 16:26:08.169807 | TASK [fetch-output : Set log path for single node]
2025-10-13 16:26:08.198464 | controller | ok
2025-10-13 16:26:08.204054 | 
2025-10-13 16:26:08.204130 | LOOP [fetch-output : Ensure local output dirs]
2025-10-13 16:26:08.588145 | controller -> localhost | ok: "/var/lib/zuul/builds/f351a4ad085742d68d019135ea0b3f59/work/logs"
2025-10-13 16:26:08.789500 | controller -> localhost | ok: "/var/lib/zuul/builds/f351a4ad085742d68d019135ea0b3f59/work/artifacts"
2025-10-13 16:26:08.993616 | controller -> localhost | ok: "/var/lib/zuul/builds/f351a4ad085742d68d019135ea0b3f59/work/docs"
2025-10-13 16:26:09.008377 | 
2025-10-13 16:26:09.008479 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-13 16:26:09.694735 | controller | ok
2025-10-13 16:26:09.694948 | controller | ok: All items complete
2025-10-13 16:26:09.694995 | 
2025-10-13 16:26:10.313849 | controller | ok
2025-10-13 16:26:10.848247 | controller | ok
2025-10-13 16:26:10.862626 | 
2025-10-13 16:26:10.862699 | TASK [include_role : fetch-output-openshift]
2025-10-13 16:26:10.876709 | controller | skipping: Conditional result was False
2025-10-13 16:26:10.882822 | 
2025-10-13 16:26:10.882900 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-13 16:26:11.266286 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007129
2025-10-13 16:26:11.501880 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.005618
2025-10-13 16:26:11.537057 | 
2025-10-13 16:26:11.537180 | PLAY [all]
2025-10-13 16:26:11.552376 | 
2025-10-13 16:26:11.552460 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-13 16:26:12.066946 | controller | changed
2025-10-13 16:26:12.100748 | 
2025-10-13 16:26:12.100829 | PLAY RECAP
2025-10-13 16:26:12.100874 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-13 16:26:12.100899 | 
2025-10-13 16:26:12.193035 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-13 16:26:12.193742 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-13 16:26:12.829692 | 
2025-10-13 16:26:12.829816 | PLAY [localhost]
2025-10-13 16:26:12.848109 | 
2025-10-13 16:26:12.848220 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-13 16:26:13.237834 | localhost | changed
2025-10-13 16:26:13.242628 | 
2025-10-13 16:26:13.242710 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-13 16:26:13.272610 | localhost | ok
2025-10-13 16:26:13.287529 | 
2025-10-13 16:26:13.287626 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-13 16:26:13.614886 | localhost | changed
2025-10-13 16:26:13.620731 | 
2025-10-13 16:26:13.620903 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-13 16:26:14.305581 | localhost | changed
2025-10-13 16:26:14.314439 | 
2025-10-13 16:26:14.314505 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-13 16:26:14.747597 | localhost | Identity added: /var/lib/zuul/builds/f351a4ad085742d68d019135ea0b3f59/work/tmp/ansible.wslkssww (/var/lib/zuul/builds/f351a4ad085742d68d019135ea0b3f59/work/tmp/ansible.wslkssww)
2025-10-13 16:26:14.747765 | localhost | ok: Runtime: 0:00:00.022948
2025-10-13 16:26:14.752014 | 
2025-10-13 16:26:14.752084 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-13 16:26:15.047575 | localhost | ok: Runtime: 0:00:00.004548
2025-10-13 16:26:15.052866 | 
2025-10-13 16:26:15.052992 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-13 16:26:15.110428 | localhost | changed
2025-10-13 16:26:15.114692 | 
2025-10-13 16:26:15.114760 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-13 16:26:15.459054 | localhost | changed
2025-10-13 16:26:15.485816 | 
2025-10-13 16:26:15.485935 | PLAY [localhost]
2025-10-13 16:26:15.499193 | 
2025-10-13 16:26:15.499277 | TASK [Generate bulk log download script]
2025-10-13 16:26:15.527629 | localhost | ok
2025-10-13 16:26:15.540252 | 
2025-10-13 16:26:15.540341 | TASK [local-log-download : Check API endpoint is defined]
2025-10-13 16:26:15.568818 | localhost | ok: All assertions passed
2025-10-13 16:26:15.573881 | 
2025-10-13 16:26:15.573998 | TASK [local-log-download : Create download script]
2025-10-13 16:26:15.983754 | localhost -> localhost | changed
2025-10-13 16:26:15.993182 | 
2025-10-13 16:26:15.993271 | TASK [Register quick-download link]
2025-10-13 16:26:16.045593 | localhost | ok
2025-10-13 16:26:16.104694 | 
2025-10-13 16:26:16.104797 | PLAY [logserver.rdoproject.org]
2025-10-13 16:26:16.122114 | 
2025-10-13 16:26:16.122303 | TASK [Set zuul-log-path fact]
2025-10-13 16:26:16.148118 | logserver.rdoproject.org | ok
2025-10-13 16:26:16.159384 | 
2025-10-13 16:26:16.165005 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-13 16:26:16.192133 | logserver.rdoproject.org | ok
2025-10-13 16:26:16.199820 | 
2025-10-13 16:26:16.199907 | TASK [upload-logs : Create log directories]
2025-10-13 16:26:17.929890 | logserver.rdoproject.org | changed
2025-10-13 16:26:17.933327 | 
2025-10-13 16:26:17.933394 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-13 16:26:18.217816 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.010955
2025-10-13 16:26:18.223066 | 
2025-10-13 16:26:18.223158 | TASK [upload-logs : Upload logs to log server]
2025-10-13 16:26:19.974945 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-13 16:26:19.980564 | 
2025-10-13 16:26:19.980641 | LOOP [upload-logs : Compress console log and json output]
2025-10-13 16:26:20.022277 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 16:26:20.031754 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 16:26:20.038417 | 
2025-10-13 16:26:20.038519 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-13 16:26:20.076337 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 16:26:20.076588 | 
2025-10-13 16:26:20.080050 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-13 16:26:20.085891 | 
2025-10-13 16:26:20.086004 | LOOP [upload-logs : Upload console log and json output]