2025-10-10 11:31:57.755550 | Job console starting...
2025-10-10 11:31:57.772178 | Updating repositories
2025-10-10 11:31:57.839297 | Preparing job workspace
2025-10-10 11:32:05.026046 | Running Ansible setup...
2025-10-10 11:32:10.824562 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-10 11:32:11.449235 | 
2025-10-10 11:32:11.449369 | PLAY [localhost]
2025-10-10 11:32:11.459667 | 
2025-10-10 11:32:11.459822 | TASK [Gathering Facts]
2025-10-10 11:32:12.438195 | localhost | ok
2025-10-10 11:32:12.459488 | 
2025-10-10 11:32:12.459646 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-10 11:32:12.927113 | localhost -> localhost | changed
2025-10-10 11:32:12.934856 | 
2025-10-10 11:32:12.935056 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-10 11:32:13.961070 | localhost -> localhost | changed
2025-10-10 11:32:13.970282 | 
2025-10-10 11:32:13.970350 | TASK [Setup log path fact]
2025-10-10 11:32:13.988599 | localhost | ok
2025-10-10 11:32:14.000114 | 
2025-10-10 11:32:14.000177 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-10 11:32:14.027057 | localhost | ok
2025-10-10 11:32:14.034817 | 
2025-10-10 11:32:14.034888 | TASK [emit-job-header : Print job information]
2025-10-10 11:32:14.090101 | # Job Information
2025-10-10 11:32:14.090379 | Ansible Version: 2.15.12
2025-10-10 11:32:14.090434 | Job: cifmw-molecule-ci_nmstate
2025-10-10 11:32:14.090477 | Pipeline: github-check
2025-10-10 11:32:14.090516 | Executor: ze03.softwarefactory-project.io
2025-10-10 11:32:14.090554 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3381
2025-10-10 11:32:14.090595 | Log URL (when completed): https://logserver.rdoproject.org/710/rdoproject.org/71040a836ab340bab398c10ad4a5cf0a/
2025-10-10 11:32:14.090662 | Event ID: 9d875990-a5cc-11f0-90f9-2bc04dc1346f
2025-10-10 11:32:14.099238 | 
2025-10-10 11:32:14.099373 | LOOP [emit-job-header : Print node information]
2025-10-10 11:32:14.222647 | localhost | ok:
2025-10-10 11:32:14.222858 | localhost | # Node Information
2025-10-10 11:32:14.222887 | localhost | Inventory Hostname: controller
2025-10-10 11:32:14.222912 | localhost | Hostname: np0005479988
2025-10-10 11:32:14.222933 | localhost | Username: zuul
2025-10-10 11:32:14.222954 | localhost | Distro: CentOS 9
2025-10-10 11:32:14.222973 | localhost | Provider: vexxhost-nodepool-tripleo
2025-10-10 11:32:14.222991 | localhost | Region: RegionOne
2025-10-10 11:32:14.223008 | localhost | Label: centos-9-stream-crc-2-48-0-xxl
2025-10-10 11:32:14.223025 | localhost | Product Name: OpenStack Nova
2025-10-10 11:32:14.223043 | localhost | Interface IP: 38.102.83.154
2025-10-10 11:32:14.252799 | 
2025-10-10 11:32:14.253020 | PLAY [all]
2025-10-10 11:32:14.261940 | 
2025-10-10 11:32:14.262027 | TASK [Gather network facts]
2025-10-10 11:32:14.932145 | controller | ok
2025-10-10 11:32:14.948389 | 
2025-10-10 11:32:14.948509 | TASK [include_role : start-zuul-console]
2025-10-10 11:32:14.967318 | controller | ok
2025-10-10 11:32:14.979869 | 
2025-10-10 11:32:14.979990 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-10 11:32:15.571282 | controller | ok
2025-10-10 11:32:15.581384 | 
2025-10-10 11:32:15.581462 | TASK [include_role : add-build-sshkey]
2025-10-10 11:32:15.601045 | controller | ok
2025-10-10 11:32:15.618272 | 
2025-10-10 11:32:15.618380 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-10 11:32:15.876465 | controller -> localhost | ok
2025-10-10 11:32:15.882552 | 
2025-10-10 11:32:15.882622 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-10 11:32:15.903577 | controller | ok
2025-10-10 11:32:15.920041 | controller | included: /var/lib/zuul/builds/71040a836ab340bab398c10ad4a5cf0a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-10 11:32:15.926274 | 
2025-10-10 11:32:15.926349 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-10 11:32:16.571081 | controller -> localhost | Generating public/private rsa key pair.
2025-10-10 11:32:16.571475 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/71040a836ab340bab398c10ad4a5cf0a/work/71040a836ab340bab398c10ad4a5cf0a_id_rsa.
2025-10-10 11:32:16.571604 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/71040a836ab340bab398c10ad4a5cf0a/work/71040a836ab340bab398c10ad4a5cf0a_id_rsa.pub.
2025-10-10 11:32:16.571657 | controller -> localhost | The key fingerprint is:
2025-10-10 11:32:16.571703 | controller -> localhost | SHA256:9NKsVNQC3rwpT/DJoogfpcfXoP5nWJB4xrHyjv2HPcQ zuul-build-sshkey
2025-10-10 11:32:16.571796 | controller -> localhost | The key's randomart image is:
2025-10-10 11:32:16.571841 | controller -> localhost | +---[RSA 3072]----+
2025-10-10 11:32:16.571881 | controller -> localhost | |        ....     |
2025-10-10 11:32:16.571921 | controller -> localhost | |       ..+. .    |
2025-10-10 11:32:16.571961 | controller -> localhost | |       o+++.     |
2025-10-10 11:32:16.572000 | controller -> localhost | |      o.BO +     |
2025-10-10 11:32:16.572037 | controller -> localhost | |      .=S.@.     |
2025-10-10 11:32:16.572074 | controller -> localhost | |   . = +.X. E    |
2025-10-10 11:32:16.572111 | controller -> localhost | |  . + =+ooo+     |
2025-10-10 11:32:16.572154 | controller -> localhost | |   . +..+ + +    |
2025-10-10 11:32:16.572193 | controller -> localhost | |    . ...+.. .   |
2025-10-10 11:32:16.572231 | controller -> localhost | +----[SHA256]-----+
2025-10-10 11:32:16.572320 | controller -> localhost | ok: Runtime: 0:00:00.200456
2025-10-10 11:32:16.591942 | 
2025-10-10 11:32:16.592097 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-10 11:32:16.626718 | controller | ok
2025-10-10 11:32:16.640317 | controller | included: /var/lib/zuul/builds/71040a836ab340bab398c10ad4a5cf0a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-10 11:32:16.662455 | 
2025-10-10 11:32:16.662592 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-10 11:32:16.697686 | controller | skipping: Conditional result was False
2025-10-10 11:32:16.703209 | 
2025-10-10 11:32:16.703277 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-10 11:32:17.422115 | controller | changed
2025-10-10 11:32:17.433008 | 
2025-10-10 11:32:17.433125 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-10 11:32:17.893565 | controller | ok
2025-10-10 11:32:17.903564 | 
2025-10-10 11:32:17.903738 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-10 11:32:19.858378 | controller | changed
2025-10-10 11:32:19.866141 | 
2025-10-10 11:32:19.866430 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-10 11:32:21.918286 | controller | changed
2025-10-10 11:32:21.924212 | 
2025-10-10 11:32:21.924301 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-10 11:32:21.959473 | controller | skipping: Conditional result was False
2025-10-10 11:32:21.965456 | 
2025-10-10 11:32:21.965528 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-10 11:32:22.404182 | controller -> localhost | changed
2025-10-10 11:32:22.416292 | 
2025-10-10 11:32:22.416440 | TASK [add-build-sshkey : Add back temp key]
2025-10-10 11:32:22.698441 | controller -> localhost | Identity added: /var/lib/zuul/builds/71040a836ab340bab398c10ad4a5cf0a/work/71040a836ab340bab398c10ad4a5cf0a_id_rsa (zuul-build-sshkey)
2025-10-10 11:32:22.698782 | controller -> localhost | ok: Runtime: 0:00:00.011300
2025-10-10 11:32:22.706772 | 
2025-10-10 11:32:22.706901 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-10 11:32:23.311153 | controller | ok
2025-10-10 11:32:23.371144 | 
2025-10-10 11:32:23.371298 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-10 11:32:23.397542 | controller | skipping: Conditional result was False
2025-10-10 11:32:23.412296 | 
2025-10-10 11:32:23.412473 | TASK [include_role : validate-host]
2025-10-10 11:32:23.436080 | controller | ok
2025-10-10 11:32:23.465178 | 
2025-10-10 11:32:23.465332 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-10 11:32:23.499382 | controller | ok
2025-10-10 11:32:23.510169 | 
2025-10-10 11:32:23.510313 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-10 11:32:23.803751 | controller -> localhost | ok
2025-10-10 11:32:23.810261 | 
2025-10-10 11:32:23.810374 | TASK [validate-host : Collect information about the host]
2025-10-10 11:32:25.811106 | controller | ok
2025-10-10 11:32:25.829609 | 
2025-10-10 11:32:25.829754 | TASK [validate-host : Sanitize hostname]
2025-10-10 11:32:25.901793 | controller | ok
2025-10-10 11:32:25.906963 | 
2025-10-10 11:32:25.907030 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-10 11:32:26.392691 | controller -> localhost | changed
2025-10-10 11:32:26.404941 | 
2025-10-10 11:32:26.405104 | TASK [validate-host : Collect information about zuul worker]
2025-10-10 11:32:26.993786 | controller | ok
2025-10-10 11:32:27.002442 | 
2025-10-10 11:32:27.002610 | TASK [validate-host : Write out all zuul information for each host]
2025-10-10 11:32:27.576676 | controller -> localhost | changed
2025-10-10 11:32:27.599424 | 
2025-10-10 11:32:27.599601 | TASK [include_role : prepare-workspace-openshift]
2025-10-10 11:32:27.626497 | controller | skipping: Conditional result was False
2025-10-10 11:32:27.641372 | 
2025-10-10 11:32:27.641545 | TASK [include_role : remove-zuul-sshkey]
2025-10-10 11:32:27.668098 | controller | skipping: Conditional result was False
2025-10-10 11:32:27.681923 | 
2025-10-10 11:32:27.682102 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-10 11:32:28.084903 | controller | ok: "logs"
2025-10-10 11:32:28.085351 | controller | ok: All items complete
2025-10-10 11:32:28.085412 | 
2025-10-10 11:32:28.439261 | controller | ok: "artifacts"
2025-10-10 11:32:28.833857 | controller | ok: "docs"
2025-10-10 11:32:28.847883 | 
2025-10-10 11:32:28.848070 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-10 11:32:29.269099 | controller | changed: "logs"
2025-10-10 11:32:29.675239 | controller | changed: "artifacts"
2025-10-10 11:32:30.077123 | controller | changed: "docs"
2025-10-10 11:32:30.117034 | 
2025-10-10 11:32:30.117179 | PLAY RECAP
2025-10-10 11:32:30.117240 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-10 11:32:30.117277 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-10 11:32:30.117303 | 
2025-10-10 11:32:30.255622 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-10 11:32:30.256669 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-10 11:32:30.921687 | 
2025-10-10 11:32:30.921814 | PLAY [all]
2025-10-10 11:32:30.942984 | 
2025-10-10 11:32:30.943105 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-10 11:32:31.002917 | controller | ok
2025-10-10 11:32:31.008167 | 
2025-10-10 11:32:31.008246 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-10 11:32:31.621141 | controller | changed
2025-10-10 11:32:31.630791 | 
2025-10-10 11:32:31.630924 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-10 11:32:33.902949 | controller | changed
2025-10-10 11:32:33.926124 | 
2025-10-10 11:32:33.926279 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-10-10 11:32:34.639020 | controller | changed:
2025-10-10 11:32:34.639367 | controller | {
2025-10-10 11:32:34.639430 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-10-10 11:32:34.639490 | controller | }
2025-10-10 11:32:35.097602 | controller | changed:
2025-10-10 11:32:35.097721 | controller | {
2025-10-10 11:32:35.097791 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-10-10 11:32:35.097821 | controller | }
2025-10-10 11:32:35.529389 | controller | changed:
2025-10-10 11:32:35.529562 | controller | {
2025-10-10 11:32:35.529618 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-10-10 11:32:35.529664 | controller | }
2025-10-10 11:32:35.935048 | controller | changed:
2025-10-10 11:32:35.935198 | controller | {
2025-10-10 11:32:35.935248 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-10-10 11:32:35.935287 | controller | }
2025-10-10 11:32:36.377873 | controller | changed:
2025-10-10 11:32:36.378023 | controller | {
2025-10-10 11:32:36.378073 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-10-10 11:32:36.378113 | controller | }
2025-10-10 11:32:36.842828 | controller | changed:
2025-10-10 11:32:36.842991 | controller | {
2025-10-10 11:32:36.843042 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-10-10 11:32:36.843083 | controller | }
2025-10-10 11:32:37.261051 | controller | changed:
2025-10-10 11:32:37.261181 | controller | {
2025-10-10 11:32:37.261217 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDLOQd4ZLtkZXQGY6UwAr/06ppWQK4fDO3HaqxPk98csyOCBXsliSKK39Bso828+5srIXiW7aI6aC9P5mwi4mUZlGPfJlQbfrcGvY+b/SocuvaGK+1RrHLoJCT52LBhwgrzlXio2jeksZeein8iaTrhsPrOAs7KggIL/rB9hEiB3NaOPWhhoCP4vlW6MEMExGcqB/1FVxXFBPnLkEyW0Lk7ycVflZl2ocRxbfjZi0+tI1Wlinp8PvSQSc/WVrAcDgKjc/mB4ODPOyYy3G8FHgfMsrXSDEyjBKgLKMsdCrAUcqJQWjkqXleXSYOV4q3pzL+9umK+q/e3P/bIoSFQzmJKTU1eDfuvPXmow9F5H54fii/Da7ezlMJ+wPGHJrRAkmzvMbALy7xwswLhZMkOGNtRcPqaKYRmIBKpw3o6bCTtcNUHOtOQnzwY8JzrM2eBWJBXAANYw+9/ho80JIiwhg29CFNpVBuHbql2YxJQNrnl90guN65rYNpDxdIluweyUf8= anbanerj@kaermorhen"
2025-10-10 11:32:37.261250 | controller | }
2025-10-10 11:32:37.648615 | controller | changed:
2025-10-10 11:32:37.648812 | controller | {
2025-10-10 11:32:37.648849 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC3VwV8Im9kRm49lt3tM36hj4Zv27FxGo4C1Q/0jqhzFmHY7RHbmeRr8ObhwWoHjXSozKWg8FL5ER0z3hTwL0W6lez3sL7hUaCmSuZmG5Hnl3x4vTSxDI9JZ/Y65rtYiiWQo2fC5xJhU/4+0e5e/pseCm8cKRSu+SaxhO+sd6FDojA2x1BzOzKiQRDy/1zWGp/cZkxcEuB1wHI5LMzN03c67vmbu+fhZRAUO4dQkvcnj2LrhQtpa+ytvnSjr8icMDosf1OsbSffwZFyHB/hfWGAfe0eIeSA2XPraxiPknXxiPKx2MJsaUTYbsZcm3EjFdHBBMumw5rBI74zLrMRvCO9GwBEmGT4rFng1nP+yw5DB8sn2zqpOsPg1LYRwCPOUveC13P6pgsZZPh812e8v5EKnETct+5XI3dVpdw6CnNiLwAyVAF15DJvBGT/u1k0Myg/bQn+Gv9k2MSj6LvQmf6WbZu2Wgjm30z3FyCneBqTL7mLF19YXzeC0ufHz5pnO1E= dasm@fedora"
2025-10-10 11:32:37.648877 | controller | }
2025-10-10 11:32:38.142550 | controller | changed:
2025-10-10 11:32:38.143105 | controller | {
2025-10-10 11:32:38.143195 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-10-10 11:32:38.143242 | controller | }
2025-10-10 11:32:38.573796 | controller | changed:
2025-10-10 11:32:38.573900 | controller | {
2025-10-10 11:32:38.573923 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-10-10 11:32:38.573942 | controller | }
2025-10-10 11:32:39.043389 | controller | changed:
2025-10-10 11:32:39.043524 | controller | {
2025-10-10 11:32:39.043576 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-10-10 11:32:39.043619 | controller | }
2025-10-10 11:32:39.469267 | controller | changed:
2025-10-10 11:32:39.469366 | controller | {
2025-10-10 11:32:39.469389 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-10-10 11:32:39.469407 | controller | }
2025-10-10 11:32:39.873279 | controller | changed:
2025-10-10 11:32:39.873430 | controller | {
2025-10-10 11:32:39.873481 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-10-10 11:32:39.873521 | controller | }
2025-10-10 11:32:40.273822 | controller | changed:
2025-10-10 11:32:40.274010 | controller | {
2025-10-10 11:32:40.274065 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-10-10 11:32:40.274107 | controller | }
2025-10-10 11:32:40.712973 | controller | changed:
2025-10-10 11:32:40.713097 | controller | {
2025-10-10 11:32:40.713126 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-10-10 11:32:40.713150 | controller | }
2025-10-10 11:32:41.156814 | controller | changed:
2025-10-10 11:32:41.156929 | controller | {
2025-10-10 11:32:41.156961 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-10-10 11:32:41.156984 | controller | }
2025-10-10 11:32:41.613774 | controller | changed:
2025-10-10 11:32:41.613890 | controller | {
2025-10-10 11:32:41.613919 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQCfNtF7NvKl915TGsGGoseUb06Hj8L/S4toWf0hExeY+F00woL6NvBlJD0nDct+P5a22I4EhvoQCRQ8reaPCm1lybR3uiRIJsj+8zkVvLwby9LXzfZorlNG9ofjd00FEmB09uW/YvTl6Q9XwwwX6tInzIOv3TMqTHHGOL74ibbj8J/FJR0cFEyj0z4WQRvtkh32xAHl83gbuINryMt0sqRI+clj2381NKL55DRLQrVw0gsfqqxiHAnXg21qWmc4J+b9e9kiuAFQjcjwTVkwJCcg3xbPwC/qokYRby/Y5S40UUd7/jEARGXT7RZgpzTuDd1oZiCVrnrqJNPaMNdVv5MLeFdf1B7iIe5aa/fGouX7AO4SdKhZUdnJmCFAGvjC6S3JMZ2wAcUl+OHnssfmdj7XL50cLo27vjuzMtLAgSqi6N99m92WCF2s8J9aVzszX7Xz9OKZCeGsiVJp3/NdABKzSEAyM9xBD/5Vho894Sav+otpySHe3p6RUTgbB5Zu8VyZRZ/UtB3ueXxyo764yrc6qWIDqrehm84Xm9g+/jpIBzGPl07NUNJpdt/6Sgf9RIKXw/7XypO5yZfUcuFNGTxLfqjTNrtgLZNcjfav6sSdVXVcMPL//XNuRdKmVFaO76eV/oGMQGr1fGcCD+N+CpI7+Q+fCNB6VFWG4nZFuI/Iuw== averdagu@redhat.com"
2025-10-10 11:32:41.613946 | controller | }
2025-10-10 11:32:42.062583 | controller | changed:
2025-10-10 11:32:42.062705 | controller | {
2025-10-10 11:32:42.062774 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDq8l27xI+QlQVdS4djp9ogSoyrNE2+Ox6vKPdhSNL1J3PE5w+WCSvMz9A5gnNuH810zwbekEApbxTze/gLQJwBHA52CChfURpXrFaxY7ePXRElwKAL3mJfzBWY/c5jnNL9TCVmFJTGZkFZP3Nh+BMgZvL6xBkt3WKm6Uq18qzd9XeKcZusrA+O+uLv1fVeQnadY9RIqOCyeFYCzLWrUfTyE8x/XG0hAWIM7qpnF2cALQS2h9n4hW5ybiUN790H08wf9hFwEf5nxY9Z9dVkPFQiTSGKNBzmnCXU9skxS/xhpFjJ5duGSZdtAHe9O+nGZm9c67hxgtf8e5PDuqAdXEv2cf6e3VBAt+Bz8EKI3yosTj0oZHfwr42Yzb1l/SKy14Rggsrc9KAQlrGXan6+u2jcQqqx7l+SWmnpFiWTV9u5cWj2IgOhApOitmRBPYqk9rE2usfO0hLn/Pj/R/Nau4803e1/EikdLE7Ps95s9mX5jRDjAoUa2JwFF5RsVFyL910= ashigupt@ashigupt.remote.csb"
2025-10-10 11:32:42.062805 | controller | }
2025-10-10 11:32:42.453103 | controller | changed:
2025-10-10 11:32:42.453253 | controller | {
2025-10-10 11:32:42.453302 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-10-10 11:32:42.453507 | controller | }
2025-10-10 11:32:42.898766 | controller | changed:
2025-10-10 11:32:42.898893 | controller | {
2025-10-10 11:32:42.898926 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-10-10 11:32:42.898955 | controller | }
2025-10-10 11:32:43.374614 | controller | changed:
2025-10-10 11:32:43.374853 | controller | {
2025-10-10 11:32:43.374913 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-10-10 11:32:43.374955 | controller | }
2025-10-10 11:32:43.790427 | controller | changed:
2025-10-10 11:32:43.790552 | controller | {
2025-10-10 11:32:43.790590 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-10-10 11:32:43.790622 | controller | }
2025-10-10 11:32:44.234977 | controller | changed:
2025-10-10 11:32:44.235100 | controller | {
2025-10-10 11:32:44.235137 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQDZdI7t1cxYx65heVI24HTV4F7oQLW1zyfxHreL2TIJKxjyrUUKIFEUmTutcBlJRLNT2Eoix6x1sOw9YrchloCLcn//SGfTElr9mSc5jbjb7QXEU+zJMhtxyEJ1Po3CUGnj7ckiIXw7wcawZtrEOAQ9pH3ExYCJcEMiyNjRQZCxT3tPK+S4B95EWh5Fsrz9CkwpjNRPPH7LigCeQTM3Wc7r97utAslBUUvYceDSLA7rMgkitJE38b7rZBeYzsGQ8YYUBjTCtehqQXxCRjizbHWaaZkBU+N3zkKB6n/iCNGIO690NK7A/qb6msTijiz1PeuM8ThOsi9qXnbX5v0PoTpcFSojV7NHAQ71f0XXuS43FhZctT+Dcx44dT8Fb5vJu2cJGrk+qF8ZgJYNpRS7gPg0EG2EqjK7JMf9ULdjSu0r+KlqIAyLvtzT4eOnQipoKlb/WG5D/0ohKv7OMQ352ggfkBFIQsRXyyTCT98Ft9juqPuahi3CAQmP4H9dyE+7+Kz437PEtsxLmfm6naNmWi7Ee1DqWPwS8rEajsm4sNM4wW9gdBboJQtc0uZw0DfLj1I9r3Mc8Ol0jYtz0yNQDSzVLrGCaJlC311trU70tZ+ZkAVV6Mn8lOhSbj1cK0lvSr6ZK4dgqGl3I1eTZJJhbLNdg7UOVaiRx9543+C/p/As7w== brjackma@redhat.com"
2025-10-10 11:32:44.235169 | controller | }
2025-10-10 11:32:44.672438 | controller | changed:
2025-10-10 11:32:44.672556 | controller | {
2025-10-10 11:32:44.672586 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-10-10 11:32:44.672611 | controller | }
2025-10-10 11:32:45.121485 | controller | changed:
2025-10-10 11:32:45.121640 | controller | {
2025-10-10 11:32:45.121690 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-10-10 11:32:45.121756 | controller | }
2025-10-10 11:32:45.586565 | controller | changed:
2025-10-10 11:32:45.586691 | controller | {
2025-10-10 11:32:45.586757 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-10-10 11:32:45.586796 | controller | }
2025-10-10 11:32:45.617510 | 
2025-10-10 11:32:45.617663 | TASK [Set timezone to UTC]
2025-10-10 11:32:46.437705 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-10-10 11:32:46.452654 | 
2025-10-10 11:32:46.452892 | TASK [Create nodepool directory]
2025-10-10 11:32:46.890089 | controller | changed
2025-10-10 11:32:46.900064 | 
2025-10-10 11:32:46.900184 | TASK [Create nodepool sub_nodes file]
2025-10-10 11:32:48.641219 | controller | changed
2025-10-10 11:32:48.648843 | 
2025-10-10 11:32:48.648941 | TASK [Create nodepool sub_nodes_private file]
2025-10-10 11:32:50.359140 | controller | changed
2025-10-10 11:32:50.366188 | 
2025-10-10 11:32:50.366339 | LOOP [Populate nodepool sub_nodes file]
2025-10-10 11:32:50.400435 | 
2025-10-10 11:32:50.400635 | LOOP [Populate nodepool sub_nodes_private file]
2025-10-10 11:32:50.436034 | 
2025-10-10 11:32:50.436240 | TASK [Create nodepool primary file]
2025-10-10 11:32:50.461974 | controller | skipping: Conditional result was False
2025-10-10 11:32:50.469246 | 
2025-10-10 11:32:50.469351 | TASK [Create nodepool node_private for this node]
2025-10-10 11:32:52.173191 | controller | changed
2025-10-10 11:32:52.186895 | 
2025-10-10 11:32:52.187029 | LOOP [Copy ssh keys to nodepool directory]
2025-10-10 11:32:52.752207 | controller | ok: Item: id_rsa Runtime: 0:00:00.011337
2025-10-10 11:32:52.752417 | 
2025-10-10 11:32:53.113314 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.010046
2025-10-10 11:32:53.133341 | 
2025-10-10 11:32:53.133523 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-10-10 11:32:54.925749 | controller | changed
2025-10-10 11:32:54.934511 | 
2025-10-10 11:32:54.934614 | TASK [Validate sudoers config after edits]
2025-10-10 11:32:55.478195 | controller | /etc/sudoers: parsed OK
2025-10-10 11:32:55.478438 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-10-10 11:32:55.478475 | controller | /etc/sudoers.d/zuul: parsed OK
2025-10-10 11:32:55.478570 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-10-10 11:32:55.526292 | controller | ok: Runtime: 0:00:00.011292
2025-10-10 11:32:55.535343 | 
2025-10-10 11:32:55.535571 | TASK [Show the environment passed in to job shell scripts]
2025-10-10 11:32:55.955254 | controller | SHELL=/bin/bash
2025-10-10 11:32:55.955312 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-10-10 11:32:55.955329 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-10-10 11:32:55.955341 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/81/3381/aba711d0a7d5f05d3615233cabf8c83406966272
2025-10-10 11:32:55.955350 | controller | PWD=/home/zuul
2025-10-10 11:32:55.955358 | controller | ZUUL_PIPELINE=github-check
2025-10-10 11:32:55.955366 | controller | LOGNAME=zuul
2025-10-10 11:32:55.955375 | controller | XDG_SESSION_TYPE=tty
2025-10-10 11:32:55.955383 | controller | _=/usr/bin/env
2025-10-10 11:32:55.955392 | controller | MOTD_SHOWN=pam
2025-10-10 11:32:55.955400 | controller | HOME=/home/zuul
2025-10-10 11:32:55.955408 | controller | LANG=en_US.UTF-8
2025-10-10 11:32:55.955417 | controller | SSH_CONNECTION=38.102.83.114 52500 38.102.83.154 22
2025-10-10 11:32:55.955425 | controller | TOX_TESTENV_PASSENV=ZUUL_UUID ZUUL_PROJECT ZUUL_SHORT_PROJECT_NAME ZUUL_PIPELINE ZUUL_VOTING WORKSPACE BUILD_TIMEOUT ZUUL_BRANCH ZUUL_CHANGES ZUUL_CHANGE_IDS ZUUL_CHANGE ZUUL_PATCHSET
2025-10-10 11:32:55.955437 | controller | ZUUL_CHANGE_IDS=3381,aba711d0a7d5f05d3615233cabf8c83406966272
2025-10-10 11:32:55.955446 | controller | WORKSPACE=/home/zuul/workspace
2025-10-10 11:32:55.955454 | controller | XDG_SESSION_CLASS=user
2025-10-10 11:32:55.955462 | controller | SELINUX_ROLE_REQUESTED=
2025-10-10 11:32:55.955471 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-10-10 11:32:55.955479 | controller | USER=zuul
2025-10-10 11:32:55.955488 | controller | ZUUL_VOTING=True
2025-10-10 11:32:55.955496 | controller | BUILD_TIMEOUT=1800000
2025-10-10 11:32:55.955505 | controller | SELINUX_USE_CURRENT_RANGE=
2025-10-10 11:32:55.955513 | controller | SHLVL=1
2025-10-10 11:32:55.955521 | controller | ZUUL_PATCHSET=aba711d0a7d5f05d3615233cabf8c83406966272
2025-10-10 11:32:55.955530 | controller | XDG_SESSION_ID=1
2025-10-10 11:32:55.955538 | controller | ZUUL_BRANCH=main
2025-10-10 11:32:55.955546 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-10-10 11:32:55.955555 | controller | SSH_CLIENT=38.102.83.114 52500 22
2025-10-10 11:32:55.955572 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-10-10 11:32:55.955588 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-10-10 11:32:55.955603 | controller | which_declare=declare -f
2025-10-10 11:32:55.955618 | controller | PATH=/home/zuul/.crc/bin/oc:/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-10-10 11:32:55.955633 | controller | SELINUX_LEVEL_REQUESTED=
2025-10-10 11:32:55.955679 | controller | ZUUL_CHANGE=3381
2025-10-10 11:32:55.955690 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-10-10 11:32:55.955698 | controller | ZUUL_UUID=71040a836ab340bab398c10ad4a5cf0a
2025-10-10 11:32:55.955707 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-10-10 11:32:55.955715 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-10-10 11:32:55.955724 | controller | }
2025-10-10 11:32:56.091252 | controller | ok: Runtime: 0:00:00.010398
2025-10-10 11:32:56.096906 | 
2025-10-10 11:32:56.096973 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-10-10 11:32:56.121132 | controller | skipping: Conditional result was False
2025-10-10 11:32:56.126824 | 
2025-10-10 11:32:56.126891 | TASK [Symlink /home/zuul-worker/workspace]
2025-10-10 11:32:56.660353 | controller | skipping: Conditional result was False
2025-10-10 11:32:56.666752 | 
2025-10-10 11:32:56.666875 | TASK [Ensure legacy workspace directory]
2025-10-10 11:32:57.027565 | controller | changed
2025-10-10 11:32:57.048253 | 
2025-10-10 11:32:57.048345 | PLAY RECAP
2025-10-10 11:32:57.048404 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-10 11:32:57.048442 | 
2025-10-10 11:32:57.188491 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-10 11:32:57.190193 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/crc/podman.yaml@master]
2025-10-10 11:32:57.904028 | 
2025-10-10 11:32:57.904144 | PLAY [all,!compute]
2025-10-10 11:32:57.925307 | 
2025-10-10 11:32:57.925433 | TASK [Enable container-tools rhel-modules for c8/crc node]
2025-10-10 11:32:58.462656 | controller | skipping: Conditional result was False
2025-10-10 11:32:58.475334 | 
2025-10-10 11:32:58.475543 | TASK [Install podman]
2025-10-10 11:32:58.534261 | controller | skipping: Conditional result was False
2025-10-10 11:32:58.548397 | 
2025-10-10 11:32:58.548593 | TASK [Set var name for quay login zuul secret]
2025-10-10 11:32:58.606859 | controller | skipping: Conditional result was False
2025-10-10 11:32:58.622242 | 
2025-10-10 11:32:58.622434 | TASK [Print the username]
2025-10-10 11:32:59.185435 | controller | skipping: Conditional result was False
2025-10-10 11:32:59.198208 | 
2025-10-10 11:32:59.198385 | TASK [Fail when user or password is not set]
2025-10-10 11:32:59.235292 | controller | skipping: Conditional result was False
2025-10-10 11:32:59.247133 | 
2025-10-10 11:32:59.247290 | TASK [Set vars for quay login]
2025-10-10 11:32:59.300832 | 
2025-10-10 11:32:59.301192 | LOOP [Perform container registry login(s) with podman]
2025-10-10 11:32:59.364865 | 
2025-10-10 11:32:59.365202 | LOOP [Perform container registry login(s) with buildah]
2025-10-10 11:32:59.428633 | 
2025-10-10 11:32:59.428975 | TASK [Set Insecure registry for content provider]
2025-10-10 11:32:59.489772 | controller | skipping: Conditional result was False
2025-10-10 11:32:59.535206 | 
2025-10-10 11:32:59.535411 | PLAY RECAP
2025-10-10 11:32:59.535536 | controller | ok: 0 changed: 0 unreachable: 0 failed: 0 skipped: 9 rescued: 0 ignored: 0
2025-10-10 11:32:59.535613 | 
2025-10-10 11:32:59.664834 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/crc/podman.yaml@master]
2025-10-10 11:32:59.665964 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/crc/simple-start.yaml@master]
2025-10-10 11:33:00.280526 | 
2025-10-10 11:33:00.280703 | PLAY [Prefer ipv4 over ipv6]
2025-10-10 11:33:00.301136 | 
2025-10-10 11:33:00.301234 | TASK [Configure /etc/gai.conf to prever ipv4 over ipv6]
2025-10-10 11:33:00.377854 | controller | skipping: Conditional result was False
2025-10-10 11:33:00.400636 | 
2025-10-10 11:33:00.400773 | PLAY [controller]
2025-10-10 11:33:00.417508 | 
2025-10-10 11:33:00.417659 | TASK [Fail when openshift_pull_sec not provided]
2025-10-10 11:33:00.452215 | controller | skipping: Conditional result was False
2025-10-10 11:33:00.458416 | 
2025-10-10 11:33:00.458479 | TASK [Clone repos in the job workspace]
2025-10-10 11:33:00.487011 | controller | ok
2025-10-10 11:33:00.514347 | 
2025-10-10 11:33:00.514504 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-10 11:33:01.076967 | controller | ok
2025-10-10 11:33:01.100897 | 
2025-10-10 11:33:01.101083 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-10 11:33:05.835788 | controller | Output suppressed because no_log was given
2025-10-10 11:33:05.849132 | 
2025-10-10 11:33:05.849238 | TASK [Create pull-secret.txt file]
2025-10-10 11:33:07.772271 | controller | Output suppressed because no_log was given
2025-10-10 11:33:07.783574 | 
2025-10-10 11:33:07.783809 | TASK [Apply CRC features and print image build date]
2025-10-10 11:33:07.812590 | controller | ok
2025-10-10 11:33:07.826098 | controller | included: /var/lib/zuul/builds/71040a836ab340bab398c10ad4a5cf0a/trusted/project_0/review.rdoproject.org/config/playbooks/crc/features.yaml
2025-10-10 11:33:07.836300 | 
2025-10-10 11:33:07.836404 | TASK [Set additional parameters for crc - telemetry]
2025-10-10 11:33:08.375606 | controller | skipping: Conditional result was False
2025-10-10 11:33:08.382377 | 
2025-10-10 11:33:08.382482 | TASK [Set additional parameters for crc - monitoring]
2025-10-10 11:33:08.913716 | controller | skipping: Conditional result was False
2025-10-10 11:33:08.919508 | 
2025-10-10 11:33:08.919583 | TASK [Set minimum required memory to run the CRC when monitoring enabled]
2025-10-10 11:33:09.487381 | controller | skipping: Conditional result was False
2025-10-10 11:33:09.500282 | 
2025-10-10 11:33:09.500457 | TASK [Set additional parameters for crc - enable microshift preset]
2025-10-10 11:33:10.050901 | controller | skipping: Conditional result was False
2025-10-10 11:33:10.064277 | 
2025-10-10 11:33:10.064460 | TASK [Set additional parameters for crc - enable okd preset]
2025-10-10 11:33:10.607472 | controller | skipping: Conditional result was False
2025-10-10 11:33:10.616198 | 
2025-10-10 11:33:10.616305 | TASK [Delete the cluster if there's a non-default bundle URL]
2025-10-10 11:33:11.157993 | controller | skipping: Conditional result was False
2025-10-10 11:33:11.166199 | 
2025-10-10 11:33:11.166328 | TASK [Execute crc start command]
2025-10-10 11:37:11.607690 | controller | ok: Runtime: 0:03:59.866332
2025-10-10 11:37:11.618851 | 
2025-10-10 11:37:11.618978 | TASK [Verify that OpenShift is up and running]
2025-10-10 11:37:11.648672 | controller | ok
2025-10-10 11:37:11.696125 | controller | included: /var/lib/zuul/builds/71040a836ab340bab398c10ad4a5cf0a/trusted/project_0/review.rdoproject.org/config/playbooks/crc/verify_openshift_start.yaml
2025-10-10 11:37:11.706093 | 
2025-10-10 11:37:11.706205 | TASK [Create script to login and verify services]
2025-10-10 11:37:13.022920 | controller | changed
2025-10-10 11:37:13.028859 | 
2025-10-10 11:37:13.028957 | TASK [Ensure that user is logged]
2025-10-10 11:37:13.377873 | controller | Checking login to the cluster 1...
2025-10-10 11:37:14.415189 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:37:14.471574 | controller |
2025-10-10 11:37:14.471708 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:37:14.481426 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:37:19.483934 | controller | Checking login to the cluster 2...
2025-10-10 11:37:19.669678 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:37:19.689410 | controller |
2025-10-10 11:37:19.689484 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:37:19.696509 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:37:24.700142 | controller | Checking login to the cluster 3...
2025-10-10 11:37:24.866379 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:37:24.892386 | controller |
2025-10-10 11:37:24.892482 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:37:24.903818 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:37:29.907119 | controller | Checking login to the cluster 4...
2025-10-10 11:37:30.050128 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:37:30.073882 | controller |
2025-10-10 11:37:30.073958 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:37:30.082790 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:37:35.085118 | controller | Checking login to the cluster 5...
2025-10-10 11:37:35.255122 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:37:35.283906 | controller |
2025-10-10 11:37:35.284010 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:37:35.292952 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:37:40.296244 | controller | Checking login to the cluster 6...
2025-10-10 11:37:40.418224 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:37:40.479520 | controller |
2025-10-10 11:37:40.479616 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503
2025-10-10 11:37:40.484632 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:37:45.486824 | controller | Checking login to the cluster 7...
2025-10-10 11:37:45.637258 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:37:45.674469 | controller |
2025-10-10 11:37:45.674559 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503
2025-10-10 11:37:45.681893 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:37:50.684779 | controller | Checking login to the cluster 8...
2025-10-10 11:37:50.841557 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:37:50.887993 | controller |
2025-10-10 11:37:50.888089 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503
2025-10-10 11:37:50.892695 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:37:55.896062 | controller | Checking login to the cluster 9...
2025-10-10 11:37:56.054118 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:37:56.099448 | controller |
2025-10-10 11:37:56.099562 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503
2025-10-10 11:37:56.106181 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:38:01.109314 | controller | Checking login to the cluster 10...
2025-10-10 11:38:01.241204 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:38:01.299870 | controller |
2025-10-10 11:38:01.299952 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503
2025-10-10 11:38:01.305924 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:38:06.308461 | controller | Checking login to the cluster 11...
2025-10-10 11:38:06.447168 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:38:06.520594 | controller |
2025-10-10 11:38:06.520712 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503
2025-10-10 11:38:06.527112 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:38:11.531528 | controller | Checking login to the cluster 12...
2025-10-10 11:38:11.702362 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:38:11.805718 | controller |
2025-10-10 11:38:11.805825 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503
2025-10-10 11:38:11.816954 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:38:16.821441 | controller | Checking login to the cluster 13...
2025-10-10 11:38:17.025757 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:38:17.091860 | controller |
2025-10-10 11:38:17.091972 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503
2025-10-10 11:38:17.100426 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:38:22.103966 | controller | Checking login to the cluster 14...
2025-10-10 11:38:22.284954 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:38:22.377711 | controller |
2025-10-10 11:38:22.377899 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:38:22.383942 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:38:27.386588 | controller | Checking login to the cluster 15...
2025-10-10 11:38:27.595246 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:38:27.647995 | controller |
2025-10-10 11:38:27.648089 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:38:27.653191 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:38:32.657940 | controller | Checking login to the cluster 16...
2025-10-10 11:38:32.861421 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:38:32.928202 | controller |
2025-10-10 11:38:32.928330 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:38:32.940977 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:38:37.946164 | controller | Checking login to the cluster 17...
2025-10-10 11:38:38.116399 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:38:38.169068 | controller |
2025-10-10 11:38:38.169190 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:38:38.176424 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:38:43.180326 | controller | Checking login to the cluster 18...
2025-10-10 11:38:43.381787 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:38:43.798316 | controller |
2025-10-10 11:38:43.798420 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:38:43.806552 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:38:48.809619 | controller | Checking login to the cluster 19...
2025-10-10 11:38:49.028445 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:38:49.158271 | controller |
2025-10-10 11:38:49.158398 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:38:49.166825 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:38:54.169635 | controller | Checking login to the cluster 20...
2025-10-10 11:38:55.151566 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:38:56.414102 | controller |
2025-10-10 11:38:56.414203 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:38:56.419001 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:39:01.422204 | controller | Checking login to the cluster 21...
2025-10-10 11:39:01.621075 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:39:01.734994 | controller |
2025-10-10 11:39:01.735092 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:39:01.749384 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:39:06.754432 | controller | Checking login to the cluster 22...
2025-10-10 11:39:07.510243 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:39:08.419841 | controller |
2025-10-10 11:39:08.419961 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:39:08.428668 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:39:13.432661 | controller | Checking login to the cluster 23...
2025-10-10 11:39:13.625877 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:39:13.859980 | controller |
2025-10-10 11:39:13.860073 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:39:13.866381 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:39:18.869937 | controller | Checking login to the cluster 24...
2025-10-10 11:39:19.026723 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:39:19.119876 | controller |
2025-10-10 11:39:19.119972 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:39:19.128712 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:39:24.132163 | controller | Checking login to the cluster 25...
2025-10-10 11:39:24.322521 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:39:24.368617 | controller |
2025-10-10 11:39:24.368707 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:39:24.377092 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:39:29.380266 | controller | Checking login to the cluster 26...
2025-10-10 11:39:29.525142 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:39:29.558540 | controller |
2025-10-10 11:39:29.558658 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:39:29.569090 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:39:34.572446 | controller | Checking login to the cluster 27...
2025-10-10 11:39:34.750122 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:39:34.784896 | controller |
2025-10-10 11:39:34.784977 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:39:34.791797 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:39:39.794874 | controller | Checking login to the cluster 28...
2025-10-10 11:39:39.960200 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:39:39.985489 | controller |
2025-10-10 11:39:39.985534 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port?
2025-10-10 11:39:39.996154 | controller | Can not login to the CRC cluster. Sleeping...
2025-10-10 11:39:45.003053 | controller | Checking login to the cluster 29...
2025-10-10 11:39:45.124782 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported!
2025-10-10 11:39:45.805230 | controller |
2025-10-10 11:39:45.805337 | controller | Login successful.
2025-10-10 11:39:45.847580 | controller |
2025-10-10 11:39:45.847673 | controller | You have access to 65 projects, the list has been suppressed. You can list all projects with 'oc projects'
2025-10-10 11:39:45.862569 | controller |
2025-10-10 11:39:45.862896 | controller | Using project "default".
2025-10-10 11:39:46.270715 | controller | changed
2025-10-10 11:39:46.285993 | 
2025-10-10 11:39:46.286173 | TASK [Delete all openshift-marketplace pods]
2025-10-10 11:39:47.939094 | controller | pod "certified-operators-99mjz" deleted
2025-10-10 11:39:47.959329 | controller | pod "certified-operators-f8szs" deleted
2025-10-10 11:39:47.984193 | controller | pod "community-operators-5zsqg" deleted
2025-10-10 11:39:48.010619 | controller | pod "community-operators-nhbv8" deleted
2025-10-10 11:39:48.035384 | controller | pod "marketplace-operator-79b997595-d2lpl" deleted
2025-10-10 11:39:48.056522 | controller | pod "redhat-marketplace-j78wz" deleted
2025-10-10 11:39:48.082895 | controller | pod "redhat-marketplace-ps6xk" deleted
2025-10-10 11:39:48.105578 | controller | pod "redhat-operators-hdd8b" deleted
2025-10-10 11:39:48.148886 | controller | pod "redhat-operators-tqxl9" deleted
2025-10-10 11:40:37.897869 | controller | ok
2025-10-10 11:40:37.912573 | 
2025-10-10 11:40:37.912826 | TASK [Copy script ensure_services_up.sh]
2025-10-10 11:40:37.981237 | controller | skipping: Conditional result was False
2025-10-10 11:40:37.996363 | 
2025-10-10 11:40:37.996505 | TASK [Ensure all pods are up and running]
2025-10-10 11:40:38.548960 | controller | skipping: Conditional result was False
2025-10-10 11:40:38.563065 | 
2025-10-10 11:40:38.563209 | TASK [Check if there is a image build date file]
2025-10-10 11:40:39.166292 | controller | ok
2025-10-10 11:40:39.179186 | 
2025-10-10 11:40:39.179319 | TASK [Print image date if available]
2025-10-10 11:40:39.553804 | controller | Tue Apr  1 06:17:46 PM EDT 2025
2025-10-10 11:40:39.730423 | controller | changed
2025-10-10 11:40:39.743173 | 
2025-10-10 11:40:39.743315 | TASK [Fix machineconfigpool]
2025-10-10 11:40:39.811550 | controller | skipping: Conditional result was False
2025-10-10 11:40:39.824961 | 
2025-10-10 11:40:39.825097 | TASK [Show available nodes]
2025-10-10 11:40:41.274950 | controller | NAME   STATUS   ROLES                         AGE    VERSION
2025-10-10 11:40:41.279072 | controller | crc    Ready    control-plane,master,worker   229d   v1.31.5
2025-10-10 11:40:41.377358 | controller | ok: Runtime: 0:00:01.010537
2025-10-10 11:40:41.389178 | 
2025-10-10 11:40:41.389483 | TASK [Configure insecure registry inside crc vm]
2025-10-10 11:40:41.437391 | controller | skipping: Conditional result was False
2025-10-10 11:40:41.451330 | 
2025-10-10 11:40:41.451477 | TASK [Catch CRC IP]
2025-10-10 11:40:41.937817 | controller | 192.168.130.11
2025-10-10 11:40:42.001709 | controller | changed
2025-10-10 11:40:42.014259 | 
2025-10-10 11:40:42.014397 | TASK [Check if id_ed25519 key exists]
2025-10-10 11:40:42.420893 | controller | ok
2025-10-10 11:40:42.433303 | 
2025-10-10 11:40:42.433432 | TASK [Set fact if new keypair exists]
2025-10-10 11:40:42.482275 | controller | ok
2025-10-10 11:40:42.493349 | 
2025-10-10 11:40:42.493483 | TASK [Run crc]
2025-10-10 11:40:44.744872 | controller |
2025-10-10 11:40:55.815171 | controller | PLAY [OpenShift secret copy and CRC securitization] ****************************
2025-10-10 11:40:55.815262 | controller |
2025-10-10 11:40:55.815280 | controller | TASK [Gathering Facts] *********************************************************
2025-10-10 11:40:55.815322 | controller | [WARNING]: Platform linux on host 192.168.130.11 is using the discovered Python
2025-10-10 11:40:55.901915 | controller | interpreter at /usr/bin/python3.9, but future installation of another Python
2025-10-10 11:40:55.901982 | controller | interpreter could change the meaning of that path. See
2025-10-10 11:40:55.901998 | controller | https://docs.ansible.com/ansible-
2025-10-10 11:40:55.902012 | controller | core/2.14/reference_appendices/interpreter_discovery.html for more information.
2025-10-10 11:40:55.902035 | controller | ok: [192.168.130.11]
2025-10-10 11:40:58.104220 | controller |
2025-10-10 11:40:58.104300 | controller | TASK [Copy pull-secret] ********************************************************
2025-10-10 11:40:58.104320 | controller | changed: [192.168.130.11]
2025-10-10 11:40:59.779697 | controller |
2025-10-10 11:40:59.779762 | controller | TASK [Add crio config] *********************************************************
2025-10-10 11:40:59.779789 | controller | changed: [192.168.130.11]
2025-10-10 11:41:10.095277 | controller |
2025-10-10 11:41:10.095362 | controller | TASK [Restart crio to pickup new configuration] ********************************
2025-10-10 11:41:10.095387 | controller | changed: [192.168.130.11]
2025-10-10 11:41:10.154211 | controller |
2025-10-10 11:41:10.154306 | controller | PLAY RECAP *********************************************************************
2025-10-10 11:41:10.154321 | controller | 192.168.130.11             : ok=4    changed=3    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-10 11:41:10.154330 | controller |
2025-10-10 11:41:10.626128 | controller | changed
2025-10-10 11:41:10.639822 | 
2025-10-10 11:41:10.640140 | TASK [Set slower etcd profile]
2025-10-10 11:41:10.720992 | controller | ok
2025-10-10 11:41:10.765405 | 
2025-10-10 11:41:10.765550 | TASK [prepare-crc-cloud : Set slower profile]
2025-10-10 11:41:11.322311 | controller | etcd.operator.openshift.io/cluster patched
2025-10-10 11:41:11.807066 | controller | ok
2025-10-10 11:41:11.814083 | 
2025-10-10 11:41:11.814161 | TASK [prepare-crc-cloud : Wait 30 seconds to apply]
2025-10-10 11:41:41.870675 | controller | ok
2025-10-10 11:41:41.882477 | 
2025-10-10 11:41:41.882613 | TASK [prepare-crc-cloud : Get pod phase status]
2025-10-10 11:46:47.479533 | controller | ok
2025-10-10 11:46:47.501389 | 
2025-10-10 11:46:47.501534 | TASK [Set limit for disk usage - IOPS and Read/Write]
2025-10-10 11:46:47.581855 | controller | ok
2025-10-10 11:46:47.598260 | controller | included: /var/lib/zuul/builds/71040a836ab340bab398c10ad4a5cf0a/trusted/project_0/review.rdoproject.org/config/playbooks/crc/limit-disk-usage.yaml
2025-10-10 11:46:47.620088 | 
2025-10-10 11:46:47.620262 | TASK [Set facts for disk limitation]
2025-10-10 11:46:47.653895 | controller | ok
2025-10-10 11:46:47.661878 | 
2025-10-10 11:46:47.662062 | TASK [Print limits for the disk]
2025-10-10 11:46:47.704941 | controller | ok: Set limit to crc VM to the vda disk: iops 18000 read/write 262144000
2025-10-10 11:46:47.712084 | 
2025-10-10 11:46:47.712164 | TASK [Set limit to crc VM to the vda disk]
2025-10-10 11:46:48.227858 | controller |
2025-10-10 11:46:48.265488 | controller | changed
2025-10-10 11:46:48.272997 | 
2025-10-10 11:46:48.273082 | TASK [Pause machineconfigpool]
2025-10-10 11:46:48.347574 | controller | ok
2025-10-10 11:46:48.380009 | 
2025-10-10 11:46:48.380251 | LOOP [prepare-crc-cloud : Pause the machineconfig configuration if mcp is not needed]
2025-10-10 11:46:48.954037 | controller | ok
2025-10-10 11:46:49.400703 | controller | ok
2025-10-10 11:46:49.422424 | 
2025-10-10 11:46:49.422696 | TASK [prepare-crc-cloud : Print current machineconfigpool]
2025-10-10 11:46:49.939531 | controller | NAME     CONFIG                                             UPDATED   UPDATING   DEGRADED   MACHINECOUNT   READYMACHINECOUNT   UPDATEDMACHINECOUNT   DEGRADEDMACHINECOUNT   AGE
2025-10-10 11:46:49.939614 | controller | master   rendered-master-95020e6e79c40b4dd095817bccfc5060   True      False      False      1              1                   1                     0                      229d
2025-10-10 11:46:49.950149 | controller | worker   rendered-worker-594cc07c9feefb5e37f2530ac457d36c   True      False      False      0              0                   0                     0                      229d
2025-10-10 11:46:49.999157 | controller | ok
2025-10-10 11:46:50.051124 | 
2025-10-10 11:46:50.051270 | PLAY [Set IOPS and Read/Write disk limitation excluding controller]
2025-10-10 11:46:50.051411 | 
2025-10-10 11:46:50.051451 | PLAY RECAP
2025-10-10 11:46:50.051504 | controller | ok: 25 changed: 10 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 0
2025-10-10 11:46:50.051535 | 
2025-10-10 11:46:50.166847 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/crc/simple-start.yaml@master]
2025-10-10 11:46:50.168557 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-10 11:46:50.772857 | 
2025-10-10 11:46:50.772967 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-10-10 11:46:50.794678 | 
2025-10-10 11:46:50.794829 | TASK [Create zuul-output directory]
2025-10-10 11:46:51.295643 | controller | changed
2025-10-10 11:46:51.307128 | 
2025-10-10 11:46:51.307298 | TASK [Slurp Zuul inventory test]
2025-10-10 11:46:51.701813 | controller -> localhost | ok
2025-10-10 11:46:51.715222 | 
2025-10-10 11:46:51.715360 | TASK [Save zuul inventory]
2025-10-10 11:46:53.473886 | controller | changed
2025-10-10 11:46:53.482055 | 
2025-10-10 11:46:53.482260 | TASK [Save zuul vars without the change_message]
2025-10-10 11:46:55.155713 | controller | changed
2025-10-10 11:46:55.196542 | 
2025-10-10 11:46:55.196651 | PLAY RECAP
2025-10-10 11:46:55.196707 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-10 11:46:55.196761 | 
2025-10-10 11:46:55.295171 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-10 11:46:55.296022 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-10 11:46:55.952393 | 
2025-10-10 11:46:55.952510 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-10-10 11:46:55.978363 | 
2025-10-10 11:46:55.978508 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-10-10 11:46:56.000355 | controller | ok
2025-10-10 11:46:56.020891 | 
2025-10-10 11:46:56.021007 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-10 11:46:56.075748 | controller | skipping: Conditional result was False
2025-10-10 11:46:56.082668 | 
2025-10-10 11:46:56.082789 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-10 11:46:56.621840 | controller | ok
2025-10-10 11:46:56.636472 | 
2025-10-10 11:46:56.636633 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-10 11:46:58.333902 | controller | ok
2025-10-10 11:46:58.356788 | 
2025-10-10 11:46:58.356921 | TASK [Prepare workspace]
2025-10-10 11:46:58.386263 | controller | ok
2025-10-10 11:46:58.419752 | 
2025-10-10 11:46:58.419905 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-10 11:46:58.912566 | controller | ok
2025-10-10 11:46:58.920493 | 
2025-10-10 11:46:58.920582 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-10 11:47:00.191249 | controller | Output suppressed because no_log was given
2025-10-10 11:47:00.239234 | 
2025-10-10 11:47:00.239377 | LOOP [Create zuul-output directory]
2025-10-10 11:47:00.559496 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-10-10 11:47:00.901913 | controller | ok: "/home/zuul/zuul-output/logs"
2025-10-10 11:47:00.912055 | 
2025-10-10 11:47:00.912133 | TASK [Install required packages]
2025-10-10 11:47:17.503148 | controller | ok: Nothing to do
2025-10-10 11:47:17.518998 | 
2025-10-10 11:47:17.519174 | TASK [Install venv]
2025-10-10 11:48:27.068595 | controller | changed
2025-10-10 11:48:27.119251 | 
2025-10-10 11:48:27.119371 | PLAY RECAP
2025-10-10 11:48:27.119429 | controller | ok: 7 changed: 2 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-10 11:48:27.119459 | 
2025-10-10 11:48:27.223923 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-10 11:48:27.224791 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-10 11:48:27.817962 | 
2025-10-10 11:48:27.818070 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-10-10 11:48:27.839314 | 
2025-10-10 11:48:27.839407 | TASK [Gather required facts]
2025-10-10 11:48:28.533835 | controller | ok
2025-10-10 11:48:28.555298 | 
2025-10-10 11:48:28.555522 | TASK [Load environment var if instructed to]
2025-10-10 11:48:28.601412 | controller | skipping: Conditional result was False
2025-10-10 11:48:28.609810 | 
2025-10-10 11:48:28.609902 | TASK [Ensure group_vars dir exists]
2025-10-10 11:48:29.236777 | controller | ok
2025-10-10 11:48:29.248591 | 
2025-10-10 11:48:29.248755 | TASK [Run molecule]
2025-10-10 11:48:30.538512 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-10-10 11:48:30.612523 | controller | INFO     Performing prerun with role_name_check=0...
2025-10-10 11:48:48.507253 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-10 11:48:48.507951 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-10 11:48:48.508854 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-10 11:48:48.509820 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-10 11:48:48.510779 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+a120bdc5 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 1.0.0+a120bdc5 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-10 11:48:48.511693 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-10 11:48:48.512562 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-10 11:48:48.513597 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-10 11:48:48.514232 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-10 11:48:48.515629 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-10 11:48:48.520670 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-10 11:48:48.530107 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-10 11:48:48.530140 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-10 11:48:48.530150 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-10 11:48:48.530159 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-10 11:48:48.530196 | controller | INFO     Running default > prepare
2025-10-10 11:48:49.325877 | controller |
2025-10-10 11:48:49.327829 | controller | PLAY [Prepare] *****************************************************************
2025-10-10 11:48:50.504639 | controller |
2025-10-10 11:48:50.504695 | controller | TASK [Gathering Facts] *********************************************************
2025-10-10 11:48:50.504703 | controller | Friday 10 October 2025  11:48:49 +0000 (0:00:00.014)       0:00:00.014 ********
2025-10-10 11:48:50.504716 | controller | ok: [instance]
2025-10-10 11:48:50.504737 | controller |
2025-10-10 11:48:50.504836 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-10-10 11:48:50.504990 | controller | Friday 10 October 2025  11:48:50 +0000 (0:00:01.179)       0:00:01.193 ********
2025-10-10 11:48:50.542461 | controller | skipping: [instance]
2025-10-10 11:48:50.542540 | controller |
2025-10-10 11:48:50.542657 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-10-10 11:48:50.542787 | controller | Friday 10 October 2025  11:48:50 +0000 (0:00:00.037)       0:00:01.231 ********
2025-10-10 11:48:50.599607 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-10-10 11:48:50.599680 | controller |
2025-10-10 11:48:50.599791 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-10-10 11:48:50.599932 | controller | Friday 10 October 2025  11:48:50 +0000 (0:00:00.057)       0:00:01.288 ********
2025-10-10 11:48:51.000027 | controller | ok: [instance]
2025-10-10 11:48:51.000090 | controller |
2025-10-10 11:48:51.000161 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-10-10 11:48:51.000262 | controller | Friday 10 October 2025  11:48:50 +0000 (0:00:00.395)       0:00:01.684 ********
2025-10-10 11:48:51.405637 | controller | ok: [instance]
2025-10-10 11:48:51.405733 | controller |
2025-10-10 11:48:51.405911 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-10-10 11:48:51.406075 | controller | Friday 10 October 2025  11:48:51 +0000 (0:00:00.409)       0:00:02.094 ********
2025-10-10 11:48:52.410030 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-10-10 11:48:52.410319 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-10-10 11:48:52.410449 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-10-10 11:48:52.410673 | controller |
2025-10-10 11:48:52.410877 | controller | TASK [Deploy repo-setup] *******************************************************
2025-10-10 11:48:52.411082 | controller | Friday 10 October 2025  11:48:52 +0000 (0:00:01.004)       0:00:03.099 ********
2025-10-10 11:48:52.501638 | controller |
2025-10-10 11:48:52.501825 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-10-10 11:48:52.502019 | controller | Friday 10 October 2025  11:48:52 +0000 (0:00:00.091)       0:00:03.190 ********
2025-10-10 11:48:53.251946 | controller | changed: [instance] => (item=tmp)
2025-10-10 11:48:53.252005 | controller | changed: [instance] => (item=artifacts/repositories)
2025-10-10 11:48:53.252106 | controller | changed: [instance] => (item=venv/repo_setup)
2025-10-10 11:48:53.252207 | controller |
2025-10-10 11:48:53.252329 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-10-10 11:48:53.252453 | controller | Friday 10 October 2025  11:48:53 +0000 (0:00:00.750)       0:00:03.941 ********
2025-10-10 11:48:54.393853 | controller | ok: [instance]
2025-10-10 11:48:54.394032 | controller |
2025-10-10 11:48:54.394869 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-10-10 11:48:55.691046 | controller | Friday 10 October 2025  11:48:54 +0000 (0:00:01.141)       0:00:05.083 ********
2025-10-10 11:48:55.691095 | controller | changed: [instance]
2025-10-10 11:48:55.691124 | controller |
2025-10-10 11:48:55.691759 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-10-10 11:49:04.047538 | controller | Friday 10 October 2025  11:48:55 +0000 (0:00:01.296)       0:00:06.379 ********
2025-10-10 11:49:04.047612 | controller | changed: [instance]
2025-10-10 11:49:04.047954 | controller |
2025-10-10 11:49:05.005375 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-10-10 11:49:05.005414 | controller | Friday 10 October 2025  11:49:04 +0000 (0:00:08.356)       0:00:14.736 ********
2025-10-10 11:49:05.005425 | controller | changed: [instance]
2025-10-10 11:49:05.066889 | controller |
2025-10-10 11:49:05.066940 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-10-10 11:49:05.066960 | controller | Friday 10 October 2025  11:49:05 +0000 (0:00:00.957)       0:00:15.694 ********
2025-10-10 11:49:05.066977 | controller | skipping: [instance]
2025-10-10 11:49:05.811164 | controller |
2025-10-10 11:49:05.811212 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-10-10 11:49:05.811220 | controller | Friday 10 October 2025  11:49:05 +0000 (0:00:00.061)       0:00:15.756 ********
2025-10-10 11:49:05.811232 | controller | changed: [instance]
2025-10-10 11:49:05.811265 | controller |
2025-10-10 11:49:05.811306 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-10-10 11:49:05.811479 | controller | Friday 10 October 2025  11:49:05 +0000 (0:00:00.744)       0:00:16.500 ********
2025-10-10 11:49:05.858400 | controller | skipping: [instance]
2025-10-10 11:49:05.858459 | controller |
2025-10-10 11:49:05.858512 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-10-10 11:49:05.858613 | controller | Friday 10 October 2025  11:49:05 +0000 (0:00:00.047)       0:00:16.547 ********
2025-10-10 11:49:05.899605 | controller | skipping: [instance]
2025-10-10 11:49:05.899666 | controller |
2025-10-10 11:49:05.899694 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-10-10 11:49:05.900139 | controller | Friday 10 October 2025  11:49:05 +0000 (0:00:00.041)       0:00:16.589 ********
2025-10-10 11:49:05.940934 | controller | skipping: [instance]
2025-10-10 11:49:05.941013 | controller |
2025-10-10 11:49:05.941142 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-10-10 11:49:05.941272 | controller | Friday 10 October 2025  11:49:05 +0000 (0:00:00.041)       0:00:16.630 ********
2025-10-10 11:49:06.486766 | controller | changed: [instance]
2025-10-10 11:49:06.486842 | controller |
2025-10-10 11:49:06.486885 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-10-10 11:49:06.486991 | controller | Friday 10 October 2025  11:49:06 +0000 (0:00:00.545)       0:00:17.176 ********
2025-10-10 11:49:07.085843 | controller | changed: [instance]
2025-10-10 11:49:07.085913 | controller |
2025-10-10 11:49:07.086032 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-10-10 11:49:07.086156 | controller | Friday 10 October 2025  11:49:07 +0000 (0:00:00.598)       0:00:17.774 ********
2025-10-10 11:49:07.124376 | controller | skipping: [instance]
2025-10-10 11:49:07.124489 | controller |
2025-10-10 11:49:07.124664 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-10-10 11:49:07.124811 | controller | Friday 10 October 2025  11:49:07 +0000 (0:00:00.038)       0:00:17.813 ********
2025-10-10 11:49:07.170015 | controller | skipping: [instance]
2025-10-10 11:49:07.170088 | controller |
2025-10-10 11:49:07.170301 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-10-10 11:49:07.170458 | controller | Friday 10 October 2025  11:49:07 +0000 (0:00:00.045)       0:00:17.858 ********
2025-10-10 11:49:07.214339 | controller | skipping: [instance]
2025-10-10 11:49:07.214606 | controller |
2025-10-10 11:49:07.214902 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-10-10 11:49:07.215160 | controller | Friday 10 October 2025  11:49:07 +0000 (0:00:00.043)       0:00:17.902 ********
2025-10-10 11:49:07.269686 | controller | ok: [instance]
2025-10-10 11:49:07.270401 | controller |
2025-10-10 11:49:07.270599 | controller | TASK [repo_setup : Create download directory] **********************************
2025-10-10 11:49:07.303143 | controller | Friday 10 October 2025  11:49:07 +0000 (0:00:00.056)       0:00:17.959 ********
2025-10-10 11:49:07.303253 | controller | skipping: [instance]
2025-10-10 11:49:07.303401 | controller |
2025-10-10 11:49:07.303424 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-10-10 11:49:07.303442 | controller | Friday 10 October 2025  11:49:07 +0000 (0:00:00.033)       0:00:17.992 ********
2025-10-10 11:49:07.338075 | controller | skipping: [instance]
2025-10-10 11:49:07.338147 | controller |
2025-10-10 11:49:07.338184 | controller | TASK [Download the RPM] ********************************************************
2025-10-10 11:49:07.338559 | controller | Friday 10 October 2025  11:49:07 +0000 (0:00:00.035)       0:00:18.027 ********
2025-10-10 11:49:07.369715 | controller | skipping: [instance]
2025-10-10 11:49:07.369758 | controller |
2025-10-10 11:49:07.369890 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-10-10 11:49:07.369982 | controller | Friday 10 October 2025  11:49:07 +0000 (0:00:00.031)       0:00:18.059 ********
2025-10-10 11:49:07.409098 | controller | skipping: [instance]
2025-10-10 11:49:07.409175 | controller |
2025-10-10 11:49:07.409333 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-10-10 11:49:07.409472 | controller | Friday 10 October 2025  11:49:07 +0000 (0:00:00.035)       0:00:18.094 ********
2025-10-10 11:49:07.448312 | controller | skipping: [instance]
2025-10-10 11:49:07.448384 | controller |
2025-10-10 11:49:07.448533 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-10-10 11:49:07.448671 | controller | Friday 10 October 2025  11:49:07 +0000 (0:00:00.043)       0:00:18.137 ********
2025-10-10 11:49:07.494419 | controller | skipping: [instance]
2025-10-10 11:49:07.494489 | controller |
2025-10-10 11:49:07.494573 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-10-10 11:49:07.494679 | controller | Friday 10 October 2025  11:49:07 +0000 (0:00:00.045)       0:00:18.183 ********
2025-10-10 11:49:07.527468 | controller | skipping: [instance]
2025-10-10 11:49:07.527534 | controller |
2025-10-10 11:49:07.527649 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-10-10 11:49:07.528806 | controller | Friday 10 October 2025  11:49:07 +0000 (0:00:00.033)       0:00:18.216 ********
2025-10-10 11:49:07.866631 | controller | ok: [instance]
2025-10-10 11:49:07.866739 | controller |
2025-10-10 11:49:07.866890 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-10-10 11:49:07.867039 | controller | Friday 10 October 2025  11:49:07 +0000 (0:00:00.339)       0:00:18.556 ********
2025-10-10 11:49:08.145608 | controller | changed: [instance]
2025-10-10 11:49:08.145657 | controller |
2025-10-10 11:49:08.145833 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-10-10 11:49:08.145949 | controller | Friday 10 October 2025  11:49:08 +0000 (0:00:00.279)       0:00:18.835 ********
2025-10-10 11:49:08.461885 | controller | changed: [instance]
2025-10-10 11:49:08.461931 | controller |
2025-10-10 11:49:08.462041 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-10-10 11:49:08.462147 | controller | Friday 10 October 2025  11:49:08 +0000 (0:00:00.315)       0:00:19.151 ********
2025-10-10 11:49:08.488102 | controller | skipping: [instance]
2025-10-10 11:49:08.488226 | controller |
2025-10-10 11:49:08.488440 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-10-10 11:49:08.488467 | controller | Friday 10 October 2025  11:49:08 +0000 (0:00:00.026)       0:00:19.177 ********
2025-10-10 11:49:08.520979 | controller | skipping: [instance]
2025-10-10 11:49:08.521110 | controller |
2025-10-10 11:49:08.521134 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-10-10 11:49:08.521244 | controller | Friday 10 October 2025  11:49:08 +0000 (0:00:00.032)       0:00:19.210 ********
2025-10-10 11:49:08.547174 | controller | skipping: [instance]
2025-10-10 11:49:08.547220 | controller |
2025-10-10 11:49:08.547310 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-10-10 11:49:08.547471 | controller | Friday 10 October 2025  11:49:08 +0000 (0:00:00.026)       0:00:19.236 ********
2025-10-10 11:49:08.588718 | controller | skipping: [instance]
2025-10-10 11:49:08.588762 | controller |
2025-10-10 11:49:08.588862 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-10-10 11:49:08.588954 | controller | Friday 10 October 2025  11:49:08 +0000 (0:00:00.041)       0:00:19.278 ********
2025-10-10 11:49:08.613996 | controller | skipping: [instance]
2025-10-10 11:49:08.614042 | controller |
2025-10-10 11:49:08.614348 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-10-10 11:49:08.647374 | controller | Friday 10 October 2025  11:49:08 +0000 (0:00:00.025)       0:00:19.303 ********
2025-10-10 11:49:08.647452 | controller | skipping: [instance]
2025-10-10 11:49:08.675276 | controller |
2025-10-10 11:49:08.675350 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-10-10 11:49:08.675363 | controller | Friday 10 October 2025  11:49:08 +0000 (0:00:00.032)       0:00:19.335 ********
2025-10-10 11:49:08.675379 | controller | skipping: [instance]
2025-10-10 11:49:08.675518 | controller |
2025-10-10 11:49:08.675536 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-10-10 11:49:08.675673 | controller | Friday 10 October 2025  11:49:08 +0000 (0:00:00.029)       0:00:19.364 ********
2025-10-10 11:49:08.722832 | controller | skipping: [instance]
2025-10-10 11:49:08.722915 | controller |
2025-10-10 11:49:08.723089 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-10-10 11:49:08.723248 | controller | Friday 10 October 2025  11:49:08 +0000 (0:00:00.047)       0:00:19.411 ********
2025-10-10 11:49:08.748323 | controller | skipping: [instance]
2025-10-10 11:49:08.748422 | controller |
2025-10-10 11:49:08.748559 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-10-10 11:49:08.748703 | controller | Friday 10 October 2025  11:49:08 +0000 (0:00:00.025)       0:00:19.437 ********
2025-10-10 11:49:08.780014 | controller | skipping: [instance]
2025-10-10 11:49:08.780118 | controller |
2025-10-10 11:49:08.780275 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-10-10 11:49:08.780406 | controller | Friday 10 October 2025  11:49:08 +0000 (0:00:00.031)       0:00:19.469 ********
2025-10-10 11:49:08.825477 | controller | skipping: [instance]
2025-10-10 11:49:08.825619 | controller |
2025-10-10 11:49:08.825634 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-10-10 11:49:08.825751 | controller | Friday 10 October 2025  11:49:08 +0000 (0:00:00.045)       0:00:19.515 ********
2025-10-10 11:49:08.870924 | controller | skipping: [instance]
2025-10-10 11:49:08.870966 | controller |
2025-10-10 11:49:08.871072 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-10-10 11:49:08.871210 | controller | Friday 10 October 2025  11:49:08 +0000 (0:00:00.045)       0:00:19.560 ********
2025-10-10 11:49:08.915262 | controller | skipping: [instance]
2025-10-10 11:49:08.915381 | controller |
2025-10-10 11:49:08.915525 | controller | TASK [test_deps : Install additional packages] *********************************
2025-10-10 11:49:08.915671 | controller | Friday 10 October 2025  11:49:08 +0000 (0:00:00.044)       0:00:19.604 ********
2025-10-10 11:49:08.959186 | controller | skipping: [instance]
2025-10-10 11:49:08.959303 | controller |
2025-10-10 11:49:08.959469 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-10-10 11:49:08.959616 | controller | Friday 10 October 2025  11:49:08 +0000 (0:00:00.043)       0:00:19.648 ********
2025-10-10 11:49:47.531783 | controller | ok: [instance]
2025-10-10 11:49:47.531876 | controller |
2025-10-10 11:49:47.531888 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-10-10 11:49:47.531991 | controller | Friday 10 October 2025  11:49:47 +0000 (0:00:38.572)       0:00:58.221 ********
2025-10-10 11:49:51.629447 | controller | ok: [instance]
2025-10-10 11:49:51.629656 | controller |
2025-10-10 11:49:51.629939 | controller | TASK [test_deps : Install extra packages] **************************************
2025-10-10 11:49:51.630156 | controller | Friday 10 October 2025  11:49:51 +0000 (0:00:04.097)       0:01:02.318 ********
2025-10-10 11:49:51.700171 | controller | skipping: [instance]
2025-10-10 11:49:51.700335 | controller |
2025-10-10 11:49:51.700572 | controller | PLAY RECAP *********************************************************************
2025-10-10 11:49:51.700876 | controller | instance                   : ok=19   changed=9    unreachable=0    failed=0    skipped=30   rescued=0    ignored=0
2025-10-10 11:49:51.700997 | controller |
2025-10-10 11:49:51.701186 | controller | Friday 10 October 2025  11:49:51 +0000 (0:00:00.070)       0:01:02.389 ********
2025-10-10 11:49:51.701468 | controller | ===============================================================================
2025-10-10 11:49:51.701681 | controller | test_deps : Install selinux python libs -------------------------------- 38.57s
2025-10-10 11:49:51.701879 | controller | repo_setup : Initialize python venv and install requirements ------------ 8.36s
2025-10-10 11:49:51.702136 | controller | test_deps : Install python yaml libs ------------------------------------ 4.10s
2025-10-10 11:49:51.702323 | controller | repo_setup : Get repo-setup repository ---------------------------------- 1.30s
2025-10-10 11:49:51.702533 | controller | Gathering Facts --------------------------------------------------------- 1.18s
2025-10-10 11:49:51.702737 | controller | repo_setup : Make sure git-core package is installed -------------------- 1.14s
2025-10-10 11:49:51.702926 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 1.00s
2025-10-10 11:49:51.703159 | controller | repo_setup : Install repo-setup package --------------------------------- 0.96s
2025-10-10 11:49:51.703402 | controller | repo_setup : Ensure directories are present ----------------------------- 0.75s
2025-10-10 11:49:51.703599 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.74s
2025-10-10 11:49:51.703796 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.60s
2025-10-10 11:49:51.703992 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.55s
2025-10-10 11:49:51.704212 | controller | test_deps : Disable ubi host subscription-manager integration ----------- 0.41s
2025-10-10 11:49:51.704442 | controller | test_deps : Detect mirrors file ----------------------------------------- 0.40s
2025-10-10 11:49:51.704647 | controller | repo_setup : Check for /etc/ci/mirror_info.sh --------------------------- 0.34s
2025-10-10 11:49:51.704882 | controller | repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist) --- 0.32s
2025-10-10 11:49:51.705260 | controller | repo_setup : Use RDO proxy mirrors -------------------------------------- 0.28s
2025-10-10 11:49:51.705458 | controller | Deploy repo-setup ------------------------------------------------------- 0.09s
2025-10-10 11:49:51.705654 | controller | test_deps : Install extra packages -------------------------------------- 0.07s
2025-10-10 11:49:51.705879 | controller | repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider --- 0.06s
2025-10-10 11:49:51.789048 | controller | INFO     Running default > converge
2025-10-10 11:49:52.357613 | controller |
2025-10-10 11:49:52.358373 | controller | PLAY [Add crc to the inventory] ************************************************
2025-10-10 11:49:52.358395 | controller |
2025-10-10 11:49:52.358406 | controller | TASK [Gathering Facts] *********************************************************
2025-10-10 11:49:52.358809 | controller | Friday 10 October 2025  11:49:52 +0000 (0:00:00.015)       0:00:00.015 ********
2025-10-10 11:49:53.452848 | controller | ok: [instance]
2025-10-10 11:49:53.453003 | controller |
2025-10-10 11:49:53.453231 | controller | TASK [Add crc hostname with it's IP to /etc/hosts] *****************************
2025-10-10 11:49:53.453471 | controller | Friday 10 October 2025  11:49:53 +0000 (0:00:01.095)       0:00:01.111 ********
2025-10-10 11:49:53.836715 | controller | changed: [instance]
2025-10-10 11:49:53.836905 | controller |
2025-10-10 11:49:53.836989 | controller | TASK [Check if new ssh keypair exists] *****************************************
2025-10-10 11:49:53.837086 | controller | Friday 10 October 2025  11:49:53 +0000 (0:00:00.384)       0:00:01.496 ********
2025-10-10 11:49:53.885344 | controller |
2025-10-10 11:49:53.885595 | controller | TASK [recognize_ssh_keypair : Check if id_ed25519 key exists] ******************
2025-10-10 11:49:54.253520 | controller | Friday 10 October 2025  11:49:53 +0000 (0:00:00.048)       0:00:01.544 ********
2025-10-10 11:49:54.253590 | controller | ok: [instance]
2025-10-10 11:49:54.278066 | controller |
2025-10-10 11:49:54.278136 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair exists] ******************
2025-10-10 11:49:54.278147 | controller | Friday 10 October 2025  11:49:54 +0000 (0:00:00.368)       0:00:01.912 ********
2025-10-10 11:49:54.278166 | controller | ok: [instance]
2025-10-10 11:49:54.308691 | controller |
2025-10-10 11:49:54.308762 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair does not exists] *********
2025-10-10 11:49:54.308774 | controller | Friday 10 October 2025  11:49:54 +0000 (0:00:00.024)       0:00:01.937 ********
2025-10-10 11:49:54.308790 | controller | skipping: [instance]
2025-10-10 11:49:54.308846 | controller |
2025-10-10 11:49:54.308875 | controller | TASK [Add the crc host dynamically] ********************************************
2025-10-10 11:49:54.308976 | controller | Friday 10 October 2025  11:49:54 +0000 (0:00:00.030)       0:00:01.967 ********
2025-10-10 11:49:54.367440 | controller | changed: [instance]
2025-10-10 11:49:54.367761 | controller |
2025-10-10 11:49:54.368046 | controller | TASK [Add a dummy ethernet interface to target the crc NMstate] ****************
2025-10-10 11:49:54.368355 | controller | Friday 10 October 2025  11:49:54 +0000 (0:00:00.058)       0:00:02.026 ********
2025-10-10 11:49:54.863698 | controller | changed: [instance]
2025-10-10 11:49:54.863864 | controller |
2025-10-10 11:49:54.864219 | controller | PLAY [Get CRC facts] ***********************************************************
2025-10-10 11:49:54.864322 | controller |
2025-10-10 11:49:54.864338 | controller | TASK [Fetch crc network facts] *************************************************
2025-10-10 11:49:54.864351 | controller | Friday 10 October 2025  11:49:54 +0000 (0:00:00.495)       0:00:02.522 ********
2025-10-10 11:50:01.718091 | controller | ok: [crc]
2025-10-10 11:50:01.718145 | controller |
2025-10-10 11:50:01.718234 | controller | PLAY [Converge] ****************************************************************
2025-10-10 11:50:01.718351 | controller |
2025-10-10 11:50:01.718457 | controller | TASK [Set common molecule test facts] ******************************************
2025-10-10 11:50:01.718551 | controller | Friday 10 October 2025  11:50:01 +0000 (0:00:06.855)       0:00:09.377 ********
2025-10-10 11:50:01.758125 | controller | ok: [instance]
2025-10-10 11:50:01.758175 | controller |
2025-10-10 11:50:01.758264 | controller | TASK [Get NetworkManager logs - before networking mapper] **********************
2025-10-10 11:50:01.758394 | controller | Friday 10 October 2025  11:50:01 +0000 (0:00:00.040)       0:00:09.417 ********
2025-10-10 11:50:02.035958 | controller | changed: [instance]
2025-10-10 11:50:02.036016 | controller |
2025-10-10 11:50:02.036134 | controller | TASK [Prepare the Networking Env Definition for ci_nmstate role] ***************
2025-10-10 11:50:02.036253 | controller | Friday 10 October 2025  11:50:02 +0000 (0:00:00.277)       0:00:09.695 ********
2025-10-10 11:50:02.078695 | controller |
2025-10-10 11:50:02.078750 | controller | TASK [networking_mapper : Check for Networking Definition file existence] ******
2025-10-10 11:50:02.078871 | controller | Friday 10 October 2025  11:50:02 +0000 (0:00:00.042)       0:00:09.737 ********
2025-10-10 11:50:02.174988 | controller | skipping: [instance]
2025-10-10 11:50:02.175048 | controller |
2025-10-10 11:50:02.175154 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2025-10-10 11:50:02.175310 | controller | Friday 10 October 2025  11:50:02 +0000 (0:00:00.095)       0:00:09.833 ********
2025-10-10 11:50:02.258883 | controller | skipping: [instance]
2025-10-10 11:50:02.258934 | controller |
2025-10-10 11:50:02.259041 | controller | TASK [networking_mapper : Check for interfaces info file existence] ************
2025-10-10 11:50:02.259178 | controller | Friday 10 October 2025  11:50:02 +0000 (0:00:00.084)       0:00:09.918 ********
2025-10-10 11:50:02.301531 | controller | skipping: [instance]
2025-10-10 11:50:02.301572 | controller |
2025-10-10 11:50:02.301678 | controller | TASK [networking_mapper : Load the interfaces info from file] ******************
2025-10-10 11:50:02.301784 | controller | Friday 10 October 2025  11:50:02 +0000 (0:00:00.042)       0:00:09.960 ********
2025-10-10 11:50:02.347239 | controller | skipping: [instance]
2025-10-10 11:50:02.347306 | controller |
2025-10-10 11:50:02.347612 | controller | TASK [networking_mapper : Ensure local fact is empty] **************************
2025-10-10 11:50:02.347702 | controller | Friday 10 October 2025  11:50:02 +0000 (0:00:00.045)       0:00:10.006 ********
2025-10-10 11:50:02.367662 | controller | ok: [instance]
2025-10-10 11:50:02.367735 | controller |
2025-10-10 11:50:02.367877 | controller | TASK [networking_mapper : Set the input Networking Definition and patch it if needed] ***
2025-10-10 11:50:02.368012 | controller | Friday 10 October 2025  11:50:02 +0000 (0:00:00.020)       0:00:10.026 ********
2025-10-10 11:50:02.485649 | controller | ok: [instance] => (item={'networks': {'default': {'network': '38.102.83.0/24', 'gateway': '38.102.83.1', 'dns': ['1.1.1.1', '9.9.9.9'], 'mtu': '1450'}, 'testing-untagged': {'network': '172.17.20.0/24', 'dns': ['192.168.130.11', '192.168.130.1'], 'mtu': '1500'}, 'testing-vlan': {'network': '172.17.21.0/24', 'vlan': 21}}, 'instances': {'crc': {'networks': {'testing-untagged': {'ip': '172.17.20.5'}, 'testing-vlan': {'ip': '172.17.21.5', 'trunk-parent': 'testing-untagged'}}}, 'instance': {'networks': {'default': {'ip': '38.102.83.154'}}}}})
2025-10-10 11:50:02.485744 | controller |
2025-10-10 11:50:02.485950 | controller | TASK [networking_mapper : Gather facts if requested] ***************************
2025-10-10 11:50:02.486112 | controller | Friday 10 October 2025  11:50:02 +0000 (0:00:00.117)       0:00:10.144 ********
2025-10-10 11:50:02.543690 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/networking_mapper/tasks/_gather_facts.yml for instance
2025-10-10 11:50:02.543745 | controller |
2025-10-10 11:50:02.543905 | controller | TASK [networking_mapper : Gather the facts] ************************************
2025-10-10 11:50:02.544086 | controller | Friday 10 October 2025  11:50:02 +0000 (0:00:00.057)       0:00:10.202 ********
2025-10-10 11:50:02.966762 | controller | skipping: [instance] => (item=crc)
2025-10-10 11:50:02.966849 | controller | skipping: [instance] => (item=instance)
2025-10-10 11:50:02.967080 | controller | skipping: [instance]
2025-10-10 11:50:02.967233 | controller |
2025-10-10 11:50:02.967433 | controller | TASK [networking_mapper : Save instances refreshed facts for troubleshooting purposes] ***
2025-10-10 11:50:02.967570 | controller | Friday 10 October 2025  11:50:02 +0000 (0:00:00.423)       0:00:10.625 ********
2025-10-10 11:50:03.739108 | controller | changed: [instance]
2025-10-10 11:50:03.739173 | controller |
2025-10-10 11:50:03.739256 | controller | TASK [networking_mapper : Ensure CI infrastructure dir exists] *****************
2025-10-10 11:50:03.739351 | controller | Friday 10 October 2025  11:50:03 +0000 (0:00:00.772)       0:00:11.398 ********
2025-10-10 11:50:04.208771 | controller | changed: [instance]
2025-10-10 11:50:04.208835 | controller |
2025-10-10 11:50:04.208948 | controller | TASK [networking_mapper : Write the Networking Definition to file] *************
2025-10-10 11:50:04.209111 | controller | Friday 10 October 2025  11:50:04 +0000 (0:00:00.469)       0:00:11.867 ********
2025-10-10 11:50:04.770226 | controller | changed: [instance]
2025-10-10 11:50:04.770342 | controller |
2025-10-10 11:50:04.770384 | controller | TASK [networking_mapper : Call the networking mapper] **************************
2025-10-10 11:50:04.770444 | controller | Friday 10 October 2025  11:50:04 +0000 (0:00:00.560)       0:00:12.428 ********
2025-10-10 11:50:04.876028 | controller | ok: [instance]
2025-10-10 11:50:04.876113 | controller |
2025-10-10 11:50:04.876260 | controller | TASK [networking_mapper : Set networking mapper facts] *************************
2025-10-10 11:50:04.876461 | controller | Friday 10 October 2025  11:50:04 +0000 (0:00:00.103)       0:00:12.531 ********
2025-10-10 11:50:04.909036 | controller | ok: [instance]
2025-10-10 11:50:05.378829 | controller |
2025-10-10 11:50:05.378904 | controller | TASK [networking_mapper : Write the Networking Environment Definition to file] ***
2025-10-10 11:50:05.378913 | controller | Friday 10 October 2025  11:50:04 +0000 (0:00:00.035)       0:00:12.567 ********
2025-10-10 11:50:05.378933 | controller | changed: [instance]
2025-10-10 11:50:05.658165 | controller |
2025-10-10 11:50:05.658243 | controller | TASK [Get NetworkManager logs - after] *****************************************
2025-10-10 11:50:05.658251 | controller | Friday 10 October 2025  11:50:05 +0000 (0:00:00.470)       0:00:13.037 ********
2025-10-10 11:50:05.658271 | controller | changed: [instance]
2025-10-10 11:50:05.704325 | controller |
2025-10-10 11:50:05.704413 | controller | TASK [Call the role under test] ************************************************
2025-10-10 11:50:05.704421 | controller | Friday 10 October 2025  11:50:05 +0000 (0:00:00.275)       0:00:13.312 ********
2025-10-10 11:50:05.704440 | controller |
2025-10-10 11:50:05.735215 | controller | TASK [networking_mapper : Check for Networking Environment Definition file existence] ***
2025-10-10 11:50:05.735307 | controller | Friday 10 October 2025  11:50:05 +0000 (0:00:00.050)       0:00:13.363 ********
2025-10-10 11:50:05.735330 | controller | skipping: [instance]
2025-10-10 11:50:05.770475 | controller |
2025-10-10 11:50:05.770553 | controller | TASK [networking_mapper : Check for Networking Definition file existance] ******
2025-10-10 11:50:05.770562 | controller | Friday 10 October 2025  11:50:05 +0000 (0:00:00.030)       0:00:13.393 ********
2025-10-10 11:50:05.770580 | controller | skipping: [instance]
2025-10-10 11:50:05.804438 | controller |
2025-10-10 11:50:05.804516 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2025-10-10 11:50:05.804548 | controller | Friday 10 October 2025  11:50:05 +0000 (0:00:00.034)       0:00:13.428 ********
2025-10-10 11:50:05.804575 | controller | skipping: [instance]
2025-10-10 11:50:05.804641 | controller |
2025-10-10 11:50:05.804655 | controller | TASK [networking_mapper : Set cifmw_networking_env_definition is present] ******
2025-10-10 11:50:05.804747 | controller | Friday 10 October 2025  11:50:05 +0000 (0:00:00.033)       0:00:13.462 ********
2025-10-10 11:50:05.840673 | controller | skipping: [instance]
2025-10-10 11:50:05.840748 | controller |
2025-10-10 11:50:05.840855 | controller | TASK [ci_nmstate : Initialize NMstates for each instance] **********************
2025-10-10 11:50:05.840977 | controller | Friday 10 October 2025  11:50:05 +0000 (0:00:00.037)       0:00:13.499 ********
2025-10-10 11:50:05.884787 | controller | ok: [instance]
2025-10-10 11:50:05.884891 | controller |
2025-10-10 11:50:05.884982 | controller | TASK [ci_nmstate : Build NMstates from the Networking Environment Definition] ***
2025-10-10 11:50:05.885110 | controller | Friday 10 October 2025  11:50:05 +0000 (0:00:00.044)       0:00:13.544 ********
2025-10-10 11:50:05.959806 | controller | ok: [instance] => (item=crc)
2025-10-10 11:50:05.959902 | controller | ok: [instance] => (item=instance)
2025-10-10 11:50:05.960009 | controller |
2025-10-10 11:50:05.960027 | controller | TASK [ci_nmstate : Get k8s nodes] **********************************************
2025-10-10 11:50:05.960142 | controller | Friday 10 October 2025  11:50:05 +0000 (0:00:00.074)       0:00:13.618 ********
2025-10-10 11:50:06.933726 | controller | ok: [instance]
2025-10-10 11:50:06.933771 | controller |
2025-10-10 11:50:06.933930 | controller | TASK [ci_nmstate : Set the hosts that will provision nmstate using k8s] ********
2025-10-10 11:50:06.934064 | controller | Friday 10 October 2025  11:50:06 +0000 (0:00:00.974)       0:00:14.592 ********
2025-10-10 11:50:07.061143 | controller | ok: [instance]
2025-10-10 11:50:07.179362 | controller |
2025-10-10 11:50:07.179409 | controller | TASK [ci_nmstate : Provision k8s workers with nmstate] *************************
2025-10-10 11:50:07.179427 | controller | Friday 10 October 2025  11:50:07 +0000 (0:00:00.124)       0:00:14.717 ********
2025-10-10 11:50:07.179443 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/ci_nmstate/tasks/nmstate_k8s_install.yml for instance
2025-10-10 11:50:07.179539 | controller |
2025-10-10 11:50:07.179549 | controller | TASK [ci_nmstate : Create the target dir to dump NMstate manifests] ************
2025-10-10 11:50:07.179637 | controller | Friday 10 October 2025  11:50:07 +0000 (0:00:00.121)       0:00:14.838 ********
2025-10-10 11:50:07.435830 | controller | changed: [instance]
2025-10-10 11:50:07.435911 | controller |
2025-10-10 11:50:07.436045 | controller | TASK [ci_nmstate : Create the nmstate namespace] *******************************
2025-10-10 11:50:07.436184 | controller | Friday 10 October 2025  11:50:07 +0000 (0:00:00.256)       0:00:15.094 ********
2025-10-10 11:50:08.423434 | controller | changed: [instance]
2025-10-10 11:50:08.423532 | controller |
2025-10-10 11:50:08.423682 | controller | TASK [ci_nmstate : Generate the OperatorGroup final CR] ************************
2025-10-10 11:50:08.423817 | controller | Friday 10 October 2025  11:50:08 +0000 (0:00:00.987)       0:00:16.082 ********
2025-10-10 11:50:08.527054 | controller | ok: [instance] => (item={'apiVersion': 'operators.coreos.com/v1', 'kind': 'OperatorGroup', 'metadata': {'annotations': {'olm.providedAPIs': 'NMState.v1.nmstate.io'}, 'name': 'openshift-nmstate', 'namespace': 'openshift-nmstate'}, 'spec': {'targetNamespaces': ['openshift-nmstate']}})
2025-10-10 11:50:08.527130 | controller |
2025-10-10 11:50:08.527276 | controller | TASK [ci_nmstate : Generate the Subscription final CR] *************************
2025-10-10 11:50:08.527449 | controller | Friday 10 October 2025  11:50:08 +0000 (0:00:00.103)       0:00:16.186 ********
2025-10-10 11:50:08.610750 | controller | ok: [instance] => (item={'apiVersion': 'operators.coreos.com/v1alpha1', 'kind': 'Subscription', 'metadata': {'labels': {'operators.coreos.com/kubernetes-nmstate-operator.openshift-nmstate': ''}, 'name': 'kubernetes-nmstate-operator', 'namespace': 'openshift-nmstate'}, 'spec': {'channel': 'stable', 'installPlanApproval': 'Automatic', 'name': 'kubernetes-nmstate-operator', 'source': 'redhat-operators', 'sourceNamespace': 'openshift-marketplace'}})
2025-10-10 11:50:08.610802 | controller |
2025-10-10 11:50:08.610927 | controller | TASK [ci_nmstate : Save k8s nmstate OLM manifests as artifacts] ****************
2025-10-10 11:50:08.611035 | controller | Friday 10 October 2025  11:50:08 +0000 (0:00:00.083)       0:00:16.269 ********
2025-10-10 11:50:09.583321 | controller | changed: [instance] => (item=openshift-nmstate)
2025-10-10 11:50:09.583500 | controller | changed: [instance] => (item=kubernetes-nmstate-operator)
2025-10-10 11:50:09.583515 | controller |
2025-10-10 11:50:09.583526 | controller | TASK [ci_nmstate : Create the OLM subscription resources] **********************
2025-10-10 11:50:09.583938 | controller | Friday 10 October 2025  11:50:09 +0000 (0:00:00.971)       0:00:17.241 ********
2025-10-10 11:50:11.179313 | controller | changed: [instance] => (item=openshift-nmstate)
2025-10-10 11:50:43.013157 | controller | changed: [instance] => (item=kubernetes-nmstate-operator)
2025-10-10 11:50:43.013206 | controller |
2025-10-10 11:50:43.013216 | controller | TASK [ci_nmstate : Wait for nmstate operator to be installed] ******************
2025-10-10 11:50:43.013224 | controller | Friday 10 October 2025  11:50:11 +0000 (0:00:01.596)       0:00:18.837 ********
2025-10-10 11:50:43.013238 | controller | FAILED - RETRYING: [instance]: Wait for nmstate operator to be installed (12 retries left).
2025-10-10 11:50:43.462995 | controller | FAILED - RETRYING: [instance]: Wait for nmstate operator to be installed (11 retries left).
2025-10-10 11:50:43.463028 | controller | FAILED - RETRYING: [instance]: Wait for nmstate operator to be installed (10 retries left).
2025-10-10 11:50:43.463035 | controller | ok: [instance]
2025-10-10 11:50:43.463041 | controller |
2025-10-10 11:50:43.463048 | controller | TASK [ci_nmstate : Save nmstate operator config as an artifact] ****************
2025-10-10 11:50:43.463054 | controller | Friday 10 October 2025  11:50:43 +0000 (0:00:31.833)       0:00:50.671 ********
2025-10-10 11:50:43.463064 | controller | changed: [instance]
2025-10-10 11:50:43.463092 | controller |
2025-10-10 11:50:43.463210 | controller | TASK [ci_nmstate : Trigger nmstate operator to install nmstate] ****************
2025-10-10 11:50:43.463254 | controller | Friday 10 October 2025  11:50:43 +0000 (0:00:00.451)       0:00:51.122 ********
2025-10-10 11:50:44.266832 | controller | changed: [instance]
2025-10-10 11:51:15.761566 | controller |
2025-10-10 11:51:15.761618 | controller | TASK [ci_nmstate : Wait for nsmtate Deployments to be ready] *******************
2025-10-10 11:51:15.761629 | controller | Friday 10 October 2025  11:50:44 +0000 (0:00:00.803)       0:00:51.925 ********
2025-10-10 11:51:15.761643 | controller | ok: [instance]
2025-10-10 11:51:16.877533 | controller |
2025-10-10 11:51:16.877574 | controller | TASK [ci_nmstate : Wait for nsmtate DaemonSet to be ready] *********************
2025-10-10 11:51:16.877583 | controller | Friday 10 October 2025  11:51:15 +0000 (0:00:31.494)       0:01:23.420 ********
2025-10-10 11:51:16.877599 | controller | ok: [instance]
2025-10-10 11:51:16.877685 | controller |
2025-10-10 11:51:16.877784 | controller | TASK [ci_nmstate : Provision nncps] ********************************************
2025-10-10 11:51:16.877801 | controller | Friday 10 October 2025  11:51:16 +0000 (0:00:01.116)       0:01:24.536 ********
2025-10-10 11:51:16.919882 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/ci_nmstate/tasks/nmstate_k8s_provision_node.yml for instance => (item=crc)
2025-10-10 11:51:17.014115 | controller |
2025-10-10 11:51:17.014156 | controller | TASK [ci_nmstate : Prepare the k8s nmstate nncp to apply] **********************
2025-10-10 11:51:17.014167 | controller | Friday 10 October 2025  11:51:16 +0000 (0:00:00.042)       0:01:24.578 ********
2025-10-10 11:51:17.014181 | controller | ok: [instance]
2025-10-10 11:51:17.014208 | controller |
2025-10-10 11:51:17.014308 | controller | TASK [ci_nmstate : Save k8s nmstate nncp manifests as artifacts] ***************
2025-10-10 11:51:17.014519 | controller | Friday 10 October 2025  11:51:17 +0000 (0:00:00.094)       0:01:24.673 ********
2025-10-10 11:51:17.553306 | controller | changed: [instance]
2025-10-10 11:51:17.553376 | controller |
2025-10-10 11:51:17.553517 | controller | TASK [ci_nmstate : Provision nmstate nncp for the node worker] *****************
2025-10-10 11:51:17.553654 | controller | Friday 10 October 2025  11:51:17 +0000 (0:00:00.538)       0:01:25.212 ********
2025-10-10 11:51:18.468771 | controller | changed: [instance]
2025-10-10 11:51:18.468863 | controller |
2025-10-10 11:51:18.469009 | controller | TASK [ci_nmstate : Wait for nsmtate nncp to be ready] **************************
2025-10-10 11:51:18.469149 | controller | Friday 10 October 2025  11:51:18 +0000 (0:00:00.915)       0:01:26.127 ********
2025-10-10 11:56:41.142404 | controller | fatal: [instance]: FAILED! => changed=false
2025-10-10 11:56:41.142605 | controller |   api_found: true
2025-10-10 11:56:41.142642 | controller |   attempts: 30
2025-10-10 11:56:41.143229 | controller |   resources:
2025-10-10 11:56:41.143267 | controller |   - apiVersion: nmstate.io/v1
2025-10-10 11:56:41.143275 | controller |     kind: NodeNetworkConfigurationPolicy
2025-10-10 11:56:41.143296 | controller |     metadata:
2025-10-10 11:56:41.143340 | controller |       annotations:
2025-10-10 11:56:41.143359 | controller |         nmstate.io/webhook-mutating-timestamp: '1760097078214058592'
2025-10-10 11:56:41.143367 | controller |       creationTimestamp: '2025-10-10T11:51:18Z'
2025-10-10 11:56:41.143376 | controller |       generation: 1
2025-10-10 11:56:41.143399 | controller |       managedFields:
2025-10-10 11:56:41.143503 | controller |       - apiVersion: nmstate.io/v1
2025-10-10 11:56:41.143629 | controller |         fieldsType: FieldsV1
2025-10-10 11:56:41.143755 | controller |         fieldsV1:
2025-10-10 11:56:41.143906 | controller |           f:spec:
2025-10-10 11:56:41.144020 | controller |             .: {}
2025-10-10 11:56:41.144162 | controller |             f:desiredState:
2025-10-10 11:56:41.144306 | controller |               .: {}
2025-10-10 11:56:41.144438 | controller |               f:dns-resolver:
2025-10-10 11:56:41.144617 | controller |                 .: {}
2025-10-10 11:56:41.144715 | controller |                 f:config:
2025-10-10 11:56:41.144879 | controller |                   .: {}
2025-10-10 11:56:41.144992 | controller |                   f:search: {}
2025-10-10 11:56:41.145115 | controller |                   f:server: {}
2025-10-10 11:56:41.145238 | controller |               f:interfaces: {}
2025-10-10 11:56:41.145427 | controller |             f:nodeSelector:
2025-10-10 11:56:41.145530 | controller |               .: {}
2025-10-10 11:56:41.145656 | controller |               f:kubernetes.io/hostname: {}
2025-10-10 11:56:41.145787 | controller |               f:node-role.kubernetes.io/worker: {}
2025-10-10 11:56:41.145917 | controller |         manager: OpenAPI-Generator
2025-10-10 11:56:41.146047 | controller |         operation: Update
2025-10-10 11:56:41.146173 | controller |         time: '2025-10-10T11:51:18Z'
2025-10-10 11:56:41.146354 | controller |       - apiVersion: nmstate.io/v1
2025-10-10 11:56:41.146506 | controller |         fieldsType: FieldsV1
2025-10-10 11:56:41.146616 | controller |         fieldsV1:
2025-10-10 11:56:41.146732 | controller |           f:status:
2025-10-10 11:56:41.146854 | controller |             .: {}
2025-10-10 11:56:41.146979 | controller |             f:conditions: {}
2025-10-10 11:56:41.147127 | controller |             f:lastUnavailableNodeCountUpdate: {}
2025-10-10 11:56:41.147239 | controller |         manager: manager
2025-10-10 11:56:41.147400 | controller |         operation: Update
2025-10-10 11:56:41.147508 | controller |         subresource: status
2025-10-10 11:56:41.147645 | controller |         time: '2025-10-10T11:53:44Z'
2025-10-10 11:56:41.147765 | controller |       name: crc
2025-10-10 11:56:41.147906 | controller |       resourceVersion: '36212'
2025-10-10 11:56:41.148013 | controller |       uid: 59e60070-fffa-411c-95c5-4ad0fbc5d010
2025-10-10 11:56:41.148141 | controller |     spec:
2025-10-10 11:56:41.148281 | controller |       desiredState:
2025-10-10 11:56:41.148428 | controller |         dns-resolver:
2025-10-10 11:56:41.148541 | controller |           config:
2025-10-10 11:56:41.148665 | controller |             search:
2025-10-10 11:56:41.148832 | controller |             - testing-untagged.example.com
2025-10-10 11:56:41.148970 | controller |             - testing-vlan.example.com
2025-10-10 11:56:41.149123 | controller |             server:
2025-10-10 11:56:41.149193 | controller |             - 192.168.130.11
2025-10-10 11:56:41.149376 | controller |             - 192.168.130.1
2025-10-10 11:56:41.149493 | controller |         interfaces:
2025-10-10 11:56:41.149624 | controller |         - description: testing-untagged
2025-10-10 11:56:41.149746 | controller |           ipv4:
2025-10-10 11:56:41.149875 | controller |             address:
2025-10-10 11:56:41.149996 | controller |             - ip: 172.17.20.5
2025-10-10 11:56:41.150141 | controller |               prefix-length: 24
2025-10-10 11:56:41.150249 | controller |             enabled: true
2025-10-10 11:56:41.150413 | controller |           ipv6:
2025-10-10 11:56:41.150528 | controller |             enabled: false
2025-10-10 11:56:41.150650 | controller |           mtu: 1500
2025-10-10 11:56:41.150774 | controller |           name: enp6s0
2025-10-10 11:56:41.150920 | controller |           state: up
2025-10-10 11:56:41.151027 | controller |           type: ethernet
2025-10-10 11:56:41.151159 | controller |         - description: testing-vlan
2025-10-10 11:56:41.151891 | controller |           ipv4:
2025-10-10 11:56:41.152004 | controller |             address:
2025-10-10 11:56:41.152024 | controller |             - ip: 172.17.21.5
2025-10-10 11:56:41.152038 | controller |               prefix-length: 24
2025-10-10 11:56:41.152052 | controller |             enabled: true
2025-10-10 11:56:41.152071 | controller |           ipv6:
2025-10-10 11:56:41.152120 | controller |             enabled: false
2025-10-10 11:56:41.152256 | controller |           mtu: 1496
2025-10-10 11:56:41.152420 | controller |           name: enp6s0.21
2025-10-10 11:56:41.152549 | controller |           state: up
2025-10-10 11:56:41.152686 | controller |           type: vlan
2025-10-10 11:56:41.152830 | controller |           vlan:
2025-10-10 11:56:41.153247 | controller |             base-iface: enp6s0
2025-10-10 11:56:41.153355 | controller |             id: 21
2025-10-10 11:56:41.153378 | controller |       nodeSelector:
2025-10-10 11:56:41.153397 | controller |         kubernetes.io/hostname: crc
2025-10-10 11:56:41.153477 | controller |         node-role.kubernetes.io/worker: ''
2025-10-10 11:56:41.153600 | controller |     status:
2025-10-10 11:56:41.153722 | controller |       conditions:
2025-10-10 11:56:41.153849 | controller |       - lastHeartbeatTime: '2025-10-10T11:53:44Z'
2025-10-10 11:56:41.154013 | controller |         lastTransitionTime: '2025-10-10T11:53:44Z'
2025-10-10 11:56:41.154206 | controller |         reason: FailedToConfigure
2025-10-10 11:56:41.154390 | controller |         status: 'False'
2025-10-10 11:56:41.154549 | controller |         type: Available
2025-10-10 11:56:41.154717 | controller |       - lastHeartbeatTime: '2025-10-10T11:53:44Z'
2025-10-10 11:56:41.154869 | controller |         lastTransitionTime: '2025-10-10T11:53:44Z'
2025-10-10 11:56:41.154997 | controller |         message: 1/1 nodes failed to configure
2025-10-10 11:56:41.155412 | controller |         reason: FailedToConfigure
2025-10-10 11:56:41.155478 | controller |         status: 'True'
2025-10-10 11:56:41.155500 | controller |         type: Degraded
2025-10-10 11:56:41.155654 | controller |       - lastHeartbeatTime: '2025-10-10T11:53:44Z'
2025-10-10 11:56:41.155878 | controller |         lastTransitionTime: '2025-10-10T11:53:44Z'
2025-10-10 11:56:41.156382 | controller |         reason: ConfigurationProgressing
2025-10-10 11:56:41.156457 | controller |         status: 'False'
2025-10-10 11:56:41.156482 | controller |         type: Progressing
2025-10-10 11:56:41.156704 | controller |       lastUnavailableNodeCountUpdate: '2025-10-10T11:53:44Z'
2025-10-10 11:56:41.157076 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (30 retries left).
2025-10-10 11:56:41.157145 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (29 retries left).
2025-10-10 11:56:41.157320 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (28 retries left).
2025-10-10 11:56:41.157457 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (27 retries left).
2025-10-10 11:56:41.157618 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (26 retries left).
2025-10-10 11:56:41.157812 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (25 retries left).
2025-10-10 11:56:41.157970 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (24 retries left).
2025-10-10 11:56:41.158109 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (23 retries left).
2025-10-10 11:56:41.158272 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (22 retries left).
2025-10-10 11:56:41.158429 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (21 retries left).
2025-10-10 11:56:41.158555 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (20 retries left).
2025-10-10 11:56:41.158687 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (19 retries left).
2025-10-10 11:56:41.158819 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (18 retries left).
2025-10-10 11:56:41.158973 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (17 retries left).
2025-10-10 11:56:41.159169 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (16 retries left).
2025-10-10 11:56:41.159385 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (15 retries left).
2025-10-10 11:56:41.159520 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (14 retries left).
2025-10-10 11:56:41.159654 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (13 retries left).
2025-10-10 11:56:41.159838 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (12 retries left).
2025-10-10 11:56:41.160028 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (11 retries left).
2025-10-10 11:56:41.160214 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (10 retries left).
2025-10-10 11:56:41.160665 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (9 retries left).
2025-10-10 11:56:41.160867 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (8 retries left).
2025-10-10 11:56:41.160893 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (7 retries left).
2025-10-10 11:56:41.161049 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (6 retries left).
2025-10-10 11:56:41.161225 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (5 retries left).
2025-10-10 11:56:41.161392 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (4 retries left).
2025-10-10 11:56:41.161525 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (3 retries left).
2025-10-10 11:56:41.161898 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (2 retries left).
2025-10-10 11:56:41.162063 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (1 retries left).
2025-10-10 11:56:41.162085 | controller |
2025-10-10 11:56:41.162209 | controller | TASK [Get NetworkManager logs - after] *****************************************
2025-10-10 11:56:41.162372 | controller | Friday 10 October 2025  11:56:41 +0000 (0:05:22.684)       0:06:48.811 ********
2025-10-10 11:56:41.473271 | controller | changed: [instance]
2025-10-10 11:56:41.473365 | controller |
2025-10-10 11:56:41.473406 | controller | TASK [Get all pods state] ******************************************************
2025-10-10 11:56:41.473538 | controller | Friday 10 October 2025  11:56:41 +0000 (0:00:00.320)       0:06:49.132 ********
2025-10-10 11:56:41.968483 | controller | ok: [instance]
2025-10-10 11:56:41.968576 | controller |
2025-10-10 11:56:41.968799 | controller | TASK [Get NodeNetworkConfigurationPolicy] **************************************
2025-10-10 11:56:41.968994 | controller | Friday 10 October 2025  11:56:41 +0000 (0:00:00.495)       0:06:49.627 ********
2025-10-10 11:56:42.783997 | controller | ok: [instance]
2025-10-10 11:56:42.784052 | controller |
2025-10-10 11:56:42.784107 | controller | TASK [Create missing enp6s0] ***************************************************
2025-10-10 11:56:42.784197 | controller | Friday 10 October 2025  11:56:42 +0000 (0:00:00.815)       0:06:50.443 ********
2025-10-10 11:56:43.485108 | controller | fatal: [instance]: FAILED! => changed=true
2025-10-10 11:56:43.485170 | controller |   cmd: |-
2025-10-10 11:56:43.485276 | controller |     set -o pipefail; oc -n openshift-nmstate exec -i $(oc -n openshift-nmstate get pod -l component=kubernetes-nmstate-handler -o name | head -n 1) -- ip link add enp6s0 type veth
2025-10-10 11:56:43.485373 | controller |   delta: '0:00:00.441209'
2025-10-10 11:56:43.485471 | controller |   end: '2025-10-10 11:56:43.448007'
2025-10-10 11:56:43.485622 | controller |   msg: non-zero return code
2025-10-10 11:56:43.485719 | controller |   rc: 2
2025-10-10 11:56:43.485813 | controller |   start: '2025-10-10 11:56:43.006798'
2025-10-10 11:56:43.485957 | controller |   stderr: |-
2025-10-10 11:56:43.486073 | controller |     RTNETLINK answers: File exists
2025-10-10 11:56:43.486089 | controller |     command terminated with exit code 2
2025-10-10 11:56:43.486224 | controller |   stderr_lines: <omitted>
2025-10-10 11:56:43.486432 | controller |   stdout: ''
2025-10-10 11:56:43.486454 | controller |   stdout_lines: <omitted>
2025-10-10 11:56:43.490746 | controller |
2025-10-10 11:56:43.491070 | controller | PLAY RECAP *********************************************************************
2025-10-10 11:56:43.491207 | controller | crc                        : ok=1    changed=0    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-10 11:56:43.491455 | controller | instance                   : ok=41   changed=18   unreachable=0    failed=1    skipped=10   rescued=1    ignored=0
2025-10-10 11:56:43.491662 | controller |
2025-10-10 11:56:43.491855 | controller | Friday 10 October 2025  11:56:43 +0000 (0:00:00.705)       0:06:51.148 ********
2025-10-10 11:56:43.492087 | controller | ===============================================================================
2025-10-10 11:56:43.492276 | controller | ci_nmstate : Wait for nsmtate nncp to be ready ------------------------ 322.68s
2025-10-10 11:56:43.492502 | controller | ci_nmstate : Wait for nmstate operator to be installed ----------------- 31.83s
2025-10-10 11:56:43.492698 | controller | ci_nmstate : Wait for nsmtate Deployments to be ready ------------------ 31.49s
2025-10-10 11:56:43.492909 | controller | Fetch crc network facts ------------------------------------------------- 6.86s
2025-10-10 11:56:43.493118 | controller | ci_nmstate : Create the OLM subscription resources ---------------------- 1.60s
2025-10-10 11:56:43.493434 | controller | ci_nmstate : Wait for nsmtate DaemonSet to be ready --------------------- 1.12s
2025-10-10 11:56:43.493548 | controller | Gathering Facts --------------------------------------------------------- 1.10s
2025-10-10 11:56:43.493751 | controller | ci_nmstate : Create the nmstate namespace ------------------------------- 0.99s
2025-10-10 11:56:43.493966 | controller | ci_nmstate : Get k8s nodes ---------------------------------------------- 0.97s
2025-10-10 11:56:43.494187 | controller | ci_nmstate : Save k8s nmstate OLM manifests as artifacts ---------------- 0.97s
2025-10-10 11:56:43.494446 | controller | ci_nmstate : Provision nmstate nncp for the node worker ----------------- 0.92s
2025-10-10 11:56:43.494677 | controller | Get NodeNetworkConfigurationPolicy -------------------------------------- 0.82s
2025-10-10 11:56:43.496214 | controller | ci_nmstate : Trigger nmstate operator to install nmstate ---------------- 0.80s
2025-10-10 11:56:43.496310 | controller | networking_mapper : Save instances refreshed facts for troubleshooting purposes --- 0.77s
2025-10-10 11:56:43.496328 | controller | Create missing enp6s0 --------------------------------------------------- 0.71s
2025-10-10 11:56:43.496337 | controller | networking_mapper : Write the Networking Definition to file ------------- 0.56s
2025-10-10 11:56:43.496354 | controller | ci_nmstate : Save k8s nmstate nncp manifests as artifacts --------------- 0.54s
2025-10-10 11:56:43.496362 | controller | Add a dummy ethernet interface to target the crc NMstate ---------------- 0.50s
2025-10-10 11:56:43.496380 | controller | Get all pods state ------------------------------------------------------ 0.50s
2025-10-10 11:56:43.496394 | controller | networking_mapper : Write the Networking Environment Definition to file --- 0.47s
2025-10-10 11:56:43.580911 | controller | CRITICAL Ansible return code was 2, command was: ['ansible-playbook', '--inventory', '/home/zuul/.cache/molecule/ci_nmstate/default/inventory', '--skip-tags', 'molecule-notest,notest', '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/ci_nmstate/molecule/default/converge.yml']
2025-10-10 11:56:43.581726 | controller | WARNING  An error occurred during the test sequence action: 'converge'. Cleaning up.
2025-10-10 11:56:43.602108 | controller | INFO     Running default > cleanup
2025-10-10 11:56:43.603112 | controller | WARNING  Skipping, cleanup playbook not configured.
2025-10-10 11:56:43.620907 | controller | INFO     Running default > destroy
2025-10-10 11:56:43.621678 | controller | WARNING  Skipping, instances are delegated.
2025-10-10 11:56:43.622384 | controller | INFO     Pruning extra files from scenario ephemeral directory
2025-10-10 11:56:43.625806 | controller | INFO     Writing /tmp/report.html report.
2025-10-10 11:56:43.881634 | controller | ERROR
2025-10-10 11:56:43.881795 | controller | {
2025-10-10 11:56:43.881825 | controller |   "delta": "0:08:13.922600",
2025-10-10 11:56:43.881846 | controller |   "end": "2025-10-10 11:56:43.694418",
2025-10-10 11:56:43.881863 | controller |   "msg": "non-zero return code",
2025-10-10 11:56:43.881882 | controller |   "rc": 1,
2025-10-10 11:56:43.881899 | controller |   "start": "2025-10-10 11:48:29.771818"
2025-10-10 11:56:43.881915 | controller | }
failure
2025-10-10 11:56:43.890392 | 
2025-10-10 11:56:43.890463 | PLAY RECAP
2025-10-10 11:56:43.890503 | controller | ok: 2 changed: 0 unreachable: 0 failed: 1 skipped: 1 rescued: 0 ignored: 0
2025-10-10 11:56:43.890523 | 
2025-10-10 11:56:43.984055 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-10 11:56:43.985976 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-10 11:56:44.592798 | 
2025-10-10 11:56:44.592907 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-10-10 11:56:44.614642 | 
2025-10-10 11:56:44.614725 | TASK [Filter out host if needed]
2025-10-10 11:56:44.623542 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-10-10 11:56:44.628146 | 
2025-10-10 11:56:44.628211 | TASK [Ensure file is present]
2025-10-10 11:56:45.192716 | controller | ok
2025-10-10 11:56:45.207258 | 
2025-10-10 11:56:45.207407 | TASK [Manage molecule report file]
2025-10-10 11:56:46.253956 | controller | changed
2025-10-10 11:56:46.266804 | 
2025-10-10 11:56:46.266983 | TASK [Check if we get ci-framework-data basedir]
2025-10-10 11:56:46.632911 | controller | ok
2025-10-10 11:56:46.645935 | 
2025-10-10 11:56:46.646119 | TASK [Create ci-framework-data log directory for zuul]
2025-10-10 11:56:47.168260 | controller | changed
2025-10-10 11:56:47.183887 | 
2025-10-10 11:56:47.184002 | TASK [Copy ci-framework interesting files]
2025-10-10 11:56:47.536986 | controller | cp: cannot open '/home/zuul/ci-framework-data/logs/NetworkManager-before.log' for reading: Permission denied
2025-10-10 11:56:47.537077 | controller | cp: cannot open '/home/zuul/ci-framework-data/logs/NetworkManager-after.log' for reading: Permission denied
2025-10-10 11:56:47.549113 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2025-10-10 11:56:47.731458 | controller | changed
2025-10-10 11:56:47.739068 | 
2025-10-10 11:56:47.739159 | TASK [Get SELinux listing]
2025-10-10 11:56:48.323565 | controller | changed
2025-10-10 11:56:48.337008 | 
2025-10-10 11:56:48.337164 | TASK [Generate log index]
2025-10-10 11:56:49.903454 | controller | changed
2025-10-10 11:56:49.915030 | 
2025-10-10 11:56:49.915176 | TASK [Get some env related data]
2025-10-10 11:56:50.720176 | controller | /home/zuul/.local/bin/ansible
2025-10-10 11:56:51.468083 | controller | changed
2025-10-10 11:56:51.499095 | 
2025-10-10 11:56:51.499216 | TASK [Generate list of logs to collect in home directory]
2025-10-10 11:56:51.943593 | controller | ok: All paths examined
2025-10-10 11:56:51.956497 | 
2025-10-10 11:56:51.956648 | LOOP [Copy logs from home directory]
2025-10-10 11:56:52.696711 | controller | changed:
2025-10-10 11:56:52.697066 | controller | {
2025-10-10 11:56:52.697102 | controller |   "atime": 1743544925.4788878,
2025-10-10 11:56:52.697122 | controller |   "ctime": 1743545329.1409318,
2025-10-10 11:56:52.697140 | controller |   "dev": 64513,
2025-10-10 11:56:52.697157 | controller |   "gid": 1000,
2025-10-10 11:56:52.697174 | controller |   "gr_name": "zuul",
2025-10-10 11:56:52.697190 | controller |   "inode": 4518807,
2025-10-10 11:56:52.697206 | controller |   "isblk": false,
2025-10-10 11:56:52.697222 | controller |   "ischr": false,
2025-10-10 11:56:52.697247 | controller |   "isdir": false,
2025-10-10 11:56:52.697264 | controller |   "isfifo": false,
2025-10-10 11:56:52.697279 | controller |   "isgid": false,
2025-10-10 11:56:52.697294 | controller |   "islnk": false,
2025-10-10 11:56:52.697309 | controller |   "isreg": true,
2025-10-10 11:56:52.697323 | controller |   "issock": false,
2025-10-10 11:56:52.697338 | controller |   "isuid": false,
2025-10-10 11:56:52.697352 | controller |   "mode": "0644",
2025-10-10 11:56:52.697367 | controller |   "mtime": 1743545329.1409318,
2025-10-10 11:56:52.697386 | controller |   "nlink": 1,
2025-10-10 11:56:52.697402 | controller |   "path": "/home/zuul/crc-setup.log",
2025-10-10 11:56:52.697417 | controller |   "pw_name": "zuul",
2025-10-10 11:56:52.697432 | controller |   "rgrp": true,
2025-10-10 11:56:52.697447 | controller |   "roth": true,
2025-10-10 11:56:52.697462 | controller |   "rusr": true,
2025-10-10 11:56:52.697478 | controller |   "size": 4108,
2025-10-10 11:56:52.697493 | controller |   "uid": 1000,
2025-10-10 11:56:52.697510 | controller |   "wgrp": false,
2025-10-10 11:56:52.697526 | controller |   "woth": false,
2025-10-10 11:56:52.697541 | controller |   "wusr": true,
2025-10-10 11:56:52.697691 | controller |   "xgrp": false,
2025-10-10 11:56:52.697720 | controller |   "xoth": false,
2025-10-10 11:56:52.697766 | controller |   "xusr": false
2025-10-10 11:56:52.697783 | controller | }
2025-10-10 11:56:53.470984 | controller | changed:
2025-10-10 11:56:53.471144 | controller | {
2025-10-10 11:56:53.471198 | controller |   "atime": 1760096233.372227,
2025-10-10 11:56:53.471241 | controller |   "ctime": 1760096231.563172,
2025-10-10 11:56:53.471280 | controller |   "dev": 64513,
2025-10-10 11:56:53.471317 | controller |   "gid": 1000,
2025-10-10 11:56:53.471353 | controller |   "gr_name": "zuul",
2025-10-10 11:56:53.471390 | controller |   "inode": 4194437,
2025-10-10 11:56:53.471429 | controller |   "isblk": false,
2025-10-10 11:56:53.471467 | controller |   "ischr": false,
2025-10-10 11:56:53.471504 | controller |   "isdir": false,
2025-10-10 11:56:53.471540 | controller |   "isfifo": false,
2025-10-10 11:56:53.471577 | controller |   "isgid": false,
2025-10-10 11:56:53.471614 | controller |   "islnk": false,
2025-10-10 11:56:53.471650 | controller |   "isreg": true,
2025-10-10 11:56:53.471687 | controller |   "issock": false,
2025-10-10 11:56:53.471788 | controller |   "isuid": false,
2025-10-10 11:56:53.471845 | controller |   "mode": "0644",
2025-10-10 11:56:53.471885 | controller |   "mtime": 1760096231.563172,
2025-10-10 11:56:53.472102 | controller |   "nlink": 1,
2025-10-10 11:56:53.472160 | controller |   "path": "/home/zuul/crc-start.log",
2025-10-10 11:56:53.472201 | controller |   "pw_name": "zuul",
2025-10-10 11:56:53.472244 | controller |   "rgrp": true,
2025-10-10 11:56:53.472282 | controller |   "roth": true,
2025-10-10 11:56:53.472319 | controller |   "rusr": true,
2025-10-10 11:56:53.472440 | controller |   "size": 3404,
2025-10-10 11:56:53.472630 | controller |   "uid": 1000,
2025-10-10 11:56:53.472687 | controller |   "wgrp": false,
2025-10-10 11:56:53.472761 | controller |   "woth": false,
2025-10-10 11:56:53.472812 | controller |   "wusr": true,
2025-10-10 11:56:53.472850 | controller |   "xgrp": false,
2025-10-10 11:56:53.472884 | controller |   "xoth": false,
2025-10-10 11:56:53.472975 | controller |   "xusr": false
2025-10-10 11:56:53.473140 | controller | }
2025-10-10 11:56:54.292947 | controller | changed:
2025-10-10 11:56:54.293095 | controller | {
2025-10-10 11:56:54.293146 | controller |   "atime": 1760096889.2161908,
2025-10-10 11:56:54.293186 | controller |   "ctime": 1760096906.3962693,
2025-10-10 11:56:54.293222 | controller |   "dev": 64513,
2025-10-10 11:56:54.293258 | controller |   "gid": 1000,
2025-10-10 11:56:54.293293 | controller |   "gr_name": "zuul",
2025-10-10 11:56:54.293329 | controller |   "inode": 4638601,
2025-10-10 11:56:54.293365 | controller |   "isblk": false,
2025-10-10 11:56:54.293401 | controller |   "ischr": false,
2025-10-10 11:56:54.293435 | controller |   "isdir": false,
2025-10-10 11:56:54.293481 | controller |   "isfifo": false,
2025-10-10 11:56:54.293519 | controller |   "isgid": false,
2025-10-10 11:56:54.293556 | controller |   "islnk": false,
2025-10-10 11:56:54.293591 | controller |   "isreg": true,
2025-10-10 11:56:54.293626 | controller |   "issock": false,
2025-10-10 11:56:54.293661 | controller |   "isuid": false,
2025-10-10 11:56:54.293696 | controller |   "mode": "0644",
2025-10-10 11:56:54.293789 | controller |   "mtime": 1760096906.3962693,
2025-10-10 11:56:54.293834 | controller |   "nlink": 1,
2025-10-10 11:56:54.293873 | controller |   "path": "/home/zuul/ansible.log",
2025-10-10 11:56:54.293910 | controller |   "pw_name": "zuul",
2025-10-10 11:56:54.293952 | controller |   "rgrp": true,
2025-10-10 11:56:54.293988 | controller |   "roth": true,
2025-10-10 11:56:54.294025 | controller |   "rusr": true,
2025-10-10 11:56:54.294061 | controller |   "size": 6749,
2025-10-10 11:56:54.294096 | controller |   "uid": 1000,
2025-10-10 11:56:54.294132 | controller |   "wgrp": false,
2025-10-10 11:56:54.294190 | controller |   "woth": false,
2025-10-10 11:56:54.294232 | controller |   "wusr": true,
2025-10-10 11:56:54.294269 | controller |   "xgrp": false,
2025-10-10 11:56:54.294306 | controller |   "xoth": false,
2025-10-10 11:56:54.294340 | controller |   "xusr": false
2025-10-10 11:56:54.294377 | controller | }
2025-10-10 11:56:54.303327 | 
2025-10-10 11:56:54.303389 | TASK [Copy crio stats log file]
2025-10-10 11:56:54.327443 | controller | skipping: Conditional result was False
2025-10-10 11:56:54.333155 | 
2025-10-10 11:56:54.333216 | TASK [Get SELinux related data]
2025-10-10 11:56:54.696091 | controller | <no matches>
2025-10-10 11:56:54.863812 | controller | ERROR
2025-10-10 11:56:54.864089 | controller | {
2025-10-10 11:56:54.864153 | controller |   "delta": "0:00:00.018874",
2025-10-10 11:56:54.864198 | controller |   "end": "2025-10-10 11:56:54.698045",
2025-10-10 11:56:54.864237 | controller |   "msg": "non-zero return code",
2025-10-10 11:56:54.864275 | controller |   "rc": 1,
2025-10-10 11:56:54.864314 | controller |   "start": "2025-10-10 11:56:54.679171"
2025-10-10 11:56:54.864350 | controller | }
2025-10-10 11:56:54.864399 | controller | ERROR: Ignoring Errors
2025-10-10 11:56:54.876603 | 
2025-10-10 11:56:54.876773 | TASK [Create system configuration directory]
2025-10-10 11:56:55.246009 | controller | changed
2025-10-10 11:56:55.258942 | 
2025-10-10 11:56:55.259143 | TASK [Get some of the system configurations]
2025-10-10 11:56:55.811286 | controller | changed
2025-10-10 11:56:55.821231 | 
2025-10-10 11:56:55.821345 | TASK [Copy generated documentation if available]
2025-10-10 11:56:55.847772 | controller | skipping: Conditional result was False
2025-10-10 11:56:55.855514 | 
2025-10-10 11:56:55.855610 | TASK [Copy generated AsciiDoc documentation if available]
2025-10-10 11:56:55.880775 | controller | skipping: Conditional result was False
2025-10-10 11:56:55.888308 | 
2025-10-10 11:56:55.888413 | TASK [Compress logs bigger than 2MB]
2025-10-10 11:56:56.427677 | controller | changed
2025-10-10 11:56:56.439941 | 
2025-10-10 11:56:56.440088 | TASK [Copy files from workspace on node]
2025-10-10 11:56:56.469001 | controller | ok
2025-10-10 11:56:56.512079 | 
2025-10-10 11:56:56.512220 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-10 11:56:56.548223 | controller | skipping: Conditional result was False
2025-10-10 11:56:56.557549 | 
2025-10-10 11:56:56.557718 | TASK [fetch-output : Set log path for single node]
2025-10-10 11:56:56.600772 | controller | ok
2025-10-10 11:56:56.608444 | 
2025-10-10 11:56:56.608535 | LOOP [fetch-output : Ensure local output dirs]
2025-10-10 11:56:56.912254 | controller -> localhost | ok: "/var/lib/zuul/builds/71040a836ab340bab398c10ad4a5cf0a/work/logs"
2025-10-10 11:56:56.912685 | controller -> localhost | changed: All items complete
2025-10-10 11:56:56.912779 | 
2025-10-10 11:56:57.205216 | controller -> localhost | changed: "/var/lib/zuul/builds/71040a836ab340bab398c10ad4a5cf0a/work/artifacts"
2025-10-10 11:56:57.459997 | controller -> localhost | changed: "/var/lib/zuul/builds/71040a836ab340bab398c10ad4a5cf0a/work/docs"
2025-10-10 11:56:57.484874 | 
2025-10-10 11:56:57.485068 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-10 11:56:58.371058 | controller | changed:
2025-10-10 11:56:58.371263 | controller | .d..t...... ./
2025-10-10 11:56:58.371290 | controller | >f+++++++++ README.html
2025-10-10 11:56:58.371310 | controller | >f+++++++++ ansible-execution.log
2025-10-10 11:56:58.371329 | controller | >f+++++++++ ansible.log
2025-10-10 11:56:58.371347 | controller | >f+++++++++ crc-setup.log
2025-10-10 11:56:58.371368 | controller | >f+++++++++ crc-start.log
2025-10-10 11:56:58.371386 | controller | >f+++++++++ dmesg.log
2025-10-10 11:56:58.371403 | controller | >f+++++++++ installed-pkgs.log
2025-10-10 11:56:58.371564 | controller | >f+++++++++ python.log
2025-10-10 11:56:58.371592 | controller | >f+++++++++ registries.conf
2025-10-10 11:56:58.371610 | controller | >f+++++++++ report.html
2025-10-10 11:56:58.371627 | controller | >f+++++++++ selinux-denials.log
2025-10-10 11:56:58.371644 | controller | >f+++++++++ selinux-listing.log
2025-10-10 11:56:58.371660 | controller | cd+++++++++ ci-framework-data/
2025-10-10 11:56:58.371676 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-10-10 11:56:58.371692 | controller | >f+++++++++ ci-framework-data/artifacts/networking-mapper-instances-facts.yml
2025-10-10 11:56:58.371709 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-10-10 11:56:58.371782 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/
2025-10-10 11:56:58.371806 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/nmstate/
2025-10-10 11:56:58.371823 | controller | >f+++++++++ ci-framework-data/artifacts/manifests/nmstate/crc-nncp.yaml
2025-10-10 11:56:58.371840 | controller | >f+++++++++ ci-framework-data/artifacts/manifests/nmstate/nmstate-nmstate-olm.yaml
2025-10-10 11:56:58.371857 | controller | >f+++++++++ ci-framework-data/artifacts/manifests/nmstate/nmstate-operatorgroup-olm.yaml
2025-10-10 11:56:58.371874 | controller | >f+++++++++ ci-framework-data/artifacts/manifests/nmstate/nmstate-subscription-olm.yaml
2025-10-10 11:56:58.371890 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-10-10 11:56:58.371906 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-10-10 11:56:58.371923 | controller | cd+++++++++ ci-framework-data/artifacts/repositories/
2025-10-10 11:56:58.371939 | controller | >f+++++++++ ci-framework-data/artifacts/repositories/delorean.repo.md5
2025-10-10 11:56:58.371955 | controller | cd+++++++++ ci-framework-data/logs/
2025-10-10 11:56:58.371971 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-10-10 11:56:58.371987 | controller | cd+++++++++ registries.conf.d/
2025-10-10 11:56:58.372003 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-10-10 11:56:58.372019 | controller | cd+++++++++ system-config/
2025-10-10 11:56:58.372034 | controller | cd+++++++++ system-config/libvirt/
2025-10-10 11:56:58.372050 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-10-10 11:56:58.372066 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-10-10 11:56:58.372081 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf
2025-10-10 11:56:58.372097 | controller | >f+++++++++ system-config/libvirt/network.conf
2025-10-10 11:56:58.372112 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf
2025-10-10 11:56:58.372128 | controller | >f+++++++++ system-config/libvirt/qemu.conf
2025-10-10 11:56:58.372143 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf
2025-10-10 11:56:58.372159 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf
2025-10-10 11:56:58.372174 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf
2025-10-10 11:56:58.372190 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf
2025-10-10 11:56:58.372206 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf
2025-10-10 11:56:58.372228 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf
2025-10-10 11:56:58.372244 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf
2025-10-10 11:56:58.372260 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf
2025-10-10 11:56:58.372275 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf
2025-10-10 11:56:58.372290 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf
2025-10-10 11:56:58.920454 | controller | changed: .d..t...... ./
2025-10-10 11:56:59.572095 | controller | changed: .d..t...... ./
2025-10-10 11:56:59.590338 | 
2025-10-10 11:56:59.590512 | TASK [Return artifact to Zuul]
2025-10-10 11:56:59.630407 | controller | ok
2025-10-10 11:56:59.651580 | 
2025-10-10 11:56:59.651672 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-10-10 11:56:59.651793 | 
2025-10-10 11:56:59.651824 | PLAY RECAP
2025-10-10 11:56:59.651863 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-10-10 11:56:59.651883 | 
2025-10-10 11:56:59.779270 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-10 11:56:59.782310 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/dlrn/dlrn-report.yaml@master]
2025-10-10 11:57:00.394227 | 
2025-10-10 11:57:00.394338 | PLAY [Report DLRN results after job run]
2025-10-10 11:57:00.418841 | 
2025-10-10 11:57:00.418962 | TASK [Report job status to DLRN]
2025-10-10 11:57:00.447877 | controller | ok
2025-10-10 11:57:00.473463 | 
2025-10-10 11:57:00.473568 | TASK [dlrn_report : Warning if DLRN is not running]
2025-10-10 11:57:00.518418 | controller | skipping: Conditional result was False
2025-10-10 11:57:00.524250 | 
2025-10-10 11:57:00.524324 | TASK [dlrn_report : Install dlrnapi-client shyaml package]
2025-10-10 11:57:00.568610 | controller | skipping: Conditional result was False
2025-10-10 11:57:00.579134 | 
2025-10-10 11:57:00.579594 | TASK [dlrn_report : Install kinit related package]
2025-10-10 11:57:00.627796 | controller | skipping: Conditional result was False
2025-10-10 11:57:00.642447 | 
2025-10-10 11:57:00.642676 | TASK [dlrn_report : Install dlrn kerberos related packages]
2025-10-10 11:57:00.690785 | controller | skipping: Conditional result was False
2025-10-10 11:57:00.699445 | 
2025-10-10 11:57:00.699587 | TASK [Set zuul-log-path fact]
2025-10-10 11:57:00.748449 | controller | skipping: Conditional result was False
2025-10-10 11:57:00.762865 | 
2025-10-10 11:57:00.763049 | TASK [dlrn_report : Set the the value of cifmw_repo_setup_promotion when multiple dlrn tags are used]
2025-10-10 11:57:00.811244 | controller | skipping: Conditional result was False
2025-10-10 11:57:00.843334 | 
2025-10-10 11:57:00.843550 | TASK [Get hash related data from repo_setup role]
2025-10-10 11:57:00.910879 | controller | skipping: Conditional result was False
2025-10-10 11:57:00.925513 | 
2025-10-10 11:57:00.925690 | TASK [dlrn_report : Perform kinit for DLRN kerberos authentication]
2025-10-10 11:57:01.476232 | controller | skipping: Conditional result was False
2025-10-10 11:57:01.485856 | 
2025-10-10 11:57:01.485990 | TASK [dlrn_report : Set empty value for dlrnapi password]
2025-10-10 11:57:01.554131 | controller | skipping: Conditional result was False
2025-10-10 11:57:01.564294 | 
2025-10-10 11:57:01.564431 | TASK [dlrn_report : Report results to dlrn for the tested hash]
2025-10-10 11:57:02.096140 | controller | skipping: Conditional result was False
2025-10-10 11:57:02.125288 | 
2025-10-10 11:57:02.125399 | PLAY RECAP
2025-10-10 11:57:02.125452 | controller | ok: 0 changed: 0 unreachable: 0 failed: 0 skipped: 10 rescued: 0 ignored: 0
2025-10-10 11:57:02.125481 | 
2025-10-10 11:57:02.249751 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/dlrn/dlrn-report.yaml@master]
2025-10-10 11:57:02.250500 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-10 11:57:02.908059 | 
2025-10-10 11:57:02.908201 | PLAY [all]
2025-10-10 11:57:02.934303 | 
2025-10-10 11:57:02.934449 | TASK [include_role : fetch-output]
2025-10-10 11:57:02.974110 | controller | ok
2025-10-10 11:57:02.993374 | 
2025-10-10 11:57:02.993516 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-10 11:57:03.037712 | controller | skipping: Conditional result was False
2025-10-10 11:57:03.044020 | 
2025-10-10 11:57:03.044105 | TASK [fetch-output : Set log path for single node]
2025-10-10 11:57:03.073037 | controller | ok
2025-10-10 11:57:03.078354 | 
2025-10-10 11:57:03.078429 | LOOP [fetch-output : Ensure local output dirs]
2025-10-10 11:57:03.467197 | controller -> localhost | ok: "/var/lib/zuul/builds/71040a836ab340bab398c10ad4a5cf0a/work/logs"
2025-10-10 11:57:03.696634 | controller -> localhost | ok: "/var/lib/zuul/builds/71040a836ab340bab398c10ad4a5cf0a/work/artifacts"
2025-10-10 11:57:03.941546 | controller -> localhost | ok: "/var/lib/zuul/builds/71040a836ab340bab398c10ad4a5cf0a/work/docs"
2025-10-10 11:57:03.961268 | 
2025-10-10 11:57:03.961459 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-10 11:57:04.741699 | controller | ok
2025-10-10 11:57:04.742057 | controller | ok: All items complete
2025-10-10 11:57:04.742117 | 
2025-10-10 11:57:05.354774 | controller | ok
2025-10-10 11:57:05.979070 | controller | ok
2025-10-10 11:57:06.015464 | 
2025-10-10 11:57:06.015612 | TASK [include_role : fetch-output-openshift]
2025-10-10 11:57:06.041398 | controller | skipping: Conditional result was False
2025-10-10 11:57:06.049071 | 
2025-10-10 11:57:06.049185 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-10 11:57:06.504247 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.012429
2025-10-10 11:57:06.859632 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.009336
2025-10-10 11:57:06.904213 | 
2025-10-10 11:57:06.904359 | PLAY [all]
2025-10-10 11:57:06.924674 | 
2025-10-10 11:57:06.924809 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-10 11:57:07.510161 | controller | changed
2025-10-10 11:57:07.553196 | 
2025-10-10 11:57:07.553315 | PLAY RECAP
2025-10-10 11:57:07.553375 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-10 11:57:07.553406 | 
2025-10-10 11:57:07.668323 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-10 11:57:07.669115 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-10 11:57:08.335934 | 
2025-10-10 11:57:08.336061 | PLAY [localhost]
2025-10-10 11:57:08.354992 | 
2025-10-10 11:57:08.355100 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-10 11:57:08.719004 | localhost | changed
2025-10-10 11:57:08.723634 | 
2025-10-10 11:57:08.723709 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-10 11:57:08.751587 | localhost | ok
2025-10-10 11:57:08.759539 | 
2025-10-10 11:57:08.759603 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-10 11:57:09.140265 | localhost | changed
2025-10-10 11:57:09.152608 | 
2025-10-10 11:57:09.152709 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-10 11:57:09.913688 | localhost | changed
2025-10-10 11:57:09.932639 | 
2025-10-10 11:57:09.932806 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-10 11:57:10.349100 | localhost | Identity added: /var/lib/zuul/builds/71040a836ab340bab398c10ad4a5cf0a/work/tmp/ansible.50zuxp06 (/var/lib/zuul/builds/71040a836ab340bab398c10ad4a5cf0a/work/tmp/ansible.50zuxp06)
2025-10-10 11:57:10.349712 | localhost | ok: Runtime: 0:00:00.007787
2025-10-10 11:57:10.359563 | 
2025-10-10 11:57:10.359860 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-10 11:57:10.636927 | localhost | ok: Runtime: 0:00:00.005122
2025-10-10 11:57:10.642803 | 
2025-10-10 11:57:10.642880 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-10 11:57:10.693527 | localhost | changed
2025-10-10 11:57:10.698237 | 
2025-10-10 11:57:10.698322 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-10 11:57:11.094366 | localhost | changed
2025-10-10 11:57:11.132320 | 
2025-10-10 11:57:11.132421 | PLAY [localhost]
2025-10-10 11:57:11.155442 | 
2025-10-10 11:57:11.155572 | TASK [Generate bulk log download script]
2025-10-10 11:57:11.181181 | localhost | ok
2025-10-10 11:57:11.211275 | 
2025-10-10 11:57:11.211448 | TASK [local-log-download : Check API endpoint is defined]
2025-10-10 11:57:11.246366 | localhost | ok: All assertions passed
2025-10-10 11:57:11.256551 | 
2025-10-10 11:57:11.256698 | TASK [local-log-download : Create download script]
2025-10-10 11:57:11.693752 | localhost -> localhost | changed
2025-10-10 11:57:11.702870 | 
2025-10-10 11:57:11.702956 | TASK [Register quick-download link]
2025-10-10 11:57:11.731474 | localhost | ok
2025-10-10 11:57:11.786189 | 
2025-10-10 11:57:11.786364 | PLAY [logserver.rdoproject.org]
2025-10-10 11:57:11.814784 | 
2025-10-10 11:57:11.814900 | TASK [Set zuul-log-path fact]
2025-10-10 11:57:11.832856 | logserver.rdoproject.org | ok
2025-10-10 11:57:11.846636 | 
2025-10-10 11:57:11.846757 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-10 11:57:11.887232 | logserver.rdoproject.org | ok
2025-10-10 11:57:11.900622 | 
2025-10-10 11:57:11.900816 | TASK [upload-logs : Create log directories]
2025-10-10 11:57:13.065082 | logserver.rdoproject.org | changed
2025-10-10 11:57:13.071935 | 
2025-10-10 11:57:13.072066 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-10 11:57:13.388834 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006813
2025-10-10 11:57:13.393586 | 
2025-10-10 11:57:13.393655 | TASK [upload-logs : Upload logs to log server]
2025-10-10 11:57:14.189962 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-10 11:57:14.197082 | 
2025-10-10 11:57:14.197218 | LOOP [upload-logs : Compress console log and json output]
2025-10-10 11:57:14.274810 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-10 11:57:14.286092 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-10 11:57:14.295179 | 
2025-10-10 11:57:14.295379 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-10 11:57:14.369213 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-10 11:57:14.369469 | 
2025-10-10 11:57:14.386655 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-10 11:57:14.402762 | 
2025-10-10 11:57:14.402904 | LOOP [upload-logs : Upload console log and json output]