2025-09-29 19:18:13.919639 | Job console starting...
2025-09-29 19:18:14.155395 | Updating repositories
2025-09-29 19:18:14.918125 | Preparing job workspace
2025-09-29 19:18:22.813160 | Running Ansible setup...
2025-09-29 19:18:26.585813 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-09-29 19:18:27.183609 | 
2025-09-29 19:18:27.183720 | PLAY [localhost]
2025-09-29 19:18:27.244320 | 
2025-09-29 19:18:27.244448 | TASK [Gathering Facts]
2025-09-29 19:18:28.070204 | localhost | ok
2025-09-29 19:18:28.085035 | 
2025-09-29 19:18:28.085146 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-09-29 19:18:28.477466 | localhost -> localhost | changed
2025-09-29 19:18:28.485210 | 
2025-09-29 19:18:28.485530 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-09-29 19:18:29.301671 | localhost -> localhost | changed
2025-09-29 19:18:29.311191 | 
2025-09-29 19:18:29.311353 | TASK [Setup log path fact]
2025-09-29 19:18:29.328855 | localhost | ok
2025-09-29 19:18:29.341203 | 
2025-09-29 19:18:29.341291 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-09-29 19:18:29.369641 | localhost | ok
2025-09-29 19:18:29.377782 | 
2025-09-29 19:18:29.377863 | TASK [emit-job-header : Print job information]
2025-09-29 19:18:29.407434 | # Job Information
2025-09-29 19:18:29.407734 | Ansible Version: 2.15.12
2025-09-29 19:18:29.407777 | Job: cifmw-molecule-rhol_crc
2025-09-29 19:18:29.407801 | Pipeline: github-check
2025-09-29 19:18:29.407820 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-09-29 19:18:29.407839 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3333
2025-09-29 19:18:29.407874 | Log URL (when completed): https://logserver.rdoproject.org/867/rdoproject.org/867f3ce1761f49a9bf874bee388bd5ba/
2025-09-29 19:18:29.407977 | Event ID: e4caed00-9d64-11f0-91c5-1ab1a6168f94
2025-09-29 19:18:29.412746 | 
2025-09-29 19:18:29.412821 | LOOP [emit-job-header : Print node information]
2025-09-29 19:18:29.506171 | localhost | ok:
2025-09-29 19:18:29.506425 | localhost | # Node Information
2025-09-29 19:18:29.506480 | localhost | Inventory Hostname: controller
2025-09-29 19:18:29.506508 | localhost | Hostname: np0005460788
2025-09-29 19:18:29.506554 | localhost | Username: zuul
2025-09-29 19:18:29.506579 | localhost | Distro: CentOS 9
2025-09-29 19:18:29.506620 | localhost | Provider: ibm-bm4-nodepool
2025-09-29 19:18:29.506645 | localhost | Region: regionOne
2025-09-29 19:18:29.506665 | localhost | Label: centos-9-stream-crc-2-48-0-xxl-ibm
2025-09-29 19:18:29.506719 | localhost | Product Name: OpenStack Compute
2025-09-29 19:18:29.506742 | localhost | Interface IP: 192.168.26.178
2025-09-29 19:18:29.528786 | 
2025-09-29 19:18:29.528852 | PLAY [all]
2025-09-29 19:18:29.536095 | 
2025-09-29 19:18:29.536158 | TASK [Gather network facts]
2025-09-29 19:18:29.992842 | controller | ok
2025-09-29 19:18:30.009787 | 
2025-09-29 19:18:30.009900 | TASK [include_role : start-zuul-console]
2025-09-29 19:18:30.028838 | controller | ok
2025-09-29 19:18:30.040525 | 
2025-09-29 19:18:30.040618 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-09-29 19:18:30.454177 | controller | ok
2025-09-29 19:18:30.463258 | 
2025-09-29 19:18:30.463339 | TASK [include_role : add-build-sshkey]
2025-09-29 19:18:30.481938 | controller | ok
2025-09-29 19:18:30.495807 | 
2025-09-29 19:18:30.495896 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-09-29 19:18:30.702670 | controller -> localhost | ok
2025-09-29 19:18:30.709229 | 
2025-09-29 19:18:30.709326 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-09-29 19:18:30.737551 | controller | ok
2025-09-29 19:18:30.752675 | controller | included: /var/lib/zuul/builds/867f3ce1761f49a9bf874bee388bd5ba/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-09-29 19:18:30.759192 | 
2025-09-29 19:18:30.759276 | TASK [add-build-sshkey : Create Temp SSH key]
2025-09-29 19:18:31.282278 | controller -> localhost | Generating public/private rsa key pair.
2025-09-29 19:18:31.282508 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/867f3ce1761f49a9bf874bee388bd5ba/work/867f3ce1761f49a9bf874bee388bd5ba_id_rsa.
2025-09-29 19:18:31.282546 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/867f3ce1761f49a9bf874bee388bd5ba/work/867f3ce1761f49a9bf874bee388bd5ba_id_rsa.pub.
2025-09-29 19:18:31.282572 | controller -> localhost | The key fingerprint is:
2025-09-29 19:18:31.282595 | controller -> localhost | SHA256:DxBZAL7iTTpcL7fgGYaX2VdMzT/XtkG2CPsXI/KhYu0 zuul-build-sshkey
2025-09-29 19:18:31.282617 | controller -> localhost | The key's randomart image is:
2025-09-29 19:18:31.282637 | controller -> localhost | +---[RSA 3072]----+
2025-09-29 19:18:31.282656 | controller -> localhost | |    ..o+.        |
2025-09-29 19:18:31.282676 | controller -> localhost | |   .  ..   o     |
2025-09-29 19:18:31.282695 | controller -> localhost | |    . .   ..o  o |
2025-09-29 19:18:31.282715 | controller -> localhost | |     . . o  o.+ o|
2025-09-29 19:18:31.282734 | controller -> localhost | |  . +   S oo +o=+|
2025-09-29 19:18:31.282753 | controller -> localhost | | o B =   +. = o+=|
2025-09-29 19:18:31.282773 | controller -> localhost | |  * X + .o.o o o |
2025-09-29 19:18:31.282793 | controller -> localhost | |   = * o. o   .  |
2025-09-29 19:18:31.282814 | controller -> localhost | |    o .    E     |
2025-09-29 19:18:31.282849 | controller -> localhost | +----[SHA256]-----+
2025-09-29 19:18:31.282899 | controller -> localhost | ok: Runtime: 0:00:00.120439
2025-09-29 19:18:31.289041 | 
2025-09-29 19:18:31.289107 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-09-29 19:18:31.320146 | controller | ok
2025-09-29 19:18:31.330843 | controller | included: /var/lib/zuul/builds/867f3ce1761f49a9bf874bee388bd5ba/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-09-29 19:18:31.340344 | 
2025-09-29 19:18:31.340438 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-09-29 19:18:31.364061 | controller | skipping: Conditional result was False
2025-09-29 19:18:31.371877 | 
2025-09-29 19:18:31.371972 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-09-29 19:18:31.907627 | controller | changed
2025-09-29 19:18:31.913959 | 
2025-09-29 19:18:31.914042 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-09-29 19:18:32.176376 | controller | ok
2025-09-29 19:18:32.182004 | 
2025-09-29 19:18:32.182082 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-09-29 19:18:33.274011 | controller | changed
2025-09-29 19:18:33.279761 | 
2025-09-29 19:18:33.279851 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-09-29 19:18:34.354309 | controller | changed
2025-09-29 19:18:34.359791 | 
2025-09-29 19:18:34.359877 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-09-29 19:18:34.384107 | controller | skipping: Conditional result was False
2025-09-29 19:18:34.390514 | 
2025-09-29 19:18:34.390609 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-09-29 19:18:34.751457 | controller -> localhost | changed
2025-09-29 19:18:34.762021 | 
2025-09-29 19:18:34.762176 | TASK [add-build-sshkey : Add back temp key]
2025-09-29 19:18:34.998391 | controller -> localhost | Identity added: /var/lib/zuul/builds/867f3ce1761f49a9bf874bee388bd5ba/work/867f3ce1761f49a9bf874bee388bd5ba_id_rsa (zuul-build-sshkey)
2025-09-29 19:18:34.998642 | controller -> localhost | ok: Runtime: 0:00:00.007186
2025-09-29 19:18:35.006069 | 
2025-09-29 19:18:35.006137 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-09-29 19:18:35.370003 | controller | ok
2025-09-29 19:18:35.375290 | 
2025-09-29 19:18:35.375379 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-09-29 19:18:35.399115 | controller | skipping: Conditional result was False
2025-09-29 19:18:35.409824 | 
2025-09-29 19:18:35.409923 | TASK [include_role : validate-host]
2025-09-29 19:18:35.428037 | controller | ok
2025-09-29 19:18:35.447789 | 
2025-09-29 19:18:35.448016 | TASK [validate-host : Define zuul_info_dir fact]
2025-09-29 19:18:35.476214 | controller | ok
2025-09-29 19:18:35.481179 | 
2025-09-29 19:18:35.481252 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-09-29 19:18:35.701036 | controller -> localhost | ok
2025-09-29 19:18:35.758785 | 
2025-09-29 19:18:35.758950 | TASK [validate-host : Collect information about the host]
2025-09-29 19:18:36.439197 | controller | ok
2025-09-29 19:18:36.448509 | 
2025-09-29 19:18:36.448594 | TASK [validate-host : Sanitize hostname]
2025-09-29 19:18:36.497529 | controller | ok
2025-09-29 19:18:36.503028 | 
2025-09-29 19:18:36.503419 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-09-29 19:18:36.913548 | controller -> localhost | changed
2025-09-29 19:18:36.918933 | 
2025-09-29 19:18:36.918999 | TASK [validate-host : Collect information about zuul worker]
2025-09-29 19:18:37.302407 | controller | ok
2025-09-29 19:18:37.308873 | 
2025-09-29 19:18:37.308997 | TASK [validate-host : Write out all zuul information for each host]
2025-09-29 19:18:37.710217 | controller -> localhost | changed
2025-09-29 19:18:37.721523 | 
2025-09-29 19:18:37.721628 | TASK [include_role : prepare-workspace-openshift]
2025-09-29 19:18:37.736048 | controller | skipping: Conditional result was False
2025-09-29 19:18:37.742136 | 
2025-09-29 19:18:37.742211 | TASK [include_role : remove-zuul-sshkey]
2025-09-29 19:18:37.756087 | controller | skipping: Conditional result was False
2025-09-29 19:18:37.762223 | 
2025-09-29 19:18:37.762309 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-09-29 19:18:38.020608 | controller | ok: "logs"
2025-09-29 19:18:38.020846 | controller | ok: All items complete
2025-09-29 19:18:38.020969 | 
2025-09-29 19:18:38.254800 | controller | ok: "artifacts"
2025-09-29 19:18:38.513523 | controller | ok: "docs"
2025-09-29 19:18:38.522354 | 
2025-09-29 19:18:38.522470 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-09-29 19:18:38.788422 | controller | changed: "logs"
2025-09-29 19:18:39.029658 | controller | changed: "artifacts"
2025-09-29 19:18:39.279942 | controller | changed: "docs"
2025-09-29 19:18:39.313105 | 
2025-09-29 19:18:39.313196 | PLAY RECAP
2025-09-29 19:18:39.313245 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-09-29 19:18:39.313276 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-09-29 19:18:39.313319 | 
2025-09-29 19:18:39.400634 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-09-29 19:18:39.401368 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-09-29 19:18:39.985930 | 
2025-09-29 19:18:39.986033 | PLAY [all]
2025-09-29 19:18:40.006381 | 
2025-09-29 19:18:40.006466 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-09-29 19:18:40.076751 | controller | ok
2025-09-29 19:18:40.081745 | 
2025-09-29 19:18:40.081846 | TASK [mirror-info-fork : Create /etc/ci]
2025-09-29 19:18:40.506695 | controller | changed
2025-09-29 19:18:40.514374 | 
2025-09-29 19:18:40.514463 | TASK [mirror-info-fork : Install ci_mirror script]
2025-09-29 19:18:41.749150 | controller | changed
2025-09-29 19:18:41.759250 | 
2025-09-29 19:18:41.759355 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-09-29 19:18:42.207827 | controller | changed:
2025-09-29 19:18:42.208017 | controller | {
2025-09-29 19:18:42.208058 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-09-29 19:18:42.208093 | controller | }
2025-09-29 19:18:42.494377 | controller | changed:
2025-09-29 19:18:42.494455 | controller | {
2025-09-29 19:18:42.494489 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-09-29 19:18:42.494512 | controller | }
2025-09-29 19:18:42.764371 | controller | changed:
2025-09-29 19:18:42.764460 | controller | {
2025-09-29 19:18:42.764492 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-09-29 19:18:42.764516 | controller | }
2025-09-29 19:18:43.059145 | controller | changed:
2025-09-29 19:18:43.059223 | controller | {
2025-09-29 19:18:43.059252 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-09-29 19:18:43.059273 | controller | }
2025-09-29 19:18:43.350492 | controller | changed:
2025-09-29 19:18:43.350584 | controller | {
2025-09-29 19:18:43.350613 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-09-29 19:18:43.350635 | controller | }
2025-09-29 19:18:43.631518 | controller | changed:
2025-09-29 19:18:43.631615 | controller | {
2025-09-29 19:18:43.631642 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-09-29 19:18:43.631663 | controller | }
2025-09-29 19:18:43.927633 | controller | changed:
2025-09-29 19:18:43.927731 | controller | {
2025-09-29 19:18:43.927760 | 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-09-29 19:18:43.927783 | controller | }
2025-09-29 19:18:44.206306 | controller | changed:
2025-09-29 19:18:44.206398 | controller | {
2025-09-29 19:18:44.206428 | 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-09-29 19:18:44.206450 | controller | }
2025-09-29 19:18:44.490027 | controller | changed:
2025-09-29 19:18:44.490136 | controller | {
2025-09-29 19:18:44.490165 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-09-29 19:18:44.490188 | controller | }
2025-09-29 19:18:44.825848 | controller | changed:
2025-09-29 19:18:44.825949 | controller | {
2025-09-29 19:18:44.825979 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-09-29 19:18:44.826001 | controller | }
2025-09-29 19:18:45.102978 | controller | changed:
2025-09-29 19:18:45.103066 | controller | {
2025-09-29 19:18:45.103096 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-09-29 19:18:45.103118 | controller | }
2025-09-29 19:18:45.411023 | controller | changed:
2025-09-29 19:18:45.411142 | controller | {
2025-09-29 19:18:45.411177 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-09-29 19:18:45.411198 | controller | }
2025-09-29 19:18:45.709129 | controller | changed:
2025-09-29 19:18:45.709253 | controller | {
2025-09-29 19:18:45.709284 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-09-29 19:18:45.709321 | controller | }
2025-09-29 19:18:46.028761 | controller | changed:
2025-09-29 19:18:46.028850 | controller | {
2025-09-29 19:18:46.028880 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-09-29 19:18:46.028901 | controller | }
2025-09-29 19:18:46.318521 | controller | changed:
2025-09-29 19:18:46.318707 | controller | {
2025-09-29 19:18:46.318752 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-09-29 19:18:46.318777 | controller | }
2025-09-29 19:18:46.610051 | controller | changed:
2025-09-29 19:18:46.610140 | controller | {
2025-09-29 19:18:46.610169 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-09-29 19:18:46.610191 | controller | }
2025-09-29 19:18:46.913621 | controller | changed:
2025-09-29 19:18:46.913699 | controller | {
2025-09-29 19:18:46.913726 | 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-09-29 19:18:46.913747 | controller | }
2025-09-29 19:18:47.215679 | controller | changed:
2025-09-29 19:18:47.215761 | controller | {
2025-09-29 19:18:47.215791 | 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-09-29 19:18:47.215823 | controller | }
2025-09-29 19:18:47.526119 | controller | changed:
2025-09-29 19:18:47.526260 | controller | {
2025-09-29 19:18:47.526293 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-09-29 19:18:47.526331 | controller | }
2025-09-29 19:18:47.840249 | controller | changed:
2025-09-29 19:18:47.840363 | controller | {
2025-09-29 19:18:47.840447 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-09-29 19:18:47.840477 | controller | }
2025-09-29 19:18:48.147032 | controller | changed:
2025-09-29 19:18:48.147176 | controller | {
2025-09-29 19:18:48.147210 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-09-29 19:18:48.147231 | controller | }
2025-09-29 19:18:48.452586 | controller | changed:
2025-09-29 19:18:48.452676 | controller | {
2025-09-29 19:18:48.452703 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-09-29 19:18:48.452724 | controller | }
2025-09-29 19:18:48.752500 | controller | changed:
2025-09-29 19:18:48.752603 | controller | {
2025-09-29 19:18:48.752634 | 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-09-29 19:18:48.752656 | controller | }
2025-09-29 19:18:49.059856 | controller | changed:
2025-09-29 19:18:49.059969 | controller | {
2025-09-29 19:18:49.060001 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-09-29 19:18:49.060023 | controller | }
2025-09-29 19:18:49.369629 | controller | changed:
2025-09-29 19:18:49.369763 | controller | {
2025-09-29 19:18:49.369794 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-09-29 19:18:49.369815 | controller | }
2025-09-29 19:18:49.669492 | controller | changed:
2025-09-29 19:18:49.669590 | controller | {
2025-09-29 19:18:49.669619 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-09-29 19:18:49.669640 | controller | }
2025-09-29 19:18:49.690663 | 
2025-09-29 19:18:49.690776 | TASK [Set timezone to UTC]
2025-09-29 19:18:50.208507 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-09-29 19:18:50.214090 | 
2025-09-29 19:18:50.214172 | TASK [Create nodepool directory]
2025-09-29 19:18:50.501107 | controller | changed
2025-09-29 19:18:50.507710 | 
2025-09-29 19:18:50.507821 | TASK [Create nodepool sub_nodes file]
2025-09-29 19:18:51.473732 | controller | changed
2025-09-29 19:18:51.478894 | 
2025-09-29 19:18:51.478993 | TASK [Create nodepool sub_nodes_private file]
2025-09-29 19:18:52.450548 | controller | changed
2025-09-29 19:18:52.457120 | 
2025-09-29 19:18:52.457192 | LOOP [Populate nodepool sub_nodes file]
2025-09-29 19:18:52.488172 | 
2025-09-29 19:18:52.488314 | LOOP [Populate nodepool sub_nodes_private file]
2025-09-29 19:18:52.518249 | 
2025-09-29 19:18:52.518399 | TASK [Create nodepool primary file]
2025-09-29 19:18:52.542857 | controller | skipping: Conditional result was False
2025-09-29 19:18:52.561260 | 
2025-09-29 19:18:52.561430 | TASK [Create nodepool node_private for this node]
2025-09-29 19:18:53.564783 | controller | changed
2025-09-29 19:18:53.570424 | 
2025-09-29 19:18:53.570494 | LOOP [Copy ssh keys to nodepool directory]
2025-09-29 19:18:53.971886 | controller | ok: Item: id_rsa Runtime: 0:00:00.005373
2025-09-29 19:18:53.972087 | 
2025-09-29 19:18:54.196766 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.004663
2025-09-29 19:18:54.211044 | 
2025-09-29 19:18:54.211144 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-09-29 19:18:55.197242 | controller | changed
2025-09-29 19:18:55.203531 | 
2025-09-29 19:18:55.203621 | TASK [Validate sudoers config after edits]
2025-09-29 19:18:55.506532 | controller | /etc/sudoers: parsed OK
2025-09-29 19:18:55.506584 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-09-29 19:18:55.506594 | controller | /etc/sudoers.d/zuul: parsed OK
2025-09-29 19:18:55.506600 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-09-29 19:18:55.738814 | controller | ok: Runtime: 0:00:00.005444
2025-09-29 19:18:55.744717 | 
2025-09-29 19:18:55.744810 | TASK [Show the environment passed in to job shell scripts]
2025-09-29 19:18:56.039715 | controller | SHELL=/bin/bash
2025-09-29 19:18:56.039790 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-09-29 19:18:56.039854 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-09-29 19:18:56.039866 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/46/3346/eb5b53fb17db92a72d33d052a56c8edd0d10ea78^openstack-k8s-operators/ci-framework:main:refs/changes/33/3333/b461fc761ffaeed72eedc04b84a1fb92d251fe5d
2025-09-29 19:18:56.039876 | controller | PWD=/home/zuul
2025-09-29 19:18:56.039882 | controller | ZUUL_PIPELINE=github-check
2025-09-29 19:18:56.039888 | controller | LOGNAME=zuul
2025-09-29 19:18:56.039893 | controller | XDG_SESSION_TYPE=tty
2025-09-29 19:18:56.039898 | controller | _=/usr/bin/env
2025-09-29 19:18:56.039904 | controller | MOTD_SHOWN=pam
2025-09-29 19:18:56.039909 | controller | HOME=/home/zuul
2025-09-29 19:18:56.039914 | controller | LANG=en_US.UTF-8
2025-09-29 19:18:56.039920 | controller | SSH_CONNECTION=192.168.26.12 52786 192.168.26.178 22
2025-09-29 19:18:56.039926 | 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-09-29 19:18:56.039932 | controller | ZUUL_CHANGE_IDS=3346,eb5b53fb17db92a72d33d052a56c8edd0d10ea78 3333,b461fc761ffaeed72eedc04b84a1fb92d251fe5d
2025-09-29 19:18:56.039938 | controller | WORKSPACE=/home/zuul/workspace
2025-09-29 19:18:56.039944 | controller | XDG_SESSION_CLASS=user
2025-09-29 19:18:56.039950 | controller | SELINUX_ROLE_REQUESTED=
2025-09-29 19:18:56.039955 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-09-29 19:18:56.039960 | controller | USER=zuul
2025-09-29 19:18:56.039966 | controller | ZUUL_VOTING=True
2025-09-29 19:18:56.039972 | controller | BUILD_TIMEOUT=5400000
2025-09-29 19:18:56.039977 | controller | SELINUX_USE_CURRENT_RANGE=
2025-09-29 19:18:56.039982 | controller | SHLVL=1
2025-09-29 19:18:56.039988 | controller | ZUUL_PATCHSET=b461fc761ffaeed72eedc04b84a1fb92d251fe5d
2025-09-29 19:18:56.039993 | controller | XDG_SESSION_ID=1
2025-09-29 19:18:56.039999 | controller | ZUUL_BRANCH=main
2025-09-29 19:18:56.040005 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-09-29 19:18:56.040010 | controller | SSH_CLIENT=192.168.26.12 52786 22
2025-09-29 19:18:56.040016 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-09-29 19:18:56.040021 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-09-29 19:18:56.040027 | controller | which_declare=declare -f
2025-09-29 19:18:56.040033 | 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-09-29 19:18:56.040039 | controller | SELINUX_LEVEL_REQUESTED=
2025-09-29 19:18:56.040044 | controller | ZUUL_CHANGE=3333
2025-09-29 19:18:56.040050 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-09-29 19:18:56.040055 | controller | ZUUL_UUID=867f3ce1761f49a9bf874bee388bd5ba
2025-09-29 19:18:56.040062 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-09-29 19:18:56.040068 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-09-29 19:18:56.040073 | controller | }
2025-09-29 19:18:56.272099 | controller | ok: Runtime: 0:00:00.006785
2025-09-29 19:18:56.278520 | 
2025-09-29 19:18:56.278610 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-09-29 19:18:56.292355 | controller | skipping: Conditional result was False
2025-09-29 19:18:56.299195 | 
2025-09-29 19:18:56.299274 | TASK [Symlink /home/zuul-worker/workspace]
2025-09-29 19:18:56.855136 | controller | skipping: Conditional result was False
2025-09-29 19:18:56.861365 | 
2025-09-29 19:18:56.861453 | TASK [Ensure legacy workspace directory]
2025-09-29 19:18:57.135990 | controller | changed
2025-09-29 19:18:57.156981 | 
2025-09-29 19:18:57.157068 | PLAY RECAP
2025-09-29 19:18:57.157115 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-09-29 19:18:57.157140 | 
2025-09-29 19:18:57.257766 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-09-29 19:18:57.258871 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/read_global_vars.yml@main]
2025-09-29 19:18:57.801013 | 
2025-09-29 19:18:57.801118 | PLAY [Load global variables]
2025-09-29 19:18:57.822374 | 
2025-09-29 19:18:57.822456 | TASK [Read group_vars all file]
2025-09-29 19:18:57.840778 | controller | ok
2025-09-29 19:18:57.856820 | 
2025-09-29 19:18:57.856906 | TASK [cifmw_helpers : Check if file is available]
2025-09-29 19:18:58.180488 | controller | ok
2025-09-29 19:18:58.185882 | 
2025-09-29 19:18:58.186011 | TASK [cifmw_helpers : Read vars]
2025-09-29 19:18:58.207691 | 
2025-09-29 19:18:58.207852 | LOOP [cifmw_helpers : Set vars as fact]
2025-09-29 19:18:58.278493 | 
2025-09-29 19:18:58.278692 | PLAY RECAP
2025-09-29 19:18:58.278747 | controller | ok: 1 changed: 0 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-09-29 19:18:58.278772 | 
2025-09-29 19:18:58.365743 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/read_global_vars.yml@main]
2025-09-29 19:18:58.366711 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-09-29 19:18:58.920898 | 
2025-09-29 19:18:58.921117 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-09-29 19:18:58.942274 | 
2025-09-29 19:18:58.942384 | TASK [Create zuul-output directory]
2025-09-29 19:18:59.357611 | controller | changed
2025-09-29 19:18:59.362739 | 
2025-09-29 19:18:59.362826 | TASK [Slurp Zuul inventory test]
2025-09-29 19:18:59.683686 | controller -> localhost | ok
2025-09-29 19:18:59.690525 | 
2025-09-29 19:18:59.690619 | TASK [Save zuul inventory]
2025-09-29 19:19:00.889156 | controller | changed
2025-09-29 19:19:00.895092 | 
2025-09-29 19:19:00.895191 | TASK [Save zuul vars without the change_message]
2025-09-29 19:19:01.967008 | controller | changed
2025-09-29 19:19:01.986625 | 
2025-09-29 19:19:01.987567 | PLAY RECAP
2025-09-29 19:19:01.987631 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-09-29 19:19:01.987658 | 
2025-09-29 19:19:02.070220 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-09-29 19:19:02.071007 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-09-29 19:19:02.684563 | 
2025-09-29 19:19:02.684686 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-09-29 19:19:02.709071 | 
2025-09-29 19:19:02.709352 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-09-29 19:19:02.729544 | controller | ok
2025-09-29 19:19:02.747818 | 
2025-09-29 19:19:02.747972 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-09-29 19:19:02.772059 | controller | skipping: Conditional result was False
2025-09-29 19:19:02.777897 | 
2025-09-29 19:19:02.778042 | TASK [mirror-info-fork : Create /etc/ci]
2025-09-29 19:19:03.183881 | controller | ok
2025-09-29 19:19:03.189674 | 
2025-09-29 19:19:03.189769 | TASK [mirror-info-fork : Install ci_mirror script]
2025-09-29 19:19:04.133465 | controller | ok
2025-09-29 19:19:04.150018 | 
2025-09-29 19:19:04.150110 | TASK [Prepare workspace]
2025-09-29 19:19:04.172258 | controller | ok
2025-09-29 19:19:04.189763 | 
2025-09-29 19:19:04.189868 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-09-29 19:19:04.549047 | controller | ok
2025-09-29 19:19:04.555874 | 
2025-09-29 19:19:04.556004 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-09-29 19:19:06.620044 | controller | Output suppressed because no_log was given
2025-09-29 19:19:06.632238 | 
2025-09-29 19:19:06.632341 | LOOP [Create zuul-output directory]
2025-09-29 19:19:06.878155 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-09-29 19:19:07.097468 | controller | ok: "/home/zuul/zuul-output/logs"
2025-09-29 19:19:07.113426 | 
2025-09-29 19:19:07.113522 | TASK [Install required packages]
2025-09-29 19:19:23.412808 | controller | ok: Nothing to do
2025-09-29 19:19:23.418461 | 
2025-09-29 19:19:23.418544 | TASK [Install venv]
2025-09-29 19:20:23.184000 | controller | changed
2025-09-29 19:20:23.212329 | 
2025-09-29 19:20:23.212454 | PLAY RECAP
2025-09-29 19:20:23.212502 | controller | ok: 7 changed: 3 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-09-29 19:20:23.212526 | 
2025-09-29 19:20:23.300440 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-09-29 19:20:23.301223 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-09-29 19:20:23.844198 | 
2025-09-29 19:20:23.844322 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-09-29 19:20:23.865249 | 
2025-09-29 19:20:23.865352 | TASK [Gather required facts]
2025-09-29 19:20:24.434158 | controller | ok
2025-09-29 19:20:24.439425 | 
2025-09-29 19:20:24.439501 | TASK [Load environment var if instructed to]
2025-09-29 19:20:24.455107 | controller | skipping: Conditional result was False
2025-09-29 19:20:24.463023 | 
2025-09-29 19:20:24.463121 | TASK [Run molecule]
2025-09-29 19:20:25.476705 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-09-29 19:20:25.831294 | controller | INFO     Performing prerun with role_name_check=0...
2025-09-29 19:20:42.477600 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:20:42.478084 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:20:42.478597 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:20:42.479079 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:20:42.479573 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+4a832a0b was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 1.0.0+4a832a0b (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:20:42.480047 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:20:42.480501 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:20:42.480963 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:20:42.481440 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:20:42.481903 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:20:42.482381 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:20:42.482820 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:20:42.483263 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:20:42.483721 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:20:42.484177 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:20:42.494430 | controller | INFO     Running add_crc_creds > prepare
2025-09-29 19:20:43.204543 | controller |
2025-09-29 19:20:43.204734 | controller | PLAY [Prepare] *****************************************************************
2025-09-29 19:20:43.204912 | controller |
2025-09-29 19:20:43.205119 | controller | TASK [Gathering Facts] *********************************************************
2025-09-29 19:20:43.205311 | controller | Monday 29 September 2025  19:20:43 +0000 (0:00:00.015)       0:00:00.015 ******
2025-09-29 19:20:44.021898 | controller | ok: [instance]
2025-09-29 19:20:44.021977 | controller |
2025-09-29 19:20:44.022125 | controller | TASK [Setup libvirt] ***********************************************************
2025-09-29 19:20:44.022262 | controller | Monday 29 September 2025  19:20:44 +0000 (0:00:00.818)       0:00:00.834 ******
2025-09-29 19:20:44.043479 | controller | skipping: [instance]
2025-09-29 19:20:44.043609 | controller |
2025-09-29 19:20:44.043715 | controller | TASK [Setup CRC] ***************************************************************
2025-09-29 19:20:44.043824 | controller | Monday 29 September 2025  19:20:44 +0000 (0:00:00.021)       0:00:00.856 ******
2025-09-29 19:20:44.064461 | controller | skipping: [instance]
2025-09-29 19:20:44.064556 | controller |
2025-09-29 19:20:44.064678 | controller | TASK [Start RHOL/CRC] **********************************************************
2025-09-29 19:20:44.064780 | controller | Monday 29 September 2025  19:20:44 +0000 (0:00:00.020)       0:00:00.877 ******
2025-09-29 19:20:44.482432 | controller | changed: [instance]
2025-09-29 19:20:44.482529 | controller |
2025-09-29 19:20:44.482546 | controller | TASK [Inject our own NetworkManager configuration] *****************************
2025-09-29 19:20:44.482665 | controller | Monday 29 September 2025  19:20:44 +0000 (0:00:00.417)       0:00:01.294 ******
2025-09-29 19:20:45.054374 | controller | changed: [instance]
2025-09-29 19:20:45.054427 | controller |
2025-09-29 19:20:45.054546 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-09-29 19:20:45.054648 | controller | Monday 29 September 2025  19:20:45 +0000 (0:00:00.572)       0:00:01.866 ******
2025-09-29 19:20:45.072920 | controller | skipping: [instance]
2025-09-29 19:20:45.072991 | controller |
2025-09-29 19:20:45.073087 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-09-29 19:20:45.073196 | controller | Monday 29 September 2025  19:20:45 +0000 (0:00:00.018)       0:00:01.885 ******
2025-09-29 19:20:45.113266 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-09-29 19:20:45.113405 | controller |
2025-09-29 19:20:45.113535 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-09-29 19:20:45.113658 | controller | Monday 29 September 2025  19:20:45 +0000 (0:00:00.040)       0:00:01.925 ******
2025-09-29 19:20:45.323026 | controller | ok: [instance]
2025-09-29 19:20:45.323071 | controller |
2025-09-29 19:20:45.323190 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-09-29 19:20:45.323291 | controller | Monday 29 September 2025  19:20:45 +0000 (0:00:00.209)       0:00:02.135 ******
2025-09-29 19:20:45.656083 | controller | ok: [instance]
2025-09-29 19:20:45.656124 | controller |
2025-09-29 19:20:45.656242 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-09-29 19:20:45.656382 | controller | Monday 29 September 2025  19:20:45 +0000 (0:00:00.333)       0:00:02.468 ******
2025-09-29 19:20:46.370032 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-09-29 19:20:46.370077 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-09-29 19:20:46.370168 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-09-29 19:20:46.370258 | controller |
2025-09-29 19:20:46.370366 | controller | TASK [Deploy repo-setup] *******************************************************
2025-09-29 19:20:46.370490 | controller | Monday 29 September 2025  19:20:46 +0000 (0:00:00.713)       0:00:03.182 ******
2025-09-29 19:20:46.433219 | controller |
2025-09-29 19:20:46.433303 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-09-29 19:20:46.433421 | controller | Monday 29 September 2025  19:20:46 +0000 (0:00:00.063)       0:00:03.245 ******
2025-09-29 19:20:47.028183 | controller | changed: [instance] => (item=tmp)
2025-09-29 19:20:47.028283 | controller | changed: [instance] => (item=artifacts/repositories)
2025-09-29 19:20:47.028311 | controller | changed: [instance] => (item=venv/repo_setup)
2025-09-29 19:20:47.028695 | controller |
2025-09-29 19:20:47.918581 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-09-29 19:20:47.918625 | controller | Monday 29 September 2025  19:20:47 +0000 (0:00:00.594)       0:00:03.840 ******
2025-09-29 19:20:47.918639 | controller | ok: [instance]
2025-09-29 19:20:49.119274 | controller |
2025-09-29 19:20:49.119320 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-09-29 19:20:49.119329 | controller | Monday 29 September 2025  19:20:47 +0000 (0:00:00.889)       0:00:04.730 ******
2025-09-29 19:20:49.119357 | controller | changed: [instance]
2025-09-29 19:20:49.119383 | controller |
2025-09-29 19:20:49.119390 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-09-29 19:20:49.119398 | controller | Monday 29 September 2025  19:20:49 +0000 (0:00:01.201)       0:00:05.931 ******
2025-09-29 19:20:58.621260 | controller | changed: [instance]
2025-09-29 19:20:59.362008 | controller |
2025-09-29 19:20:59.362058 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-09-29 19:20:59.362066 | controller | Monday 29 September 2025  19:20:58 +0000 (0:00:09.500)       0:00:15.432 ******
2025-09-29 19:20:59.362081 | controller | changed: [instance]
2025-09-29 19:20:59.393938 | controller |
2025-09-29 19:20:59.394038 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-09-29 19:20:59.394047 | controller | Monday 29 September 2025  19:20:59 +0000 (0:00:00.741)       0:00:16.173 ******
2025-09-29 19:20:59.394057 | controller | skipping: [instance]
2025-09-29 19:21:00.358553 | controller |
2025-09-29 19:21:00.358594 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-09-29 19:21:00.358603 | controller | Monday 29 September 2025  19:20:59 +0000 (0:00:00.032)       0:00:16.205 ******
2025-09-29 19:21:00.358613 | controller | changed: [instance]
2025-09-29 19:21:00.407828 | controller |
2025-09-29 19:21:00.407870 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-09-29 19:21:00.407879 | controller | Monday 29 September 2025  19:21:00 +0000 (0:00:00.964)       0:00:17.170 ******
2025-09-29 19:21:00.407893 | controller | skipping: [instance]
2025-09-29 19:21:00.458006 | controller |
2025-09-29 19:21:00.458036 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-09-29 19:21:00.458044 | controller | Monday 29 September 2025  19:21:00 +0000 (0:00:00.048)       0:00:17.219 ******
2025-09-29 19:21:00.458058 | controller | skipping: [instance]
2025-09-29 19:21:00.505072 | controller |
2025-09-29 19:21:00.505104 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-09-29 19:21:00.505116 | controller | Monday 29 September 2025  19:21:00 +0000 (0:00:00.050)       0:00:17.269 ******
2025-09-29 19:21:00.505129 | controller | skipping: [instance]
2025-09-29 19:21:01.156124 | controller |
2025-09-29 19:21:01.156162 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-09-29 19:21:01.156174 | controller | Monday 29 September 2025  19:21:00 +0000 (0:00:00.047)       0:00:17.317 ******
2025-09-29 19:21:01.156190 | controller | changed: [instance]
2025-09-29 19:21:01.561593 | controller |
2025-09-29 19:21:01.561640 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-09-29 19:21:01.561653 | controller | Monday 29 September 2025  19:21:01 +0000 (0:00:00.650)       0:00:17.968 ******
2025-09-29 19:21:01.561664 | controller | changed: [instance]
2025-09-29 19:21:01.598252 | controller |
2025-09-29 19:21:01.598285 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-09-29 19:21:01.598293 | controller | Monday 29 September 2025  19:21:01 +0000 (0:00:00.405)       0:00:18.373 ******
2025-09-29 19:21:01.598303 | controller | skipping: [instance]
2025-09-29 19:21:01.630731 | controller |
2025-09-29 19:21:01.630754 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-09-29 19:21:01.630762 | controller | Monday 29 September 2025  19:21:01 +0000 (0:00:00.037)       0:00:18.410 ******
2025-09-29 19:21:01.630785 | controller | skipping: [instance]
2025-09-29 19:21:01.662479 | controller |
2025-09-29 19:21:01.662500 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-09-29 19:21:01.662508 | controller | Monday 29 September 2025  19:21:01 +0000 (0:00:00.032)       0:00:18.442 ******
2025-09-29 19:21:01.662533 | controller | skipping: [instance]
2025-09-29 19:21:01.703976 | controller |
2025-09-29 19:21:01.703998 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-09-29 19:21:01.704011 | controller | Monday 29 September 2025  19:21:01 +0000 (0:00:00.031)       0:00:18.474 ******
2025-09-29 19:21:01.704020 | controller | ok: [instance]
2025-09-29 19:21:01.733367 | controller |
2025-09-29 19:21:01.733388 | controller | TASK [repo_setup : Create download directory] **********************************
2025-09-29 19:21:01.733396 | controller | Monday 29 September 2025  19:21:01 +0000 (0:00:00.041)       0:00:18.516 ******
2025-09-29 19:21:01.733412 | controller | skipping: [instance]
2025-09-29 19:21:01.733642 | controller |
2025-09-29 19:21:01.733835 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-09-29 19:21:01.734006 | controller | Monday 29 September 2025  19:21:01 +0000 (0:00:00.029)       0:00:18.546 ******
2025-09-29 19:21:01.771251 | controller | skipping: [instance]
2025-09-29 19:21:01.771497 | controller |
2025-09-29 19:21:01.771758 | controller | TASK [Download the RPM] ********************************************************
2025-09-29 19:21:01.771934 | controller | Monday 29 September 2025  19:21:01 +0000 (0:00:00.037)       0:00:18.583 ******
2025-09-29 19:21:01.811256 | controller | skipping: [instance]
2025-09-29 19:21:01.811457 | controller |
2025-09-29 19:21:01.811646 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-09-29 19:21:01.811821 | controller | Monday 29 September 2025  19:21:01 +0000 (0:00:00.039)       0:00:18.623 ******
2025-09-29 19:21:01.841301 | controller | skipping: [instance]
2025-09-29 19:21:01.841510 | controller |
2025-09-29 19:21:01.841709 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-09-29 19:21:01.841884 | controller | Monday 29 September 2025  19:21:01 +0000 (0:00:00.030)       0:00:18.653 ******
2025-09-29 19:21:01.873673 | controller | skipping: [instance]
2025-09-29 19:21:01.873848 | controller |
2025-09-29 19:21:01.874028 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-09-29 19:21:01.874217 | controller | Monday 29 September 2025  19:21:01 +0000 (0:00:00.032)       0:00:18.686 ******
2025-09-29 19:21:01.913218 | controller | skipping: [instance]
2025-09-29 19:21:01.913484 | controller |
2025-09-29 19:21:01.913749 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-09-29 19:21:01.913957 | controller | Monday 29 September 2025  19:21:01 +0000 (0:00:00.039)       0:00:18.725 ******
2025-09-29 19:21:01.944438 | controller | skipping: [instance]
2025-09-29 19:21:02.164785 | controller |
2025-09-29 19:21:02.164820 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-09-29 19:21:02.164829 | controller | Monday 29 September 2025  19:21:01 +0000 (0:00:00.030)       0:00:18.756 ******
2025-09-29 19:21:02.164840 | controller | ok: [instance]
2025-09-29 19:21:02.409918 | controller |
2025-09-29 19:21:02.409957 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-09-29 19:21:02.409972 | controller | Monday 29 September 2025  19:21:02 +0000 (0:00:00.217)       0:00:18.974 ******
2025-09-29 19:21:02.409983 | controller | changed: [instance]
2025-09-29 19:21:02.666938 | controller |
2025-09-29 19:21:02.666970 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-09-29 19:21:02.666978 | controller | Monday 29 September 2025  19:21:02 +0000 (0:00:00.247)       0:00:19.222 ******
2025-09-29 19:21:02.666995 | controller | changed: [instance]
2025-09-29 19:21:02.691168 | controller |
2025-09-29 19:21:02.691201 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-09-29 19:21:02.691210 | controller | Monday 29 September 2025  19:21:02 +0000 (0:00:00.256)       0:00:19.478 ******
2025-09-29 19:21:02.691222 | controller | skipping: [instance]
2025-09-29 19:21:02.717423 | controller |
2025-09-29 19:21:02.717459 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-09-29 19:21:02.717481 | controller | Monday 29 September 2025  19:21:02 +0000 (0:00:00.024)       0:00:19.503 ******
2025-09-29 19:21:02.717493 | controller | skipping: [instance]
2025-09-29 19:21:02.745486 | controller |
2025-09-29 19:21:02.745525 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-09-29 19:21:02.745539 | controller | Monday 29 September 2025  19:21:02 +0000 (0:00:00.026)       0:00:19.529 ******
2025-09-29 19:21:02.745550 | controller | skipping: [instance]
2025-09-29 19:21:02.773620 | controller |
2025-09-29 19:21:02.773653 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-09-29 19:21:02.773661 | controller | Monday 29 September 2025  19:21:02 +0000 (0:00:00.028)       0:00:19.557 ******
2025-09-29 19:21:02.773677 | controller | skipping: [instance]
2025-09-29 19:21:02.802453 | controller |
2025-09-29 19:21:02.802478 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-09-29 19:21:02.802488 | controller | Monday 29 September 2025  19:21:02 +0000 (0:00:00.028)       0:00:19.585 ******
2025-09-29 19:21:02.802513 | controller | skipping: [instance]
2025-09-29 19:21:02.828905 | controller |
2025-09-29 19:21:02.828931 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-09-29 19:21:02.828939 | controller | Monday 29 September 2025  19:21:02 +0000 (0:00:00.028)       0:00:19.614 ******
2025-09-29 19:21:02.828953 | controller | skipping: [instance]
2025-09-29 19:21:02.850085 | controller |
2025-09-29 19:21:02.850105 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-09-29 19:21:02.850113 | controller | Monday 29 September 2025  19:21:02 +0000 (0:00:00.026)       0:00:19.641 ******
2025-09-29 19:21:02.850122 | controller | skipping: [instance]
2025-09-29 19:21:02.887976 | controller |
2025-09-29 19:21:02.887997 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-09-29 19:21:02.888004 | controller | Monday 29 September 2025  19:21:02 +0000 (0:00:00.021)       0:00:19.662 ******
2025-09-29 19:21:02.888013 | controller | skipping: [instance]
2025-09-29 19:21:02.910377 | controller |
2025-09-29 19:21:02.910417 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-09-29 19:21:02.910428 | controller | Monday 29 September 2025  19:21:02 +0000 (0:00:00.037)       0:00:19.700 ******
2025-09-29 19:21:02.910442 | controller | skipping: [instance]
2025-09-29 19:21:02.937203 | controller |
2025-09-29 19:21:02.937232 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-09-29 19:21:02.937240 | controller | Monday 29 September 2025  19:21:02 +0000 (0:00:00.022)       0:00:19.722 ******
2025-09-29 19:21:02.937251 | controller | skipping: [instance]
2025-09-29 19:21:02.972819 | controller |
2025-09-29 19:21:02.972879 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-09-29 19:21:02.972893 | controller | Monday 29 September 2025  19:21:02 +0000 (0:00:00.026)       0:00:19.749 ******
2025-09-29 19:21:02.972903 | controller | skipping: [instance]
2025-09-29 19:21:03.007276 | controller |
2025-09-29 19:21:03.007413 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-09-29 19:21:03.007449 | controller | Monday 29 September 2025  19:21:02 +0000 (0:00:00.035)       0:00:19.784 ******
2025-09-29 19:21:03.007475 | controller | skipping: [instance]
2025-09-29 19:21:03.039786 | controller |
2025-09-29 19:21:03.039816 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-09-29 19:21:03.039824 | controller | Monday 29 September 2025  19:21:03 +0000 (0:00:00.034)       0:00:19.818 ******
2025-09-29 19:21:03.039840 | controller | skipping: [instance]
2025-09-29 19:21:03.073990 | controller |
2025-09-29 19:21:03.074025 | controller | TASK [test_deps : Install additional packages] *********************************
2025-09-29 19:21:03.074034 | controller | Monday 29 September 2025  19:21:03 +0000 (0:00:00.033)       0:00:19.852 ******
2025-09-29 19:21:03.074044 | controller | skipping: [instance]
2025-09-29 19:21:49.949532 | controller |
2025-09-29 19:21:49.949576 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-09-29 19:21:49.949585 | controller | Monday 29 September 2025  19:21:03 +0000 (0:00:00.033)       0:00:19.885 ******
2025-09-29 19:21:49.949595 | controller | ok: [instance]
2025-09-29 19:21:51.177174 | controller |
2025-09-29 19:21:51.177207 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-09-29 19:21:51.177222 | controller | Monday 29 September 2025  19:21:49 +0000 (0:00:46.875)       0:01:06.761 ******
2025-09-29 19:21:51.177233 | controller | ok: [instance]
2025-09-29 19:21:51.211034 | controller |
2025-09-29 19:21:51.211086 | controller | TASK [test_deps : Install extra packages] **************************************
2025-09-29 19:21:51.211095 | controller | Monday 29 September 2025  19:21:51 +0000 (0:00:01.227)       0:01:07.989 ******
2025-09-29 19:21:51.211105 | controller | skipping: [instance]
2025-09-29 19:21:51.254489 | controller |
2025-09-29 19:21:51.254525 | controller | TASK [ci_setup : Gather variables for each operating system] *******************
2025-09-29 19:21:51.254535 | controller | Monday 29 September 2025  19:21:51 +0000 (0:00:00.034)       0:01:08.023 ******
2025-09-29 19:21:51.254548 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/ci_setup/vars/redhat.yml)
2025-09-29 19:21:51.254577 | controller |
2025-09-29 19:21:51.254587 | controller | TASK [ci_setup : List packages to install] *************************************
2025-09-29 19:21:51.254689 | controller | Monday 29 September 2025  19:21:51 +0000 (0:00:00.043)       0:01:08.067 ******
2025-09-29 19:21:51.274233 | controller | ok: [instance] =>
2025-09-29 19:21:51.274477 | controller |   cifmw_ci_setup_packages:
2025-09-29 19:21:51.274511 | controller |   - bash-completion
2025-09-29 19:21:51.274519 | controller |   - ca-certificates
2025-09-29 19:21:51.274525 | controller |   - git-core
2025-09-29 19:21:51.274531 | controller |   - make
2025-09-29 19:21:51.274541 | controller |   - tar
2025-09-29 19:21:51.274566 | controller |   - tmux
2025-09-29 19:21:51.274574 | controller |   - python3-pip
2025-09-29 19:21:51.274813 | controller |
2025-09-29 19:21:59.265232 | controller | TASK [ci_setup : Install needed packages] **************************************
2025-09-29 19:21:59.265271 | controller | Monday 29 September 2025  19:21:51 +0000 (0:00:00.019)       0:01:08.086 ******
2025-09-29 19:21:59.265284 | controller | changed: [instance]
2025-09-29 19:21:59.895458 | controller |
2025-09-29 19:21:59.895499 | controller | TASK [ci_setup : Gather version of openshift client] ***************************
2025-09-29 19:21:59.895508 | controller | Monday 29 September 2025  19:21:59 +0000 (0:00:07.990)       0:01:16.077 ******
2025-09-29 19:21:59.895522 | controller | ok: [instance]
2025-09-29 19:22:00.121838 | controller |
2025-09-29 19:22:00.121877 | controller | TASK [ci_setup : Ensure openshift client install path is present] **************
2025-09-29 19:22:00.121891 | controller | Monday 29 September 2025  19:21:59 +0000 (0:00:00.630)       0:01:16.707 ******
2025-09-29 19:22:00.121902 | controller | changed: [instance]
2025-09-29 19:22:06.230453 | controller |
2025-09-29 19:22:06.230498 | controller | TASK [ci_setup : Install openshift client] *************************************
2025-09-29 19:22:06.230507 | controller | Monday 29 September 2025  19:22:00 +0000 (0:00:00.226)       0:01:16.933 ******
2025-09-29 19:22:06.230518 | controller | changed: [instance]
2025-09-29 19:22:06.273481 | controller |
2025-09-29 19:22:06.273516 | controller | TASK [ci_setup : Add the OC path to cifmw_path if needed] **********************
2025-09-29 19:22:06.273524 | controller | Monday 29 September 2025  19:22:06 +0000 (0:00:06.104)       0:01:23.038 ******
2025-09-29 19:22:06.273535 | controller | ok: [instance]
2025-09-29 19:22:06.546093 | controller |
2025-09-29 19:22:06.546125 | controller | TASK [ci_setup : Create completion file] ***************************************
2025-09-29 19:22:06.546134 | controller | Monday 29 September 2025  19:22:06 +0000 (0:00:00.047)       0:01:23.085 ******
2025-09-29 19:22:06.546144 | controller | changed: [instance]
2025-09-29 19:22:06.827499 | controller |
2025-09-29 19:22:06.827540 | controller | TASK [ci_setup : Source completion from within .bashrc] ************************
2025-09-29 19:22:06.827548 | controller | Monday 29 September 2025  19:22:06 +0000 (0:00:00.272)       0:01:23.358 ******
2025-09-29 19:22:06.827560 | controller | changed: [instance]
2025-09-29 19:22:06.845252 | controller |
2025-09-29 19:22:06.845289 | controller | TASK [ci_setup : Check rhsm status] ********************************************
2025-09-29 19:22:06.845300 | controller | Monday 29 September 2025  19:22:06 +0000 (0:00:00.281)       0:01:23.639 ******
2025-09-29 19:22:06.845312 | controller | skipping: [instance]
2025-09-29 19:22:06.845361 | controller |
2025-09-29 19:22:06.845378 | controller | TASK [ci_setup : Gather the repos to be enabled] *******************************
2025-09-29 19:22:06.845501 | controller | Monday 29 September 2025  19:22:06 +0000 (0:00:00.018)       0:01:23.658 ******
2025-09-29 19:22:06.863035 | controller | skipping: [instance]
2025-09-29 19:22:06.863170 | controller |
2025-09-29 19:22:06.863207 | controller | TASK [ci_setup : Enabling the required repositories.] **************************
2025-09-29 19:22:06.863222 | controller | Monday 29 September 2025  19:22:06 +0000 (0:00:00.017)       0:01:23.675 ******
2025-09-29 19:22:06.881042 | controller | skipping: [instance]
2025-09-29 19:22:06.897846 | controller |
2025-09-29 19:22:06.897870 | controller | TASK [ci_setup : Get current /etc/redhat-release] ******************************
2025-09-29 19:22:06.897878 | controller | Monday 29 September 2025  19:22:06 +0000 (0:00:00.018)       0:01:23.693 ******
2025-09-29 19:22:06.897887 | controller | skipping: [instance]
2025-09-29 19:22:06.915145 | controller |
2025-09-29 19:22:06.915185 | controller | TASK [ci_setup : Print current /etc/redhat-release] ****************************
2025-09-29 19:22:06.915194 | controller | Monday 29 September 2025  19:22:06 +0000 (0:00:00.016)       0:01:23.710 ******
2025-09-29 19:22:06.915220 | controller | skipping: [instance]
2025-09-29 19:22:06.937584 | controller |
2025-09-29 19:22:06.937618 | controller | TASK [ci_setup : Ensure the repos are enabled in the system using yum] *********
2025-09-29 19:22:06.937626 | controller | Monday 29 September 2025  19:22:06 +0000 (0:00:00.017)       0:01:23.727 ******
2025-09-29 19:22:06.937637 | controller | skipping: [instance]
2025-09-29 19:22:06.937816 | controller |
2025-09-29 19:22:06.937840 | controller | TASK [ci_setup : Manage directories] *******************************************
2025-09-29 19:22:07.961077 | controller | Monday 29 September 2025  19:22:06 +0000 (0:00:00.022)       0:01:23.750 ******
2025-09-29 19:22:07.961114 | controller | changed: [instance] => (item=/home/zuul/ci-framework-data/artifacts/manifests/openstack/cr)
2025-09-29 19:23:48.728509 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/logs)
2025-09-29 19:23:48.728556 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/tmp)
2025-09-29 19:23:48.728565 | controller | changed: [instance] => (item=/home/zuul/ci-framework-data/volumes)
2025-09-29 19:23:48.728571 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/artifacts/parameters)
2025-09-29 19:23:48.728577 | controller |
2025-09-29 19:23:48.728583 | controller | TASK [Check for CRC startup] ***************************************************
2025-09-29 19:23:48.728588 | controller | Monday 29 September 2025  19:22:07 +0000 (0:00:01.022)       0:01:24.772 ******
2025-09-29 19:23:48.728598 | controller | FAILED - RETRYING: [instance]: Check for CRC startup (120 retries left).
2025-09-29 19:23:49.409153 | controller | FAILED - RETRYING: [instance]: Check for CRC startup (119 retries left).
2025-09-29 19:23:49.409191 | controller | changed: [instance]
2025-09-29 19:23:49.409200 | controller |
2025-09-29 19:23:49.409206 | controller | RUNNING HANDLER [Restart NetworkManager] ***************************************
2025-09-29 19:23:49.409211 | controller | Monday 29 September 2025  19:23:48 +0000 (0:01:40.767)       0:03:05.540 ******
2025-09-29 19:23:49.409222 | controller | changed: [instance]
2025-09-29 19:23:49.409386 | controller |
2025-09-29 19:23:49.409541 | controller | PLAY RECAP *********************************************************************
2025-09-29 19:23:49.409556 | controller | instance                   : ok=33   changed=19   unreachable=0    failed=0    skipped=38   rescued=0    ignored=0
2025-09-29 19:23:49.409727 | controller |
2025-09-29 19:23:49.409741 | controller | Monday 29 September 2025  19:23:49 +0000 (0:00:00.681)       0:03:06.221 ******
2025-09-29 19:23:49.410007 | controller | ===============================================================================
2025-09-29 19:23:49.410749 | controller | Check for CRC startup ------------------------------------------------- 100.77s
2025-09-29 19:23:49.410782 | controller | test_deps : Install selinux python libs -------------------------------- 46.88s
2025-09-29 19:23:49.410795 | controller | repo_setup : Initialize python venv and install requirements ------------ 9.50s
2025-09-29 19:23:49.410867 | controller | ci_setup : Install needed packages -------------------------------------- 7.99s
2025-09-29 19:23:49.410878 | controller | ci_setup : Install openshift client ------------------------------------- 6.10s
2025-09-29 19:23:49.410884 | controller | test_deps : Install python yaml libs ------------------------------------ 1.23s
2025-09-29 19:23:49.410897 | controller | repo_setup : Get repo-setup repository ---------------------------------- 1.20s
2025-09-29 19:23:49.410903 | controller | ci_setup : Manage directories ------------------------------------------- 1.02s
2025-09-29 19:23:49.410908 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.96s
2025-09-29 19:23:49.410916 | controller | repo_setup : Make sure git-core package is installed -------------------- 0.89s
2025-09-29 19:23:49.411021 | controller | Gathering Facts --------------------------------------------------------- 0.82s
2025-09-29 19:23:49.411035 | controller | repo_setup : Install repo-setup package --------------------------------- 0.74s
2025-09-29 19:23:49.411059 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.71s
2025-09-29 19:23:49.411322 | controller | Restart NetworkManager -------------------------------------------------- 0.68s
2025-09-29 19:23:49.411580 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.65s
2025-09-29 19:23:49.411597 | controller | ci_setup : Gather version of openshift client --------------------------- 0.63s
2025-09-29 19:23:49.412569 | controller | repo_setup : Ensure directories are present ----------------------------- 0.59s
2025-09-29 19:23:49.412614 | controller | Inject our own NetworkManager configuration ----------------------------- 0.57s
2025-09-29 19:23:49.412678 | controller | Start RHOL/CRC ---------------------------------------------------------- 0.42s
2025-09-29 19:23:49.413058 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.41s
2025-09-29 19:23:49.474220 | controller | INFO     Running add_crc_creds > converge
2025-09-29 19:23:49.918702 | controller |
2025-09-29 19:23:49.918776 | controller | PLAY [Converge add_crc_creds] **************************************************
2025-09-29 19:23:49.918886 | controller |
2025-09-29 19:23:49.918898 | controller | TASK [Gathering Facts] *********************************************************
2025-09-29 19:23:49.919004 | controller | Monday 29 September 2025  19:23:49 +0000 (0:00:00.045)       0:00:00.045 ******
2025-09-29 19:23:50.825701 | controller | ok: [instance]
2025-09-29 19:23:50.825755 | controller |
2025-09-29 19:23:50.825861 | controller | TASK [Verify crc creds playbook] ***********************************************
2025-09-29 19:23:50.825974 | controller | Monday 29 September 2025  19:23:50 +0000 (0:00:00.907)       0:00:00.952 ******
2025-09-29 19:23:50.855077 | controller |
2025-09-29 19:23:50.855176 | controller | TASK [rhol_crc : Make sure kubeconfig file exists] *****************************
2025-09-29 19:23:50.855305 | controller | Monday 29 September 2025  19:23:50 +0000 (0:00:00.029)       0:00:00.982 ******
2025-09-29 19:23:51.152872 | controller | ok: [instance]
2025-09-29 19:23:51.152938 | controller |
2025-09-29 19:23:51.153028 | controller | TASK [rhol_crc : Warn the user that the kubeconfig files doesn't exist] ********
2025-09-29 19:23:51.153136 | controller | Monday 29 September 2025  19:23:51 +0000 (0:00:00.297)       0:00:01.279 ******
2025-09-29 19:23:51.180299 | controller | skipping: [instance]
2025-09-29 19:23:51.180384 | controller |
2025-09-29 19:23:51.180503 | controller | TASK [rhol_crc : Add crc creds in the user bashrc file] ************************
2025-09-29 19:23:51.180643 | controller | Monday 29 September 2025  19:23:51 +0000 (0:00:00.027)       0:00:01.307 ******
2025-09-29 19:23:51.465955 | controller | changed: [instance]
2025-09-29 19:23:51.466020 | controller |
2025-09-29 19:23:51.466130 | controller | TASK [rhol_crc : Source bashrc and confirm crc login] **************************
2025-09-29 19:23:51.466238 | controller | Monday 29 September 2025  19:23:51 +0000 (0:00:00.285)       0:00:01.593 ******
2025-09-29 19:23:52.043333 | controller | ok: [instance]
2025-09-29 19:23:52.043411 | controller |
2025-09-29 19:23:52.043474 | controller | TASK [rhol_crc : Check bashrc results] *****************************************
2025-09-29 19:23:52.043587 | controller | Monday 29 September 2025  19:23:52 +0000 (0:00:00.577)       0:00:02.170 ******
2025-09-29 19:23:52.085690 | controller | ok: [instance] =>
2025-09-29 19:23:52.085757 | controller |   bashrc_result.stdout: |-
2025-09-29 19:23:52.085877 | controller |     /usr/local/bin/crc
2025-09-29 19:23:52.085972 | controller |     system:admin
2025-09-29 19:23:52.086073 | controller |
2025-09-29 19:23:52.086189 | controller | PLAY RECAP *********************************************************************
2025-09-29 19:23:52.086307 | controller | instance                   : ok=5    changed=1    unreachable=0    failed=0    skipped=1    rescued=0    ignored=0
2025-09-29 19:23:52.086436 | controller |
2025-09-29 19:23:52.086539 | controller | Monday 29 September 2025  19:23:52 +0000 (0:00:00.043)       0:00:02.213 ******
2025-09-29 19:23:52.086640 | controller | ===============================================================================
2025-09-29 19:23:52.086763 | controller | Gathering Facts --------------------------------------------------------- 0.91s
2025-09-29 19:23:52.086863 | controller | rhol_crc : Source bashrc and confirm crc login -------------------------- 0.58s
2025-09-29 19:23:52.086964 | controller | rhol_crc : Make sure kubeconfig file exists ----------------------------- 0.30s
2025-09-29 19:23:52.087062 | controller | rhol_crc : Add crc creds in the user bashrc file ------------------------ 0.29s
2025-09-29 19:23:52.087165 | controller | rhol_crc : Check bashrc results ----------------------------------------- 0.04s
2025-09-29 19:23:52.087265 | controller | Verify crc creds playbook ----------------------------------------------- 0.03s
2025-09-29 19:23:52.087391 | controller | rhol_crc : Warn the user that the kubeconfig files doesn't exist -------- 0.03s
2025-09-29 19:23:52.148134 | controller | INFO     Running add_crc_creds > cleanup
2025-09-29 19:23:52.590209 | controller |
2025-09-29 19:23:52.590318 | controller | PLAY [Prepare] *****************************************************************
2025-09-29 19:23:52.590466 | controller |
2025-09-29 19:23:52.590581 | controller | TASK [Gathering Facts] *********************************************************
2025-09-29 19:23:52.590696 | controller | Monday 29 September 2025  19:23:52 +0000 (0:00:00.015)       0:00:00.015 ******
2025-09-29 19:23:53.460789 | controller | ok: [instance]
2025-09-29 19:23:53.460855 | controller |
2025-09-29 19:23:53.460987 | controller | TASK [rhol_crc : Check RHOL/CRC binary exists] *********************************
2025-09-29 19:23:53.461120 | controller | Monday 29 September 2025  19:23:53 +0000 (0:00:00.870)       0:00:00.885 ******
2025-09-29 19:23:53.741483 | controller | ok: [instance]
2025-09-29 19:23:53.741608 | controller |
2025-09-29 19:23:53.741833 | controller | TASK [rhol_crc : Delete RHOL/CRC instance and associated configuration] ********
2025-09-29 19:23:57.216490 | controller | Monday 29 September 2025  19:23:53 +0000 (0:00:00.280)       0:00:01.166 ******
2025-09-29 19:23:57.216537 | controller | changed: [instance]
2025-09-29 19:23:57.216569 | controller |
2025-09-29 19:23:57.216578 | controller | PLAY RECAP *********************************************************************
2025-09-29 19:23:57.216585 | controller | instance                   : ok=3    changed=1    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-09-29 19:23:57.216592 | controller |
2025-09-29 19:23:57.216601 | controller | Monday 29 September 2025  19:23:57 +0000 (0:00:03.475)       0:00:04.641 ******
2025-09-29 19:23:57.217010 | controller | ===============================================================================
2025-09-29 19:23:57.274474 | controller | rhol_crc : Delete RHOL/CRC instance and associated configuration -------- 3.48s
2025-09-29 19:23:57.274535 | controller | Gathering Facts --------------------------------------------------------- 0.87s
2025-09-29 19:23:57.274544 | controller | rhol_crc : Check RHOL/CRC binary exists --------------------------------- 0.28s
2025-09-29 19:23:57.274560 | controller | INFO     Performing prerun with role_name_check=0...
2025-09-29 19:24:14.383406 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:24:14.383904 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:24:14.384361 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:24:14.384842 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:24:14.385312 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+4a832a0b was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 1.0.0+4a832a0b (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:24:14.385785 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:24:14.386224 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:24:14.386679 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:24:14.387117 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:24:14.387561 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:24:14.387976 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:24:14.388433 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:24:14.388886 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:24:14.389309 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:24:14.389783 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:24:14.398836 | controller | INFO     Running binary > prepare
2025-09-29 19:24:14.866137 | controller |
2025-09-29 19:24:14.866262 | controller | PLAY [Prepare] *****************************************************************
2025-09-29 19:24:14.866391 | controller |
2025-09-29 19:24:14.866517 | controller | TASK [Gathering Facts] *********************************************************
2025-09-29 19:24:14.866653 | controller | Monday 29 September 2025  19:24:14 +0000 (0:00:00.019)       0:00:00.019 ******
2025-09-29 19:24:15.692494 | controller | ok: [instance]
2025-09-29 19:24:15.692524 | controller |
2025-09-29 19:24:15.692532 | controller | TASK [Setup libvirt] ***********************************************************
2025-09-29 19:24:15.692541 | controller | Monday 29 September 2025  19:24:15 +0000 (0:00:00.826)       0:00:00.845 ******
2025-09-29 19:24:15.714440 | controller | skipping: [instance]
2025-09-29 19:24:15.736469 | controller |
2025-09-29 19:24:15.736509 | controller | TASK [Setup CRC] ***************************************************************
2025-09-29 19:24:15.736526 | controller | Monday 29 September 2025  19:24:15 +0000 (0:00:00.022)       0:00:00.867 ******
2025-09-29 19:24:15.736537 | controller | skipping: [instance]
2025-09-29 19:24:15.758483 | controller |
2025-09-29 19:24:15.758520 | controller | TASK [Start RHOL/CRC] **********************************************************
2025-09-29 19:24:15.758530 | controller | Monday 29 September 2025  19:24:15 +0000 (0:00:00.021)       0:00:00.889 ******
2025-09-29 19:24:15.758541 | controller | skipping: [instance]
2025-09-29 19:24:15.758584 | controller |
2025-09-29 19:24:15.758604 | controller | TASK [Inject our own NetworkManager configuration] *****************************
2025-09-29 19:24:15.758615 | controller | Monday 29 September 2025  19:24:15 +0000 (0:00:00.022)       0:00:00.911 ******
2025-09-29 19:24:16.350279 | controller | ok: [instance]
2025-09-29 19:24:16.369448 | controller |
2025-09-29 19:24:16.369476 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-09-29 19:24:16.369484 | controller | Monday 29 September 2025  19:24:16 +0000 (0:00:00.591)       0:00:01.503 ******
2025-09-29 19:24:16.369494 | controller | skipping: [instance]
2025-09-29 19:24:16.369518 | controller |
2025-09-29 19:24:16.369526 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-09-29 19:24:16.369636 | controller | Monday 29 September 2025  19:24:16 +0000 (0:00:00.019)       0:00:01.522 ******
2025-09-29 19:24:16.413291 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-09-29 19:24:16.601446 | controller |
2025-09-29 19:24:16.601477 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-09-29 19:24:16.601485 | controller | Monday 29 September 2025  19:24:16 +0000 (0:00:00.043)       0:00:01.566 ******
2025-09-29 19:24:16.601495 | controller | ok: [instance]
2025-09-29 19:24:16.601727 | controller |
2025-09-29 19:24:16.601750 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-09-29 19:24:16.813395 | controller | Monday 29 September 2025  19:24:16 +0000 (0:00:00.188)       0:00:01.754 ******
2025-09-29 19:24:16.813428 | controller | ok: [instance]
2025-09-29 19:24:17.514203 | controller |
2025-09-29 19:24:17.514234 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-09-29 19:24:17.514243 | controller | Monday 29 September 2025  19:24:16 +0000 (0:00:00.211)       0:00:01.966 ******
2025-09-29 19:24:17.514253 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-09-29 19:24:17.577474 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-09-29 19:24:17.577513 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-09-29 19:24:17.577522 | controller |
2025-09-29 19:24:17.577530 | controller | TASK [Deploy repo-setup] *******************************************************
2025-09-29 19:24:17.577537 | controller | Monday 29 September 2025  19:24:17 +0000 (0:00:00.700)       0:00:02.667 ******
2025-09-29 19:24:17.577559 | controller |
2025-09-29 19:24:18.153446 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-09-29 19:24:18.153477 | controller | Monday 29 September 2025  19:24:17 +0000 (0:00:00.063)       0:00:02.730 ******
2025-09-29 19:24:18.153489 | controller | ok: [instance] => (item=tmp)
2025-09-29 19:24:19.534194 | controller | ok: [instance] => (item=artifacts/repositories)
2025-09-29 19:24:19.534225 | controller | ok: [instance] => (item=venv/repo_setup)
2025-09-29 19:24:19.534233 | controller |
2025-09-29 19:24:19.534239 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-09-29 19:24:19.534245 | controller | Monday 29 September 2025  19:24:18 +0000 (0:00:00.575)       0:00:03.306 ******
2025-09-29 19:24:19.534255 | controller | ok: [instance]
2025-09-29 19:24:20.139911 | controller |
2025-09-29 19:24:20.139941 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-09-29 19:24:20.139949 | controller | Monday 29 September 2025  19:24:19 +0000 (0:00:01.381)       0:00:04.687 ******
2025-09-29 19:24:20.139959 | controller | ok: [instance]
2025-09-29 19:24:21.456187 | controller |
2025-09-29 19:24:21.456220 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-09-29 19:24:21.456228 | controller | Monday 29 September 2025  19:24:20 +0000 (0:00:00.605)       0:00:05.292 ******
2025-09-29 19:24:21.456245 | controller | ok: [instance]
2025-09-29 19:24:21.762515 | controller |
2025-09-29 19:24:21.762545 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-09-29 19:24:21.762553 | controller | Monday 29 September 2025  19:24:21 +0000 (0:00:01.316)       0:00:06.609 ******
2025-09-29 19:24:21.762563 | controller | ok: [instance]
2025-09-29 19:24:21.787326 | controller |
2025-09-29 19:24:21.787373 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-09-29 19:24:21.787382 | controller | Monday 29 September 2025  19:24:21 +0000 (0:00:00.306)       0:00:06.915 ******
2025-09-29 19:24:21.787394 | controller | skipping: [instance]
2025-09-29 19:24:22.674161 | controller |
2025-09-29 19:24:22.674192 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-09-29 19:24:22.674200 | controller | Monday 29 September 2025  19:24:21 +0000 (0:00:00.024)       0:00:06.940 ******
2025-09-29 19:24:22.674210 | controller | changed: [instance]
2025-09-29 19:24:22.715160 | controller |
2025-09-29 19:24:22.715190 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-09-29 19:24:22.715198 | controller | Monday 29 September 2025  19:24:22 +0000 (0:00:00.886)       0:00:07.827 ******
2025-09-29 19:24:22.715208 | controller | skipping: [instance]
2025-09-29 19:24:22.756477 | controller |
2025-09-29 19:24:22.756518 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-09-29 19:24:22.756527 | controller | Monday 29 September 2025  19:24:22 +0000 (0:00:00.041)       0:00:07.868 ******
2025-09-29 19:24:22.756538 | controller | skipping: [instance]
2025-09-29 19:24:22.756566 | controller |
2025-09-29 19:24:22.756824 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-09-29 19:24:22.797124 | controller | Monday 29 September 2025  19:24:22 +0000 (0:00:00.041)       0:00:07.909 ******
2025-09-29 19:24:22.797156 | controller | skipping: [instance]
2025-09-29 19:24:23.360303 | controller |
2025-09-29 19:24:23.360334 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-09-29 19:24:23.360362 | controller | Monday 29 September 2025  19:24:22 +0000 (0:00:00.040)       0:00:07.950 ******
2025-09-29 19:24:23.360374 | controller | changed: [instance]
2025-09-29 19:24:23.720317 | controller |
2025-09-29 19:24:23.720363 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-09-29 19:24:23.720374 | controller | Monday 29 September 2025  19:24:23 +0000 (0:00:00.563)       0:00:08.513 ******
2025-09-29 19:24:23.720384 | controller | ok: [instance]
2025-09-29 19:24:23.751446 | controller |
2025-09-29 19:24:23.751469 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-09-29 19:24:23.751477 | controller | Monday 29 September 2025  19:24:23 +0000 (0:00:00.360)       0:00:08.873 ******
2025-09-29 19:24:23.751486 | controller | skipping: [instance]
2025-09-29 19:24:23.751693 | controller |
2025-09-29 19:24:23.751712 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-09-29 19:24:23.782074 | controller | Monday 29 September 2025  19:24:23 +0000 (0:00:00.031)       0:00:08.904 ******
2025-09-29 19:24:23.782106 | controller | skipping: [instance]
2025-09-29 19:24:23.837798 | controller |
2025-09-29 19:24:23.837821 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-09-29 19:24:23.837829 | controller | Monday 29 September 2025  19:24:23 +0000 (0:00:00.030)       0:00:08.935 ******
2025-09-29 19:24:23.837838 | controller | skipping: [instance]
2025-09-29 19:24:23.880475 | controller |
2025-09-29 19:24:23.880513 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-09-29 19:24:23.880528 | controller | Monday 29 September 2025  19:24:23 +0000 (0:00:00.055)       0:00:08.990 ******
2025-09-29 19:24:23.880541 | controller | ok: [instance]
2025-09-29 19:24:23.911046 | controller |
2025-09-29 19:24:23.911079 | controller | TASK [repo_setup : Create download directory] **********************************
2025-09-29 19:24:23.911087 | controller | Monday 29 September 2025  19:24:23 +0000 (0:00:00.042)       0:00:09.033 ******
2025-09-29 19:24:23.911097 | controller | skipping: [instance]
2025-09-29 19:24:23.940775 | controller |
2025-09-29 19:24:23.940811 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-09-29 19:24:23.940820 | controller | Monday 29 September 2025  19:24:23 +0000 (0:00:00.030)       0:00:09.063 ******
2025-09-29 19:24:23.940840 | controller | skipping: [instance]
2025-09-29 19:24:23.940990 | controller |
2025-09-29 19:24:23.941135 | controller | TASK [Download the RPM] ********************************************************
2025-09-29 19:24:23.941275 | controller | Monday 29 September 2025  19:24:23 +0000 (0:00:00.030)       0:00:09.094 ******
2025-09-29 19:24:23.972012 | controller | skipping: [instance]
2025-09-29 19:24:23.972176 | controller |
2025-09-29 19:24:23.972321 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-09-29 19:24:23.972491 | controller | Monday 29 September 2025  19:24:23 +0000 (0:00:00.031)       0:00:09.125 ******
2025-09-29 19:24:24.003322 | controller | skipping: [instance]
2025-09-29 19:24:24.003556 | controller |
2025-09-29 19:24:24.003763 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-09-29 19:24:24.003935 | controller | Monday 29 September 2025  19:24:24 +0000 (0:00:00.031)       0:00:09.156 ******
2025-09-29 19:24:24.056269 | controller | skipping: [instance]
2025-09-29 19:24:24.056462 | controller |
2025-09-29 19:24:24.056642 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-09-29 19:24:24.056799 | controller | Monday 29 September 2025  19:24:24 +0000 (0:00:00.053)       0:00:09.209 ******
2025-09-29 19:24:24.088184 | controller | skipping: [instance]
2025-09-29 19:24:24.088385 | controller |
2025-09-29 19:24:24.088563 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-09-29 19:24:24.088729 | controller | Monday 29 September 2025  19:24:24 +0000 (0:00:00.031)       0:00:09.241 ******
2025-09-29 19:24:24.116257 | controller | skipping: [instance]
2025-09-29 19:24:24.116450 | controller |
2025-09-29 19:24:24.116602 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-09-29 19:24:24.116776 | controller | Monday 29 September 2025  19:24:24 +0000 (0:00:00.028)       0:00:09.269 ******
2025-09-29 19:24:24.303917 | controller | ok: [instance]
2025-09-29 19:24:24.521483 | controller |
2025-09-29 19:24:24.521515 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-09-29 19:24:24.521523 | controller | Monday 29 September 2025  19:24:24 +0000 (0:00:00.187)       0:00:09.456 ******
2025-09-29 19:24:24.521533 | controller | changed: [instance]
2025-09-29 19:24:24.754090 | controller |
2025-09-29 19:24:24.754121 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-09-29 19:24:24.754129 | controller | Monday 29 September 2025  19:24:24 +0000 (0:00:00.217)       0:00:09.674 ******
2025-09-29 19:24:24.754139 | controller | changed: [instance]
2025-09-29 19:24:24.776489 | controller |
2025-09-29 19:24:24.776531 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-09-29 19:24:24.776541 | controller | Monday 29 September 2025  19:24:24 +0000 (0:00:00.232)       0:00:09.906 ******
2025-09-29 19:24:24.776553 | controller | skipping: [instance]
2025-09-29 19:24:24.776587 | controller |
2025-09-29 19:24:24.776819 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-09-29 19:24:24.802439 | controller | Monday 29 September 2025  19:24:24 +0000 (0:00:00.022)       0:00:09.929 ******
2025-09-29 19:24:24.802477 | controller | skipping: [instance]
2025-09-29 19:24:24.802502 | controller |
2025-09-29 19:24:24.802744 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-09-29 19:24:24.828254 | controller | Monday 29 September 2025  19:24:24 +0000 (0:00:00.025)       0:00:09.955 ******
2025-09-29 19:24:24.828285 | controller | skipping: [instance]
2025-09-29 19:24:24.855922 | controller |
2025-09-29 19:24:24.855956 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-09-29 19:24:24.855965 | controller | Monday 29 September 2025  19:24:24 +0000 (0:00:00.025)       0:00:09.981 ******
2025-09-29 19:24:24.855974 | controller | skipping: [instance]
2025-09-29 19:24:24.881739 | controller |
2025-09-29 19:24:24.881792 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-09-29 19:24:24.881800 | controller | Monday 29 September 2025  19:24:24 +0000 (0:00:00.027)       0:00:10.008 ******
2025-09-29 19:24:24.881812 | controller | skipping: [instance]
2025-09-29 19:24:24.881963 | controller |
2025-09-29 19:24:24.882117 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-09-29 19:24:24.882292 | controller | Monday 29 September 2025  19:24:24 +0000 (0:00:00.025)       0:00:10.034 ******
2025-09-29 19:24:24.908291 | controller | skipping: [instance]
2025-09-29 19:24:24.908576 | controller |
2025-09-29 19:24:24.908775 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-09-29 19:24:24.908931 | controller | Monday 29 September 2025  19:24:24 +0000 (0:00:00.026)       0:00:10.061 ******
2025-09-29 19:24:24.930097 | controller | skipping: [instance]
2025-09-29 19:24:24.930384 | controller |
2025-09-29 19:24:24.930577 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-09-29 19:24:24.930753 | controller | Monday 29 September 2025  19:24:24 +0000 (0:00:00.021)       0:00:10.083 ******
2025-09-29 19:24:24.963089 | controller | skipping: [instance]
2025-09-29 19:24:24.963368 | controller |
2025-09-29 19:24:24.963560 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-09-29 19:24:24.963738 | controller | Monday 29 September 2025  19:24:24 +0000 (0:00:00.032)       0:00:10.116 ******
2025-09-29 19:24:24.983738 | controller | skipping: [instance]
2025-09-29 19:24:24.984156 | controller |
2025-09-29 19:24:24.984322 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-09-29 19:24:24.984520 | controller | Monday 29 September 2025  19:24:24 +0000 (0:00:00.020)       0:00:10.136 ******
2025-09-29 19:24:25.011469 | controller | skipping: [instance]
2025-09-29 19:24:25.011643 | controller |
2025-09-29 19:24:25.011818 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-09-29 19:24:25.011940 | controller | Monday 29 September 2025  19:24:25 +0000 (0:00:00.027)       0:00:10.164 ******
2025-09-29 19:24:25.042925 | controller | skipping: [instance]
2025-09-29 19:24:25.043096 | controller |
2025-09-29 19:24:25.043230 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-09-29 19:24:25.043446 | controller | Monday 29 September 2025  19:24:25 +0000 (0:00:00.031)       0:00:10.195 ******
2025-09-29 19:24:25.075872 | controller | skipping: [instance]
2025-09-29 19:24:25.076053 | controller |
2025-09-29 19:24:25.076196 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-09-29 19:24:25.076319 | controller | Monday 29 September 2025  19:24:25 +0000 (0:00:00.032)       0:00:10.228 ******
2025-09-29 19:24:25.109078 | controller | skipping: [instance]
2025-09-29 19:24:25.109199 | controller |
2025-09-29 19:24:25.109332 | controller | TASK [test_deps : Install additional packages] *********************************
2025-09-29 19:24:25.109474 | controller | Monday 29 September 2025  19:24:25 +0000 (0:00:00.033)       0:00:10.262 ******
2025-09-29 19:24:25.140835 | controller | skipping: [instance]
2025-09-29 19:24:25.141007 | controller |
2025-09-29 19:24:25.141138 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-09-29 19:24:25.141262 | controller | Monday 29 September 2025  19:24:25 +0000 (0:00:00.031)       0:00:10.293 ******
2025-09-29 19:25:25.782222 | controller | ok: [instance]
2025-09-29 19:25:27.038529 | controller |
2025-09-29 19:25:27.038590 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-09-29 19:25:27.038601 | controller | Monday 29 September 2025  19:25:25 +0000 (0:01:00.640)       0:01:10.934 ******
2025-09-29 19:25:27.038614 | controller | ok: [instance]
2025-09-29 19:25:27.072472 | controller |
2025-09-29 19:25:27.072506 | controller | TASK [test_deps : Install extra packages] **************************************
2025-09-29 19:25:27.072514 | controller | Monday 29 September 2025  19:25:27 +0000 (0:00:01.256)       0:01:12.191 ******
2025-09-29 19:25:27.072526 | controller | skipping: [instance]
2025-09-29 19:25:27.072902 | controller |
2025-09-29 19:25:27.118754 | controller | TASK [ci_setup : Gather variables for each operating system] *******************
2025-09-29 19:25:27.118781 | controller | Monday 29 September 2025  19:25:27 +0000 (0:00:00.034)       0:01:12.225 ******
2025-09-29 19:25:27.118794 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/ci_setup/vars/redhat.yml)
2025-09-29 19:25:27.139469 | controller |
2025-09-29 19:25:27.139516 | controller | TASK [ci_setup : List packages to install] *************************************
2025-09-29 19:25:27.139526 | controller | Monday 29 September 2025  19:25:27 +0000 (0:00:00.046)       0:01:12.271 ******
2025-09-29 19:25:27.139553 | controller | ok: [instance] =>
2025-09-29 19:25:27.139601 | controller |   cifmw_ci_setup_packages:
2025-09-29 19:25:27.139610 | controller |   - bash-completion
2025-09-29 19:25:27.139617 | controller |   - ca-certificates
2025-09-29 19:25:27.139623 | controller |   - git-core
2025-09-29 19:25:27.139630 | controller |   - make
2025-09-29 19:25:27.139638 | controller |   - tar
2025-09-29 19:25:27.139646 | controller |   - tmux
2025-09-29 19:25:27.139672 | controller |   - python3-pip
2025-09-29 19:25:27.139970 | controller |
2025-09-29 19:25:28.408864 | controller | TASK [ci_setup : Install needed packages] **************************************
2025-09-29 19:25:28.408895 | controller | Monday 29 September 2025  19:25:27 +0000 (0:00:00.020)       0:01:12.292 ******
2025-09-29 19:25:28.408908 | controller | ok: [instance]
2025-09-29 19:25:28.662261 | controller |
2025-09-29 19:25:28.662292 | controller | TASK [ci_setup : Gather version of openshift client] ***************************
2025-09-29 19:25:28.662300 | controller | Monday 29 September 2025  19:25:28 +0000 (0:00:01.269)       0:01:13.561 ******
2025-09-29 19:25:28.662310 | controller | ok: [instance]
2025-09-29 19:25:28.869458 | controller |
2025-09-29 19:25:28.869493 | controller | TASK [ci_setup : Ensure openshift client install path is present] **************
2025-09-29 19:25:28.869502 | controller | Monday 29 September 2025  19:25:28 +0000 (0:00:00.253)       0:01:13.815 ******
2025-09-29 19:25:28.869513 | controller | ok: [instance]
2025-09-29 19:25:28.869594 | controller |
2025-09-29 19:25:28.869626 | controller | TASK [ci_setup : Install openshift client] *************************************
2025-09-29 19:25:28.869646 | controller | Monday 29 September 2025  19:25:28 +0000 (0:00:00.206)       0:01:14.021 ******
2025-09-29 19:25:28.937833 | controller | skipping: [instance]
2025-09-29 19:25:28.975238 | controller |
2025-09-29 19:25:28.975271 | controller | TASK [ci_setup : Add the OC path to cifmw_path if needed] **********************
2025-09-29 19:25:28.975279 | controller | Monday 29 September 2025  19:25:28 +0000 (0:00:00.068)       0:01:14.090 ******
2025-09-29 19:25:28.975289 | controller | skipping: [instance]
2025-09-29 19:25:29.160516 | controller |
2025-09-29 19:25:29.160557 | controller | TASK [ci_setup : Create completion file] ***************************************
2025-09-29 19:25:29.160565 | controller | Monday 29 September 2025  19:25:28 +0000 (0:00:00.037)       0:01:14.128 ******
2025-09-29 19:25:29.160591 | controller | ok: [instance]
2025-09-29 19:25:29.160616 | controller |
2025-09-29 19:25:29.160623 | controller | TASK [ci_setup : Source completion from within .bashrc] ************************
2025-09-29 19:25:29.160631 | controller | Monday 29 September 2025  19:25:29 +0000 (0:00:00.185)       0:01:14.313 ******
2025-09-29 19:25:29.446759 | controller | changed: [instance]
2025-09-29 19:25:29.464471 | controller |
2025-09-29 19:25:29.464508 | controller | TASK [ci_setup : Check rhsm status] ********************************************
2025-09-29 19:25:29.464518 | controller | Monday 29 September 2025  19:25:29 +0000 (0:00:00.286)       0:01:14.599 ******
2025-09-29 19:25:29.464530 | controller | skipping: [instance]
2025-09-29 19:25:29.464560 | controller |
2025-09-29 19:25:29.464590 | controller | TASK [ci_setup : Gather the repos to be enabled] *******************************
2025-09-29 19:25:29.464685 | controller | Monday 29 September 2025  19:25:29 +0000 (0:00:00.018)       0:01:14.617 ******
2025-09-29 19:25:29.482866 | controller | skipping: [instance]
2025-09-29 19:25:29.501325 | controller |
2025-09-29 19:25:29.501372 | controller | TASK [ci_setup : Enabling the required repositories.] **************************
2025-09-29 19:25:29.501383 | controller | Monday 29 September 2025  19:25:29 +0000 (0:00:00.018)       0:01:14.636 ******
2025-09-29 19:25:29.501395 | controller | skipping: [instance]
2025-09-29 19:25:29.519904 | controller |
2025-09-29 19:25:29.519924 | controller | TASK [ci_setup : Get current /etc/redhat-release] ******************************
2025-09-29 19:25:29.519931 | controller | Monday 29 September 2025  19:25:29 +0000 (0:00:00.018)       0:01:14.654 ******
2025-09-29 19:25:29.519940 | controller | skipping: [instance]
2025-09-29 19:25:29.538873 | controller |
2025-09-29 19:25:29.538893 | controller | TASK [ci_setup : Print current /etc/redhat-release] ****************************
2025-09-29 19:25:29.538901 | controller | Monday 29 September 2025  19:25:29 +0000 (0:00:00.018)       0:01:14.673 ******
2025-09-29 19:25:29.538911 | controller | skipping: [instance]
2025-09-29 19:25:29.564359 | controller |
2025-09-29 19:25:29.564390 | controller | TASK [ci_setup : Ensure the repos are enabled in the system using yum] *********
2025-09-29 19:25:29.564398 | controller | Monday 29 September 2025  19:25:29 +0000 (0:00:00.018)       0:01:14.692 ******
2025-09-29 19:25:29.564407 | controller | skipping: [instance]
2025-09-29 19:25:30.554419 | controller |
2025-09-29 19:25:30.554450 | controller | TASK [ci_setup : Manage directories] *******************************************
2025-09-29 19:25:30.554458 | controller | Monday 29 September 2025  19:25:29 +0000 (0:00:00.025)       0:01:14.717 ******
2025-09-29 19:25:30.554469 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/artifacts/manifests/openstack/cr)
2025-09-29 19:25:30.554493 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/logs)
2025-09-29 19:25:30.554499 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/tmp)
2025-09-29 19:25:30.554505 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/volumes)
2025-09-29 19:25:30.554510 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/artifacts/parameters)
2025-09-29 19:25:30.554517 | controller |
2025-09-29 19:25:30.554746 | controller | TASK [Check for CRC startup] ***************************************************
2025-09-29 19:25:30.594525 | controller | Monday 29 September 2025  19:25:30 +0000 (0:00:00.989)       0:01:15.707 ******
2025-09-29 19:25:30.594604 | controller | skipping: [instance]
2025-09-29 19:25:30.594642 | controller |
2025-09-29 19:25:30.594651 | controller | PLAY RECAP *********************************************************************
2025-09-29 19:25:30.594658 | controller | instance                   : ok=28   changed=5    unreachable=0    failed=0    skipped=42   rescued=0    ignored=0
2025-09-29 19:25:30.594665 | controller |
2025-09-29 19:25:30.594671 | controller | Monday 29 September 2025  19:25:30 +0000 (0:00:00.039)       0:01:15.746 ******
2025-09-29 19:25:30.594678 | controller | ===============================================================================
2025-09-29 19:25:30.594684 | controller | test_deps : Install selinux python libs -------------------------------- 60.64s
2025-09-29 19:25:30.594691 | controller | repo_setup : Make sure git-core package is installed -------------------- 1.38s
2025-09-29 19:25:30.594698 | controller | repo_setup : Initialize python venv and install requirements ------------ 1.32s
2025-09-29 19:25:30.594707 | controller | ci_setup : Install needed packages -------------------------------------- 1.27s
2025-09-29 19:25:30.594745 | controller | test_deps : Install python yaml libs ------------------------------------ 1.26s
2025-09-29 19:25:30.596419 | controller | ci_setup : Manage directories ------------------------------------------- 0.99s
2025-09-29 19:25:30.664209 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.89s
2025-09-29 19:25:30.664246 | controller | Gathering Facts --------------------------------------------------------- 0.83s
2025-09-29 19:25:30.664254 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.70s
2025-09-29 19:25:30.664260 | controller | repo_setup : Get repo-setup repository ---------------------------------- 0.61s
2025-09-29 19:25:30.664265 | controller | Inject our own NetworkManager configuration ----------------------------- 0.59s
2025-09-29 19:25:30.664271 | controller | repo_setup : Ensure directories are present ----------------------------- 0.58s
2025-09-29 19:25:30.664276 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.56s
2025-09-29 19:25:30.664281 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.36s
2025-09-29 19:25:30.664286 | controller | repo_setup : Install repo-setup package --------------------------------- 0.31s
2025-09-29 19:25:30.664292 | controller | ci_setup : Source completion from within .bashrc ------------------------ 0.29s
2025-09-29 19:25:30.664297 | controller | ci_setup : Gather version of openshift client --------------------------- 0.25s
2025-09-29 19:25:30.664302 | controller | repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist) --- 0.23s
2025-09-29 19:25:30.664308 | controller | repo_setup : Use RDO proxy mirrors -------------------------------------- 0.22s
2025-09-29 19:25:30.664313 | controller | test_deps : Disable ubi host subscription-manager integration ----------- 0.21s
2025-09-29 19:25:30.664323 | controller | INFO     Running binary > converge
2025-09-29 19:25:31.116309 | controller |
2025-09-29 19:25:31.116592 | controller | PLAY [Converge binary] *********************************************************
2025-09-29 19:25:31.116752 | controller |
2025-09-29 19:25:31.116904 | controller | TASK [Gathering Facts] *********************************************************
2025-09-29 19:25:31.117049 | controller | Monday 29 September 2025  19:25:31 +0000 (0:00:00.015)       0:00:00.015 ******
2025-09-29 19:25:31.949074 | controller | ok: [instance]
2025-09-29 19:25:32.258331 | controller |
2025-09-29 19:25:32.258382 | controller | TASK [rhol_crc : Create bin directory if it does not exist] ********************
2025-09-29 19:25:32.258390 | controller | Monday 29 September 2025  19:25:31 +0000 (0:00:00.832)       0:00:00.847 ******
2025-09-29 19:25:32.258401 | controller | ok: [instance]
2025-09-29 19:25:32.530122 | controller |
2025-09-29 19:25:32.530155 | controller | TASK [rhol_crc : Create temporary directory for downloading RHOL/CRC] **********
2025-09-29 19:25:32.530163 | controller | Monday 29 September 2025  19:25:32 +0000 (0:00:00.309)       0:00:01.157 ******
2025-09-29 19:25:32.530173 | controller | changed: [instance]
2025-09-29 19:25:37.771453 | controller |
2025-09-29 19:25:37.771498 | controller | TASK [rhol_crc : Download RHOL/CRC with sha256 checksum] ***********************
2025-09-29 19:25:37.771508 | controller | Monday 29 September 2025  19:25:32 +0000 (0:00:00.271)       0:00:01.429 ******
2025-09-29 19:25:37.771521 | controller | changed: [instance]
2025-09-29 19:25:37.771549 | controller |
2025-09-29 19:25:37.771589 | controller | TASK [rhol_crc : Unarchive RHOL/CRC binary] ************************************
2025-09-29 19:25:37.771654 | controller | Monday 29 September 2025  19:25:37 +0000 (0:00:05.241)       0:00:06.670 ******
2025-09-29 19:25:42.871427 | controller | changed: [instance]
2025-09-29 19:25:42.871482 | controller |
2025-09-29 19:25:42.871761 | controller | TASK [rhol_crc : Delete temporary directory for downloading RHOL/CRC] **********
2025-09-29 19:25:43.053460 | controller | Monday 29 September 2025  19:25:42 +0000 (0:00:05.100)       0:00:11.770 ******
2025-09-29 19:25:43.053506 | controller | ok: [instance]
2025-09-29 19:25:43.053538 | controller |
2025-09-29 19:25:43.053548 | controller | TASK [rhol_crc : Get CRC binary version] ***************************************
2025-09-29 19:25:43.053718 | controller | Monday 29 September 2025  19:25:43 +0000 (0:00:00.181)       0:00:11.952 ******
2025-09-29 19:25:43.547838 | controller | changed: [instance]
2025-09-29 19:25:43.583930 | controller |
2025-09-29 19:25:43.583962 | controller | TASK [rhol_crc : Extract versions] *********************************************
2025-09-29 19:25:43.583976 | controller | Monday 29 September 2025  19:25:43 +0000 (0:00:00.494)       0:00:12.446 ******
2025-09-29 19:25:43.583987 | controller | ok: [instance]
2025-09-29 19:25:43.632453 | controller |
2025-09-29 19:25:43.632489 | controller | TASK [rhol_crc : Output found binary location and versions] ********************
2025-09-29 19:25:43.632499 | controller | Monday 29 September 2025  19:25:43 +0000 (0:00:00.036)       0:00:12.482 ******
2025-09-29 19:25:43.632512 | controller | ok: [instance] =>
2025-09-29 19:25:43.632540 | controller |   msg: 'Found crc at /usr/local/bin/crc, with version 2.39.0 (wants: 2.39.0) and serving OpenShift version 4.16.0.'
2025-09-29 19:25:43.632548 | controller |
2025-09-29 19:25:43.632558 | controller | PLAY [Verify get_version] ******************************************************
2025-09-29 19:25:43.632850 | controller |
2025-09-29 19:25:44.258858 | controller | TASK [Gathering Facts] *********************************************************
2025-09-29 19:25:44.258893 | controller | Monday 29 September 2025  19:25:43 +0000 (0:00:00.048)       0:00:12.531 ******
2025-09-29 19:25:44.258908 | controller | ok: [instance]
2025-09-29 19:25:44.300463 | controller |
2025-09-29 19:25:44.300498 | controller | TASK [Ensure facts are set and look correct] ***********************************
2025-09-29 19:25:44.300508 | controller | Monday 29 September 2025  19:25:44 +0000 (0:00:00.625)       0:00:13.157 ******
2025-09-29 19:25:44.300520 | controller | ok: [instance] => changed=false
2025-09-29 19:25:44.300551 | controller |   msg: All assertions passed
2025-09-29 19:25:44.301507 | controller |
2025-09-29 19:25:44.301584 | controller | PLAY RECAP *********************************************************************
2025-09-29 19:25:44.301595 | controller | instance                   : ok=11   changed=4    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-09-29 19:25:44.301603 | controller |
2025-09-29 19:25:44.301610 | controller | Monday 29 September 2025  19:25:44 +0000 (0:00:00.042)       0:00:13.199 ******
2025-09-29 19:25:44.301623 | controller | ===============================================================================
2025-09-29 19:25:44.301629 | controller | rhol_crc : Download RHOL/CRC with sha256 checksum ----------------------- 5.24s
2025-09-29 19:25:44.301636 | controller | rhol_crc : Unarchive RHOL/CRC binary ------------------------------------ 5.10s
2025-09-29 19:25:44.301643 | controller | Gathering Facts --------------------------------------------------------- 0.83s
2025-09-29 19:25:44.301652 | controller | Gathering Facts --------------------------------------------------------- 0.63s
2025-09-29 19:25:44.301678 | controller | rhol_crc : Get CRC binary version --------------------------------------- 0.49s
2025-09-29 19:25:44.302236 | controller | rhol_crc : Create bin directory if it does not exist -------------------- 0.31s
2025-09-29 19:25:44.360245 | controller | rhol_crc : Create temporary directory for downloading RHOL/CRC ---------- 0.27s
2025-09-29 19:25:44.360278 | controller | rhol_crc : Delete temporary directory for downloading RHOL/CRC ---------- 0.18s
2025-09-29 19:25:44.360286 | controller | rhol_crc : Output found binary location and versions -------------------- 0.05s
2025-09-29 19:25:44.360291 | controller | Ensure facts are set and look correct ----------------------------------- 0.04s
2025-09-29 19:25:44.360296 | controller | rhol_crc : Extract versions --------------------------------------------- 0.04s
2025-09-29 19:25:44.360307 | controller | INFO     Running binary > cleanup
2025-09-29 19:25:44.785144 | controller |
2025-09-29 19:25:44.785362 | controller | PLAY [Prepare] *****************************************************************
2025-09-29 19:25:44.785526 | controller |
2025-09-29 19:25:44.785689 | controller | TASK [Gathering Facts] *********************************************************
2025-09-29 19:25:44.785842 | controller | Monday 29 September 2025  19:25:44 +0000 (0:00:00.015)       0:00:00.015 ******
2025-09-29 19:25:45.614969 | controller | ok: [instance]
2025-09-29 19:25:46.052426 | controller |
2025-09-29 19:25:46.052461 | controller | TASK [Cleanup RHOL/CRC after tests] ********************************************
2025-09-29 19:25:46.052469 | controller | Monday 29 September 2025  19:25:45 +0000 (0:00:00.829)       0:00:00.845 ******
2025-09-29 19:25:46.052480 | controller | changed: [instance]
2025-09-29 19:25:46.052503 | controller |
2025-09-29 19:25:46.052510 | controller | PLAY RECAP *********************************************************************
2025-09-29 19:25:46.052516 | controller | instance                   : ok=2    changed=1    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-09-29 19:25:46.052521 | controller |
2025-09-29 19:25:46.052528 | controller | Monday 29 September 2025  19:25:46 +0000 (0:00:00.437)       0:00:01.283 ******
2025-09-29 19:25:46.052820 | controller | ===============================================================================
2025-09-29 19:25:46.102015 | controller | Gathering Facts --------------------------------------------------------- 0.83s
2025-09-29 19:25:46.102062 | controller | Cleanup RHOL/CRC after tests -------------------------------------------- 0.44s
2025-09-29 19:25:46.102081 | controller | INFO     Performing prerun with role_name_check=0...
2025-09-29 19:26:05.039188 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:26:05.039670 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:26:05.040126 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:26:05.040589 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:26:05.041058 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+4a832a0b was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 1.0.0+4a832a0b (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:26:05.041512 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:26:05.041971 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:26:05.042420 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:26:05.042888 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:26:05.043292 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:26:05.043772 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:26:05.044207 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:26:05.044859 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:26:05.045306 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:26:05.045782 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/b025d2/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-29 19:26:05.054787 | controller | INFO     Running default > prepare
2025-09-29 19:26:05.534188 | controller |
2025-09-29 19:26:05.534332 | controller | PLAY [Prepare] *****************************************************************
2025-09-29 19:26:05.534466 | controller |
2025-09-29 19:26:05.534614 | controller | TASK [Gathering Facts] *********************************************************
2025-09-29 19:26:05.534732 | controller | Monday 29 September 2025  19:26:05 +0000 (0:00:00.019)       0:00:00.019 ******
2025-09-29 19:26:06.377225 | controller | ok: [instance]
2025-09-29 19:26:06.399870 | controller |
2025-09-29 19:26:06.399906 | controller | TASK [Setup libvirt] ***********************************************************
2025-09-29 19:26:06.399914 | controller | Monday 29 September 2025  19:26:06 +0000 (0:00:00.843)       0:00:00.862 ******
2025-09-29 19:26:06.399925 | controller | skipping: [instance]
2025-09-29 19:26:06.422190 | controller |
2025-09-29 19:26:06.422219 | controller | TASK [Setup CRC] ***************************************************************
2025-09-29 19:26:06.422227 | controller | Monday 29 September 2025  19:26:06 +0000 (0:00:00.022)       0:00:00.885 ******
2025-09-29 19:26:06.422237 | controller | skipping: [instance]
2025-09-29 19:26:06.443929 | controller |
2025-09-29 19:26:06.443966 | controller | TASK [Start RHOL/CRC] **********************************************************
2025-09-29 19:26:06.443975 | controller | Monday 29 September 2025  19:26:06 +0000 (0:00:00.022)       0:00:00.907 ******
2025-09-29 19:26:06.443985 | controller | skipping: [instance]
2025-09-29 19:26:07.085522 | controller |
2025-09-29 19:26:07.085593 | controller | TASK [Inject our own NetworkManager configuration] *****************************
2025-09-29 19:26:07.085602 | controller | Monday 29 September 2025  19:26:06 +0000 (0:00:00.021)       0:00:00.929 ******
2025-09-29 19:26:07.085616 | controller | ok: [instance]
2025-09-29 19:26:07.106514 | controller |
2025-09-29 19:26:07.106577 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-09-29 19:26:07.106586 | controller | Monday 29 September 2025  19:26:07 +0000 (0:00:00.641)       0:00:01.570 ******
2025-09-29 19:26:07.106598 | controller | skipping: [instance]
2025-09-29 19:26:07.152002 | controller |
2025-09-29 19:26:07.152036 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-09-29 19:26:07.152044 | controller | Monday 29 September 2025  19:26:07 +0000 (0:00:00.020)       0:00:01.591 ******
2025-09-29 19:26:07.152055 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-09-29 19:26:07.343962 | controller |
2025-09-29 19:26:07.343998 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-09-29 19:26:07.344006 | controller | Monday 29 September 2025  19:26:07 +0000 (0:00:00.045)       0:00:01.637 ******
2025-09-29 19:26:07.344017 | controller | ok: [instance]
2025-09-29 19:26:07.577450 | controller |
2025-09-29 19:26:07.577505 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-09-29 19:26:07.577515 | controller | Monday 29 September 2025  19:26:07 +0000 (0:00:00.191)       0:00:01.829 ******
2025-09-29 19:26:07.577528 | controller | ok: [instance]
2025-09-29 19:26:07.577601 | controller |
2025-09-29 19:26:07.577780 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-09-29 19:26:08.270541 | controller | Monday 29 September 2025  19:26:07 +0000 (0:00:00.233)       0:00:02.062 ******
2025-09-29 19:26:08.270595 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-09-29 19:26:08.335178 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-09-29 19:26:08.335219 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-09-29 19:26:08.335229 | controller |
2025-09-29 19:26:08.335236 | controller | TASK [Deploy repo-setup] *******************************************************
2025-09-29 19:26:08.335244 | controller | Monday 29 September 2025  19:26:08 +0000 (0:00:00.692)       0:00:02.755 ******
2025-09-29 19:26:08.335256 | controller |
2025-09-29 19:26:08.907464 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-09-29 19:26:08.907499 | controller | Monday 29 September 2025  19:26:08 +0000 (0:00:00.064)       0:00:02.820 ******
2025-09-29 19:26:08.907512 | controller | ok: [instance] => (item=tmp)
2025-09-29 19:26:08.907541 | controller | ok: [instance] => (item=artifacts/repositories)
2025-09-29 19:26:08.907979 | controller | ok: [instance] => (item=venv/repo_setup)
2025-09-29 19:26:10.272015 | controller |
2025-09-29 19:26:10.272049 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-09-29 19:26:10.272058 | controller | Monday 29 September 2025  19:26:08 +0000 (0:00:00.572)       0:00:03.392 ******
2025-09-29 19:26:10.272069 | controller | ok: [instance]
2025-09-29 19:26:10.862022 | controller |
2025-09-29 19:26:10.862055 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-09-29 19:26:10.862063 | controller | Monday 29 September 2025  19:26:10 +0000 (0:00:01.364)       0:00:04.757 ******
2025-09-29 19:26:10.862073 | controller | ok: [instance]
2025-09-29 19:26:12.175165 | controller |
2025-09-29 19:26:12.175201 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-09-29 19:26:12.175218 | controller | Monday 29 September 2025  19:26:10 +0000 (0:00:00.589)       0:00:05.347 ******
2025-09-29 19:26:12.175228 | controller | ok: [instance]
2025-09-29 19:26:12.483461 | controller |
2025-09-29 19:26:12.483500 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-09-29 19:26:12.483510 | controller | Monday 29 September 2025  19:26:12 +0000 (0:00:01.313)       0:00:06.660 ******
2025-09-29 19:26:12.483529 | controller | ok: [instance]
2025-09-29 19:26:12.483575 | controller |
2025-09-29 19:26:12.483841 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-09-29 19:26:12.507925 | controller | Monday 29 September 2025  19:26:12 +0000 (0:00:00.308)       0:00:06.968 ******
2025-09-29 19:26:12.507964 | controller | skipping: [instance]
2025-09-29 19:26:13.420447 | controller |
2025-09-29 19:26:13.420481 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-09-29 19:26:13.420489 | controller | Monday 29 September 2025  19:26:12 +0000 (0:00:00.024)       0:00:06.993 ******
2025-09-29 19:26:13.420499 | controller | changed: [instance]
2025-09-29 19:26:13.420522 | controller |
2025-09-29 19:26:13.420530 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-09-29 19:26:13.420564 | controller | Monday 29 September 2025  19:26:13 +0000 (0:00:00.912)       0:00:07.905 ******
2025-09-29 19:26:13.462444 | controller | skipping: [instance]
2025-09-29 19:26:13.504384 | controller |
2025-09-29 19:26:13.504423 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-09-29 19:26:13.504430 | controller | Monday 29 September 2025  19:26:13 +0000 (0:00:00.041)       0:00:07.947 ******
2025-09-29 19:26:13.504441 | controller | skipping: [instance]
2025-09-29 19:26:13.544484 | controller |
2025-09-29 19:26:13.544528 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-09-29 19:26:13.544538 | controller | Monday 29 September 2025  19:26:13 +0000 (0:00:00.041)       0:00:07.989 ******
2025-09-29 19:26:13.544567 | controller | skipping: [instance]
2025-09-29 19:26:14.133862 | controller |
2025-09-29 19:26:14.133895 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-09-29 19:26:14.133904 | controller | Monday 29 September 2025  19:26:13 +0000 (0:00:00.040)       0:00:08.029 ******
2025-09-29 19:26:14.133914 | controller | changed: [instance]
2025-09-29 19:26:14.506445 | controller |
2025-09-29 19:26:14.506481 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-09-29 19:26:14.506489 | controller | Monday 29 September 2025  19:26:14 +0000 (0:00:00.589)       0:00:08.619 ******
2025-09-29 19:26:14.506500 | controller | ok: [instance]
2025-09-29 19:26:14.540069 | controller |
2025-09-29 19:26:14.540103 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-09-29 19:26:14.540112 | controller | Monday 29 September 2025  19:26:14 +0000 (0:00:00.372)       0:00:08.991 ******
2025-09-29 19:26:14.540123 | controller | skipping: [instance]
2025-09-29 19:26:14.573800 | controller |
2025-09-29 19:26:14.573839 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-09-29 19:26:14.573856 | controller | Monday 29 September 2025  19:26:14 +0000 (0:00:00.033)       0:00:09.025 ******
2025-09-29 19:26:14.573868 | controller | skipping: [instance]
2025-09-29 19:26:14.605915 | controller |
2025-09-29 19:26:14.605951 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-09-29 19:26:14.605959 | controller | Monday 29 September 2025  19:26:14 +0000 (0:00:00.033)       0:00:09.058 ******
2025-09-29 19:26:14.605969 | controller | skipping: [instance]
2025-09-29 19:26:14.648506 | controller |
2025-09-29 19:26:14.648594 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-09-29 19:26:14.648603 | controller | Monday 29 September 2025  19:26:14 +0000 (0:00:00.032)       0:00:09.091 ******
2025-09-29 19:26:14.648619 | controller | ok: [instance]
2025-09-29 19:26:14.680085 | controller |
2025-09-29 19:26:14.680131 | controller | TASK [repo_setup : Create download directory] **********************************
2025-09-29 19:26:14.680142 | controller | Monday 29 September 2025  19:26:14 +0000 (0:00:00.042)       0:00:09.133 ******
2025-09-29 19:26:14.680156 | controller | skipping: [instance]
2025-09-29 19:26:14.680211 | controller |
2025-09-29 19:26:14.680392 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-09-29 19:26:14.680591 | controller | Monday 29 September 2025  19:26:14 +0000 (0:00:00.031)       0:00:09.165 ******
2025-09-29 19:26:14.710805 | controller | skipping: [instance]
2025-09-29 19:26:14.710935 | controller |
2025-09-29 19:26:14.711045 | controller | TASK [Download the RPM] ********************************************************
2025-09-29 19:26:14.711080 | controller | Monday 29 September 2025  19:26:14 +0000 (0:00:00.030)       0:00:09.196 ******
2025-09-29 19:26:14.741387 | controller | skipping: [instance]
2025-09-29 19:26:14.741512 | controller |
2025-09-29 19:26:14.741528 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-09-29 19:26:14.741738 | controller | Monday 29 September 2025  19:26:14 +0000 (0:00:00.030)       0:00:09.226 ******
2025-09-29 19:26:14.773648 | controller | skipping: [instance]
2025-09-29 19:26:14.773769 | controller |
2025-09-29 19:26:14.773784 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-09-29 19:26:14.773844 | controller | Monday 29 September 2025  19:26:14 +0000 (0:00:00.032)       0:00:09.259 ******
2025-09-29 19:26:14.804182 | controller | skipping: [instance]
2025-09-29 19:26:14.804288 | controller |
2025-09-29 19:26:14.804377 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-09-29 19:26:14.804505 | controller | Monday 29 September 2025  19:26:14 +0000 (0:00:00.030)       0:00:09.289 ******
2025-09-29 19:26:14.837635 | controller | skipping: [instance]
2025-09-29 19:26:14.837750 | controller |
2025-09-29 19:26:14.837839 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-09-29 19:26:14.837986 | controller | Monday 29 September 2025  19:26:14 +0000 (0:00:00.033)       0:00:09.323 ******
2025-09-29 19:26:14.867852 | controller | skipping: [instance]
2025-09-29 19:26:14.867949 | controller |
2025-09-29 19:26:14.868038 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-09-29 19:26:14.868158 | controller | Monday 29 September 2025  19:26:14 +0000 (0:00:00.030)       0:00:09.353 ******
2025-09-29 19:26:15.071470 | controller | ok: [instance]
2025-09-29 19:26:15.071843 | controller |
2025-09-29 19:26:15.290913 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-09-29 19:26:15.290947 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.203)       0:00:09.557 ******
2025-09-29 19:26:15.290959 | controller | changed: [instance]
2025-09-29 19:26:15.525091 | controller |
2025-09-29 19:26:15.525127 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-09-29 19:26:15.525137 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.219)       0:00:09.776 ******
2025-09-29 19:26:15.525150 | controller | changed: [instance]
2025-09-29 19:26:15.548118 | controller |
2025-09-29 19:26:15.548148 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-09-29 19:26:15.548157 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.234)       0:00:10.010 ******
2025-09-29 19:26:15.548170 | controller | skipping: [instance]
2025-09-29 19:26:15.573812 | controller |
2025-09-29 19:26:15.573838 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-09-29 19:26:15.573845 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.023)       0:00:10.033 ******
2025-09-29 19:26:15.573855 | controller | skipping: [instance]
2025-09-29 19:26:15.599842 | controller |
2025-09-29 19:26:15.599864 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-09-29 19:26:15.599873 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.025)       0:00:10.059 ******
2025-09-29 19:26:15.599884 | controller | skipping: [instance]
2025-09-29 19:26:15.625085 | controller |
2025-09-29 19:26:15.625118 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-09-29 19:26:15.625128 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.026)       0:00:10.085 ******
2025-09-29 19:26:15.625139 | controller | skipping: [instance]
2025-09-29 19:26:15.650271 | controller |
2025-09-29 19:26:15.650309 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-09-29 19:26:15.650318 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.025)       0:00:10.110 ******
2025-09-29 19:26:15.650330 | controller | skipping: [instance]
2025-09-29 19:26:15.675605 | controller |
2025-09-29 19:26:15.675632 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-09-29 19:26:15.675641 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.025)       0:00:10.135 ******
2025-09-29 19:26:15.675660 | controller | skipping: [instance]
2025-09-29 19:26:15.675830 | controller |
2025-09-29 19:26:15.676000 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-09-29 19:26:15.676161 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.025)       0:00:10.161 ******
2025-09-29 19:26:15.696069 | controller | skipping: [instance]
2025-09-29 19:26:15.696246 | controller |
2025-09-29 19:26:15.696447 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-09-29 19:26:15.696613 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.020)       0:00:10.181 ******
2025-09-29 19:26:15.728580 | controller | skipping: [instance]
2025-09-29 19:26:15.728749 | controller |
2025-09-29 19:26:15.728892 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-09-29 19:26:15.729030 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.032)       0:00:10.214 ******
2025-09-29 19:26:15.749872 | controller | skipping: [instance]
2025-09-29 19:26:15.750055 | controller |
2025-09-29 19:26:15.750236 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-09-29 19:26:15.750437 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.021)       0:00:10.235 ******
2025-09-29 19:26:15.775679 | controller | skipping: [instance]
2025-09-29 19:26:15.775847 | controller |
2025-09-29 19:26:15.775996 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-09-29 19:26:15.776151 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.025)       0:00:10.261 ******
2025-09-29 19:26:15.807240 | controller | skipping: [instance]
2025-09-29 19:26:15.807465 | controller |
2025-09-29 19:26:15.807663 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-09-29 19:26:15.807808 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.031)       0:00:10.292 ******
2025-09-29 19:26:15.838918 | controller | skipping: [instance]
2025-09-29 19:26:15.839070 | controller |
2025-09-29 19:26:15.839219 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-09-29 19:26:15.839383 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.031)       0:00:10.324 ******
2025-09-29 19:26:15.869904 | controller | skipping: [instance]
2025-09-29 19:26:15.870075 | controller |
2025-09-29 19:26:15.870215 | controller | TASK [test_deps : Install additional packages] *********************************
2025-09-29 19:26:15.870379 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.030)       0:00:10.355 ******
2025-09-29 19:26:15.900412 | controller | skipping: [instance]
2025-09-29 19:26:15.900588 | controller |
2025-09-29 19:26:15.900746 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-09-29 19:26:15.900888 | controller | Monday 29 September 2025  19:26:15 +0000 (0:00:00.030)       0:00:10.386 ******
2025-09-29 19:26:57.083106 | controller | ok: [instance]
2025-09-29 19:26:58.350457 | controller |
2025-09-29 19:26:58.350489 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-09-29 19:26:58.350497 | controller | Monday 29 September 2025  19:26:57 +0000 (0:00:41.181)       0:00:51.568 ******
2025-09-29 19:26:58.350508 | controller | ok: [instance]
2025-09-29 19:26:58.388249 | controller |
2025-09-29 19:26:58.388282 | controller | TASK [test_deps : Install extra packages] **************************************
2025-09-29 19:26:58.388292 | controller | Monday 29 September 2025  19:26:58 +0000 (0:00:01.267)       0:00:52.835 ******
2025-09-29 19:26:58.388304 | controller | skipping: [instance]
2025-09-29 19:26:58.435451 | controller |
2025-09-29 19:26:58.435475 | controller | TASK [ci_setup : Gather variables for each operating system] *******************
2025-09-29 19:26:58.435483 | controller | Monday 29 September 2025  19:26:58 +0000 (0:00:00.037)       0:00:52.873 ******
2025-09-29 19:26:58.435493 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/ci_setup/vars/redhat.yml)
2025-09-29 19:26:58.435709 | controller |
2025-09-29 19:26:58.435728 | controller | TASK [ci_setup : List packages to install] *************************************
2025-09-29 19:26:58.458518 | controller | Monday 29 September 2025  19:26:58 +0000 (0:00:00.047)       0:00:52.921 ******
2025-09-29 19:26:58.458598 | controller | ok: [instance] =>
2025-09-29 19:26:58.458632 | controller |   cifmw_ci_setup_packages:
2025-09-29 19:26:58.458649 | controller |   - bash-completion
2025-09-29 19:26:58.458657 | controller |   - ca-certificates
2025-09-29 19:26:58.458663 | controller |   - git-core
2025-09-29 19:26:58.458672 | controller |   - make
2025-09-29 19:26:58.459220 | controller |   - tar
2025-09-29 19:26:59.700488 | controller |   - tmux
2025-09-29 19:26:59.700619 | controller |   - python3-pip
2025-09-29 19:26:59.700629 | controller |
2025-09-29 19:26:59.700637 | controller | TASK [ci_setup : Install needed packages] **************************************
2025-09-29 19:26:59.700645 | controller | Monday 29 September 2025  19:26:58 +0000 (0:00:00.022)       0:00:52.943 ******
2025-09-29 19:26:59.700664 | controller | ok: [instance]
2025-09-29 19:26:59.961474 | controller |
2025-09-29 19:26:59.961505 | controller | TASK [ci_setup : Gather version of openshift client] ***************************
2025-09-29 19:26:59.961514 | controller | Monday 29 September 2025  19:26:59 +0000 (0:00:01.242)       0:00:54.185 ******
2025-09-29 19:26:59.961524 | controller | ok: [instance]
2025-09-29 19:26:59.961627 | controller |
2025-09-29 19:26:59.961657 | controller | TASK [ci_setup : Ensure openshift client install path is present] **************
2025-09-29 19:26:59.961669 | controller | Monday 29 September 2025  19:26:59 +0000 (0:00:00.261)       0:00:54.446 ******
2025-09-29 19:27:00.163936 | controller | ok: [instance]
2025-09-29 19:27:00.225968 | controller |
2025-09-29 19:27:00.226002 | controller | TASK [ci_setup : Install openshift client] *************************************
2025-09-29 19:27:00.226010 | controller | Monday 29 September 2025  19:27:00 +0000 (0:00:00.202)       0:00:54.649 ******
2025-09-29 19:27:00.226020 | controller | skipping: [instance]
2025-09-29 19:27:00.260469 | controller |
2025-09-29 19:27:00.260517 | controller | TASK [ci_setup : Add the OC path to cifmw_path if needed] **********************
2025-09-29 19:27:00.260526 | controller | Monday 29 September 2025  19:27:00 +0000 (0:00:00.062)       0:00:54.711 ******
2025-09-29 19:27:00.260538 | controller | skipping: [instance]
2025-09-29 19:27:00.260757 | controller |
2025-09-29 19:27:00.260780 | controller | TASK [ci_setup : Create completion file] ***************************************
2025-09-29 19:27:00.445412 | controller | Monday 29 September 2025  19:27:00 +0000 (0:00:00.034)       0:00:54.745 ******
2025-09-29 19:27:00.445451 | controller | ok: [instance]
2025-09-29 19:27:00.741491 | controller |
2025-09-29 19:27:00.741529 | controller | TASK [ci_setup : Source completion from within .bashrc] ************************
2025-09-29 19:27:00.741539 | controller | Monday 29 September 2025  19:27:00 +0000 (0:00:00.184)       0:00:54.930 ******
2025-09-29 19:27:00.741577 | controller | ok: [instance]
2025-09-29 19:27:00.741613 | controller |
2025-09-29 19:27:00.741623 | controller | TASK [ci_setup : Check rhsm status] ********************************************
2025-09-29 19:27:00.760091 | controller | Monday 29 September 2025  19:27:00 +0000 (0:00:00.296)       0:00:55.226 ******
2025-09-29 19:27:00.760131 | controller | skipping: [instance]
2025-09-29 19:27:00.778461 | controller |
2025-09-29 19:27:00.778490 | controller | TASK [ci_setup : Gather the repos to be enabled] *******************************
2025-09-29 19:27:00.778499 | controller | Monday 29 September 2025  19:27:00 +0000 (0:00:00.018)       0:00:55.245 ******
2025-09-29 19:27:00.778509 | controller | skipping: [instance]
2025-09-29 19:27:00.778534 | controller |
2025-09-29 19:27:00.778543 | controller | TASK [ci_setup : Enabling the required repositories.] **************************
2025-09-29 19:27:00.778672 | controller | Monday 29 September 2025  19:27:00 +0000 (0:00:00.018)       0:00:55.264 ******
2025-09-29 19:27:00.796458 | controller | skipping: [instance]
2025-09-29 19:27:00.796614 | controller |
2025-09-29 19:27:00.796632 | controller | TASK [ci_setup : Get current /etc/redhat-release] ******************************
2025-09-29 19:27:00.796644 | controller | Monday 29 September 2025  19:27:00 +0000 (0:00:00.017)       0:00:55.281 ******
2025-09-29 19:27:00.814947 | controller | skipping: [instance]
2025-09-29 19:27:00.832826 | controller |
2025-09-29 19:27:00.832856 | controller | TASK [ci_setup : Print current /etc/redhat-release] ****************************
2025-09-29 19:27:00.832864 | controller | Monday 29 September 2025  19:27:00 +0000 (0:00:00.018)       0:00:55.300 ******
2025-09-29 19:27:00.832874 | controller | skipping: [instance]
2025-09-29 19:27:00.858726 | controller |
2025-09-29 19:27:00.858758 | controller | TASK [ci_setup : Ensure the repos are enabled in the system using yum] *********
2025-09-29 19:27:00.858772 | controller | Monday 29 September 2025  19:27:00 +0000 (0:00:00.018)       0:00:55.318 ******
2025-09-29 19:27:00.858786 | controller | skipping: [instance]
2025-09-29 19:27:00.858934 | controller |
2025-09-29 19:27:00.859082 | controller | TASK [ci_setup : Manage directories] *******************************************
2025-09-29 19:27:00.859234 | controller | Monday 29 September 2025  19:27:00 +0000 (0:00:00.026)       0:00:55.344 ******
2025-09-29 19:27:01.862147 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/artifacts/manifests/openstack/cr)
2025-09-29 19:27:01.899483 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/logs)
2025-09-29 19:27:01.899520 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/tmp)
2025-09-29 19:27:01.899528 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/volumes)
2025-09-29 19:27:01.899533 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/artifacts/parameters)
2025-09-29 19:27:01.899539 | controller |
2025-09-29 19:27:01.899545 | controller | TASK [Check for CRC startup] ***************************************************
2025-09-29 19:27:01.899564 | controller | Monday 29 September 2025  19:27:01 +0000 (0:00:01.002)       0:00:56.347 ******
2025-09-29 19:27:01.899575 | controller | skipping: [instance]
2025-09-29 19:27:01.899603 | controller |
2025-09-29 19:27:01.899610 | controller | PLAY RECAP *********************************************************************
2025-09-29 19:27:01.901499 | controller | instance                   : ok=28   changed=4    unreachable=0    failed=0    skipped=42   rescued=0    ignored=0
2025-09-29 19:27:01.901576 | controller |
2025-09-29 19:27:01.901587 | controller | Monday 29 September 2025  19:27:01 +0000 (0:00:00.037)       0:00:56.384 ******
2025-09-29 19:27:01.901595 | controller | ===============================================================================
2025-09-29 19:27:01.901602 | controller | test_deps : Install selinux python libs -------------------------------- 41.18s
2025-09-29 19:27:01.901609 | controller | repo_setup : Make sure git-core package is installed -------------------- 1.36s
2025-09-29 19:27:01.901615 | controller | repo_setup : Initialize python venv and install requirements ------------ 1.31s
2025-09-29 19:27:01.901621 | controller | test_deps : Install python yaml libs ------------------------------------ 1.27s
2025-09-29 19:27:01.901627 | controller | ci_setup : Install needed packages -------------------------------------- 1.24s
2025-09-29 19:27:01.901634 | controller | ci_setup : Manage directories ------------------------------------------- 1.00s
2025-09-29 19:27:01.901642 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.91s
2025-09-29 19:27:01.901650 | controller | Gathering Facts --------------------------------------------------------- 0.84s
2025-09-29 19:27:01.901656 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.69s
2025-09-29 19:27:01.901662 | controller | Inject our own NetworkManager configuration ----------------------------- 0.64s
2025-09-29 19:27:01.901669 | controller | repo_setup : Get repo-setup repository ---------------------------------- 0.59s
2025-09-29 19:27:01.901688 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.59s
2025-09-29 19:27:01.901695 | controller | repo_setup : Ensure directories are present ----------------------------- 0.57s
2025-09-29 19:27:01.901702 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.37s
2025-09-29 19:27:01.901708 | controller | repo_setup : Install repo-setup package --------------------------------- 0.31s
2025-09-29 19:27:01.901717 | controller | ci_setup : Source completion from within .bashrc ------------------------ 0.30s
2025-09-29 19:27:01.901744 | controller | ci_setup : Gather version of openshift client --------------------------- 0.26s
2025-09-29 19:27:01.901933 | controller | repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist) --- 0.23s
2025-09-29 19:27:01.901962 | controller | test_deps : Disable ubi host subscription-manager integration ----------- 0.23s
2025-09-29 19:27:01.960543 | controller | repo_setup : Use RDO proxy mirrors -------------------------------------- 0.22s
2025-09-29 19:27:01.960594 | controller | INFO     Running default > converge
2025-09-29 19:27:02.451272 | controller |
2025-09-29 19:27:02.451508 | controller | PLAY [Converge default] ********************************************************
2025-09-29 19:27:02.451679 | controller |
2025-09-29 19:27:02.451822 | controller | TASK [Gathering Facts] *********************************************************
2025-09-29 19:27:02.451976 | controller | Monday 29 September 2025  19:27:02 +0000 (0:00:00.031)       0:00:00.031 ******
2025-09-29 19:27:03.265426 | controller | ok: [instance]
2025-09-29 19:27:03.265472 | controller |
2025-09-29 19:27:03.265482 | controller | TASK [rhol_crc : Ensure directories exist] *************************************
2025-09-29 19:27:03.265619 | controller | Monday 29 September 2025  19:27:03 +0000 (0:00:00.814)       0:00:00.845 ******
2025-09-29 19:27:03.920141 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/artifacts)
2025-09-29 19:27:04.130437 | controller | ok: [instance] => (item=/home/zuul/ci-framework-data/logs)
2025-09-29 19:27:04.130468 | controller | ok: [instance] => (item=/usr/local/bin)
2025-09-29 19:27:04.130476 | controller |
2025-09-29 19:27:04.130482 | controller | TASK [manage_secrets : Ensure directory tree exist] ****************************
2025-09-29 19:27:04.130488 | controller | Monday 29 September 2025  19:27:03 +0000 (0:00:00.654)       0:00:01.500 ******
2025-09-29 19:27:04.130497 | controller | changed: [instance]
2025-09-29 19:27:04.399409 | controller |
2025-09-29 19:27:04.399454 | controller | TASK [rhol_crc : Check for binary] *********************************************
2025-09-29 19:27:04.399462 | controller | Monday 29 September 2025  19:27:04 +0000 (0:00:00.210)       0:00:01.710 ******
2025-09-29 19:27:04.399474 | controller | ok: [instance]
2025-09-29 19:27:04.399509 | controller |
2025-09-29 19:27:04.399517 | controller | TASK [rhol_crc : Get versions if binary is available] **************************
2025-09-29 19:27:04.399539 | controller | Monday 29 September 2025  19:27:04 +0000 (0:00:00.269)       0:00:01.979 ******
2025-09-29 19:27:04.465205 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/rhol_crc/tasks/get_versions.yml for instance
2025-09-29 19:27:04.942451 | controller |
2025-09-29 19:27:04.942483 | controller | TASK [rhol_crc : Get CRC binary version] ***************************************
2025-09-29 19:27:04.942491 | controller | Monday 29 September 2025  19:27:04 +0000 (0:00:00.065)       0:00:02.045 ******
2025-09-29 19:27:04.942501 | controller | changed: [instance]
2025-09-29 19:27:04.942533 | controller |
2025-09-29 19:27:04.942542 | controller | TASK [rhol_crc : Extract versions] *********************************************
2025-09-29 19:27:04.942585 | controller | Monday 29 September 2025  19:27:04 +0000 (0:00:00.477)       0:00:02.522 ******
2025-09-29 19:27:04.980180 | controller | ok: [instance]
2025-09-29 19:27:05.001452 | controller |
2025-09-29 19:27:05.001491 | controller | TASK [rhol_crc : Output found binary location and versions] ********************
2025-09-29 19:27:05.001501 | controller | Monday 29 September 2025  19:27:04 +0000 (0:00:00.037)       0:00:02.560 ******
2025-09-29 19:27:05.001514 | controller | ok: [instance] =>
2025-09-29 19:27:05.001543 | controller |   msg: 'Found crc at /usr/local/bin/crc, with version 2.39.0 (wants: 2.39.0) and serving OpenShift version 4.16.0.'
2025-09-29 19:27:05.001564 | controller |
2025-09-29 19:27:05.001574 | controller | TASK [rhol_crc : Get CRC VM availability] **************************************
2025-09-29 19:27:05.001699 | controller | Monday 29 September 2025  19:27:04 +0000 (0:00:00.021)       0:00:02.581 ******
2025-09-29 19:27:05.336303 | controller | ok: [instance]
2025-09-29 19:27:05.362483 | controller |
2025-09-29 19:27:05.362518 | controller | TASK [rhol_crc : Set CRC status] ***********************************************
2025-09-29 19:27:05.362526 | controller | Monday 29 September 2025  19:27:05 +0000 (0:00:00.334)       0:00:02.916 ******
2025-09-29 19:27:05.362537 | controller | ok: [instance]
2025-09-29 19:27:05.362578 | controller |
2025-09-29 19:27:05.362586 | controller | TASK [rhol_crc : Fail if crc domain is already defined] ************************
2025-09-29 19:27:05.362595 | controller | Monday 29 September 2025  19:27:05 +0000 (0:00:00.026)       0:00:02.942 ******
2025-09-29 19:27:05.389368 | controller | skipping: [instance]
2025-09-29 19:27:05.432258 | controller |
2025-09-29 19:27:05.432294 | controller | TASK [Ensure pull-secret is in place if we need to configure CRC] **************
2025-09-29 19:27:05.432304 | controller | Monday 29 September 2025  19:27:05 +0000 (0:00:00.026)       0:00:02.969 ******
2025-09-29 19:27:05.432315 | controller |
2025-09-29 19:27:05.455493 | controller | TASK [manage_secrets : Assert we get needed data] ******************************
2025-09-29 19:27:05.455529 | controller | Monday 29 September 2025  19:27:05 +0000 (0:00:00.042)       0:00:03.012 ******
2025-09-29 19:27:05.455548 | controller | ok: [instance]
2025-09-29 19:27:05.455771 | controller |
2025-09-29 19:27:05.455804 | controller | TASK [manage_secrets : Manage secret] ******************************************
2025-09-29 19:27:05.482103 | controller | Monday 29 September 2025  19:27:05 +0000 (0:00:00.023)       0:00:03.035 ******
2025-09-29 19:27:05.482143 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/manage_secrets/tasks/_push_secret.yml for instance
2025-09-29 19:27:05.482334 | controller |
2025-09-29 19:27:05.482595 | controller | TASK [manage_secrets : Debug _secret_dest] *************************************
2025-09-29 19:27:05.482789 | controller | Monday 29 September 2025  19:27:05 +0000 (0:00:00.026)       0:00:03.062 ******
2025-09-29 19:27:05.505657 | controller | ok: [instance] =>
2025-09-29 19:27:05.505852 | controller |   _secret_dest: /home/zuul/pull-secret.json
2025-09-29 19:27:05.505986 | controller |
2025-09-29 19:27:05.506136 | controller | TASK [manage_secrets : Debug _secret_file] *************************************
2025-09-29 19:27:05.506273 | controller | Monday 29 September 2025  19:27:05 +0000 (0:00:00.023)       0:00:03.086 ******
2025-09-29 19:27:05.526834 | controller | ok: [instance] =>
2025-09-29 19:27:05.526999 | controller |   _secret_file: ''
2025-09-29 19:27:05.527132 | controller |
2025-09-29 19:27:05.527276 | controller | TASK [manage_secrets : Debug _secret_content] **********************************
2025-09-29 19:27:05.527445 | controller | Monday 29 September 2025  19:27:05 +0000 (0:00:00.021)       0:00:03.107 ******
2025-09-29 19:27:05.547426 | controller | ok: [instance] =>
2025-09-29 19:27:05.547613 | controller |   _secret_content:
2025-09-29 19:27:05.547761 | controller |     auths:
2025-09-29 19:27:05.547899 | controller |       fake:
2025-09-29 19:27:05.548035 | controller |         auth: Zm9vOmJhcgo=
2025-09-29 19:27:05.548161 | controller |
2025-09-29 19:27:05.548294 | controller | TASK [manage_secrets : Ensure parameter is an absolute path] *******************
2025-09-29 19:27:05.548464 | controller | Monday 29 September 2025  19:27:05 +0000 (0:00:00.020)       0:00:03.128 ******
2025-09-29 19:27:05.564533 | controller | skipping: [instance]
2025-09-29 19:27:05.564706 | controller |
2025-09-29 19:27:05.564854 | controller | TASK [manage_secrets : Check if pull secret src file exists] *******************
2025-09-29 19:27:05.564994 | controller | Monday 29 September 2025  19:27:05 +0000 (0:00:00.017)       0:00:03.145 ******
2025-09-29 19:27:05.582153 | controller | skipping: [instance]
2025-09-29 19:27:05.582362 | controller |
2025-09-29 19:27:05.582573 | controller | TASK [manage_secrets : Copy file to location] **********************************
2025-09-29 19:27:05.582749 | controller | Monday 29 September 2025  19:27:05 +0000 (0:00:00.017)       0:00:03.162 ******
2025-09-29 19:27:05.598295 | controller | skipping: [instance]
2025-09-29 19:27:05.598510 | controller |
2025-09-29 19:27:05.598707 | controller | TASK [manage_secrets : Create file from content] *******************************
2025-09-29 19:27:05.598875 | controller | Monday 29 September 2025  19:27:05 +0000 (0:00:00.016)       0:00:03.179 ******
2025-09-29 19:27:06.055076 | controller | changed: [instance]
2025-09-29 19:27:06.089486 | controller |
2025-09-29 19:27:06.089523 | controller | TASK [rhol_crc : Get wanted RHOL/CRC version binary if needed] *****************
2025-09-29 19:27:06.089531 | controller | Monday 29 September 2025  19:27:06 +0000 (0:00:00.456)       0:00:03.635 ******
2025-09-29 19:27:06.089541 | controller | skipping: [instance]
2025-09-29 19:27:06.089586 | controller |
2025-09-29 19:27:06.089595 | controller | TASK [rhol_crc : Setup sudoers file for sudo commands in RHOL/CRC setup] *******
2025-09-29 19:27:06.089694 | controller | Monday 29 September 2025  19:27:06 +0000 (0:00:00.034)       0:00:03.670 ******
2025-09-29 19:27:06.126413 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/rhol_crc/tasks/sudoers_grant.yml for instance
2025-09-29 19:27:06.440039 | controller |
2025-09-29 19:27:06.440068 | controller | TASK [rhol_crc : Add passwordless sudo access for CRC commands] ****************
2025-09-29 19:27:06.440076 | controller | Monday 29 September 2025  19:27:06 +0000 (0:00:00.036)       0:00:03.706 ******
2025-09-29 19:27:06.440087 | controller | changed: [instance]
2025-09-29 19:27:06.468469 | controller |
2025-09-29 19:27:06.468500 | controller | TASK [rhol_crc : Clean RHOL/CRC if wanted] *************************************
2025-09-29 19:27:06.468509 | controller | Monday 29 September 2025  19:27:06 +0000 (0:00:00.313)       0:00:04.020 ******
2025-09-29 19:27:06.468527 | controller | skipping: [instance]
2025-09-29 19:27:06.468573 | controller |
2025-09-29 19:27:06.468764 | controller | TASK [rhol_crc : Set RHOL/CRC configuration options] ***************************
2025-09-29 19:27:06.504904 | controller | Monday 29 September 2025  19:27:06 +0000 (0:00:00.028)       0:00:04.049 ******
2025-09-29 19:27:06.504928 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/rhol_crc/tasks/configuration.yml for instance
2025-09-29 19:27:08.364010 | controller |
2025-09-29 19:27:08.364042 | controller | TASK [rhol_crc : Set RHOL/CRC configuration options] ***************************
2025-09-29 19:27:08.364056 | controller | Monday 29 September 2025  19:27:06 +0000 (0:00:00.036)       0:00:04.085 ******
2025-09-29 19:27:08.364067 | controller | changed: [instance] => (item={'key': 'consent-telemetry', 'value': 'no'})
2025-09-29 19:31:24.359171 | controller | changed: [instance] => (item={'key': 'disk-size', 'value': 32})
2025-09-29 19:31:24.359390 | controller | changed: [instance] => (item={'key': 'memory', 'value': 10752})
2025-09-29 19:31:24.359405 | controller | changed: [instance] => (item={'key': 'cpus', 'value': 4})
2025-09-29 19:31:24.359412 | controller | changed: [instance] => (item={'key': 'preset', 'value': 'openshift'})
2025-09-29 19:31:24.359417 | controller | changed: [instance] => (item={'key': 'pull-secret-file', 'value': '/home/zuul/pull-secret.json'})
2025-09-29 19:31:24.359423 | controller | changed: [instance] => (item={'key': 'skip-check-daemon-systemd-unit', 'value': True})
2025-09-29 19:31:24.359428 | controller | changed: [instance] => (item={'key': 'skip-check-daemon-systemd-sockets', 'value': True})
2025-09-29 19:31:24.359434 | controller | changed: [instance] => (item={'key': 'kubeadmin-password', 'value': 12345678})
2025-09-29 19:31:24.359439 | controller |
2025-09-29 19:31:24.359444 | controller | TASK [rhol_crc : Setup RHOL/CRC] ***********************************************
2025-09-29 19:31:24.359450 | controller | Monday 29 September 2025  19:27:08 +0000 (0:00:01.857)       0:00:05.943 ******
2025-09-29 19:31:24.359460 | controller | changed: [instance]
2025-09-29 19:48:26.761248 | controller |
2025-09-29 19:48:26.761290 | controller | TASK [rhol_crc : Start RHOL/CRC] ***********************************************
2025-09-29 19:48:26.761299 | controller | Monday 29 September 2025  19:31:24 +0000 (0:04:15.996)       0:04:21.939 ******
2025-09-29 19:48:26.761309 | controller | fatal: [instance]: FAILED! => changed=true
2025-09-29 19:48:26.761352 | controller |   cmd: set -o pipefail; /usr/local/bin/crc start 2>&1 | tee /home/zuul/ci-framework-data/logs/crc-start.log
2025-09-29 19:48:26.761562 | controller |   delta: '0:17:02.185665'
2025-09-29 19:48:26.761580 | controller |   end: '2025-09-29 19:48:26.728209'
2025-09-29 19:48:26.761842 | controller |   msg: non-zero return code
2025-09-29 19:48:26.762395 | controller |   rc: 1
2025-09-29 19:48:26.762407 | controller |   start: '2025-09-29 19:31:24.542544'
2025-09-29 19:48:26.762416 | controller |   stderr: ''
2025-09-29 19:48:26.762535 | controller |   stderr_lines: <omitted>
2025-09-29 19:48:26.762550 | controller |   stdout: |-
2025-09-29 19:48:26.762557 | controller |     level=warning msg="A new version (2.54.0) has been published on https://developers.redhat.com/content-gateway/file/pub/openshift-v4/clients/crc/2.54.0/crc-linux-amd64.tar.xz"
2025-09-29 19:48:26.762563 | controller |     level=info msg="Using bundle path /home/zuul/.crc/cache/crc_libvirt_4.16.0_amd64.crcbundle"
2025-09-29 19:48:26.762568 | controller |     level=info msg="Checking if running as non-root"
2025-09-29 19:48:26.762576 | controller |     level=info msg="Checking if running inside WSL2"
2025-09-29 19:48:26.762599 | controller |     level=info msg="Checking if crc-admin-helper executable is cached"
2025-09-29 19:48:26.762875 | controller |     level=info msg="Checking if running on a supported CPU architecture"
2025-09-29 19:48:26.762972 | controller |     level=info msg="Checking if crc executable symlink exists"
2025-09-29 19:48:26.762999 | controller |     level=info msg="Checking minimum RAM requirements"
2025-09-29 19:48:26.763405 | controller |     level=info msg="Check if Podman binary exists in: /home/zuul/.crc/bin/oc"
2025-09-29 19:48:26.763430 | controller |     level=info msg="Checking if Virtualization is enabled"
2025-09-29 19:48:26.764459 | controller |     level=info msg="Checking if KVM is enabled"
2025-09-29 19:48:26.764486 | controller |     level=info msg="Checking if libvirt is installed"
2025-09-29 19:48:26.764523 | controller |     level=info msg="Checking if user is part of libvirt group"
2025-09-29 19:48:26.764534 | controller |     level=info msg="Checking if active user/process is currently part of the libvirt group"
2025-09-29 19:48:26.764653 | controller |     level=info msg="Checking if libvirt daemon is running"
2025-09-29 19:48:26.764668 | controller |     level=info msg="Checking if a supported libvirt version is installed"
2025-09-29 19:48:26.764675 | controller |     level=info msg="Checking if crc-driver-libvirt is installed"
2025-09-29 19:48:26.764681 | controller |     level=info msg="Checking crc daemon systemd socket units"
2025-09-29 19:48:26.764686 | controller |     level=warning msg="Skipping above check..."
2025-09-29 19:48:26.764692 | controller |     level=info msg="Checking if systemd-networkd is running"
2025-09-29 19:48:26.764697 | controller |     level=info msg="Checking if NetworkManager is installed"
2025-09-29 19:48:26.764702 | controller |     level=info msg="Checking if NetworkManager service is running"
2025-09-29 19:48:26.764707 | controller |     level=info msg="Checking if /etc/NetworkManager/conf.d/crc-nm-dnsmasq.conf exists"
2025-09-29 19:48:26.764713 | controller |     level=info msg="Checking if /etc/NetworkManager/dnsmasq.d/crc.conf exists"
2025-09-29 19:48:26.764721 | controller |     level=info msg="Checking if libvirt 'crc' network is available"
2025-09-29 19:48:26.764744 | controller |     level=info msg="Checking if libvirt 'crc' network is active"
2025-09-29 19:48:26.764750 | controller |     level=info msg="Loading bundle: crc_libvirt_4.16.0_amd64..."
2025-09-29 19:48:26.764756 | controller |     level=info msg="Creating CRC VM for OpenShift 4.16.0..."
2025-09-29 19:48:26.765024 | controller |     level=info msg="Generating new SSH key pair..."
2025-09-29 19:48:26.765038 | controller |     level=info msg="Generating new password for the kubeadmin user"
2025-09-29 19:48:26.765046 | controller |     level=info msg="Starting CRC VM for openshift 4.16.0..."
2025-09-29 19:48:26.765159 | controller |     level=info msg="CRC instance is running with IP 192.168.130.11"
2025-09-29 19:48:26.765266 | controller |     level=info msg="CRC VM is running"
2025-09-29 19:48:26.765384 | controller |     level=info msg="Updating authorized keys..."
2025-09-29 19:48:26.765513 | controller |     level=info msg="Resizing /dev/vda4 filesystem"
2025-09-29 19:48:26.765613 | controller |     level=info msg="Configuring shared directories"
2025-09-29 19:48:26.765720 | controller |     level=info msg="Check internal and public DNS query..."
2025-09-29 19:48:26.765825 | controller |     level=info msg="Check DNS query from host..."
2025-09-29 19:48:26.765932 | controller |     level=info msg="Verifying validity of the kubelet certificates..."
2025-09-29 19:48:26.766079 | controller |     level=info msg="Starting kubelet service"
2025-09-29 19:48:26.766196 | controller |     level=info msg="Kubelet client certificate has expired, renewing it... [will take up to 10 minutes]"
2025-09-29 19:48:26.766312 | controller |     Failed to renew TLS certificates: please check if a newer CRC release is available: Temporary error: No Pending CSR with signerName kubernetes.io/kubelet-serving (x112)
2025-09-29 19:48:26.766437 | controller |   stdout_lines: <omitted>
2025-09-29 19:48:26.768907 | controller |
2025-09-29 19:48:26.769045 | controller | TASK [rhol_crc : Revoke permissions granted in sudoers file for CRC/RHOL setup] ***
2025-09-29 19:48:26.769158 | controller | Monday 29 September 2025  19:48:26 +0000 (0:17:02.410)       0:21:24.349 ******
2025-09-29 19:48:26.982709 | controller | changed: [instance]
2025-09-29 19:48:26.982775 | controller |
2025-09-29 19:48:26.982782 | controller | PLAY RECAP *********************************************************************
2025-09-29 19:48:26.982791 | controller | instance                   : ok=22   changed=7    unreachable=0    failed=1    skipped=6    rescued=0    ignored=0
2025-09-29 19:48:26.982799 | controller |
2025-09-29 19:48:26.982807 | controller | Monday 29 September 2025  19:48:26 +0000 (0:00:00.213)       0:21:24.562 ******
2025-09-29 19:48:26.983565 | controller | ===============================================================================
2025-09-29 19:48:26.983602 | controller | rhol_crc : Start RHOL/CRC -------------------------------------------- 1022.41s
2025-09-29 19:48:26.983610 | controller | rhol_crc : Setup RHOL/CRC --------------------------------------------- 256.00s
2025-09-29 19:48:26.983615 | controller | rhol_crc : Set RHOL/CRC configuration options --------------------------- 1.86s
2025-09-29 19:48:26.983632 | controller | Gathering Facts --------------------------------------------------------- 0.81s
2025-09-29 19:48:26.983639 | controller | rhol_crc : Ensure directories exist ------------------------------------- 0.65s
2025-09-29 19:48:26.984401 | controller | rhol_crc : Get CRC binary version --------------------------------------- 0.48s
2025-09-29 19:48:26.985133 | controller | manage_secrets : Create file from content ------------------------------- 0.46s
2025-09-29 19:48:26.985209 | controller | rhol_crc : Get CRC VM availability -------------------------------------- 0.33s
2025-09-29 19:48:26.985217 | controller | rhol_crc : Add passwordless sudo access for CRC commands ---------------- 0.31s
2025-09-29 19:48:26.985224 | controller | rhol_crc : Check for binary --------------------------------------------- 0.27s
2025-09-29 19:48:26.985230 | controller | rhol_crc : Revoke permissions granted in sudoers file for CRC/RHOL setup --- 0.21s
2025-09-29 19:48:26.985240 | controller | manage_secrets : Ensure directory tree exist ---------------------------- 0.21s
2025-09-29 19:48:26.985246 | controller | rhol_crc : Get versions if binary is available -------------------------- 0.07s
2025-09-29 19:48:26.985263 | controller | Ensure pull-secret is in place if we need to configure CRC -------------- 0.04s
2025-09-29 19:48:27.044885 | controller | rhol_crc : Extract versions --------------------------------------------- 0.04s
2025-09-29 19:48:27.044908 | controller | rhol_crc : Setup sudoers file for sudo commands in RHOL/CRC setup ------- 0.04s
2025-09-29 19:48:27.044916 | controller | rhol_crc : Set RHOL/CRC configuration options --------------------------- 0.04s
2025-09-29 19:48:27.044926 | controller | rhol_crc : Get wanted RHOL/CRC version binary if needed ----------------- 0.03s
2025-09-29 19:48:27.044932 | controller | rhol_crc : Clean RHOL/CRC if wanted ------------------------------------- 0.03s
2025-09-29 19:48:27.044937 | controller | rhol_crc : Fail if crc domain is already defined ------------------------ 0.03s
2025-09-29 19:48:27.044948 | controller | CRITICAL Ansible return code was 2, command was: ['ansible-playbook', '--inventory', '/home/zuul/.cache/molecule/rhol_crc/default/inventory', '--skip-tags', 'molecule-notest,notest', '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/rhol_crc/molecule/default/converge.yml']
2025-09-29 19:48:27.045410 | controller | WARNING  An error occurred during the test sequence action: 'converge'. Cleaning up.
2025-09-29 19:48:27.054393 | controller | INFO     Running default > cleanup
2025-09-29 19:48:27.496252 | controller |
2025-09-29 19:48:27.496487 | controller | PLAY [Prepare] *****************************************************************
2025-09-29 19:48:27.496632 | controller |
2025-09-29 19:48:27.496775 | controller | TASK [Gathering Facts] *********************************************************
2025-09-29 19:48:27.496914 | controller | Monday 29 September 2025  19:48:27 +0000 (0:00:00.017)       0:00:00.017 ******
2025-09-29 19:48:28.421291 | controller | ok: [instance]
2025-09-29 19:48:28.709642 | controller |
2025-09-29 19:48:28.709680 | controller | TASK [rhol_crc : Check RHOL/CRC binary exists] *********************************
2025-09-29 19:48:28.709690 | controller | Monday 29 September 2025  19:48:28 +0000 (0:00:00.925)       0:00:00.942 ******
2025-09-29 19:48:28.709702 | controller | ok: [instance]
2025-09-29 19:48:28.709724 | controller |
2025-09-29 19:48:28.709899 | controller | TASK [rhol_crc : Delete RHOL/CRC instance and associated configuration] ********
2025-09-29 19:48:31.562449 | controller | Monday 29 September 2025  19:48:28 +0000 (0:00:00.288)       0:00:01.231 ******
2025-09-29 19:48:31.562493 | controller | changed: [instance]
2025-09-29 19:48:31.562520 | controller |
2025-09-29 19:48:31.562527 | controller | PLAY RECAP *********************************************************************
2025-09-29 19:48:31.562534 | controller | instance                   : ok=3    changed=1    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-09-29 19:48:31.563136 | controller |
2025-09-29 19:48:31.618787 | controller | Monday 29 September 2025  19:48:31 +0000 (0:00:02.852)       0:00:04.084 ******
2025-09-29 19:48:31.618816 | controller | ===============================================================================
2025-09-29 19:48:31.618824 | controller | rhol_crc : Delete RHOL/CRC instance and associated configuration -------- 2.85s
2025-09-29 19:48:31.618830 | controller | Gathering Facts --------------------------------------------------------- 0.93s
2025-09-29 19:48:31.618838 | controller | rhol_crc : Check RHOL/CRC binary exists --------------------------------- 0.29s
2025-09-29 19:48:31.618848 | controller | INFO     Running default > destroy
2025-09-29 19:48:31.619222 | controller | WARNING  Skipping, instances are delegated.
2025-09-29 19:48:31.619588 | controller | INFO     Pruning extra files from scenario ephemeral directory
2025-09-29 19:48:31.621258 | controller | INFO     Writing /tmp/report.html report.
2025-09-29 19:48:32.018832 | controller | ERROR
2025-09-29 19:48:32.019016 | controller | {
2025-09-29 19:48:32.019059 | controller |   "delta": "0:28:06.828749",
2025-09-29 19:48:32.019082 | controller |   "end": "2025-09-29 19:48:31.669049",
2025-09-29 19:48:32.019100 | controller |   "msg": "non-zero return code",
2025-09-29 19:48:32.019115 | controller |   "rc": 1,
2025-09-29 19:48:32.019135 | controller |   "start": "2025-09-29 19:20:24.840300"
2025-09-29 19:48:32.019151 | controller | }
failure
2025-09-29 19:48:32.069603 | 
2025-09-29 19:48:32.069654 | PLAY RECAP
2025-09-29 19:48:32.069692 | controller | ok: 1 changed: 0 unreachable: 0 failed: 1 skipped: 1 rescued: 0 ignored: 0
2025-09-29 19:48:32.069713 | 
2025-09-29 19:48:32.131188 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-09-29 19:48:32.131932 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-09-29 19:48:32.647863 | 
2025-09-29 19:48:32.647984 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-09-29 19:48:32.668268 | 
2025-09-29 19:48:32.668342 | TASK [Filter out host if needed]
2025-09-29 19:48:32.676659 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-09-29 19:48:32.681045 | 
2025-09-29 19:48:32.681113 | TASK [Ensure file is present]
2025-09-29 19:48:33.003624 | controller | ok
2025-09-29 19:48:33.010127 | 
2025-09-29 19:48:33.010193 | TASK [Manage molecule report file]
2025-09-29 19:48:33.535253 | controller | changed
2025-09-29 19:48:33.540470 | 
2025-09-29 19:48:33.540562 | TASK [Check if we get ci-framework-data basedir]
2025-09-29 19:48:33.761214 | controller | ok
2025-09-29 19:48:33.766433 | 
2025-09-29 19:48:33.766512 | TASK [Create ci-framework-data log directory for zuul]
2025-09-29 19:48:34.088942 | controller | changed
2025-09-29 19:48:34.093954 | 
2025-09-29 19:48:34.094020 | TASK [Copy ci-framework interesting files]
2025-09-29 19:48:34.310486 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2025-09-29 19:48:34.618143 | controller | changed
2025-09-29 19:48:34.622833 | 
2025-09-29 19:48:34.622898 | TASK [Get SELinux listing]
2025-09-29 19:48:35.147240 | controller | changed
2025-09-29 19:48:35.153159 | 
2025-09-29 19:48:35.153247 | TASK [Generate log index]
2025-09-29 19:48:35.941196 | controller | changed
2025-09-29 19:48:35.945950 | 
2025-09-29 19:48:35.946016 | TASK [Get some env related data]
2025-09-29 19:48:36.615535 | controller | /home/zuul/.local/bin/ansible
2025-09-29 19:48:37.473646 | controller | changed
2025-09-29 19:48:37.479149 | 
2025-09-29 19:48:37.479233 | TASK [Generate list of logs to collect in home directory]
2025-09-29 19:48:37.792195 | controller | ok: All paths examined
2025-09-29 19:48:37.815589 | 
2025-09-29 19:48:37.815677 | LOOP [Copy logs from home directory]
2025-09-29 19:48:38.194416 | controller | changed:
2025-09-29 19:48:38.194647 | controller | {
2025-09-29 19:48:38.194685 | controller |   "atime": 1743544925.4788878,
2025-09-29 19:48:38.194718 | controller |   "ctime": 1743545329.1409318,
2025-09-29 19:48:38.194742 | controller |   "dev": 64513,
2025-09-29 19:48:38.194763 | controller |   "gid": 1000,
2025-09-29 19:48:38.194784 | controller |   "gr_name": "zuul",
2025-09-29 19:48:38.194804 | controller |   "inode": 4518807,
2025-09-29 19:48:38.194824 | controller |   "isblk": false,
2025-09-29 19:48:38.194843 | controller |   "ischr": false,
2025-09-29 19:48:38.194862 | controller |   "isdir": false,
2025-09-29 19:48:38.194881 | controller |   "isfifo": false,
2025-09-29 19:48:38.194900 | controller |   "isgid": false,
2025-09-29 19:48:38.194942 | controller |   "islnk": false,
2025-09-29 19:48:38.194965 | controller |   "isreg": true,
2025-09-29 19:48:38.194985 | controller |   "issock": false,
2025-09-29 19:48:38.195003 | controller |   "isuid": false,
2025-09-29 19:48:38.195022 | controller |   "mode": "0644",
2025-09-29 19:48:38.195049 | controller |   "mtime": 1743545329.1409318,
2025-09-29 19:48:38.195068 | controller |   "nlink": 1,
2025-09-29 19:48:38.195087 | controller |   "path": "/home/zuul/crc-setup.log",
2025-09-29 19:48:38.195105 | controller |   "pw_name": "zuul",
2025-09-29 19:48:38.195124 | controller |   "rgrp": true,
2025-09-29 19:48:38.195142 | controller |   "roth": true,
2025-09-29 19:48:38.195261 | controller |   "rusr": true,
2025-09-29 19:48:38.195291 | controller |   "size": 4108,
2025-09-29 19:48:38.195313 | controller |   "uid": 1000,
2025-09-29 19:48:38.195334 | controller |   "wgrp": false,
2025-09-29 19:48:38.195353 | controller |   "woth": false,
2025-09-29 19:48:38.195375 | controller |   "wusr": true,
2025-09-29 19:48:38.195395 | controller |   "xgrp": false,
2025-09-29 19:48:38.195414 | controller |   "xoth": false,
2025-09-29 19:48:38.195432 | controller |   "xusr": false
2025-09-29 19:48:38.195449 | controller | }
2025-09-29 19:48:38.548612 | controller | changed:
2025-09-29 19:48:38.548706 | controller | {
2025-09-29 19:48:38.548732 | controller |   "atime": 1743545331.0429637,
2025-09-29 19:48:38.548752 | controller |   "ctime": 1743545842.0111232,
2025-09-29 19:48:38.548768 | controller |   "dev": 64513,
2025-09-29 19:48:38.548785 | controller |   "gid": 1000,
2025-09-29 19:48:38.548799 | controller |   "gr_name": "zuul",
2025-09-29 19:48:38.548813 | controller |   "inode": 4194437,
2025-09-29 19:48:38.548828 | controller |   "isblk": false,
2025-09-29 19:48:38.548842 | controller |   "ischr": false,
2025-09-29 19:48:38.548857 | controller |   "isdir": false,
2025-09-29 19:48:38.548871 | controller |   "isfifo": false,
2025-09-29 19:48:38.548884 | controller |   "isgid": false,
2025-09-29 19:48:38.548898 | controller |   "islnk": false,
2025-09-29 19:48:38.548932 | controller |   "isreg": true,
2025-09-29 19:48:38.548953 | controller |   "issock": false,
2025-09-29 19:48:38.548969 | controller |   "isuid": false,
2025-09-29 19:48:38.548984 | controller |   "mode": "0644",
2025-09-29 19:48:38.548998 | controller |   "mtime": 1743545842.0111232,
2025-09-29 19:48:38.549012 | controller |   "nlink": 1,
2025-09-29 19:48:38.549028 | controller |   "path": "/home/zuul/crc-start.log",
2025-09-29 19:48:38.549123 | controller |   "pw_name": "zuul",
2025-09-29 19:48:38.549139 | controller |   "rgrp": true,
2025-09-29 19:48:38.549154 | controller |   "roth": true,
2025-09-29 19:48:38.549169 | controller |   "rusr": true,
2025-09-29 19:48:38.549189 | controller |   "size": 4023,
2025-09-29 19:48:38.549203 | controller |   "uid": 1000,
2025-09-29 19:48:38.549217 | controller |   "wgrp": false,
2025-09-29 19:48:38.549231 | controller |   "woth": false,
2025-09-29 19:48:38.549244 | controller |   "wusr": true,
2025-09-29 19:48:38.549258 | controller |   "xgrp": false,
2025-09-29 19:48:38.549271 | controller |   "xoth": false,
2025-09-29 19:48:38.549285 | controller |   "xusr": false
2025-09-29 19:48:38.549298 | controller | }
2025-09-29 19:48:38.907703 | controller | changed:
2025-09-29 19:48:38.907795 | controller | {
2025-09-29 19:48:38.907821 | controller |   "atime": 1759173606.6779637,
2025-09-29 19:48:38.907847 | controller |   "ctime": 1759173622.7679267,
2025-09-29 19:48:38.907891 | controller |   "dev": 64513,
2025-09-29 19:48:38.907932 | controller |   "gid": 1000,
2025-09-29 19:48:38.907954 | controller |   "gr_name": "zuul",
2025-09-29 19:48:38.907970 | controller |   "inode": 4686334,
2025-09-29 19:48:38.907985 | controller |   "isblk": false,
2025-09-29 19:48:38.907999 | controller |   "ischr": false,
2025-09-29 19:48:38.908013 | controller |   "isdir": false,
2025-09-29 19:48:38.908037 | controller |   "isfifo": false,
2025-09-29 19:48:38.908054 | controller |   "isgid": false,
2025-09-29 19:48:38.908068 | controller |   "islnk": false,
2025-09-29 19:48:38.908082 | controller |   "isreg": true,
2025-09-29 19:48:38.908097 | controller |   "issock": false,
2025-09-29 19:48:38.908111 | controller |   "isuid": false,
2025-09-29 19:48:38.908124 | controller |   "mode": "0644",
2025-09-29 19:48:38.908137 | controller |   "mtime": 1759173622.7679267,
2025-09-29 19:48:38.908151 | controller |   "nlink": 1,
2025-09-29 19:48:38.908165 | controller |   "path": "/home/zuul/ansible.log",
2025-09-29 19:48:38.908180 | controller |   "pw_name": "zuul",
2025-09-29 19:48:38.908194 | controller |   "rgrp": true,
2025-09-29 19:48:38.908208 | controller |   "roth": true,
2025-09-29 19:48:38.908224 | controller |   "rusr": true,
2025-09-29 19:48:38.908239 | controller |   "size": 6749,
2025-09-29 19:48:38.908253 | controller |   "uid": 1000,
2025-09-29 19:48:38.908267 | controller |   "wgrp": false,
2025-09-29 19:48:38.908280 | controller |   "woth": false,
2025-09-29 19:48:38.908294 | controller |   "wusr": true,
2025-09-29 19:48:38.908307 | controller |   "xgrp": false,
2025-09-29 19:48:38.908320 | controller |   "xoth": false,
2025-09-29 19:48:38.908333 | controller |   "xusr": false
2025-09-29 19:48:38.908345 | controller | }
2025-09-29 19:48:38.921598 | 
2025-09-29 19:48:38.921705 | TASK [Copy crio stats log file]
2025-09-29 19:48:38.935146 | controller | skipping: Conditional result was False
2025-09-29 19:48:38.940318 | 
2025-09-29 19:48:38.940444 | TASK [Get SELinux related data]
2025-09-29 19:48:39.169605 | controller | <no matches>
2025-09-29 19:48:39.466283 | controller | ERROR
2025-09-29 19:48:39.466498 | controller | {
2025-09-29 19:48:39.466537 | controller |   "delta": "0:00:00.008556",
2025-09-29 19:48:39.466563 | controller |   "end": "2025-09-29 19:48:39.170474",
2025-09-29 19:48:39.466584 | controller |   "msg": "non-zero return code",
2025-09-29 19:48:39.466604 | controller |   "rc": 1,
2025-09-29 19:48:39.466623 | controller |   "start": "2025-09-29 19:48:39.161918"
2025-09-29 19:48:39.466638 | controller | }
2025-09-29 19:48:39.466660 | controller | ERROR: Ignoring Errors
2025-09-29 19:48:39.471973 | 
2025-09-29 19:48:39.472045 | TASK [Create system configuration directory]
2025-09-29 19:48:39.683561 | controller | changed
2025-09-29 19:48:39.688309 | 
2025-09-29 19:48:39.688372 | TASK [Get some of the system configurations]
2025-09-29 19:48:40.215363 | controller | changed
2025-09-29 19:48:40.220746 | 
2025-09-29 19:48:40.220816 | TASK [Copy generated documentation if available]
2025-09-29 19:48:40.235205 | controller | skipping: Conditional result was False
2025-09-29 19:48:40.240732 | 
2025-09-29 19:48:40.240795 | TASK [Copy generated AsciiDoc documentation if available]
2025-09-29 19:48:40.253965 | controller | skipping: Conditional result was False
2025-09-29 19:48:40.259006 | 
2025-09-29 19:48:40.259079 | TASK [Compress logs bigger than 2MB]
2025-09-29 19:48:40.785293 | controller | changed
2025-09-29 19:48:40.790650 | 
2025-09-29 19:48:40.790716 | TASK [Copy files from workspace on node]
2025-09-29 19:48:40.809316 | controller | ok
2025-09-29 19:48:40.832253 | 
2025-09-29 19:48:40.832356 | TASK [fetch-output : Set log path for multiple nodes]
2025-09-29 19:48:40.845296 | controller | skipping: Conditional result was False
2025-09-29 19:48:40.850536 | 
2025-09-29 19:48:40.850602 | TASK [fetch-output : Set log path for single node]
2025-09-29 19:48:40.877875 | controller | ok
2025-09-29 19:48:40.883694 | 
2025-09-29 19:48:40.883756 | LOOP [fetch-output : Ensure local output dirs]
2025-09-29 19:48:41.075712 | controller -> localhost | ok: "/var/lib/zuul/builds/867f3ce1761f49a9bf874bee388bd5ba/work/logs"
2025-09-29 19:48:41.075983 | controller -> localhost | changed: All items complete
2025-09-29 19:48:41.076014 | 
2025-09-29 19:48:41.253489 | controller -> localhost | changed: "/var/lib/zuul/builds/867f3ce1761f49a9bf874bee388bd5ba/work/artifacts"
2025-09-29 19:48:41.429604 | controller -> localhost | changed: "/var/lib/zuul/builds/867f3ce1761f49a9bf874bee388bd5ba/work/docs"
2025-09-29 19:48:41.440403 | 
2025-09-29 19:48:41.440500 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-09-29 19:48:42.013062 | controller | changed:
2025-09-29 19:48:42.013246 | controller | .d..t...... ./
2025-09-29 19:48:42.013278 | controller | >f+++++++++ README.html
2025-09-29 19:48:42.013301 | controller | >f+++++++++ ansible-execution.log
2025-09-29 19:48:42.013323 | controller | >f+++++++++ ansible.log
2025-09-29 19:48:42.013343 | controller | >f+++++++++ crc-setup.log
2025-09-29 19:48:42.013363 | controller | >f+++++++++ crc-start.log
2025-09-29 19:48:42.013384 | controller | >f+++++++++ dmesg.log
2025-09-29 19:48:42.013404 | controller | >f+++++++++ installed-pkgs.log
2025-09-29 19:48:42.013423 | controller | >f+++++++++ python.log
2025-09-29 19:48:42.013441 | controller | >f+++++++++ registries.conf
2025-09-29 19:48:42.013459 | controller | >f+++++++++ report.html
2025-09-29 19:48:42.013476 | controller | >f+++++++++ selinux-denials.log
2025-09-29 19:48:42.013494 | controller | >f+++++++++ selinux-listing.log
2025-09-29 19:48:42.013512 | controller | cd+++++++++ ci-framework-data/
2025-09-29 19:48:42.013530 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-09-29 19:48:42.013549 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-09-29 19:48:42.013566 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/
2025-09-29 19:48:42.013583 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/openstack/
2025-09-29 19:48:42.013600 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/openstack/cr/
2025-09-29 19:48:42.013616 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-09-29 19:48:42.013632 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-09-29 19:48:42.013649 | controller | cd+++++++++ ci-framework-data/artifacts/repositories/
2025-09-29 19:48:42.013666 | controller | >f+++++++++ ci-framework-data/artifacts/repositories/delorean.repo.md5
2025-09-29 19:48:42.013682 | controller | cd+++++++++ ci-framework-data/logs/
2025-09-29 19:48:42.013699 | controller | >f+++++++++ ci-framework-data/logs/crc-config.log
2025-09-29 19:48:42.013716 | controller | >f+++++++++ ci-framework-data/logs/crc-setup.log
2025-09-29 19:48:42.013733 | controller | >f+++++++++ ci-framework-data/logs/crc-start-add_crc_creds
2025-09-29 19:48:42.013750 | controller | >f+++++++++ ci-framework-data/logs/crc-start.log
2025-09-29 19:48:42.013767 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-09-29 19:48:42.013784 | controller | cd+++++++++ registries.conf.d/
2025-09-29 19:48:42.013801 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-09-29 19:48:42.013818 | controller | cd+++++++++ system-config/
2025-09-29 19:48:42.013834 | controller | cd+++++++++ system-config/libvirt/
2025-09-29 19:48:42.013851 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-09-29 19:48:42.013867 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-09-29 19:48:42.013884 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf
2025-09-29 19:48:42.013900 | controller | >f+++++++++ system-config/libvirt/network.conf
2025-09-29 19:48:42.013939 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf
2025-09-29 19:48:42.013960 | controller | >f+++++++++ system-config/libvirt/qemu.conf
2025-09-29 19:48:42.013977 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf
2025-09-29 19:48:42.014000 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf
2025-09-29 19:48:42.014018 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf
2025-09-29 19:48:42.014047 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf
2025-09-29 19:48:42.014066 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf
2025-09-29 19:48:42.014084 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf
2025-09-29 19:48:42.014102 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf
2025-09-29 19:48:42.014119 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf
2025-09-29 19:48:42.014136 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf
2025-09-29 19:48:42.014152 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf
2025-09-29 19:48:42.402733 | controller | changed: .d..t...... ./
2025-09-29 19:48:42.798399 | controller | changed: .d..t...... ./
2025-09-29 19:48:42.812277 | 
2025-09-29 19:48:42.812382 | TASK [Return artifact to Zuul]
2025-09-29 19:48:42.840245 | controller | ok
2025-09-29 19:48:42.859080 | 
2025-09-29 19:48:42.859137 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-09-29 19:48:42.859233 | 
2025-09-29 19:48:42.859259 | PLAY RECAP
2025-09-29 19:48:42.859296 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-09-29 19:48:42.859317 | 
2025-09-29 19:48:42.937946 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-09-29 19:48:42.938635 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-09-29 19:48:43.454308 | 
2025-09-29 19:48:43.454440 | PLAY [all]
2025-09-29 19:48:43.473978 | 
2025-09-29 19:48:43.474063 | TASK [include_role : fetch-output]
2025-09-29 19:48:43.502605 | controller | ok
2025-09-29 19:48:43.519935 | 
2025-09-29 19:48:43.520024 | TASK [fetch-output : Set log path for multiple nodes]
2025-09-29 19:48:43.563395 | controller | skipping: Conditional result was False
2025-09-29 19:48:43.568775 | 
2025-09-29 19:48:43.568850 | TASK [fetch-output : Set log path for single node]
2025-09-29 19:48:43.596705 | controller | ok
2025-09-29 19:48:43.601701 | 
2025-09-29 19:48:43.601773 | LOOP [fetch-output : Ensure local output dirs]
2025-09-29 19:48:43.918200 | controller -> localhost | ok: "/var/lib/zuul/builds/867f3ce1761f49a9bf874bee388bd5ba/work/logs"
2025-09-29 19:48:44.094411 | controller -> localhost | ok: "/var/lib/zuul/builds/867f3ce1761f49a9bf874bee388bd5ba/work/artifacts"
2025-09-29 19:48:44.269549 | controller -> localhost | ok: "/var/lib/zuul/builds/867f3ce1761f49a9bf874bee388bd5ba/work/docs"
2025-09-29 19:48:44.280836 | 
2025-09-29 19:48:44.280951 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-09-29 19:48:44.811878 | controller | ok
2025-09-29 19:48:44.812120 | controller | ok: All items complete
2025-09-29 19:48:44.812152 | 
2025-09-29 19:48:45.216424 | controller | ok
2025-09-29 19:48:45.624773 | controller | ok
2025-09-29 19:48:45.640836 | 
2025-09-29 19:48:45.640923 | TASK [include_role : fetch-output-openshift]
2025-09-29 19:48:45.665554 | controller | skipping: Conditional result was False
2025-09-29 19:48:45.671560 | 
2025-09-29 19:48:45.671628 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-09-29 19:48:46.063116 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007095
2025-09-29 19:48:46.263606 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.009320
2025-09-29 19:48:46.293667 | 
2025-09-29 19:48:46.293806 | PLAY [all]
2025-09-29 19:48:46.308582 | 
2025-09-29 19:48:46.308662 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-09-29 19:48:46.733843 | controller | changed
2025-09-29 19:48:46.755903 | 
2025-09-29 19:48:46.755981 | PLAY RECAP
2025-09-29 19:48:46.756046 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-09-29 19:48:46.756076 | 
2025-09-29 19:48:46.841801 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-09-29 19:48:46.842592 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-09-29 19:48:47.379613 | 
2025-09-29 19:48:47.379729 | PLAY [localhost]
2025-09-29 19:48:47.397648 | 
2025-09-29 19:48:47.397724 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-09-29 19:48:47.700285 | localhost | changed
2025-09-29 19:48:47.704947 | 
2025-09-29 19:48:47.705046 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-09-29 19:48:47.722646 | localhost | ok
2025-09-29 19:48:47.730288 | 
2025-09-29 19:48:47.730357 | TASK [add-fileserver : Create SSH private key tempfile]
2025-09-29 19:48:48.031218 | localhost | changed
2025-09-29 19:48:48.036707 | 
2025-09-29 19:48:48.036779 | TASK [add-fileserver : Create SSH private key from secret]
2025-09-29 19:48:48.580565 | localhost | changed
2025-09-29 19:48:48.585317 | 
2025-09-29 19:48:48.585384 | TASK [add-fileserver : Add fileserver ssh key]
2025-09-29 19:48:48.916323 | localhost | Identity added: /var/lib/zuul/builds/867f3ce1761f49a9bf874bee388bd5ba/work/tmp/ansible.oxaocgx4 (/var/lib/zuul/builds/867f3ce1761f49a9bf874bee388bd5ba/work/tmp/ansible.oxaocgx4)
2025-09-29 19:48:48.916493 | localhost | ok: Runtime: 0:00:00.006121
2025-09-29 19:48:48.920521 | 
2025-09-29 19:48:48.920587 | TASK [add-fileserver : Remove SSH private key from disk]
2025-09-29 19:48:49.130142 | localhost | ok: Runtime: 0:00:00.004466
2025-09-29 19:48:49.134715 | 
2025-09-29 19:48:49.134799 | TASK [add-fileserver : Add fileserver to inventory]
2025-09-29 19:48:49.182523 | localhost | changed
2025-09-29 19:48:49.187309 | 
2025-09-29 19:48:49.187379 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-09-29 19:48:49.498013 | localhost | changed
2025-09-29 19:48:49.518001 | 
2025-09-29 19:48:49.518067 | PLAY [localhost]
2025-09-29 19:48:49.529252 | 
2025-09-29 19:48:49.529318 | TASK [Generate bulk log download script]
2025-09-29 19:48:49.546876 | localhost | ok
2025-09-29 19:48:49.558162 | 
2025-09-29 19:48:49.558227 | TASK [local-log-download : Check API endpoint is defined]
2025-09-29 19:48:49.584985 | localhost | ok: All assertions passed
2025-09-29 19:48:49.589229 | 
2025-09-29 19:48:49.589293 | TASK [local-log-download : Create download script]
2025-09-29 19:48:49.953940 | localhost -> localhost | changed
2025-09-29 19:48:49.962238 | 
2025-09-29 19:48:49.962300 | TASK [Register quick-download link]
2025-09-29 19:48:50.000682 | localhost | ok
2025-09-29 19:48:50.032833 | 
2025-09-29 19:48:50.032902 | PLAY [logserver.rdoproject.org]
2025-09-29 19:48:50.042021 | 
2025-09-29 19:48:50.042092 | TASK [Set zuul-log-path fact]
2025-09-29 19:48:50.057529 | logserver.rdoproject.org | ok
2025-09-29 19:48:50.066509 | 
2025-09-29 19:48:50.066574 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-09-29 19:48:50.092356 | logserver.rdoproject.org | ok
2025-09-29 19:48:50.097767 | 
2025-09-29 19:48:50.097828 | TASK [upload-logs : Create log directories]
2025-09-29 19:48:51.950515 | logserver.rdoproject.org | changed
2025-09-29 19:48:51.953676 | 
2025-09-29 19:48:51.953742 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-09-29 19:48:52.170367 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004610
2025-09-29 19:48:52.174787 | 
2025-09-29 19:48:52.174849 | TASK [upload-logs : Upload logs to log server]
2025-09-29 19:48:53.758887 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-09-29 19:48:53.761681 | 
2025-09-29 19:48:53.761751 | LOOP [upload-logs : Compress console log and json output]
2025-09-29 19:48:53.797667 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-29 19:48:53.805654 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-29 19:48:53.818869 | 
2025-09-29 19:48:53.818959 | LOOP [upload-logs : Upload compressed console log and json output]
2025-09-29 19:48:53.853280 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-29 19:48:53.853482 | 
2025-09-29 19:48:53.856809 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-29 19:48:53.867023 | 
2025-09-29 19:48:53.867110 | LOOP [upload-logs : Upload console log and json output]