2026-02-24 18:11:38.283088 | Job console starting...
2026-02-24 18:11:38.501753 | Updating repositories
2026-02-24 18:11:39.245780 | Preparing job workspace
2026-02-24 18:11:45.890442 | Running Ansible setup...
2026-02-24 18:11:49.358022 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2026-02-24 18:11:49.826804 | 
2026-02-24 18:11:49.826895 | PLAY [localhost]
2026-02-24 18:11:49.834680 | 
2026-02-24 18:11:49.834746 | TASK [Gathering Facts]
2026-02-24 18:11:50.579912 | localhost | ok
2026-02-24 18:11:50.591883 | 
2026-02-24 18:11:50.591974 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-02-24 18:11:50.898540 | localhost -> localhost | changed
2026-02-24 18:11:50.903643 | 
2026-02-24 18:11:50.903713 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-02-24 18:11:51.545910 | localhost -> localhost | changed
2026-02-24 18:11:51.553743 | 
2026-02-24 18:11:51.553833 | TASK [Setup log path fact]
2026-02-24 18:11:51.571138 | localhost | ok
2026-02-24 18:11:51.581605 | 
2026-02-24 18:11:51.581678 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-24 18:11:51.599045 | localhost | ok
2026-02-24 18:11:51.605882 | 
2026-02-24 18:11:51.605950 | TASK [emit-job-header : Print job information]
2026-02-24 18:11:51.632827 | # Job Information
2026-02-24 18:11:51.632938 | Ansible Version: 2.15.12
2026-02-24 18:11:51.632966 | Job: cifmw-molecule-sushy_emulator
2026-02-24 18:11:51.632987 | Pipeline: github-check
2026-02-24 18:11:51.633005 | Executor: ibm-bm4-ze.softwarefactory-project.io
2026-02-24 18:11:51.633023 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3678
2026-02-24 18:11:51.633042 | Log URL (when completed): https://logserver.rdoproject.org/bb9/rdoproject.org/bb9a4d59823d4873bdd7d877a891d312/
2026-02-24 18:11:51.633060 | Event ID: 212d9ac0-11ac-11f1-8230-ebdb7e3205b1
2026-02-24 18:11:51.636517 | 
2026-02-24 18:11:51.636580 | LOOP [emit-job-header : Print node information]
2026-02-24 18:11:51.713871 | localhost | ok:
2026-02-24 18:11:51.714126 | localhost | # Node Information
2026-02-24 18:11:51.714161 | localhost | Inventory Hostname: controller
2026-02-24 18:11:51.714187 | localhost | Hostname: np0005628539
2026-02-24 18:11:51.714210 | localhost | Username: zuul
2026-02-24 18:11:51.714232 | localhost | Distro: CentOS 9
2026-02-24 18:11:51.714251 | localhost | Provider: ibm-bm4-nodepool
2026-02-24 18:11:51.714270 | localhost | Region: regionOne
2026-02-24 18:11:51.714289 | localhost | Label: centos-9-stream-crc-2-48-0-xl-ibm
2026-02-24 18:11:51.714345 | localhost | Product Name: OpenStack Compute
2026-02-24 18:11:51.714369 | localhost | Interface IP: 192.168.26.96
2026-02-24 18:11:51.739259 | 
2026-02-24 18:11:51.739347 | PLAY [all]
2026-02-24 18:11:51.745458 | 
2026-02-24 18:11:51.745533 | TASK [Gather network facts]
2026-02-24 18:11:52.190730 | controller | ok
2026-02-24 18:11:52.204058 | 
2026-02-24 18:11:52.204120 | TASK [include_role : start-zuul-console]
2026-02-24 18:11:52.221787 | controller | ok
2026-02-24 18:11:52.232650 | 
2026-02-24 18:11:52.232716 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-02-24 18:11:52.605144 | controller | ok
2026-02-24 18:11:52.612941 | 
2026-02-24 18:11:52.612998 | TASK [include_role : add-build-sshkey]
2026-02-24 18:11:52.630000 | controller | ok
2026-02-24 18:11:52.641205 | 
2026-02-24 18:11:52.641265 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-02-24 18:11:52.815880 | controller -> localhost | ok
2026-02-24 18:11:52.820727 | 
2026-02-24 18:11:52.820784 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-02-24 18:11:52.837757 | controller | ok
2026-02-24 18:11:52.848545 | controller | included: /var/lib/zuul/builds/bb9a4d59823d4873bdd7d877a891d312/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-02-24 18:11:52.853496 | 
2026-02-24 18:11:52.853553 | TASK [add-build-sshkey : Create Temp SSH key]
2026-02-24 18:11:53.371847 | controller -> localhost | Generating public/private rsa key pair.
2026-02-24 18:11:53.372051 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/bb9a4d59823d4873bdd7d877a891d312/work/bb9a4d59823d4873bdd7d877a891d312_id_rsa.
2026-02-24 18:11:53.372084 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/bb9a4d59823d4873bdd7d877a891d312/work/bb9a4d59823d4873bdd7d877a891d312_id_rsa.pub.
2026-02-24 18:11:53.372108 | controller -> localhost | The key fingerprint is:
2026-02-24 18:11:53.372128 | controller -> localhost | SHA256:Pyt3SEW2TAFp9G52Qn/r3P8X5si0BKzECkobFQEkiJY zuul-build-sshkey
2026-02-24 18:11:53.372148 | controller -> localhost | The key's randomart image is:
2026-02-24 18:11:53.372167 | controller -> localhost | +---[RSA 3072]----+
2026-02-24 18:11:53.372185 | controller -> localhost | |o.oo.oo  .oo..   |
2026-02-24 18:11:53.372204 | controller -> localhost | |oE.  .    o.+    |
2026-02-24 18:11:53.372222 | controller -> localhost | |.   .   ...=o.   |
2026-02-24 18:11:53.372239 | controller -> localhost | |   o .   o =+.   |
2026-02-24 18:11:53.372257 | controller -> localhost | |  . + . S ..* o .|
2026-02-24 18:11:53.372275 | controller -> localhost | |   o   . o.o = +.|
2026-02-24 18:11:53.372292 | controller -> localhost | |         .o.+ =..|
2026-02-24 18:11:53.372354 | controller -> localhost | |        . oo.+o.o|
2026-02-24 18:11:53.372377 | controller -> localhost | |         o..   oB|
2026-02-24 18:11:53.372396 | controller -> localhost | +----[SHA256]-----+
2026-02-24 18:11:53.372441 | controller -> localhost | ok: Runtime: 0:00:00.215184
2026-02-24 18:11:53.377784 | 
2026-02-24 18:11:53.377851 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-02-24 18:11:53.395257 | controller | ok
2026-02-24 18:11:53.403826 | controller | included: /var/lib/zuul/builds/bb9a4d59823d4873bdd7d877a891d312/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-02-24 18:11:53.411033 | 
2026-02-24 18:11:53.411092 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-02-24 18:11:53.424465 | controller | skipping: Conditional result was False
2026-02-24 18:11:53.429354 | 
2026-02-24 18:11:53.429423 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-02-24 18:11:53.894570 | controller | changed
2026-02-24 18:11:53.899114 | 
2026-02-24 18:11:53.899175 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-02-24 18:11:54.171541 | controller | ok
2026-02-24 18:11:54.175969 | 
2026-02-24 18:11:54.176031 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-02-24 18:11:55.319724 | controller | changed
2026-02-24 18:11:55.324469 | 
2026-02-24 18:11:55.324544 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-02-24 18:11:56.469456 | controller | changed
2026-02-24 18:11:56.474250 | 
2026-02-24 18:11:56.474333 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-02-24 18:11:56.487874 | controller | skipping: Conditional result was False
2026-02-24 18:11:56.492787 | 
2026-02-24 18:11:56.492849 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-02-24 18:11:56.759738 | controller -> localhost | changed
2026-02-24 18:11:56.768153 | 
2026-02-24 18:11:56.768212 | TASK [add-build-sshkey : Add back temp key]
2026-02-24 18:11:56.973963 | controller -> localhost | Identity added: /var/lib/zuul/builds/bb9a4d59823d4873bdd7d877a891d312/work/bb9a4d59823d4873bdd7d877a891d312_id_rsa (zuul-build-sshkey)
2026-02-24 18:11:56.974119 | controller -> localhost | ok: Runtime: 0:00:00.006547
2026-02-24 18:11:56.979280 | 
2026-02-24 18:11:56.979354 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-02-24 18:11:57.331961 | controller | ok
2026-02-24 18:11:57.335952 | 
2026-02-24 18:11:57.336009 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-02-24 18:11:57.359278 | controller | skipping: Conditional result was False
2026-02-24 18:11:57.368014 | 
2026-02-24 18:11:57.368080 | TASK [include_role : validate-host]
2026-02-24 18:11:57.385559 | controller | ok
2026-02-24 18:11:57.402117 | 
2026-02-24 18:11:57.402182 | TASK [validate-host : Define zuul_info_dir fact]
2026-02-24 18:11:57.429578 | controller | ok
2026-02-24 18:11:57.433631 | 
2026-02-24 18:11:57.433690 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2026-02-24 18:11:57.618879 | controller -> localhost | ok
2026-02-24 18:11:57.624342 | 
2026-02-24 18:11:57.624414 | TASK [validate-host : Collect information about the host]
2026-02-24 18:11:58.335391 | controller | ok
2026-02-24 18:11:58.342445 | 
2026-02-24 18:11:58.342511 | TASK [validate-host : Sanitize hostname]
2026-02-24 18:11:58.380263 | controller | ok
2026-02-24 18:11:58.384592 | 
2026-02-24 18:11:58.384653 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2026-02-24 18:11:58.721810 | controller -> localhost | changed
2026-02-24 18:11:58.726879 | 
2026-02-24 18:11:58.726944 | TASK [validate-host : Collect information about zuul worker]
2026-02-24 18:11:59.100109 | controller | ok
2026-02-24 18:11:59.104498 | 
2026-02-24 18:11:59.104567 | TASK [validate-host : Write out all zuul information for each host]
2026-02-24 18:11:59.442247 | controller -> localhost | changed
2026-02-24 18:11:59.450248 | 
2026-02-24 18:11:59.450353 | TASK [include_role : prepare-workspace-openshift]
2026-02-24 18:11:59.463423 | controller | skipping: Conditional result was False
2026-02-24 18:11:59.468191 | 
2026-02-24 18:11:59.468247 | TASK [include_role : remove-zuul-sshkey]
2026-02-24 18:11:59.481207 | controller | skipping: Conditional result was False
2026-02-24 18:11:59.485681 | 
2026-02-24 18:11:59.485741 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-02-24 18:11:59.739960 | controller | ok: "logs"
2026-02-24 18:11:59.740167 | controller | ok: All items complete
2026-02-24 18:11:59.740196 | 
2026-02-24 18:11:59.971612 | controller | ok: "artifacts"
2026-02-24 18:12:00.200104 | controller | ok: "docs"
2026-02-24 18:12:00.205374 | 
2026-02-24 18:12:00.205439 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-02-24 18:12:00.465816 | controller | changed: "logs"
2026-02-24 18:12:00.708152 | controller | changed: "artifacts"
2026-02-24 18:12:00.943568 | controller | changed: "docs"
2026-02-24 18:12:00.962851 | 
2026-02-24 18:12:00.962934 | PLAY RECAP
2026-02-24 18:12:00.962975 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2026-02-24 18:12:00.963000 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-24 18:12:00.963018 | 
2026-02-24 18:12:01.032676 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2026-02-24 18:12:01.033327 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2026-02-24 18:12:01.522687 | 
2026-02-24 18:12:01.522784 | PLAY [all]
2026-02-24 18:12:01.540267 | 
2026-02-24 18:12:01.540362 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2026-02-24 18:12:01.588716 | controller | ok
2026-02-24 18:12:01.593137 | 
2026-02-24 18:12:01.593210 | TASK [mirror-info-fork : Create /etc/ci]
2026-02-24 18:12:01.987627 | controller | changed
2026-02-24 18:12:01.992931 | 
2026-02-24 18:12:01.993000 | TASK [mirror-info-fork : Install ci_mirror script]
2026-02-24 18:12:03.339132 | controller | changed
2026-02-24 18:12:03.348634 | 
2026-02-24 18:12:03.348701 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2026-02-24 18:12:03.786971 | controller | changed:
2026-02-24 18:12:03.787178 | controller | {
2026-02-24 18:12:03.787214 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2026-02-24 18:12:03.787244 | controller | }
2026-02-24 18:12:04.078219 | controller | changed:
2026-02-24 18:12:04.078329 | controller | {
2026-02-24 18:12:04.078359 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2026-02-24 18:12:04.078381 | controller | }
2026-02-24 18:12:04.395649 | controller | changed:
2026-02-24 18:12:04.395732 | controller | {
2026-02-24 18:12:04.395757 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2026-02-24 18:12:04.395776 | controller | }
2026-02-24 18:12:04.695198 | controller | changed:
2026-02-24 18:12:04.695286 | controller | {
2026-02-24 18:12:04.695329 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2026-02-24 18:12:04.695350 | controller | }
2026-02-24 18:12:04.989917 | controller | changed:
2026-02-24 18:12:04.989971 | controller | {
2026-02-24 18:12:04.989997 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2026-02-24 18:12:04.990017 | controller | }
2026-02-24 18:12:05.288773 | controller | changed:
2026-02-24 18:12:05.288841 | controller | {
2026-02-24 18:12:05.288867 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2026-02-24 18:12:05.288888 | controller | }
2026-02-24 18:12:05.581055 | controller | changed:
2026-02-24 18:12:05.581185 | controller | {
2026-02-24 18:12:05.581215 | 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"
2026-02-24 18:12:05.581235 | controller | }
2026-02-24 18:12:05.885158 | controller | changed:
2026-02-24 18:12:05.885332 | controller | {
2026-02-24 18:12:05.885369 | 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"
2026-02-24 18:12:05.885393 | controller | }
2026-02-24 18:12:06.193604 | controller | changed:
2026-02-24 18:12:06.193661 | controller | {
2026-02-24 18:12:06.193685 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2026-02-24 18:12:06.193703 | controller | }
2026-02-24 18:12:06.506320 | controller | changed:
2026-02-24 18:12:06.506396 | controller | {
2026-02-24 18:12:06.506421 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2026-02-24 18:12:06.506440 | controller | }
2026-02-24 18:12:06.810943 | controller | changed:
2026-02-24 18:12:06.811002 | controller | {
2026-02-24 18:12:06.811025 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2026-02-24 18:12:06.811042 | controller | }
2026-02-24 18:12:07.101278 | controller | changed:
2026-02-24 18:12:07.101395 | controller | {
2026-02-24 18:12:07.101419 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2026-02-24 18:12:07.101437 | controller | }
2026-02-24 18:12:07.416558 | controller | changed:
2026-02-24 18:12:07.416648 | controller | {
2026-02-24 18:12:07.416673 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICWBreHW95Wz2Toz5YwCGQwFcUG8oFYkienDh9tntmDc ralfieri@redhat.com"
2026-02-24 18:12:07.416692 | controller | }
2026-02-24 18:12:07.719314 | controller | changed:
2026-02-24 18:12:07.719393 | controller | {
2026-02-24 18:12:07.719416 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2026-02-24 18:12:07.719434 | controller | }
2026-02-24 18:12:08.018705 | controller | changed:
2026-02-24 18:12:08.018765 | controller | {
2026-02-24 18:12:08.018790 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2026-02-24 18:12:08.018810 | controller | }
2026-02-24 18:12:08.306182 | controller | changed:
2026-02-24 18:12:08.306268 | controller | {
2026-02-24 18:12:08.306292 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2026-02-24 18:12:08.306333 | controller | }
2026-02-24 18:12:08.589279 | controller | changed:
2026-02-24 18:12:08.589373 | controller | {
2026-02-24 18:12:08.589398 | 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"
2026-02-24 18:12:08.589418 | controller | }
2026-02-24 18:12:08.879380 | controller | changed:
2026-02-24 18:12:08.879462 | controller | {
2026-02-24 18:12:08.879500 | 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"
2026-02-24 18:12:08.879529 | controller | }
2026-02-24 18:12:09.168848 | controller | changed:
2026-02-24 18:12:09.168902 | controller | {
2026-02-24 18:12:09.168925 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2026-02-24 18:12:09.168942 | controller | }
2026-02-24 18:12:09.456932 | controller | changed:
2026-02-24 18:12:09.456991 | controller | {
2026-02-24 18:12:09.457014 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2026-02-24 18:12:09.457031 | controller | }
2026-02-24 18:12:09.757435 | controller | changed:
2026-02-24 18:12:09.757497 | controller | {
2026-02-24 18:12:09.757523 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2026-02-24 18:12:09.757542 | controller | }
2026-02-24 18:12:10.062608 | controller | changed:
2026-02-24 18:12:10.062659 | controller | {
2026-02-24 18:12:10.062684 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2026-02-24 18:12:10.062704 | controller | }
2026-02-24 18:12:10.381099 | controller | changed:
2026-02-24 18:12:10.381183 | controller | {
2026-02-24 18:12:10.381208 | 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"
2026-02-24 18:12:10.381228 | controller | }
2026-02-24 18:12:10.688038 | controller | changed:
2026-02-24 18:12:10.688113 | controller | {
2026-02-24 18:12:10.688139 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2026-02-24 18:12:10.688160 | controller | }
2026-02-24 18:12:10.998871 | controller | changed:
2026-02-24 18:12:10.998919 | controller | {
2026-02-24 18:12:10.998942 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2026-02-24 18:12:10.998960 | controller | }
2026-02-24 18:12:11.294101 | controller | changed:
2026-02-24 18:12:11.294147 | controller | {
2026-02-24 18:12:11.294170 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2026-02-24 18:12:11.294187 | controller | }
2026-02-24 18:12:11.312397 | 
2026-02-24 18:12:11.312456 | TASK [Set timezone to UTC]
2026-02-24 18:12:11.809413 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2026-02-24 18:12:11.814026 | 
2026-02-24 18:12:11.814086 | TASK [Create nodepool directory]
2026-02-24 18:12:12.087164 | controller | changed
2026-02-24 18:12:12.092092 | 
2026-02-24 18:12:12.092153 | TASK [Create nodepool sub_nodes file]
2026-02-24 18:12:13.130409 | controller | changed
2026-02-24 18:12:13.135152 | 
2026-02-24 18:12:13.135217 | TASK [Create nodepool sub_nodes_private file]
2026-02-24 18:12:14.170793 | controller | changed
2026-02-24 18:12:14.175705 | 
2026-02-24 18:12:14.175766 | LOOP [Populate nodepool sub_nodes file]
2026-02-24 18:12:14.204855 | 
2026-02-24 18:12:14.204969 | LOOP [Populate nodepool sub_nodes_private file]
2026-02-24 18:12:14.233110 | 
2026-02-24 18:12:14.233220 | TASK [Create nodepool primary file]
2026-02-24 18:12:14.256491 | controller | skipping: Conditional result was False
2026-02-24 18:12:14.261503 | 
2026-02-24 18:12:14.261567 | TASK [Create nodepool node_private for this node]
2026-02-24 18:12:15.292444 | controller | changed
2026-02-24 18:12:15.297701 | 
2026-02-24 18:12:15.297773 | LOOP [Copy ssh keys to nodepool directory]
2026-02-24 18:12:15.680703 | controller | ok: Item: id_rsa Runtime: 0:00:00.007224
2026-02-24 18:12:15.680890 | 
2026-02-24 18:12:15.913644 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.005610
2026-02-24 18:12:15.925366 | 
2026-02-24 18:12:15.925470 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2026-02-24 18:12:16.905808 | controller | changed
2026-02-24 18:12:16.910558 | 
2026-02-24 18:12:16.910630 | TASK [Validate sudoers config after edits]
2026-02-24 18:12:17.184113 | controller | /etc/sudoers: parsed OK
2026-02-24 18:12:17.184170 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2026-02-24 18:12:17.184180 | controller | /etc/sudoers.d/zuul: parsed OK
2026-02-24 18:12:17.184185 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2026-02-24 18:12:17.436170 | controller | ok: Runtime: 0:00:00.005887
2026-02-24 18:12:17.440898 | 
2026-02-24 18:12:17.440960 | TASK [Show the environment passed in to job shell scripts]
2026-02-24 18:12:17.701312 | controller | SHELL=/bin/bash
2026-02-24 18:12:17.701344 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2026-02-24 18:12:17.701352 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2026-02-24 18:12:17.701358 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/78/3678/2434a201b9d11793db57a091ab062e6a97d89961
2026-02-24 18:12:17.701363 | controller | PWD=/home/zuul
2026-02-24 18:12:17.701368 | controller | ZUUL_PIPELINE=github-check
2026-02-24 18:12:17.701372 | controller | LOGNAME=zuul
2026-02-24 18:12:17.701377 | controller | XDG_SESSION_TYPE=tty
2026-02-24 18:12:17.701408 | controller | _=/usr/bin/env
2026-02-24 18:12:17.701415 | controller | MOTD_SHOWN=pam
2026-02-24 18:12:17.701419 | controller | HOME=/home/zuul
2026-02-24 18:12:17.701424 | controller | LANG=en_US.UTF-8
2026-02-24 18:12:17.701429 | controller | SSH_CONNECTION=192.168.26.12 34186 192.168.26.96 22
2026-02-24 18:12:17.701434 | 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
2026-02-24 18:12:17.701461 | controller | ZUUL_CHANGE_IDS=3678,2434a201b9d11793db57a091ab062e6a97d89961
2026-02-24 18:12:17.701466 | controller | WORKSPACE=/home/zuul/workspace
2026-02-24 18:12:17.701471 | controller | XDG_SESSION_CLASS=user
2026-02-24 18:12:17.701476 | controller | SELINUX_ROLE_REQUESTED=
2026-02-24 18:12:17.701480 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2026-02-24 18:12:17.701485 | controller | USER=zuul
2026-02-24 18:12:17.701490 | controller | ZUUL_VOTING=True
2026-02-24 18:12:17.701494 | controller | BUILD_TIMEOUT=1800000
2026-02-24 18:12:17.701499 | controller | SELINUX_USE_CURRENT_RANGE=
2026-02-24 18:12:17.701504 | controller | SHLVL=1
2026-02-24 18:12:17.701508 | controller | ZUUL_PATCHSET=2434a201b9d11793db57a091ab062e6a97d89961
2026-02-24 18:12:17.701513 | controller | XDG_SESSION_ID=1
2026-02-24 18:12:17.701518 | controller | ZUUL_BRANCH=main
2026-02-24 18:12:17.701523 | controller | XDG_RUNTIME_DIR=/run/user/1000
2026-02-24 18:12:17.701527 | controller | SSH_CLIENT=192.168.26.12 34186 22
2026-02-24 18:12:17.701532 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2026-02-24 18:12:17.701536 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2026-02-24 18:12:17.701541 | controller | which_declare=declare -f
2026-02-24 18:12:17.701546 | controller | PATH=/home/zuul/.crc/bin/oc:/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2026-02-24 18:12:17.701551 | controller | SELINUX_LEVEL_REQUESTED=
2026-02-24 18:12:17.701556 | controller | ZUUL_CHANGE=3678
2026-02-24 18:12:17.701560 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2026-02-24 18:12:17.701565 | controller | ZUUL_UUID=bb9a4d59823d4873bdd7d877a891d312
2026-02-24 18:12:17.701570 | controller | BASH_FUNC_which%%=() {  ( alias;
2026-02-24 18:12:17.701576 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2026-02-24 18:12:17.701580 | controller | }
2026-02-24 18:12:17.965187 | controller | ok: Runtime: 0:00:00.005210
2026-02-24 18:12:17.970145 | 
2026-02-24 18:12:17.970205 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2026-02-24 18:12:17.983931 | controller | skipping: Conditional result was False
2026-02-24 18:12:17.988903 | 
2026-02-24 18:12:17.988961 | TASK [Symlink /home/zuul-worker/workspace]
2026-02-24 18:12:18.532503 | controller | skipping: Conditional result was False
2026-02-24 18:12:18.537465 | 
2026-02-24 18:12:18.537531 | TASK [Ensure legacy workspace directory]
2026-02-24 18:12:18.779486 | controller | changed
2026-02-24 18:12:18.796712 | 
2026-02-24 18:12:18.796765 | PLAY RECAP
2026-02-24 18:12:18.796807 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2026-02-24 18:12:18.796829 | 
2026-02-24 18:12:18.874526 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2026-02-24 18:12:18.875221 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2026-02-24 18:12:19.346584 | 
2026-02-24 18:12:19.346677 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2026-02-24 18:12:19.365682 | 
2026-02-24 18:12:19.365754 | TASK [Create zuul-output directory]
2026-02-24 18:12:19.729734 | controller | changed
2026-02-24 18:12:19.734624 | 
2026-02-24 18:12:19.734697 | TASK [Slurp Zuul inventory test]
2026-02-24 18:12:19.991204 | controller -> localhost | ok
2026-02-24 18:12:19.996584 | 
2026-02-24 18:12:19.996643 | TASK [Save zuul inventory]
2026-02-24 18:12:21.225904 | controller | changed
2026-02-24 18:12:21.231238 | 
2026-02-24 18:12:21.231317 | TASK [Save zuul vars without the change_message]
2026-02-24 18:12:22.339155 | controller | changed
2026-02-24 18:12:22.357384 | 
2026-02-24 18:12:22.357438 | PLAY RECAP
2026-02-24 18:12:22.357549 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-02-24 18:12:22.357576 | 
2026-02-24 18:12:22.417829 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2026-02-24 18:12:22.418524 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2026-02-24 18:12:22.913989 | 
2026-02-24 18:12:22.914084 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2026-02-24 18:12:22.933896 | 
2026-02-24 18:12:22.933962 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2026-02-24 18:12:22.951840 | controller | ok
2026-02-24 18:12:22.967225 | 
2026-02-24 18:12:22.967325 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2026-02-24 18:12:22.990606 | controller | skipping: Conditional result was False
2026-02-24 18:12:22.995794 | 
2026-02-24 18:12:22.995861 | TASK [mirror-info-fork : Create /etc/ci]
2026-02-24 18:12:23.378052 | controller | ok
2026-02-24 18:12:23.383355 | 
2026-02-24 18:12:23.383434 | TASK [mirror-info-fork : Install ci_mirror script]
2026-02-24 18:12:24.388142 | controller | ok
2026-02-24 18:12:24.397194 | 
2026-02-24 18:12:24.397258 | TASK [Prepare workspace]
2026-02-24 18:12:24.414871 | controller | ok
2026-02-24 18:12:24.431783 | 
2026-02-24 18:12:24.431856 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-02-24 18:12:24.796619 | controller | ok
2026-02-24 18:12:24.802053 | 
2026-02-24 18:12:24.802118 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-02-24 18:12:27.179730 | controller | Output suppressed because no_log was given
2026-02-24 18:12:27.188195 | 
2026-02-24 18:12:27.188257 | LOOP [Create zuul-output directory]
2026-02-24 18:12:27.475698 | controller | changed: "/home/zuul/ci-framework-data/logs"
2026-02-24 18:12:27.709509 | controller | ok: "/home/zuul/zuul-output/logs"
2026-02-24 18:12:27.715963 | 
2026-02-24 18:12:27.716067 | TASK [Install required packages]
2026-02-24 18:12:52.505893 | controller | ok: Nothing to do
2026-02-24 18:12:52.510380 | 
2026-02-24 18:12:52.510440 | TASK [Install venv]
2026-02-24 18:13:50.008967 | controller | changed
2026-02-24 18:13:50.032621 | 
2026-02-24 18:13:50.032725 | PLAY RECAP
2026-02-24 18:13:50.032773 | controller | ok: 7 changed: 3 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-02-24 18:13:50.032795 | 
2026-02-24 18:13:50.105452 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2026-02-24 18:13:50.106258 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2026-02-24 18:13:50.586057 | 
2026-02-24 18:13:50.586153 | PLAY [Run ci/playbooks/molecule-test.yml]
2026-02-24 18:13:50.604646 | 
2026-02-24 18:13:50.604710 | TASK [Gather required facts]
2026-02-24 18:13:51.151156 | controller | ok
2026-02-24 18:13:51.156363 | 
2026-02-24 18:13:51.156443 | TASK [Load environment var if instructed to]
2026-02-24 18:13:51.171164 | controller | skipping: Conditional result was False
2026-02-24 18:13:51.176337 | 
2026-02-24 18:13:51.176405 | TASK [Ensure group_vars dir exists]
2026-02-24 18:13:51.550737 | controller | ok
2026-02-24 18:13:51.555694 | 
2026-02-24 18:13:51.555767 | TASK [Print related variables]
2026-02-24 18:13:51.584202 | controller | ok:
2026-02-24 18:13:51.584326 | controller | mol_config_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config_local.yml
2026-02-24 18:13:51.584359 | controller | roles_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/sushy_emulator
2026-02-24 18:13:51.588876 | 
2026-02-24 18:13:51.588938 | TASK [Run molecule]
2026-02-24 18:13:52.572683 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2026-02-24 18:13:52.638741 | controller | INFO     Performing prerun with role_name_check=0...
2026-02-24 18:14:09.667030 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2026-02-24 18:14:09.667412 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2026-02-24 18:14:09.667841 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2026-02-24 18:14:09.668241 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2026-02-24 18:14:09.668660 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+2434a201 was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 1.0.0+2434a201 (/home/zuul/.ansible/collections/ansible_collections).
2026-02-24 18:14:09.669056 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2026-02-24 18:14:09.669451 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2026-02-24 18:14:09.669854 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2026-02-24 18:14:09.670246 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2026-02-24 18:14:09.670652 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2026-02-24 18:14:09.671047 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2026-02-24 18:14:09.671431 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2026-02-24 18:14:09.671852 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2026-02-24 18:14:09.672246 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2026-02-24 18:14:09.672668 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2026-02-24 18:14:09.682175 | controller | INFO     Running default > prepare
2026-02-24 18:14:10.309400 | controller |
2026-02-24 18:14:10.309587 | controller | PLAY [Prepare] *****************************************************************
2026-02-24 18:14:10.309617 | controller |
2026-02-24 18:14:10.309762 | controller | TASK [Gathering Facts] *********************************************************
2026-02-24 18:14:10.309822 | controller | Tuesday 24 February 2026  18:14:10 +0000 (0:00:00.012)       0:00:00.012 ******
2026-02-24 18:14:11.199285 | controller | ok: [instance]
2026-02-24 18:14:11.199418 | controller |
2026-02-24 18:14:11.199430 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2026-02-24 18:14:11.199544 | controller | Tuesday 24 February 2026  18:14:11 +0000 (0:00:00.890)       0:00:00.902 ******
2026-02-24 18:14:11.219905 | controller | skipping: [instance]
2026-02-24 18:14:11.219945 | controller |
2026-02-24 18:14:11.220137 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2026-02-24 18:14:11.220228 | controller | Tuesday 24 February 2026  18:14:11 +0000 (0:00:00.021)       0:00:00.923 ******
2026-02-24 18:14:11.263712 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2026-02-24 18:14:11.263786 | controller |
2026-02-24 18:14:11.263955 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2026-02-24 18:14:11.264060 | controller | Tuesday 24 February 2026  18:14:11 +0000 (0:00:00.043)       0:00:00.967 ******
2026-02-24 18:14:11.550808 | controller | ok: [instance]
2026-02-24 18:14:11.550856 | controller |
2026-02-24 18:14:11.550953 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2026-02-24 18:14:11.551040 | controller | Tuesday 24 February 2026  18:14:11 +0000 (0:00:00.286)       0:00:01.254 ******
2026-02-24 18:14:11.886169 | controller | ok: [instance]
2026-02-24 18:14:11.886206 | controller |
2026-02-24 18:14:11.886313 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2026-02-24 18:14:11.886405 | controller | Tuesday 24 February 2026  18:14:11 +0000 (0:00:00.335)       0:00:01.589 ******
2026-02-24 18:14:12.605317 | controller | ok: [instance] => (item=ubi-9-appstream)
2026-02-24 18:14:12.605388 | controller | ok: [instance] => (item=ubi-9-baseos)
2026-02-24 18:14:12.605412 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2026-02-24 18:14:12.605547 | controller |
2026-02-24 18:14:12.605647 | controller | TASK [Deploy repo-setup] *******************************************************
2026-02-24 18:14:12.605727 | controller | Tuesday 24 February 2026  18:14:12 +0000 (0:00:00.718)       0:00:02.308 ******
2026-02-24 18:14:12.664623 | controller |
2026-02-24 18:14:12.664847 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2026-02-24 18:14:12.664982 | controller | Tuesday 24 February 2026  18:14:12 +0000 (0:00:00.059)       0:00:02.368 ******
2026-02-24 18:14:13.213726 | controller | changed: [instance] => (item=tmp)
2026-02-24 18:14:13.213863 | controller | changed: [instance] => (item=artifacts/repositories)
2026-02-24 18:14:13.214021 | controller | changed: [instance] => (item=venv/repo_setup)
2026-02-24 18:14:13.214107 | controller |
2026-02-24 18:14:13.214195 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2026-02-24 18:14:13.214266 | controller | Tuesday 24 February 2026  18:14:13 +0000 (0:00:00.548)       0:00:02.917 ******
2026-02-24 18:14:14.084338 | controller | ok: [instance]
2026-02-24 18:14:14.084406 | controller |
2026-02-24 18:14:14.084702 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2026-02-24 18:14:15.200066 | controller | Tuesday 24 February 2026  18:14:14 +0000 (0:00:00.870)       0:00:03.787 ******
2026-02-24 18:14:15.200120 | controller | changed: [instance]
2026-02-24 18:14:15.200342 | controller |
2026-02-24 18:14:22.838176 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2026-02-24 18:14:22.838230 | controller | Tuesday 24 February 2026  18:14:15 +0000 (0:00:01.115)       0:00:04.903 ******
2026-02-24 18:14:22.838244 | controller | changed: [instance]
2026-02-24 18:14:23.567535 | controller |
2026-02-24 18:14:23.567598 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2026-02-24 18:14:23.567607 | controller | Tuesday 24 February 2026  18:14:22 +0000 (0:00:07.637)       0:00:12.541 ******
2026-02-24 18:14:23.567620 | controller | changed: [instance]
2026-02-24 18:14:23.588769 | controller |
2026-02-24 18:14:23.588835 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2026-02-24 18:14:23.588850 | controller | Tuesday 24 February 2026  18:14:23 +0000 (0:00:00.729)       0:00:13.270 ******
2026-02-24 18:14:23.588870 | controller | skipping: [instance]
2026-02-24 18:14:24.443043 | controller |
2026-02-24 18:14:24.443104 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2026-02-24 18:14:24.443113 | controller | Tuesday 24 February 2026  18:14:23 +0000 (0:00:00.021)       0:00:13.292 ******
2026-02-24 18:14:24.443126 | controller | changed: [instance]
2026-02-24 18:14:24.475594 | controller |
2026-02-24 18:14:24.475644 | controller | TASK [repo_setup : Get component repo] *****************************************
2026-02-24 18:14:24.475665 | controller | Tuesday 24 February 2026  18:14:24 +0000 (0:00:00.852)       0:00:14.145 ******
2026-02-24 18:14:24.475679 | controller | skipping: [instance]
2026-02-24 18:14:24.475942 | controller |
2026-02-24 18:14:24.475981 | controller | TASK [repo_setup : Rename component repo] **************************************
2026-02-24 18:14:24.530567 | controller | Tuesday 24 February 2026  18:14:24 +0000 (0:00:00.034)       0:00:14.179 ******
2026-02-24 18:14:24.530618 | controller | skipping: [instance]
2026-02-24 18:14:24.530659 | controller |
2026-02-24 18:14:24.530795 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2026-02-24 18:14:24.530822 | controller | Tuesday 24 February 2026  18:14:24 +0000 (0:00:00.054)       0:00:14.234 ******
2026-02-24 18:14:24.567598 | controller | skipping: [instance]
2026-02-24 18:14:24.568706 | controller |
2026-02-24 18:14:24.568723 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2026-02-24 18:14:24.568848 | controller | Tuesday 24 February 2026  18:14:24 +0000 (0:00:00.036)       0:00:14.270 ******
2026-02-24 18:14:25.113627 | controller | changed: [instance]
2026-02-24 18:14:25.549561 | controller |
2026-02-24 18:14:25.549616 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2026-02-24 18:14:25.549627 | controller | Tuesday 24 February 2026  18:14:25 +0000 (0:00:00.546)       0:00:14.816 ******
2026-02-24 18:14:25.549640 | controller | changed: [instance]
2026-02-24 18:14:25.578667 | controller |
2026-02-24 18:14:25.578720 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2026-02-24 18:14:25.578735 | controller | Tuesday 24 February 2026  18:14:25 +0000 (0:00:00.435)       0:00:15.252 ******
2026-02-24 18:14:25.578753 | controller | skipping: [instance]
2026-02-24 18:14:25.615601 | controller |
2026-02-24 18:14:25.615633 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2026-02-24 18:14:25.615648 | controller | Tuesday 24 February 2026  18:14:25 +0000 (0:00:00.029)       0:00:15.282 ******
2026-02-24 18:14:25.615690 | controller | skipping: [instance]
2026-02-24 18:14:25.615739 | controller |
2026-02-24 18:14:25.615755 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2026-02-24 18:14:25.615893 | controller | Tuesday 24 February 2026  18:14:25 +0000 (0:00:00.036)       0:00:15.319 ******
2026-02-24 18:14:25.646663 | controller | skipping: [instance]
2026-02-24 18:14:25.646711 | controller |
2026-02-24 18:14:25.646722 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2026-02-24 18:14:25.646735 | controller | Tuesday 24 February 2026  18:14:25 +0000 (0:00:00.031)       0:00:15.350 ******
2026-02-24 18:14:25.690984 | controller | ok: [instance]
2026-02-24 18:14:25.719952 | controller |
2026-02-24 18:14:25.719975 | controller | TASK [repo_setup : Create download directory] **********************************
2026-02-24 18:14:25.719986 | controller | Tuesday 24 February 2026  18:14:25 +0000 (0:00:00.044)       0:00:15.394 ******
2026-02-24 18:14:25.719997 | controller | skipping: [instance]
2026-02-24 18:14:25.751207 | controller |
2026-02-24 18:14:25.751226 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2026-02-24 18:14:25.751235 | controller | Tuesday 24 February 2026  18:14:25 +0000 (0:00:00.028)       0:00:15.423 ******
2026-02-24 18:14:25.751258 | controller | skipping: [instance]
2026-02-24 18:14:25.778980 | controller |
2026-02-24 18:14:25.779003 | controller | TASK [Download the RPM] ********************************************************
2026-02-24 18:14:25.779011 | controller | Tuesday 24 February 2026  18:14:25 +0000 (0:00:00.031)       0:00:15.455 ******
2026-02-24 18:14:25.779022 | controller | skipping: [instance]
2026-02-24 18:14:25.779174 | controller |
2026-02-24 18:14:25.779327 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2026-02-24 18:14:25.779501 | controller | Tuesday 24 February 2026  18:14:25 +0000 (0:00:00.028)       0:00:15.483 ******
2026-02-24 18:14:25.809631 | controller | skipping: [instance]
2026-02-24 18:14:25.809809 | controller |
2026-02-24 18:14:25.809984 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2026-02-24 18:14:25.810118 | controller | Tuesday 24 February 2026  18:14:25 +0000 (0:00:00.030)       0:00:15.513 ******
2026-02-24 18:14:25.837381 | controller | skipping: [instance]
2026-02-24 18:14:25.837574 | controller |
2026-02-24 18:14:25.837745 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2026-02-24 18:14:25.837891 | controller | Tuesday 24 February 2026  18:14:25 +0000 (0:00:00.027)       0:00:15.541 ******
2026-02-24 18:14:25.869825 | controller | skipping: [instance]
2026-02-24 18:14:25.870007 | controller |
2026-02-24 18:14:25.870173 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2026-02-24 18:14:25.870296 | controller | Tuesday 24 February 2026  18:14:25 +0000 (0:00:00.032)       0:00:15.573 ******
2026-02-24 18:14:25.896097 | controller | skipping: [instance]
2026-02-24 18:14:25.896259 | controller |
2026-02-24 18:14:25.896412 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2026-02-24 18:14:25.896595 | controller | Tuesday 24 February 2026  18:14:25 +0000 (0:00:00.026)       0:00:15.600 ******
2026-02-24 18:14:26.082903 | controller | ok: [instance]
2026-02-24 18:14:26.308908 | controller |
2026-02-24 18:14:26.308931 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2026-02-24 18:14:26.308939 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.186)       0:00:15.786 ******
2026-02-24 18:14:26.308948 | controller | changed: [instance]
2026-02-24 18:14:26.550253 | controller |
2026-02-24 18:14:26.550281 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2026-02-24 18:14:26.550291 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.225)       0:00:16.012 ******
2026-02-24 18:14:26.550302 | controller | changed: [instance]
2026-02-24 18:14:26.575960 | controller |
2026-02-24 18:14:26.575981 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2026-02-24 18:14:26.575990 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.241)       0:00:16.253 ******
2026-02-24 18:14:26.576000 | controller | skipping: [instance]
2026-02-24 18:14:26.602882 | controller |
2026-02-24 18:14:26.602904 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2026-02-24 18:14:26.602913 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.025)       0:00:16.279 ******
2026-02-24 18:14:26.602924 | controller | skipping: [instance]
2026-02-24 18:14:26.627531 | controller |
2026-02-24 18:14:26.627557 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2026-02-24 18:14:26.627567 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.026)       0:00:16.306 ******
2026-02-24 18:14:26.627585 | controller | skipping: [instance]
2026-02-24 18:14:26.627651 | controller |
2026-02-24 18:14:26.627679 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2026-02-24 18:14:26.627691 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.024)       0:00:16.331 ******
2026-02-24 18:14:26.650162 | controller | skipping: [instance]
2026-02-24 18:14:26.673649 | controller |
2026-02-24 18:14:26.673719 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2026-02-24 18:14:26.673730 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.022)       0:00:16.353 ******
2026-02-24 18:14:26.673744 | controller | skipping: [instance]
2026-02-24 18:14:26.673752 | controller |
2026-02-24 18:14:26.673762 | controller | TASK [repo_setup : Lower the priority of component repos to allow installation from gating repo] ***
2026-02-24 18:14:26.695391 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.023)       0:00:16.377 ******
2026-02-24 18:14:26.695417 | controller | skipping: [instance]
2026-02-24 18:14:26.695546 | controller |
2026-02-24 18:14:26.695679 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2026-02-24 18:14:26.695795 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.022)       0:00:16.399 ******
2026-02-24 18:14:26.712465 | controller | skipping: [instance]
2026-02-24 18:14:26.712691 | controller |
2026-02-24 18:14:26.712811 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2026-02-24 18:14:26.712918 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.017)       0:00:16.416 ******
2026-02-24 18:14:26.745113 | controller | skipping: [instance]
2026-02-24 18:14:26.745244 | controller |
2026-02-24 18:14:26.745372 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2026-02-24 18:14:26.745523 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.032)       0:00:16.449 ******
2026-02-24 18:14:26.761889 | controller | skipping: [instance]
2026-02-24 18:14:26.762230 | controller |
2026-02-24 18:14:26.762269 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2026-02-24 18:14:26.762497 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.016)       0:00:16.465 ******
2026-02-24 18:14:26.782399 | controller | skipping: [instance]
2026-02-24 18:14:26.782677 | controller |
2026-02-24 18:14:26.782896 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2026-02-24 18:14:26.782988 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.020)       0:00:16.486 ******
2026-02-24 18:14:26.813986 | controller | skipping: [instance]
2026-02-24 18:14:26.814094 | controller |
2026-02-24 18:14:26.814251 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2026-02-24 18:14:26.814348 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.031)       0:00:16.518 ******
2026-02-24 18:14:26.844003 | controller | skipping: [instance]
2026-02-24 18:14:26.844241 | controller |
2026-02-24 18:14:26.844472 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2026-02-24 18:14:26.844713 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.029)       0:00:16.547 ******
2026-02-24 18:14:26.873495 | controller | skipping: [instance]
2026-02-24 18:14:26.873682 | controller |
2026-02-24 18:14:26.873805 | controller | TASK [test_deps : Install additional packages] *********************************
2026-02-24 18:14:26.873919 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.029)       0:00:16.577 ******
2026-02-24 18:14:26.902617 | controller | skipping: [instance]
2026-02-24 18:14:26.902657 | controller |
2026-02-24 18:14:26.902953 | controller | TASK [test_deps : Install selinux python libs] *********************************
2026-02-24 18:14:26.903162 | controller | Tuesday 24 February 2026  18:14:26 +0000 (0:00:00.028)       0:00:16.606 ******
2026-02-24 18:15:10.164205 | controller | ok: [instance]
2026-02-24 18:15:11.325205 | controller |
2026-02-24 18:15:11.325260 | controller | TASK [test_deps : Install python yaml libs] ************************************
2026-02-24 18:15:11.325268 | controller | Tuesday 24 February 2026  18:15:10 +0000 (0:00:43.260)       0:00:59.867 ******
2026-02-24 18:15:11.325280 | controller | ok: [instance]
2026-02-24 18:15:11.353375 | controller |
2026-02-24 18:15:11.353395 | controller | TASK [test_deps : Install extra packages] **************************************
2026-02-24 18:15:11.353403 | controller | Tuesday 24 February 2026  18:15:11 +0000 (0:00:01.161)       0:01:01.028 ******
2026-02-24 18:15:11.353422 | controller | skipping: [instance]
2026-02-24 18:35:30.421124 | controller |
2026-02-24 18:35:30.421380 | controller | TASK [Ensure CRC is started] ***************************************************
2026-02-24 18:35:30.421393 | controller | Tuesday 24 February 2026  18:15:11 +0000 (0:00:00.028)       0:01:01.057 ******
2026-02-24 18:35:30.421404 | controller | changed: [instance]
2026-02-24 18:35:30.801332 | controller |
2026-02-24 18:35:30.801382 | controller | TASK [Inject crc hostname/IP in hosts] *****************************************
2026-02-24 18:35:30.801390 | controller | Tuesday 24 February 2026  18:35:30 +0000 (0:20:19.066)       0:21:20.123 ******
2026-02-24 18:35:30.801400 | controller | changed: [instance]
2026-02-24 18:35:30.801426 | controller |
2026-02-24 18:35:30.801667 | controller | PLAY RECAP *********************************************************************
2026-02-24 18:35:30.801768 | controller | instance                   : ok=21   changed=11   unreachable=0    failed=0    skipped=30   rescued=0    ignored=0
2026-02-24 18:35:30.801796 | controller |
2026-02-24 18:35:30.801806 | controller | Tuesday 24 February 2026  18:35:30 +0000 (0:00:00.381)       0:21:20.504 ******
2026-02-24 18:35:30.802502 | controller | ===============================================================================
2026-02-24 18:35:30.802532 | controller | Ensure CRC is started ------------------------------------------------ 1219.07s
2026-02-24 18:35:30.802538 | controller | test_deps : Install selinux python libs -------------------------------- 43.26s
2026-02-24 18:35:30.802543 | controller | repo_setup : Initialize python venv and install requirements ------------ 7.64s
2026-02-24 18:35:30.802548 | controller | test_deps : Install python yaml libs ------------------------------------ 1.16s
2026-02-24 18:35:30.802553 | controller | repo_setup : Get repo-setup repository ---------------------------------- 1.12s
2026-02-24 18:35:30.802558 | controller | Gathering Facts --------------------------------------------------------- 0.89s
2026-02-24 18:35:30.802565 | controller | repo_setup : Make sure git-core package is installed -------------------- 0.87s
2026-02-24 18:35:30.803602 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.85s
2026-02-24 18:35:30.803658 | controller | repo_setup : Install repo-setup package --------------------------------- 0.73s
2026-02-24 18:35:30.803665 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.72s
2026-02-24 18:35:30.803671 | controller | repo_setup : Ensure directories are present ----------------------------- 0.55s
2026-02-24 18:35:30.803676 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.55s
2026-02-24 18:35:30.803681 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.44s
2026-02-24 18:35:30.803686 | controller | Inject crc hostname/IP in hosts ----------------------------------------- 0.38s
2026-02-24 18:35:30.803692 | controller | test_deps : Disable ubi host subscription-manager integration ----------- 0.34s
2026-02-24 18:35:30.803698 | controller | test_deps : Detect mirrors file ----------------------------------------- 0.29s
2026-02-24 18:35:30.803703 | controller | repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist) --- 0.24s
2026-02-24 18:35:30.803709 | controller | repo_setup : Use RDO proxy mirrors -------------------------------------- 0.23s
2026-02-24 18:35:30.803714 | controller | repo_setup : Check for /etc/ci/mirror_info.sh --------------------------- 0.19s
2026-02-24 18:35:30.803723 | controller | Deploy repo-setup ------------------------------------------------------- 0.06s
2026-02-24 18:35:30.879661 | controller | INFO     Running default > converge
2026-02-24 18:35:31.386537 | controller |
2026-02-24 18:35:31.386725 | controller | PLAY [Converge] ****************************************************************
2026-02-24 18:35:31.386833 | controller |
2026-02-24 18:35:31.386986 | controller | TASK [Gathering Facts] *********************************************************
2026-02-24 18:35:31.387087 | controller | Tuesday 24 February 2026  18:35:31 +0000 (0:00:00.019)       0:00:00.019 ******
2026-02-24 18:35:32.313667 | controller | ok: [instance]
2026-02-24 18:35:32.313886 | controller |
2026-02-24 18:35:32.313945 | controller | TASK [Load networking_definition] **********************************************
2026-02-24 18:35:32.337633 | controller | Tuesday 24 February 2026  18:35:32 +0000 (0:00:00.926)       0:00:00.946 ******
2026-02-24 18:35:32.337694 | controller | ok: [instance]
2026-02-24 18:35:32.368268 | controller |
2026-02-24 18:35:32.368319 | controller | TASK [Check if new ssh keypair exists] *****************************************
2026-02-24 18:35:32.368329 | controller | Tuesday 24 February 2026  18:35:32 +0000 (0:00:00.023)       0:00:00.969 ******
2026-02-24 18:35:32.368342 | controller |
2026-02-24 18:35:32.672379 | controller | TASK [recognize_ssh_keypair : Check if id_ed25519 key exists] ******************
2026-02-24 18:35:32.672421 | controller | Tuesday 24 February 2026  18:35:32 +0000 (0:00:00.031)       0:00:01.001 ******
2026-02-24 18:35:32.672434 | controller | ok: [instance]
2026-02-24 18:35:32.699530 | controller |
2026-02-24 18:35:32.699563 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair exists] ******************
2026-02-24 18:35:32.699577 | controller | Tuesday 24 February 2026  18:35:32 +0000 (0:00:00.303)       0:00:01.304 ******
2026-02-24 18:35:32.699587 | controller | ok: [instance]
2026-02-24 18:35:32.699618 | controller |
2026-02-24 18:35:32.699626 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair does not exists] *********
2026-02-24 18:35:32.699860 | controller | Tuesday 24 February 2026  18:35:32 +0000 (0:00:00.028)       0:00:01.332 ******
2026-02-24 18:35:32.726115 | controller | skipping: [instance]
2026-02-24 18:35:32.749781 | controller |
2026-02-24 18:35:32.749819 | controller | TASK [Add the crc host dynamically] ********************************************
2026-02-24 18:35:32.749830 | controller | Tuesday 24 February 2026  18:35:32 +0000 (0:00:00.026)       0:00:01.359 ******
2026-02-24 18:35:32.749844 | controller | changed: [instance]
2026-02-24 18:35:32.749866 | controller |
2026-02-24 18:35:32.749875 | controller | TASK [Add ansible_host entry to "controller-0"] ********************************
2026-02-24 18:35:32.777859 | controller | Tuesday 24 February 2026  18:35:32 +0000 (0:00:00.023)       0:00:01.383 ******
2026-02-24 18:35:32.777888 | controller | changed: [instance]
2026-02-24 18:35:32.777920 | controller |
2026-02-24 18:35:32.778026 | controller | TASK [Add host key to controller-0] ********************************************
2026-02-24 18:35:32.778114 | controller | Tuesday 24 February 2026  18:35:32 +0000 (0:00:00.028)       0:00:01.411 ******
2026-02-24 18:35:33.130146 | controller | changed: [instance]
2026-02-24 18:35:33.130216 | controller |
2026-02-24 18:35:33.130275 | controller | TASK [libvirt_manager : Ensure output directory exists] ************************
2026-02-24 18:35:33.130381 | controller | Tuesday 24 February 2026  18:35:33 +0000 (0:00:00.351)       0:00:01.762 ******
2026-02-24 18:35:33.468197 | controller | ok: [instance]
2026-02-24 18:35:33.684220 | controller |
2026-02-24 18:35:33.684282 | controller | TASK [libvirt_manager : Get vmx/svm extensions from /proc/cpuinfo] *************
2026-02-24 18:35:33.684291 | controller | Tuesday 24 February 2026  18:35:33 +0000 (0:00:00.337)       0:00:02.100 ******
2026-02-24 18:35:33.684306 | controller | changed: [instance]
2026-02-24 18:35:33.896733 | controller |
2026-02-24 18:35:33.896804 | controller | TASK [libvirt_manager : Check if KVM is enabled] *******************************
2026-02-24 18:35:33.896814 | controller | Tuesday 24 February 2026  18:35:33 +0000 (0:00:00.216)       0:00:02.316 ******
2026-02-24 18:35:33.896830 | controller | ok: [instance]
2026-02-24 18:35:33.896878 | controller |
2026-02-24 18:35:33.896889 | controller | TASK [libvirt_manager : Fail if KVM not enabled] *******************************
2026-02-24 18:35:33.937215 | controller | Tuesday 24 February 2026  18:35:33 +0000 (0:00:00.212)       0:00:02.529 ******
2026-02-24 18:35:33.937261 | controller | skipping: [instance]
2026-02-24 18:35:33.937397 | controller |
2026-02-24 18:35:33.937409 | controller | TASK [libvirt_manager : Check if VMX virtualization] ***************************
2026-02-24 18:35:33.937551 | controller | Tuesday 24 February 2026  18:35:33 +0000 (0:00:00.041)       0:00:02.570 ******
2026-02-24 18:35:33.959265 | controller | skipping: [instance]
2026-02-24 18:35:33.959535 | controller |
2026-02-24 18:35:33.984019 | controller | TASK [libvirt_manager : Check if SVM virtualization] ***************************
2026-02-24 18:35:33.984049 | controller | Tuesday 24 February 2026  18:35:33 +0000 (0:00:00.022)       0:00:02.592 ******
2026-02-24 18:35:33.984063 | controller | ok: [instance]
2026-02-24 18:35:33.984073 | controller |
2026-02-24 18:35:33.984180 | controller | TASK [libvirt_manager : Enable VMX virtualization] *****************************
2026-02-24 18:35:33.984268 | controller | Tuesday 24 February 2026  18:35:33 +0000 (0:00:00.024)       0:00:02.617 ******
2026-02-24 18:35:34.019555 | controller | skipping: [instance]
2026-02-24 18:35:46.023147 | controller |
2026-02-24 18:35:46.023219 | controller | TASK [libvirt_manager : Install packages required for using KVM] ***************
2026-02-24 18:35:46.023228 | controller | Tuesday 24 February 2026  18:35:34 +0000 (0:00:00.035)       0:00:02.652 ******
2026-02-24 18:35:46.023246 | controller | changed: [instance]
2026-02-24 18:35:46.306750 | controller |
2026-02-24 18:35:46.306813 | controller | TASK [libvirt_manager : Create rules.d polkit folder] **************************
2026-02-24 18:35:46.306822 | controller | Tuesday 24 February 2026  18:35:46 +0000 (0:00:12.003)       0:00:14.655 ******
2026-02-24 18:35:46.306838 | controller | changed: [instance]
2026-02-24 18:35:46.879429 | controller |
2026-02-24 18:35:46.879507 | controller | TASK [libvirt_manager : Enable UNIX socket PolicyKit auth] *********************
2026-02-24 18:35:46.879516 | controller | Tuesday 24 February 2026  18:35:46 +0000 (0:00:00.283)       0:00:14.939 ******
2026-02-24 18:35:46.879535 | controller | changed: [instance]
2026-02-24 18:35:47.528268 | controller |
2026-02-24 18:35:47.528334 | controller | TASK [libvirt_manager : Restart service polkit service] ************************
2026-02-24 18:35:47.528344 | controller | Tuesday 24 February 2026  18:35:46 +0000 (0:00:00.572)       0:00:15.512 ******
2026-02-24 18:35:47.528378 | controller | changed: [instance]
2026-02-24 18:35:47.791095 | controller |
2026-02-24 18:35:47.791150 | controller | TASK [libvirt_manager : Remove directory for service override] *****************
2026-02-24 18:35:47.791160 | controller | Tuesday 24 February 2026  18:35:47 +0000 (0:00:00.648)       0:00:16.161 ******
2026-02-24 18:35:47.791178 | controller | ok: [instance]
2026-02-24 18:35:47.791314 | controller |
2026-02-24 18:35:48.536366 | controller | TASK [libvirt_manager : Reload systemctl and start/enable virtproxyd.service] ***
2026-02-24 18:35:48.536430 | controller | Tuesday 24 February 2026  18:35:47 +0000 (0:00:00.262)       0:00:16.423 ******
2026-02-24 18:35:48.536467 | controller | ok: [instance]
2026-02-24 18:35:48.536529 | controller |
2026-02-24 18:35:48.536749 | controller | TASK [libvirt_manager : Ensure firewalld service is up] ************************
2026-02-24 18:35:49.525654 | controller | Tuesday 24 February 2026  18:35:48 +0000 (0:00:00.744)       0:00:17.168 ******
2026-02-24 18:35:49.525692 | controller | changed: [instance]
2026-02-24 18:35:49.619335 | controller |
2026-02-24 18:35:49.619419 | controller | TASK [libvirt_manager : Ensure libvirt modular driver daemons are started.] ****
2026-02-24 18:35:49.619430 | controller | Tuesday 24 February 2026  18:35:49 +0000 (0:00:00.989)       0:00:18.158 ******
2026-02-24 18:35:49.619561 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=qemu)
2026-02-24 18:35:49.619732 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=interface)
2026-02-24 18:35:49.619750 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=network)
2026-02-24 18:35:49.619824 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nodedev)
2026-02-24 18:35:49.619832 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nwfilter)
2026-02-24 18:35:49.619840 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=secret)
2026-02-24 18:35:49.619850 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=storage)
2026-02-24 18:35:49.620129 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=proxy)
2026-02-24 18:35:50.014610 | controller |
2026-02-24 18:35:50.014677 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for qemu.] *********
2026-02-24 18:35:50.014686 | controller | Tuesday 24 February 2026  18:35:49 +0000 (0:00:00.094)       0:00:18.252 ******
2026-02-24 18:35:50.014703 | controller | ok: [instance]
2026-02-24 18:35:51.394150 | controller |
2026-02-24 18:35:51.394211 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for qemu.] **********
2026-02-24 18:35:51.394221 | controller | Tuesday 24 February 2026  18:35:50 +0000 (0:00:00.394)       0:00:18.646 ******
2026-02-24 18:35:51.394237 | controller | ok: [instance]
2026-02-24 18:35:51.766806 | controller |
2026-02-24 18:35:51.766868 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for qemu.] **************
2026-02-24 18:35:51.766877 | controller | Tuesday 24 February 2026  18:35:51 +0000 (0:00:01.380)       0:00:20.026 ******
2026-02-24 18:35:51.766894 | controller | ok: [instance]
2026-02-24 18:35:51.766901 | controller |
2026-02-24 18:35:51.766910 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for interface.] ****
2026-02-24 18:35:51.767014 | controller | Tuesday 24 February 2026  18:35:51 +0000 (0:00:00.373)       0:00:20.399 ******
2026-02-24 18:35:53.113286 | controller | ok: [instance]
2026-02-24 18:35:53.113338 | controller |
2026-02-24 18:35:53.113929 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for interface.] *****
2026-02-24 18:35:53.475999 | controller | Tuesday 24 February 2026  18:35:53 +0000 (0:00:01.346)       0:00:21.746 ******
2026-02-24 18:35:53.476070 | controller | ok: [instance]
2026-02-24 18:35:53.476128 | controller |
2026-02-24 18:35:53.476138 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for interface.] *********
2026-02-24 18:35:53.476216 | controller | Tuesday 24 February 2026  18:35:53 +0000 (0:00:00.362)       0:00:22.108 ******
2026-02-24 18:35:53.874353 | controller | ok: [instance]
2026-02-24 18:35:53.874922 | controller |
2026-02-24 18:35:54.251290 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for network.] ******
2026-02-24 18:35:54.251390 | controller | Tuesday 24 February 2026  18:35:53 +0000 (0:00:00.398)       0:00:22.507 ******
2026-02-24 18:35:54.251417 | controller | ok: [instance]
2026-02-24 18:35:54.634579 | controller |
2026-02-24 18:35:54.634651 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for network.] *******
2026-02-24 18:35:54.634660 | controller | Tuesday 24 February 2026  18:35:54 +0000 (0:00:00.376)       0:00:22.884 ******
2026-02-24 18:35:54.634678 | controller | ok: [instance]
2026-02-24 18:35:54.634706 | controller |
2026-02-24 18:35:54.634712 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for network.] ***********
2026-02-24 18:35:54.634722 | controller | Tuesday 24 February 2026  18:35:54 +0000 (0:00:00.383)       0:00:23.267 ******
2026-02-24 18:35:55.016862 | controller | ok: [instance]
2026-02-24 18:35:55.016904 | controller |
2026-02-24 18:35:55.017020 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nodedev.] ******
2026-02-24 18:35:55.017113 | controller | Tuesday 24 February 2026  18:35:55 +0000 (0:00:00.382)       0:00:23.650 ******
2026-02-24 18:35:55.375746 | controller | ok: [instance]
2026-02-24 18:35:55.376010 | controller |
2026-02-24 18:35:55.732008 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nodedev.] *******
2026-02-24 18:35:55.732078 | controller | Tuesday 24 February 2026  18:35:55 +0000 (0:00:00.359)       0:00:24.009 ******
2026-02-24 18:35:55.732096 | controller | ok: [instance]
2026-02-24 18:35:55.732234 | controller |
2026-02-24 18:35:55.732282 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nodedev.] ***********
2026-02-24 18:35:55.732309 | controller | Tuesday 24 February 2026  18:35:55 +0000 (0:00:00.355)       0:00:24.364 ******
2026-02-24 18:35:56.091565 | controller | ok: [instance]
2026-02-24 18:35:56.454908 | controller |
2026-02-24 18:35:56.454947 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nwfilter.] *****
2026-02-24 18:35:56.454969 | controller | Tuesday 24 February 2026  18:35:56 +0000 (0:00:00.359)       0:00:24.724 ******
2026-02-24 18:35:56.454980 | controller | ok: [instance]
2026-02-24 18:35:56.455164 | controller |
2026-02-24 18:35:56.824041 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nwfilter.] ******
2026-02-24 18:35:56.824073 | controller | Tuesday 24 February 2026  18:35:56 +0000 (0:00:00.363)       0:00:25.088 ******
2026-02-24 18:35:56.824085 | controller | ok: [instance]
2026-02-24 18:35:57.198070 | controller |
2026-02-24 18:35:57.198113 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nwfilter.] **********
2026-02-24 18:35:57.198121 | controller | Tuesday 24 February 2026  18:35:56 +0000 (0:00:00.368)       0:00:25.456 ******
2026-02-24 18:35:57.198133 | controller | ok: [instance]
2026-02-24 18:35:57.198162 | controller |
2026-02-24 18:35:57.198185 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for secret.] *******
2026-02-24 18:35:57.198332 | controller | Tuesday 24 February 2026  18:35:57 +0000 (0:00:00.374)       0:00:25.831 ******
2026-02-24 18:35:57.551709 | controller | ok: [instance]
2026-02-24 18:35:57.934779 | controller |
2026-02-24 18:35:57.934844 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for secret.] ********
2026-02-24 18:35:57.934855 | controller | Tuesday 24 February 2026  18:35:57 +0000 (0:00:00.353)       0:00:26.184 ******
2026-02-24 18:35:57.934869 | controller | ok: [instance]
2026-02-24 18:35:57.934897 | controller |
2026-02-24 18:35:57.934907 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for secret.] ************
2026-02-24 18:35:57.934928 | controller | Tuesday 24 February 2026  18:35:57 +0000 (0:00:00.383)       0:00:26.567 ******
2026-02-24 18:35:58.312231 | controller | ok: [instance]
2026-02-24 18:35:58.312295 | controller |
2026-02-24 18:35:58.312649 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for storage.] ******
2026-02-24 18:35:58.312691 | controller | Tuesday 24 February 2026  18:35:58 +0000 (0:00:00.377)       0:00:26.945 ******
2026-02-24 18:35:59.687644 | controller | ok: [instance]
2026-02-24 18:35:59.687737 | controller |
2026-02-24 18:35:59.687809 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for storage.] *******
2026-02-24 18:35:59.687822 | controller | Tuesday 24 February 2026  18:35:59 +0000 (0:00:01.375)       0:00:28.320 ******
2026-02-24 18:36:00.027572 | controller | ok: [instance]
2026-02-24 18:36:00.382419 | controller |
2026-02-24 18:36:00.382476 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for storage.] ***********
2026-02-24 18:36:00.382485 | controller | Tuesday 24 February 2026  18:36:00 +0000 (0:00:00.339)       0:00:28.660 ******
2026-02-24 18:36:00.382496 | controller | ok: [instance]
2026-02-24 18:36:00.382677 | controller |
2026-02-24 18:36:00.382691 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for proxy.] ********
2026-02-24 18:36:00.745483 | controller | Tuesday 24 February 2026  18:36:00 +0000 (0:00:00.355)       0:00:29.015 ******
2026-02-24 18:36:00.745523 | controller | ok: [instance]
2026-02-24 18:36:01.114222 | controller |
2026-02-24 18:36:01.114259 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for proxy.] *********
2026-02-24 18:36:01.114267 | controller | Tuesday 24 February 2026  18:36:00 +0000 (0:00:00.362)       0:00:29.378 ******
2026-02-24 18:36:01.114278 | controller | ok: [instance]
2026-02-24 18:36:01.472996 | controller |
2026-02-24 18:36:01.473030 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for proxy.] *************
2026-02-24 18:36:01.473038 | controller | Tuesday 24 February 2026  18:36:01 +0000 (0:00:00.368)       0:00:29.746 ******
2026-02-24 18:36:01.473048 | controller | ok: [instance]
2026-02-24 18:36:01.504304 | controller |
2026-02-24 18:36:01.504325 | controller | TASK [libvirt_manager : Manage service for older releases] *********************
2026-02-24 18:36:01.504332 | controller | Tuesday 24 February 2026  18:36:01 +0000 (0:00:00.358)       0:00:30.105 ******
2026-02-24 18:36:01.504341 | controller | skipping: [instance]
2026-02-24 18:36:01.794983 | controller |
2026-02-24 18:36:01.795028 | controller | TASK [libvirt_manager : Get libvirt group users] *******************************
2026-02-24 18:36:01.795036 | controller | Tuesday 24 February 2026  18:36:01 +0000 (0:00:00.031)       0:00:30.137 ******
2026-02-24 18:36:01.795047 | controller | ok: [instance]
2026-02-24 18:36:02.249327 | controller |
2026-02-24 18:36:02.249368 | controller | TASK [libvirt_manager : Add user if not exists in libvirt group] ***************
2026-02-24 18:36:02.249376 | controller | Tuesday 24 February 2026  18:36:01 +0000 (0:00:00.290)       0:00:30.427 ******
2026-02-24 18:36:02.249395 | controller | ok: [instance]
2026-02-24 18:36:02.620668 | controller |
2026-02-24 18:36:02.620710 | controller | TASK [libvirt_manager : Allow QEMU on home directory for the storage access] ***
2026-02-24 18:36:02.620718 | controller | Tuesday 24 February 2026  18:36:02 +0000 (0:00:00.454)       0:00:30.881 ******
2026-02-24 18:36:02.620729 | controller | changed: [instance]
2026-02-24 18:36:02.948333 | controller |
2026-02-24 18:36:02.948379 | controller | TASK [libvirt_manager : Inject system connection parameters in bashrc] *********
2026-02-24 18:36:02.948387 | controller | Tuesday 24 February 2026  18:36:02 +0000 (0:00:00.368)       0:00:31.250 ******
2026-02-24 18:36:02.948397 | controller | [WARNING]: Reset is not implemented for this connection
2026-02-24 18:36:02.958387 | controller | changed: [instance]
2026-02-24 18:36:03.028237 | controller |
2026-02-24 18:36:03.028256 | controller | TASK [libvirt_manager : Ensure we reload user env] *****************************
2026-02-24 18:36:03.028264 | controller | Tuesday 24 February 2026  18:36:02 +0000 (0:00:00.324)       0:00:31.575 ******
2026-02-24 18:36:03.028269 | controller |
2026-02-24 18:36:03.028274 | controller | TASK [Create virtual baremetal VMs] ********************************************
2026-02-24 18:36:03.028279 | controller | Tuesday 24 February 2026  18:36:02 +0000 (0:00:00.015)       0:00:31.591 ******
2026-02-24 18:36:03.028287 | controller |
2026-02-24 18:36:03.067656 | controller | TASK [libvirt_manager : Import layout generator if needed] *********************
2026-02-24 18:36:03.067683 | controller | Tuesday 24 February 2026  18:36:03 +0000 (0:00:00.070)       0:00:31.661 ******
2026-02-24 18:36:03.067703 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/generate_layout.yml for instance
2026-02-24 18:36:03.111811 | controller |
2026-02-24 18:36:03.111839 | controller | TASK [libvirt_manager : Chose right parameter for layout definition] ***********
2026-02-24 18:36:03.111847 | controller | Tuesday 24 February 2026  18:36:03 +0000 (0:00:00.039)       0:00:31.700 ******
2026-02-24 18:36:03.111856 | controller | ok: [instance]
2026-02-24 18:36:03.181750 | controller |
2026-02-24 18:36:03.181816 | controller | TASK [libvirt_manager : Patch the layout if needed] ****************************
2026-02-24 18:36:03.181826 | controller | Tuesday 24 February 2026  18:36:03 +0000 (0:00:00.043)       0:00:31.744 ******
2026-02-24 18:36:03.181839 | controller | skipping: [instance]
2026-02-24 18:36:03.181847 | controller |
2026-02-24 18:36:03.181855 | controller | TASK [libvirt_manager : Enable forwarding in the libvirt zone] *****************
2026-02-24 18:36:03.632254 | controller | Tuesday 24 February 2026  18:36:03 +0000 (0:00:00.071)       0:00:31.815 ******
2026-02-24 18:36:03.632349 | controller | changed: [instance]
2026-02-24 18:36:04.212393 | controller |
2026-02-24 18:36:04.212556 | controller | TASK [libvirt_manager : Enable masquerading for public traffic] ****************
2026-02-24 18:36:04.212569 | controller | Tuesday 24 February 2026  18:36:03 +0000 (0:00:00.449)       0:00:32.264 ******
2026-02-24 18:36:04.212665 | controller | changed: [instance]
2026-02-24 18:36:04.979548 | controller |
2026-02-24 18:36:04.979587 | controller | TASK [libvirt_manager : Ensure firewalld is restarts] **************************
2026-02-24 18:36:04.979595 | controller | Tuesday 24 February 2026  18:36:04 +0000 (0:00:00.570)       0:00:32.835 ******
2026-02-24 18:36:04.979601 | controller |
2026-02-24 18:36:04.979607 | controller | RUNNING HANDLER [libvirt_manager : Restart firewalld] **************************
2026-02-24 18:36:04.979612 | controller | Tuesday 24 February 2026  18:36:04 +0000 (0:00:00.009)       0:00:32.844 ******
2026-02-24 18:36:04.979622 | controller | changed: [instance]
2026-02-24 18:36:04.979643 | controller |
2026-02-24 18:36:04.979667 | controller | TASK [Deploy virtualbmc] *******************************************************
2026-02-24 18:36:04.979776 | controller | Tuesday 24 February 2026  18:36:04 +0000 (0:00:00.767)       0:00:33.612 ******
2026-02-24 18:36:05.020844 | controller | skipping: [instance]
2026-02-24 18:36:05.020900 | controller |
2026-02-24 18:36:05.021012 | controller | TASK [libvirt_manager : Let the project know we have vbmc available] ***********
2026-02-24 18:36:05.021103 | controller | Tuesday 24 February 2026  18:36:05 +0000 (0:00:00.041)       0:00:33.654 ******
2026-02-24 18:36:05.060611 | controller | skipping: [instance]
2026-02-24 18:36:05.060734 | controller |
2026-02-24 18:36:05.060783 | controller | TASK [libvirt_manager : Create needed workload directory] **********************
2026-02-24 18:36:05.060847 | controller | Tuesday 24 February 2026  18:36:05 +0000 (0:00:00.038)       0:00:33.692 ******
2026-02-24 18:36:05.688779 | controller | changed: [instance] => (item=workload)
2026-02-24 18:36:05.688840 | controller | changed: [instance] => (item=reproducer-inventory)
2026-02-24 18:36:05.688849 | controller | changed: [instance] => (item=volumes)
2026-02-24 18:36:05.688859 | controller |
2026-02-24 18:36:05.689064 | controller | TASK [libvirt_manager : Allow QEMU on workload directory] **********************
2026-02-24 18:36:05.689130 | controller | Tuesday 24 February 2026  18:36:05 +0000 (0:00:00.627)       0:00:34.320 ******
2026-02-24 18:36:06.230113 | controller | changed: [instance] => (item=workload)
2026-02-24 18:36:06.230175 | controller | changed: [instance] => (item=volumes)
2026-02-24 18:36:06.230186 | controller |
2026-02-24 18:36:06.230521 | controller | TASK [libvirt_manager : Generate networking data] ******************************
2026-02-24 18:36:06.331260 | controller | Tuesday 24 February 2026  18:36:06 +0000 (0:00:00.541)       0:00:34.862 ******
2026-02-24 18:36:06.331305 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/generate_networking_data.yml for instance
2026-02-24 18:36:06.331341 | controller |
2026-02-24 18:36:06.331351 | controller | TASK [libvirt_manager : Ensure fact is existing, and empty] ********************
2026-02-24 18:36:06.331562 | controller | Tuesday 24 February 2026  18:36:06 +0000 (0:00:00.101)       0:00:34.963 ******
2026-02-24 18:36:06.356060 | controller | ok: [instance]
2026-02-24 18:36:06.356543 | controller |
2026-02-24 18:36:06.356566 | controller | TASK [libvirt_manager : Check if we get an existing interfaces-info.yml] *******
2026-02-24 18:36:06.582627 | controller | Tuesday 24 February 2026  18:36:06 +0000 (0:00:00.025)       0:00:34.988 ******
2026-02-24 18:36:06.582705 | controller | ok: [instance]
2026-02-24 18:36:06.582731 | controller |
2026-02-24 18:36:06.582835 | controller | TASK [libvirt_manager : Load file if exists] ***********************************
2026-02-24 18:36:06.582873 | controller | Tuesday 24 February 2026  18:36:06 +0000 (0:00:00.226)       0:00:35.215 ******
2026-02-24 18:36:06.628494 | controller | skipping: [instance]
2026-02-24 18:36:06.661448 | controller |
2026-02-24 18:36:06.661475 | controller | TASK [libvirt_manager : Update fact with existing content] *********************
2026-02-24 18:36:06.661484 | controller | Tuesday 24 February 2026  18:36:06 +0000 (0:00:00.046)       0:00:35.261 ******
2026-02-24 18:36:06.661493 | controller | skipping: [instance]
2026-02-24 18:36:06.717132 | controller |
2026-02-24 18:36:06.717153 | controller | TASK [libvirt_manager : Generate VM list] **************************************
2026-02-24 18:36:06.717161 | controller | Tuesday 24 February 2026  18:36:06 +0000 (0:00:00.033)       0:00:35.294 ******
2026-02-24 18:36:06.717171 | controller | ok: [instance]
2026-02-24 18:36:06.825080 | controller |
2026-02-24 18:36:06.825107 | controller | TASK [libvirt_manager : Generate/update mapping all nodes] *********************
2026-02-24 18:36:06.825115 | controller | Tuesday 24 February 2026  18:36:06 +0000 (0:00:00.055)       0:00:35.350 ******
2026-02-24 18:36:06.825125 | controller | ok: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
2026-02-24 18:36:06.872141 | controller | ok: [instance] => (item={'key': 'compute-1', 'value': 'compute'})
2026-02-24 18:36:06.872168 | controller |
2026-02-24 18:36:06.872176 | controller | TASK [libvirt_manager : Append baremetal nodes if needed] **********************
2026-02-24 18:36:06.872182 | controller | Tuesday 24 February 2026  18:36:06 +0000 (0:00:00.107)       0:00:35.458 ******
2026-02-24 18:36:06.872191 | controller | skipping: [instance]
2026-02-24 18:36:07.289792 | controller |
2026-02-24 18:36:07.289838 | controller | TASK [libvirt_manager : Dump MAC mapping] **************************************
2026-02-24 18:36:07.289845 | controller | Tuesday 24 February 2026  18:36:06 +0000 (0:00:00.046)       0:00:35.504 ******
2026-02-24 18:36:07.289856 | controller | changed: [instance]
2026-02-24 18:36:07.289884 | controller |
2026-02-24 18:36:07.289892 | controller | TASK [libvirt_manager : Inject all VMs in the inventory] ***********************
2026-02-24 18:36:07.370122 | controller | Tuesday 24 February 2026  18:36:07 +0000 (0:00:00.417)       0:00:35.922 ******
2026-02-24 18:36:07.370149 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/add_vm_to_inventory.yml for instance => (item=Adding compute-0 to computes)
2026-02-24 18:36:07.423867 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/add_vm_to_inventory.yml for instance => (item=Adding compute-1 to computes)
2026-02-24 18:36:07.423903 | controller |
2026-02-24 18:36:07.423911 | controller | TASK [libvirt_manager : Add host to runtime inventory] *************************
2026-02-24 18:36:07.423917 | controller | Tuesday 24 February 2026  18:36:07 +0000 (0:00:00.080)       0:00:36.003 ******
2026-02-24 18:36:07.423926 | controller | changed: [instance]
2026-02-24 18:36:07.423998 | controller |
2026-02-24 18:36:07.424010 | controller | TASK [libvirt_manager : Ensure group section exists] ***************************
2026-02-24 18:36:07.424255 | controller | Tuesday 24 February 2026  18:36:07 +0000 (0:00:00.053)       0:00:36.057 ******
2026-02-24 18:36:07.807305 | controller | changed: [instance]
2026-02-24 18:36:07.807355 | controller |
2026-02-24 18:36:07.807489 | controller | TASK [libvirt_manager : Append host under proper group] ************************
2026-02-24 18:36:07.807580 | controller | Tuesday 24 February 2026  18:36:07 +0000 (0:00:00.383)       0:00:36.440 ******
2026-02-24 18:36:08.038328 | controller | changed: [instance]
2026-02-24 18:36:08.038393 | controller |
2026-02-24 18:36:08.038650 | controller | TASK [libvirt_manager : Add host to runtime inventory] *************************
2026-02-24 18:36:08.038668 | controller | Tuesday 24 February 2026  18:36:08 +0000 (0:00:00.230)       0:00:36.671 ******
2026-02-24 18:36:08.102948 | controller | changed: [instance]
2026-02-24 18:36:08.103144 | controller |
2026-02-24 18:36:08.103268 | controller | TASK [libvirt_manager : Ensure group section exists] ***************************
2026-02-24 18:36:08.103286 | controller | Tuesday 24 February 2026  18:36:08 +0000 (0:00:00.064)       0:00:36.736 ******
2026-02-24 18:36:08.338187 | controller | ok: [instance]
2026-02-24 18:36:08.338247 | controller |
2026-02-24 18:36:08.338336 | controller | TASK [libvirt_manager : Append host under proper group] ************************
2026-02-24 18:36:08.338433 | controller | Tuesday 24 February 2026  18:36:08 +0000 (0:00:00.235)       0:00:36.971 ******
2026-02-24 18:36:08.580103 | controller | changed: [instance]
2026-02-24 18:36:08.580140 | controller |
2026-02-24 18:36:08.580220 | controller | TASK [libvirt_manager : Check if ini inventory file exists] ********************
2026-02-24 18:36:08.580315 | controller | Tuesday 24 February 2026  18:36:08 +0000 (0:00:00.238)       0:00:37.209 ******
2026-02-24 18:36:08.804763 | controller | ok: [instance]
2026-02-24 18:36:08.804802 | controller |
2026-02-24 18:36:08.804921 | controller | TASK [libvirt_manager : Convert ini inventory file into yaml] ******************
2026-02-24 18:36:08.805012 | controller | Tuesday 24 February 2026  18:36:08 +0000 (0:00:00.228)       0:00:37.437 ******
2026-02-24 18:36:09.380256 | controller | changed: [instance]
2026-02-24 18:36:09.380506 | controller |
2026-02-24 18:36:09.380839 | controller | TASK [libvirt_manager : Remove ini file after conversion] **********************
2026-02-24 18:36:09.591160 | controller | Tuesday 24 February 2026  18:36:09 +0000 (0:00:00.575)       0:00:38.013 ******
2026-02-24 18:36:09.591197 | controller | changed: [instance]
2026-02-24 18:36:09.620755 | controller |
2026-02-24 18:36:09.620830 | controller | TASK [networking_mapper : Check for Networking Definition file existence] ******
2026-02-24 18:36:09.620841 | controller | Tuesday 24 February 2026  18:36:09 +0000 (0:00:00.210)       0:00:38.224 ******
2026-02-24 18:36:09.620859 | controller | skipping: [instance]
2026-02-24 18:36:09.653043 | controller |
2026-02-24 18:36:09.653073 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2026-02-24 18:36:09.653082 | controller | Tuesday 24 February 2026  18:36:09 +0000 (0:00:00.029)       0:00:38.253 ******
2026-02-24 18:36:09.653095 | controller | skipping: [instance]
2026-02-24 18:36:09.653103 | controller |
2026-02-24 18:36:09.653225 | controller | TASK [networking_mapper : Check for interfaces info file existence] ************
2026-02-24 18:36:09.653318 | controller | Tuesday 24 February 2026  18:36:09 +0000 (0:00:00.032)       0:00:38.286 ******
2026-02-24 18:36:09.682680 | controller | skipping: [instance]
2026-02-24 18:36:09.682740 | controller |
2026-02-24 18:36:09.682779 | controller | TASK [networking_mapper : Load the interfaces info from file] ******************
2026-02-24 18:36:09.683008 | controller | Tuesday 24 February 2026  18:36:09 +0000 (0:00:00.029)       0:00:38.316 ******
2026-02-24 18:36:09.712769 | controller | skipping: [instance]
2026-02-24 18:36:09.712844 | controller |
2026-02-24 18:36:09.712937 | controller | TASK [networking_mapper : Ensure local fact is empty] **************************
2026-02-24 18:36:09.713029 | controller | Tuesday 24 February 2026  18:36:09 +0000 (0:00:00.030)       0:00:38.346 ******
2026-02-24 18:36:09.737792 | controller | ok: [instance]
2026-02-24 18:36:09.737951 | controller |
2026-02-24 18:36:09.738032 | controller | TASK [networking_mapper : Set the input Networking Definition and patch it if needed] ***
2026-02-24 18:36:09.738043 | controller | Tuesday 24 February 2026  18:36:09 +0000 (0:00:00.025)       0:00:38.371 ******
2026-02-24 18:36:09.824009 | controller | ok: [instance] => (item={'networks': {'ctlplane': {'network': '192.168.122.0/24', 'gateway': '192.168.122.1', 'dns': ['192.168.122.253', '192.168.122.254'], 'search-domain': 'ctlplane.example.local', 'mtu': 1500}}, 'group-templates': {'computes': {'network-template': {'range': {'start': 10, 'end': 15}}, 'networks': {'ctlplane': {}}}}})
2026-02-24 18:36:09.824084 | controller |
2026-02-24 18:36:09.824176 | controller | TASK [networking_mapper : Gather facts if requested] ***************************
2026-02-24 18:36:09.824265 | controller | Tuesday 24 February 2026  18:36:09 +0000 (0:00:00.085)       0:00:38.457 ******
2026-02-24 18:36:09.847775 | controller | skipping: [instance]
2026-02-24 18:36:09.847860 | controller |
2026-02-24 18:36:09.847954 | controller | TASK [networking_mapper : Ensure CI infrastructure dir exists] *****************
2026-02-24 18:36:09.848043 | controller | Tuesday 24 February 2026  18:36:09 +0000 (0:00:00.023)       0:00:38.481 ******
2026-02-24 18:36:10.124217 | controller | changed: [instance]
2026-02-24 18:36:10.124280 | controller |
2026-02-24 18:36:10.124361 | controller | TASK [networking_mapper : Write the Networking Definition to file] *************
2026-02-24 18:36:10.124513 | controller | Tuesday 24 February 2026  18:36:10 +0000 (0:00:00.276)       0:00:38.757 ******
2026-02-24 18:36:10.576744 | controller | changed: [instance]
2026-02-24 18:36:10.576806 | controller |
2026-02-24 18:36:10.576913 | controller | TASK [networking_mapper : Call the networking mapper] **************************
2026-02-24 18:36:10.577015 | controller | Tuesday 24 February 2026  18:36:10 +0000 (0:00:00.452)       0:00:39.209 ******
2026-02-24 18:36:10.644677 | controller | ok: [instance]
2026-02-24 18:36:10.644860 | controller |
2026-02-24 18:36:10.644942 | controller | TASK [networking_mapper : Set networking mapper facts] *************************
2026-02-24 18:36:10.645099 | controller | Tuesday 24 February 2026  18:36:10 +0000 (0:00:00.068)       0:00:39.277 ******
2026-02-24 18:36:10.675219 | controller | ok: [instance]
2026-02-24 18:36:10.675322 | controller |
2026-02-24 18:36:10.675460 | controller | TASK [networking_mapper : Write the Networking Environment Definition to file] ***
2026-02-24 18:36:10.675562 | controller | Tuesday 24 February 2026  18:36:10 +0000 (0:00:00.030)       0:00:39.308 ******
2026-02-24 18:36:11.112854 | controller | changed: [instance]
2026-02-24 18:36:11.113109 | controller |
2026-02-24 18:36:11.197843 | controller | TASK [libvirt_manager : Manage networks if needed] *****************************
2026-02-24 18:36:11.197878 | controller | Tuesday 24 February 2026  18:36:11 +0000 (0:00:00.437)       0:00:39.745 ******
2026-02-24 18:36:11.197892 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_networks.yml for instance
2026-02-24 18:36:11.197900 | controller |
2026-02-24 18:36:11.198015 | controller | TASK [libvirt_manager : Define the localized variables for performing the tasks here.] ***
2026-02-24 18:36:11.198107 | controller | Tuesday 24 February 2026  18:36:11 +0000 (0:00:00.085)       0:00:39.831 ******
2026-02-24 18:36:11.251236 | controller | ok: [instance] => (item=public)
2026-02-24 18:36:11.251261 | controller |
2026-02-24 18:36:11.251383 | controller | TASK [libvirt_manager : Ensure networks are defined] ***************************
2026-02-24 18:36:11.251487 | controller | Tuesday 24 February 2026  18:36:11 +0000 (0:00:00.053)       0:00:39.884 ******
2026-02-24 18:36:11.671576 | controller | changed: [instance] => (item=cifmw-public)
2026-02-24 18:36:11.671643 | controller |
2026-02-24 18:36:11.671753 | controller | TASK [libvirt_manager : Ensure networks are created/started] *******************
2026-02-24 18:36:11.671798 | controller | Tuesday 24 February 2026  18:36:11 +0000 (0:00:00.420)       0:00:40.304 ******
2026-02-24 18:36:12.050379 | controller | ok: [instance] => (item=cifmw-public)
2026-02-24 18:36:12.050448 | controller |
2026-02-24 18:36:12.050549 | controller | TASK [libvirt_manager : Ensure networks are active] ****************************
2026-02-24 18:36:12.050642 | controller | Tuesday 24 February 2026  18:36:12 +0000 (0:00:00.378)       0:00:40.683 ******
2026-02-24 18:36:12.321314 | controller | ok: [instance] => (item=cifmw-public)
2026-02-24 18:36:12.321378 | controller |
2026-02-24 18:36:12.321502 | controller | TASK [libvirt_manager : Ensure networks enabled to autostart] ******************
2026-02-24 18:36:12.321584 | controller | Tuesday 24 February 2026  18:36:12 +0000 (0:00:00.270)       0:00:40.954 ******
2026-02-24 18:36:12.596007 | controller | changed: [instance] => (item=cifmw-public)
2026-02-24 18:36:12.596061 | controller |
2026-02-24 18:36:12.596168 | controller | TASK [libvirt_manager : Add a dummy interface to bridges if required] **********
2026-02-24 18:36:12.596246 | controller | Tuesday 24 February 2026  18:36:12 +0000 (0:00:00.274)       0:00:41.228 ******
2026-02-24 18:36:12.659047 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_networks_dummy_interfaces.yml for instance
2026-02-24 18:36:12.659126 | controller |
2026-02-24 18:36:12.659218 | controller | TASK [libvirt_manager : Fetch present bridge interfaces] ***********************
2026-02-24 18:36:12.659306 | controller | Tuesday 24 February 2026  18:36:12 +0000 (0:00:00.063)       0:00:41.292 ******
2026-02-24 18:36:12.871743 | controller | ok: [instance]
2026-02-24 18:36:12.871798 | controller |
2026-02-24 18:36:12.871869 | controller | TASK [libvirt_manager : Fetch bridges ports link info] *************************
2026-02-24 18:36:12.871963 | controller | Tuesday 24 February 2026  18:36:12 +0000 (0:00:00.212)       0:00:41.504 ******
2026-02-24 18:36:13.109276 | controller | ok: [instance] => (item=cifmw-public)
2026-02-24 18:36:13.185786 | controller |
2026-02-24 18:36:13.185829 | controller | TASK [Create dummy interfaces to ensure bridges are UP] ************************
2026-02-24 18:36:13.185838 | controller | Tuesday 24 February 2026  18:36:13 +0000 (0:00:00.237)       0:00:41.742 ******
2026-02-24 18:36:13.185849 | controller |
2026-02-24 18:36:13.185867 | controller | TASK [ci_nmstate : Ensure we have needed facts] ********************************
2026-02-24 18:36:13.185937 | controller | Tuesday 24 February 2026  18:36:13 +0000 (0:00:00.076)       0:00:41.819 ******
2026-02-24 18:36:13.227714 | controller | skipping: [instance]
2026-02-24 18:36:13.227774 | controller |
2026-02-24 18:36:13.227924 | controller | TASK [ci_nmstate : Install required packages on instance] **********************
2026-02-24 18:36:13.228009 | controller | Tuesday 24 February 2026  18:36:13 +0000 (0:00:00.041)       0:00:41.860 ******
2026-02-24 18:36:18.159059 | controller | changed: [instance]
2026-02-24 18:36:18.159151 | controller |
2026-02-24 18:36:18.159184 | controller | TASK [ci_nmstate : Create the target NMstate dump directory] *******************
2026-02-24 18:36:18.159196 | controller | Tuesday 24 February 2026  18:36:18 +0000 (0:00:04.930)       0:00:46.791 ******
2026-02-24 18:36:18.391796 | controller | changed: [instance]
2026-02-24 18:36:18.818922 | controller |
2026-02-24 18:36:18.818957 | controller | TASK [ci_nmstate : Save nmstate state for instance] ****************************
2026-02-24 18:36:18.818965 | controller | Tuesday 24 February 2026  18:36:18 +0000 (0:00:00.232)       0:00:47.024 ******
2026-02-24 18:36:18.818975 | controller | changed: [instance]
2026-02-24 18:36:18.819343 | controller |
2026-02-24 18:36:20.932695 | controller | TASK [ci_nmstate : Apply the desidered state on instance] **********************
2026-02-24 18:36:20.932729 | controller | Tuesday 24 February 2026  18:36:18 +0000 (0:00:00.426)       0:00:47.450 ******
2026-02-24 18:36:20.932741 | controller | changed: [instance]
2026-02-24 18:36:20.932796 | controller |
2026-02-24 18:36:20.932832 | controller | TASK [ci_nmstate : Save nmstate debugging data for instance] *******************
2026-02-24 18:36:20.932844 | controller | Tuesday 24 February 2026  18:36:20 +0000 (0:00:02.114)       0:00:49.565 ******
2026-02-24 18:36:21.356083 | controller | changed: [instance]
2026-02-24 18:36:21.396204 | controller |
2026-02-24 18:36:21.396248 | controller | TASK [Create extra network configuration] **************************************
2026-02-24 18:36:21.396256 | controller | Tuesday 24 February 2026  18:36:21 +0000 (0:00:00.423)       0:00:49.989 ******
2026-02-24 18:36:21.396267 | controller | skipping: [instance]
2026-02-24 18:36:21.435811 | controller |
2026-02-24 18:36:21.435841 | controller | TASK [libvirt_manager : Ensure extra networks is in correct zone] **************
2026-02-24 18:36:21.435850 | controller | Tuesday 24 February 2026  18:36:21 +0000 (0:00:00.040)       0:00:50.029 ******
2026-02-24 18:36:21.435859 | controller | skipping: [instance]
2026-02-24 18:36:21.975860 | controller |
2026-02-24 18:36:21.975899 | controller | TASK [libvirt_manager : Refresh networking facts on host] **********************
2026-02-24 18:36:21.975908 | controller | Tuesday 24 February 2026  18:36:21 +0000 (0:00:00.039)       0:00:50.068 ******
2026-02-24 18:36:21.975919 | controller | ok: [instance]
2026-02-24 18:36:22.124312 | controller |
2026-02-24 18:36:22.124349 | controller | TASK [libvirt_manager : Build needed network/dnsmasq related content] **********
2026-02-24 18:36:22.124357 | controller | Tuesday 24 February 2026  18:36:21 +0000 (0:00:00.539)       0:00:50.608 ******
2026-02-24 18:36:22.124368 | controller | ok: [instance] => (item=cifmw-public)
2026-02-24 18:36:23.409740 | controller |
2026-02-24 18:36:23.409780 | controller | TASK [dnsmasq : Install needed packages] ***************************************
2026-02-24 18:36:23.409788 | controller | Tuesday 24 February 2026  18:36:22 +0000 (0:00:00.148)       0:00:50.756 ******
2026-02-24 18:36:23.409798 | controller | ok: [instance]
2026-02-24 18:36:23.409963 | controller |
2026-02-24 18:36:27.582779 | controller | TASK [dnsmasq : Ensure SELinux knows about the new files and directories] ******
2026-02-24 18:36:27.582994 | controller | Tuesday 24 February 2026  18:36:23 +0000 (0:00:01.285)       0:00:52.042 ******
2026-02-24 18:36:27.583020 | controller | changed: [instance] => (item={'target': '/etc/cifmw-dnsmasq.conf', 'setype': 'dnsmasq_etc_t'})
2026-02-24 18:36:27.842789 | controller | changed: [instance] => (item={'target': '/etc/cifmw-dnsmasq.d(/.*)?', 'setype': 'dnsmasq_etc_t'})
2026-02-24 18:36:27.842849 | controller | changed: [instance] => (item={'target': '/var/run/cifmw-dnsmasq.pid', 'setype': 'dnsmasq_var_run_t'})
2026-02-24 18:36:27.842858 | controller |
2026-02-24 18:36:27.842865 | controller | TASK [dnsmasq : Manage configuration directory] ********************************
2026-02-24 18:36:27.842871 | controller | Tuesday 24 February 2026  18:36:27 +0000 (0:00:04.172)       0:00:56.215 ******
2026-02-24 18:36:27.842885 | controller | changed: [instance]
2026-02-24 18:36:27.842911 | controller |
2026-02-24 18:36:27.843115 | controller | TASK [dnsmasq : Manage systemd unit file] **************************************
2026-02-24 18:36:27.843134 | controller | Tuesday 24 February 2026  18:36:27 +0000 (0:00:00.260)       0:00:56.475 ******
2026-02-24 18:36:28.255352 | controller | changed: [instance]
2026-02-24 18:36:28.255472 | controller |
2026-02-24 18:36:28.255977 | controller | TASK [dnsmasq : Manage base configuration file] ********************************
2026-02-24 18:36:28.256250 | controller | Tuesday 24 February 2026  18:36:28 +0000 (0:00:00.412)       0:00:56.888 ******
2026-02-24 18:36:28.736323 | controller | changed: [instance]
2026-02-24 18:36:28.736405 | controller |
2026-02-24 18:36:28.736415 | controller | TASK [dnsmasq : Render listener configuration] *********************************
2026-02-24 18:36:28.736426 | controller | Tuesday 24 February 2026  18:36:28 +0000 (0:00:00.479)       0:00:57.367 ******
2026-02-24 18:36:28.777926 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/listener.yml for instance
2026-02-24 18:36:28.777973 | controller |
2026-02-24 18:36:28.778705 | controller | TASK [dnsmasq : Create listener configuration file] ****************************
2026-02-24 18:36:29.259660 | controller | Tuesday 24 February 2026  18:36:28 +0000 (0:00:00.043)       0:00:57.411 ******
2026-02-24 18:36:29.259709 | controller | changed: [instance]
2026-02-24 18:36:29.259731 | controller |
2026-02-24 18:36:29.259901 | controller | TASK [dnsmasq : Remove listener configuration file] ****************************
2026-02-24 18:36:29.283942 | controller | Tuesday 24 February 2026  18:36:29 +0000 (0:00:00.481)       0:00:57.892 ******
2026-02-24 18:36:29.283966 | controller | skipping: [instance]
2026-02-24 18:36:29.284013 | controller |
2026-02-24 18:36:29.284118 | controller | TASK [dnsmasq : Render dns configuration] **************************************
2026-02-24 18:36:29.284213 | controller | Tuesday 24 February 2026  18:36:29 +0000 (0:00:00.025)       0:00:57.917 ******
2026-02-24 18:36:29.322849 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/dns.yml for instance
2026-02-24 18:36:29.322918 | controller |
2026-02-24 18:36:29.323036 | controller | TASK [dnsmasq : Create dns configuration file] *********************************
2026-02-24 18:36:29.323136 | controller | Tuesday 24 February 2026  18:36:29 +0000 (0:00:00.038)       0:00:57.956 ******
2026-02-24 18:36:29.776040 | controller | changed: [instance]
2026-02-24 18:36:29.776099 | controller |
2026-02-24 18:36:29.776216 | controller | TASK [dnsmasq : Remove dns configuration file] *********************************
2026-02-24 18:36:29.776321 | controller | Tuesday 24 February 2026  18:36:29 +0000 (0:00:00.452)       0:00:58.409 ******
2026-02-24 18:36:29.798579 | controller | skipping: [instance]
2026-02-24 18:36:29.798655 | controller |
2026-02-24 18:36:29.798760 | controller | TASK [dnsmasq : Add localhost addresses from defined dnsmasq listen addresses to loopback interface] ***
2026-02-24 18:36:29.798895 | controller | Tuesday 24 February 2026  18:36:29 +0000 (0:00:00.022)       0:00:58.431 ******
2026-02-24 18:36:30.049017 | controller | ok: [instance] => (item=127.0.0.2)
2026-02-24 18:36:30.049063 | controller |
2026-02-24 18:36:30.049177 | controller | TASK [dnsmasq : Enable and start service] **************************************
2026-02-24 18:36:30.049262 | controller | Tuesday 24 February 2026  18:36:30 +0000 (0:00:00.250)       0:00:58.682 ******
2026-02-24 18:36:30.974894 | controller | changed: [instance]
2026-02-24 18:36:30.975187 | controller |
2026-02-24 18:36:31.003453 | controller | TASK [dnsmasq : Stop service] **************************************************
2026-02-24 18:36:31.003488 | controller | Tuesday 24 February 2026  18:36:30 +0000 (0:00:00.924)       0:00:59.606 ******
2026-02-24 18:36:31.003502 | controller | skipping: [instance]
2026-02-24 18:36:31.003547 | controller |
2026-02-24 18:36:31.003835 | controller | TASK [dnsmasq : Remove unit file] **********************************************
2026-02-24 18:36:31.036509 | controller | Tuesday 24 February 2026  18:36:31 +0000 (0:00:00.029)       0:00:59.636 ******
2026-02-24 18:36:31.036615 | controller | skipping: [instance]
2026-02-24 18:36:31.036642 | controller |
2026-02-24 18:36:31.036652 | controller | TASK [dnsmasq : Remove main configuration files] *******************************
2026-02-24 18:36:31.036728 | controller | Tuesday 24 February 2026  18:36:31 +0000 (0:00:00.033)       0:00:59.669 ******
2026-02-24 18:36:31.077890 | controller | skipping: [instance] => (item=/etc/cifmw-dnsmasq.conf)
2026-02-24 18:36:31.077965 | controller | skipping: [instance] => (item=/etc/cifmw-dnsmasq.d)
2026-02-24 18:36:31.078061 | controller | skipping: [instance]
2026-02-24 18:36:31.078146 | controller |
2026-02-24 18:36:31.078239 | controller | TASK [Create dnsmasq networks] *************************************************
2026-02-24 18:36:31.078342 | controller | Tuesday 24 February 2026  18:36:31 +0000 (0:00:00.041)       0:00:59.711 ******
2026-02-24 18:36:31.161491 | controller |
2026-02-24 18:36:31.161573 | controller | TASK [dnsmasq : Assert mandatory parameter] ************************************
2026-02-24 18:36:31.161675 | controller | Tuesday 24 February 2026  18:36:31 +0000 (0:00:00.083)       0:00:59.794 ******
2026-02-24 18:36:31.200208 | controller | ok: [instance] => changed=false
2026-02-24 18:36:31.200277 | controller |   msg: All assertions passed
2026-02-24 18:36:31.200360 | controller |
2026-02-24 18:36:31.200494 | controller | TASK [dnsmasq : Assert mandatory parameters for new network] *******************
2026-02-24 18:36:31.200583 | controller | Tuesday 24 February 2026  18:36:31 +0000 (0:00:00.038)       0:00:59.833 ******
2026-02-24 18:36:31.252474 | controller | ok: [instance] => changed=false
2026-02-24 18:36:31.252637 | controller |   msg: All assertions passed
2026-02-24 18:36:31.252731 | controller |
2026-02-24 18:36:31.252828 | controller | TASK [dnsmasq : Create network] ************************************************
2026-02-24 18:36:31.253238 | controller | Tuesday 24 February 2026  18:36:31 +0000 (0:00:00.051)       0:00:59.885 ******
2026-02-24 18:36:31.798341 | controller | changed: [instance]
2026-02-24 18:36:31.798435 | controller |
2026-02-24 18:36:31.798501 | controller | TASK [dnsmasq : Remove network] ************************************************
2026-02-24 18:36:31.798619 | controller | Tuesday 24 February 2026  18:36:31 +0000 (0:00:00.545)       0:01:00.430 ******
2026-02-24 18:36:31.827993 | controller | skipping: [instance]
2026-02-24 18:36:31.828074 | controller |
2026-02-24 18:36:31.828174 | controller | TASK [dnsmasq : Remove dhcp host files] ****************************************
2026-02-24 18:36:31.828268 | controller | Tuesday 24 February 2026  18:36:31 +0000 (0:00:00.030)       0:01:00.461 ******
2026-02-24 18:36:31.860988 | controller | skipping: [instance]
2026-02-24 18:36:31.861055 | controller |
2026-02-24 18:36:31.861147 | controller | TASK [Deploy radvd for IPv6 router advertisements] *****************************
2026-02-24 18:36:31.861244 | controller | Tuesday 24 February 2026  18:36:31 +0000 (0:00:00.033)       0:01:00.494 ******
2026-02-24 18:36:31.902742 | controller | skipping: [instance]
2026-02-24 18:36:31.902832 | controller |
2026-02-24 18:36:31.902919 | controller | TASK [libvirt_manager : Ensure network is in correct zone] *********************
2026-02-24 18:36:31.902997 | controller | Tuesday 24 February 2026  18:36:31 +0000 (0:00:00.041)       0:01:00.536 ******
2026-02-24 18:36:32.266417 | controller | changed: [instance] => (item=cifmw-public)
2026-02-24 18:36:32.266538 | controller |
2026-02-24 18:36:32.266584 | controller | TASK [libvirt_manager : Extract IP address from network bridges] ***************
2026-02-24 18:36:32.266698 | controller | Tuesday 24 February 2026  18:36:32 +0000 (0:00:00.362)       0:01:00.898 ******
2026-02-24 18:36:32.307374 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/network_bridge_info_gen.yml for instance => (item=cifmw-public)
2026-02-24 18:36:32.307426 | controller |
2026-02-24 18:36:32.307558 | controller | TASK [libvirt_manager : Extract IP address from network bridges] ***************
2026-02-24 18:36:32.307627 | controller | Tuesday 24 February 2026  18:36:32 +0000 (0:00:00.041)       0:01:00.940 ******
2026-02-24 18:36:32.646621 | controller | ok: [instance]
2026-02-24 18:36:32.699082 | controller |
2026-02-24 18:36:32.699137 | controller | TASK [libvirt_manager : Set network_bridge_info fact with network and address] ***
2026-02-24 18:36:32.699147 | controller | Tuesday 24 February 2026  18:36:32 +0000 (0:00:00.338)       0:01:01.278 ******
2026-02-24 18:36:32.699172 | controller | ok: [instance]
2026-02-24 18:36:32.699195 | controller |
2026-02-24 18:36:32.699284 | controller | TASK [libvirt_manager : Output _network_data] **********************************
2026-02-24 18:36:32.699296 | controller | Tuesday 24 February 2026  18:36:32 +0000 (0:00:00.053)       0:01:01.332 ******
2026-02-24 18:36:33.105322 | controller | changed: [instance]
2026-02-24 18:36:33.105411 | controller |
2026-02-24 18:36:33.105464 | controller | TASK [libvirt_manager : Output pub_net] ****************************************
2026-02-24 18:36:33.105589 | controller | Tuesday 24 February 2026  18:36:33 +0000 (0:00:00.405)       0:01:01.737 ******
2026-02-24 18:36:33.514237 | controller | changed: [instance]
2026-02-24 18:36:33.514304 | controller |
2026-02-24 18:36:33.514371 | controller | TASK [libvirt_manager : Output _cifmw_libvirt_manager_layout] ******************
2026-02-24 18:36:33.514518 | controller | Tuesday 24 February 2026  18:36:33 +0000 (0:00:00.408)       0:01:02.146 ******
2026-02-24 18:36:33.892123 | controller | changed: [instance]
2026-02-24 18:36:33.892298 | controller |
2026-02-24 18:36:33.892355 | controller | TASK [libvirt_manager : Expose patch for networking_mapper] ********************
2026-02-24 18:36:33.892366 | controller | Tuesday 24 February 2026  18:36:33 +0000 (0:00:00.378)       0:01:02.524 ******
2026-02-24 18:36:33.995032 | controller | ok: [instance]
2026-02-24 18:36:33.995064 | controller |
2026-02-24 18:36:33.995169 | controller | TASK [libvirt_manager : Save networking_mapper patch] **************************
2026-02-24 18:36:33.995262 | controller | Tuesday 24 February 2026  18:36:33 +0000 (0:00:00.103)       0:01:02.628 ******
2026-02-24 18:36:34.399567 | controller | changed: [instance]
2026-02-24 18:36:34.399616 | controller |
2026-02-24 18:36:34.399701 | controller | TASK [networking_mapper : Check for Networking Definition file existence] ******
2026-02-24 18:36:34.399790 | controller | Tuesday 24 February 2026  18:36:34 +0000 (0:00:00.404)       0:01:03.032 ******
2026-02-24 18:36:34.429542 | controller | skipping: [instance]
2026-02-24 18:36:34.429589 | controller |
2026-02-24 18:36:34.429687 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2026-02-24 18:36:34.429772 | controller | Tuesday 24 February 2026  18:36:34 +0000 (0:00:00.030)       0:01:03.062 ******
2026-02-24 18:36:34.459955 | controller | skipping: [instance]
2026-02-24 18:36:34.460021 | controller |
2026-02-24 18:36:34.460120 | controller | TASK [networking_mapper : Check for interfaces info file existence] ************
2026-02-24 18:36:34.460213 | controller | Tuesday 24 February 2026  18:36:34 +0000 (0:00:00.030)       0:01:03.093 ******
2026-02-24 18:36:34.490068 | controller | skipping: [instance]
2026-02-24 18:36:34.490139 | controller |
2026-02-24 18:36:34.490220 | controller | TASK [networking_mapper : Load the interfaces info from file] ******************
2026-02-24 18:36:34.490312 | controller | Tuesday 24 February 2026  18:36:34 +0000 (0:00:00.030)       0:01:03.123 ******
2026-02-24 18:36:34.518574 | controller | skipping: [instance]
2026-02-24 18:36:34.518898 | controller |
2026-02-24 18:36:34.548713 | controller | TASK [networking_mapper : Ensure local fact is empty] **************************
2026-02-24 18:36:34.548736 | controller | Tuesday 24 February 2026  18:36:34 +0000 (0:00:00.028)       0:01:03.152 ******
2026-02-24 18:36:34.548747 | controller | ok: [instance]
2026-02-24 18:36:34.637872 | controller |
2026-02-24 18:36:34.637892 | controller | TASK [networking_mapper : Set the input Networking Definition and patch it if needed] ***
2026-02-24 18:36:34.637900 | controller | Tuesday 24 February 2026  18:36:34 +0000 (0:00:00.029)       0:01:03.181 ******
2026-02-24 18:36:34.637911 | controller | ok: [instance] => (item={'networks': {'ctlplane': {'network': '192.168.122.0/24', 'gateway': '192.168.122.1', 'dns': ['192.168.122.253', '192.168.122.254'], 'search-domain': 'ctlplane.example.local', 'mtu': 1500}}, 'group-templates': {'computes': {'network-template': {'range': {'start': 10, 'end': 15}}, 'networks': {'ctlplane': {}}}}})
2026-02-24 18:36:34.662806 | controller | ok: [instance] => (item={'networks': {'public': {'network-v4': '192.168.100.0/24'}}, 'group-templates': {'computes': {'networks': {'public': None}}}})
2026-02-24 18:36:34.662838 | controller |
2026-02-24 18:36:34.662846 | controller | TASK [networking_mapper : Gather facts if requested] ***************************
2026-02-24 18:36:34.662852 | controller | Tuesday 24 February 2026  18:36:34 +0000 (0:00:00.089)       0:01:03.270 ******
2026-02-24 18:36:34.662862 | controller | skipping: [instance]
2026-02-24 18:36:34.903349 | controller |
2026-02-24 18:36:34.903414 | controller | TASK [networking_mapper : Ensure CI infrastructure dir exists] *****************
2026-02-24 18:36:34.903426 | controller | Tuesday 24 February 2026  18:36:34 +0000 (0:00:00.025)       0:01:03.295 ******
2026-02-24 18:36:34.903455 | controller | ok: [instance]
2026-02-24 18:36:34.903488 | controller |
2026-02-24 18:36:34.903650 | controller | TASK [networking_mapper : Write the Networking Definition to file] *************
2026-02-24 18:36:34.903705 | controller | Tuesday 24 February 2026  18:36:34 +0000 (0:00:00.240)       0:01:03.536 ******
2026-02-24 18:36:35.386842 | controller | changed: [instance]
2026-02-24 18:36:35.387123 | controller |
2026-02-24 18:36:35.387188 | controller | TASK [networking_mapper : Call the networking mapper] **************************
2026-02-24 18:36:35.441404 | controller | Tuesday 24 February 2026  18:36:35 +0000 (0:00:00.483)       0:01:04.019 ******
2026-02-24 18:36:35.441473 | controller | ok: [instance]
2026-02-24 18:36:35.477455 | controller |
2026-02-24 18:36:35.477479 | controller | TASK [networking_mapper : Set networking mapper facts] *************************
2026-02-24 18:36:35.477497 | controller | Tuesday 24 February 2026  18:36:35 +0000 (0:00:00.055)       0:01:04.074 ******
2026-02-24 18:36:35.477510 | controller | ok: [instance]
2026-02-24 18:36:35.938893 | controller |
2026-02-24 18:36:35.938948 | controller | TASK [networking_mapper : Write the Networking Environment Definition to file] ***
2026-02-24 18:36:35.938957 | controller | Tuesday 24 February 2026  18:36:35 +0000 (0:00:00.035)       0:01:04.110 ******
2026-02-24 18:36:35.938969 | controller | changed: [instance]
2026-02-24 18:36:35.968397 | controller |
2026-02-24 18:36:35.968418 | controller | TASK [libvirt_manager : Be sure to save current state of networking_mapper environment] ***
2026-02-24 18:36:35.968426 | controller | Tuesday 24 February 2026  18:36:35 +0000 (0:00:00.460)       0:01:04.571 ******
2026-02-24 18:36:35.968456 | controller | ok: [instance]
2026-02-24 18:36:35.997408 | controller |
2026-02-24 18:36:35.997424 | controller | TASK [libvirt_manager : Unset patch] *******************************************
2026-02-24 18:36:35.997430 | controller | Tuesday 24 February 2026  18:36:35 +0000 (0:00:00.030)       0:01:04.601 ******
2026-02-24 18:36:35.997456 | controller | ok: [instance]
2026-02-24 18:36:36.021540 | controller |
2026-02-24 18:36:36.021576 | controller | TASK [libvirt_manager : Initialize empty _lm_dhcp_entries fact] ****************
2026-02-24 18:36:36.021584 | controller | Tuesday 24 February 2026  18:36:35 +0000 (0:00:00.028)       0:01:04.630 ******
2026-02-24 18:36:36.021594 | controller | ok: [instance]
2026-02-24 18:36:36.021689 | controller |
2026-02-24 18:36:36.021697 | controller | TASK [libvirt_manager : Reserve IPs on networks] *******************************
2026-02-24 18:36:36.021705 | controller | Tuesday 24 February 2026  18:36:36 +0000 (0:00:00.024)       0:01:04.654 ******
2026-02-24 18:36:36.066993 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/reserve_dnsmasq_ips.yml for instance => (item=ctlplane)
2026-02-24 18:36:36.067092 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/reserve_dnsmasq_ips.yml for instance => (item=public)
2026-02-24 18:36:36.067102 | controller |
2026-02-24 18:36:36.067110 | controller | TASK [libvirt_manager : Loop on host IPs] **************************************
2026-02-24 18:36:36.067121 | controller | Tuesday 24 February 2026  18:36:36 +0000 (0:00:00.045)       0:01:04.700 ******
2026-02-24 18:36:36.141252 | controller | skipping: [instance] => (item=compute-0 - ctlplane)
2026-02-24 18:36:36.141491 | controller | skipping: [instance] => (item=compute-1 - ctlplane)
2026-02-24 18:36:36.141607 | controller | skipping: [instance]
2026-02-24 18:36:36.141619 | controller |
2026-02-24 18:36:36.141626 | controller | TASK [libvirt_manager : Loop on host IPs] **************************************
2026-02-24 18:36:36.141639 | controller | Tuesday 24 February 2026  18:36:36 +0000 (0:00:00.074)       0:01:04.774 ******
2026-02-24 18:36:36.261598 | controller | ok: [instance] => (item=compute-0 - public)
2026-02-24 18:36:36.261654 | controller | ok: [instance] => (item=compute-1 - public)
2026-02-24 18:36:36.261812 | controller |
2026-02-24 18:36:36.261843 | controller | TASK [Inject DHCP entries for net {{ net_name }}] ******************************
2026-02-24 18:36:36.261948 | controller | Tuesday 24 February 2026  18:36:36 +0000 (0:00:00.120)       0:01:04.894 ******
2026-02-24 18:36:36.320503 | controller |
2026-02-24 18:36:36.320570 | controller | TASK [dnsmasq : Ensure we have the right data and type] ************************
2026-02-24 18:36:36.320583 | controller | Tuesday 24 February 2026  18:36:36 +0000 (0:00:00.059)       0:01:04.953 ******
2026-02-24 18:36:36.364287 | controller | ok: [instance]
2026-02-24 18:36:36.425128 | controller |
2026-02-24 18:36:36.425157 | controller | TASK [dnsmasq : Assert we have needed host data] *******************************
2026-02-24 18:36:36.425166 | controller | Tuesday 24 February 2026  18:36:36 +0000 (0:00:00.043)       0:01:04.997 ******
2026-02-24 18:36:36.425178 | controller | ok: [instance] => (item={'network': 'public', 'name': 'compute-0', 'state': 'present', 'mac': '52:54:00:42:b6:1e', 'ips': ['192.168.100.10', ''], 'tag': 'compute'})
2026-02-24 18:36:36.477403 | controller | ok: [instance] => (item={'network': 'public', 'name': 'compute-1', 'state': 'present', 'mac': '52:54:01:cf:23:35', 'ips': ['192.168.100.11', ''], 'tag': 'compute'})
2026-02-24 18:36:36.477431 | controller |
2026-02-24 18:36:36.477459 | controller | TASK [dnsmasq : Ensure networks exists] ****************************************
2026-02-24 18:36:36.477466 | controller | Tuesday 24 February 2026  18:36:36 +0000 (0:00:00.060)       0:01:05.057 ******
2026-02-24 18:36:36.477490 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/_check_net_status.yml for instance => (item=public)
2026-02-24 18:36:36.687373 | controller |
2026-02-24 18:36:36.687456 | controller | TASK [dnsmasq : Check network file status] *************************************
2026-02-24 18:36:36.687470 | controller | Tuesday 24 February 2026  18:36:36 +0000 (0:00:00.052)       0:01:05.110 ******
2026-02-24 18:36:36.687486 | controller | ok: [instance]
2026-02-24 18:36:36.725032 | controller |
2026-02-24 18:36:36.725058 | controller | TASK [dnsmasq : Assert network exists] *****************************************
2026-02-24 18:36:36.725067 | controller | Tuesday 24 February 2026  18:36:36 +0000 (0:00:00.209)       0:01:05.320 ******
2026-02-24 18:36:36.725081 | controller | ok: [instance]
2026-02-24 18:36:36.725184 | controller |
2026-02-24 18:36:36.725194 | controller | TASK [dnsmasq : Initialize empty dhcp_host_entries] ****************************
2026-02-24 18:36:36.725288 | controller | Tuesday 24 February 2026  18:36:36 +0000 (0:00:00.037)       0:01:05.357 ******
2026-02-24 18:36:36.755793 | controller | ok: [instance]
2026-02-24 18:36:36.755876 | controller |
2026-02-24 18:36:36.755978 | controller | TASK [dnsmasq : Compute entry] *************************************************
2026-02-24 18:36:36.756096 | controller | Tuesday 24 February 2026  18:36:36 +0000 (0:00:00.030)       0:01:05.388 ******
2026-02-24 18:36:36.873806 | controller | ok: [instance] => (item={'network': 'public', 'name': 'compute-0', 'state': 'present', 'mac': '52:54:00:42:b6:1e', 'ips': ['192.168.100.10', ''], 'tag': 'compute'})
2026-02-24 18:36:36.873859 | controller | ok: [instance] => (item={'network': 'public', 'name': 'compute-1', 'state': 'present', 'mac': '52:54:01:cf:23:35', 'ips': ['192.168.100.11', ''], 'tag': 'compute'})
2026-02-24 18:36:36.873957 | controller |
2026-02-24 18:36:36.874054 | controller | TASK [dnsmasq : Create add/remove sets] ****************************************
2026-02-24 18:36:36.874152 | controller | Tuesday 24 February 2026  18:36:36 +0000 (0:00:00.118)       0:01:05.506 ******
2026-02-24 18:36:36.922516 | controller | ok: [instance]
2026-02-24 18:36:36.922600 | controller |
2026-02-24 18:36:36.922698 | controller | TASK [dnsmasq : Add DHCP entries] **********************************************
2026-02-24 18:36:36.922795 | controller | Tuesday 24 February 2026  18:36:36 +0000 (0:00:00.048)       0:01:05.555 ******
2026-02-24 18:36:37.735329 | controller | changed: [instance] => (item={'file': 'public_compute-0_52:54:00:42:b6:1e', 'entry': 'set:compute,52:54:00:42:b6:1e,192.168.100.10,compute-0', 'state': 'present'})
2026-02-24 18:36:37.735549 | controller | changed: [instance] => (item={'file': 'public_compute-1_52:54:01:cf:23:35', 'entry': 'set:compute,52:54:01:cf:23:35,192.168.100.11,compute-1', 'state': 'present'})
2026-02-24 18:36:37.735569 | controller |
2026-02-24 18:36:37.735579 | controller | TASK [dnsmasq : Remove DHCP entries] *******************************************
2026-02-24 18:36:37.735676 | controller | Tuesday 24 February 2026  18:36:37 +0000 (0:00:00.812)       0:01:06.368 ******
2026-02-24 18:36:37.761235 | controller | skipping: [instance]
2026-02-24 18:36:37.761301 | controller |
2026-02-24 18:36:37.761419 | controller | TASK [libvirt_manager : Create per-network and .utility DNS entries] ***********
2026-02-24 18:36:37.762549 | controller | Tuesday 24 February 2026  18:36:37 +0000 (0:00:00.026)       0:01:06.394 ******
2026-02-24 18:36:37.920160 | controller | ok: [instance] => (item=compute-0)
2026-02-24 18:36:37.920229 | controller | ok: [instance] => (item=compute-1)
2026-02-24 18:36:37.920333 | controller |
2026-02-24 18:36:37.920473 | controller | TASK [Inject VMs in the .utility zone] *****************************************
2026-02-24 18:36:37.920576 | controller | Tuesday 24 February 2026  18:36:37 +0000 (0:00:00.158)       0:01:06.553 ******
2026-02-24 18:36:37.990955 | controller |
2026-02-24 18:36:37.991079 | controller | TASK [dnsmasq : Assert we have needed host record data] ************************
2026-02-24 18:36:37.991169 | controller | Tuesday 24 February 2026  18:36:37 +0000 (0:00:00.070)       0:01:06.624 ******
2026-02-24 18:36:38.110233 | controller | ok: [instance]
2026-02-24 18:36:38.110348 | controller |
2026-02-24 18:36:38.110364 | controller | TASK [dnsmasq : Assert each address element have needed data] ******************
2026-02-24 18:36:38.110604 | controller | Tuesday 24 February 2026  18:36:38 +0000 (0:00:00.119)       0:01:06.743 ******
2026-02-24 18:36:38.219363 | controller | ok: [instance] => (item={'names': ['compute-0.utility', 'compute-0.instance', 'compute-0.utility', 'compute-0.instance'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
2026-02-24 18:36:38.219450 | controller | ok: [instance] => (item={'names': ['compute-0.ctlplane.local', 'compute-0.ctlplane.local'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
2026-02-24 18:36:38.219547 | controller | ok: [instance] => (item={'names': ['compute-0.public.local', 'compute-0.public.local'], 'ips': ['192.168.100.10', ''], 'state': 'present'})
2026-02-24 18:36:38.219643 | controller | ok: [instance] => (item={'names': ['compute-1.utility', 'compute-1.instance', 'compute-1.utility', 'compute-1.instance'], 'ips': ['192.168.122.11', ''], 'state': 'present'})
2026-02-24 18:36:38.219729 | controller | ok: [instance] => (item={'names': ['compute-1.ctlplane.local', 'compute-1.ctlplane.local'], 'ips': ['192.168.122.11', ''], 'state': 'present'})
2026-02-24 18:36:38.219897 | controller | ok: [instance] => (item={'names': ['compute-1.public.local', 'compute-1.public.local'], 'ips': ['192.168.100.11', ''], 'state': 'present'})
2026-02-24 18:36:38.219959 | controller |
2026-02-24 18:36:38.219967 | controller | TASK [dnsmasq : Add/Remove address] ********************************************
2026-02-24 18:36:38.220039 | controller | Tuesday 24 February 2026  18:36:38 +0000 (0:00:00.108)       0:01:06.852 ******
2026-02-24 18:36:39.548843 | controller | changed: [instance] => (item={'names': ['compute-0.utility', 'compute-0.instance', 'compute-0.utility', 'compute-0.instance'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
2026-02-24 18:36:39.548910 | controller | changed: [instance] => (item={'names': ['compute-0.ctlplane.local', 'compute-0.ctlplane.local'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
2026-02-24 18:36:39.549012 | controller | changed: [instance] => (item={'names': ['compute-0.public.local', 'compute-0.public.local'], 'ips': ['192.168.100.10', ''], 'state': 'present'})
2026-02-24 18:36:39.549116 | controller | changed: [instance] => (item={'names': ['compute-1.utility', 'compute-1.instance', 'compute-1.utility', 'compute-1.instance'], 'ips': ['192.168.122.11', ''], 'state': 'present'})
2026-02-24 18:36:39.549214 | controller | changed: [instance] => (item={'names': ['compute-1.ctlplane.local', 'compute-1.ctlplane.local'], 'ips': ['192.168.122.11', ''], 'state': 'present'})
2026-02-24 18:36:39.549307 | controller | changed: [instance] => (item={'names': ['compute-1.public.local', 'compute-1.public.local'], 'ips': ['192.168.100.11', ''], 'state': 'present'})
2026-02-24 18:36:39.549409 | controller |
2026-02-24 18:36:39.549576 | controller | TASK [dnsmasq : Add controller-0 short hostname record when 'utility' in the name into /etc/hosts] ***
2026-02-24 18:36:39.549667 | controller | Tuesday 24 February 2026  18:36:39 +0000 (0:00:01.329)       0:01:08.181 ******
2026-02-24 18:36:39.654767 | controller | skipping: [instance] => (item={'names': ['compute-0.utility', 'compute-0.instance', 'compute-0.utility', 'compute-0.instance'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
2026-02-24 18:36:39.654855 | controller | skipping: [instance] => (item={'names': ['compute-0.ctlplane.local', 'compute-0.ctlplane.local'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
2026-02-24 18:36:39.654951 | controller | skipping: [instance] => (item={'names': ['compute-0.public.local', 'compute-0.public.local'], 'ips': ['192.168.100.10', ''], 'state': 'present'})
2026-02-24 18:36:39.655051 | controller | skipping: [instance] => (item={'names': ['compute-1.utility', 'compute-1.instance', 'compute-1.utility', 'compute-1.instance'], 'ips': ['192.168.122.11', ''], 'state': 'present'})
2026-02-24 18:36:39.655146 | controller | skipping: [instance] => (item={'names': ['compute-1.ctlplane.local', 'compute-1.ctlplane.local'], 'ips': ['192.168.122.11', ''], 'state': 'present'})
2026-02-24 18:36:39.655225 | controller | skipping: [instance] => (item={'names': ['compute-1.public.local', 'compute-1.public.local'], 'ips': ['192.168.100.11', ''], 'state': 'present'})
2026-02-24 18:36:39.655314 | controller | skipping: [instance]
2026-02-24 18:36:39.655413 | controller |
2026-02-24 18:36:39.655555 | controller | TASK [libvirt_manager : Initialize empty _lm_dhcp_options fact] ****************
2026-02-24 18:36:39.655680 | controller | Tuesday 24 February 2026  18:36:39 +0000 (0:00:00.106)       0:01:08.288 ******
2026-02-24 18:36:39.683581 | controller | ok: [instance]
2026-02-24 18:36:39.683687 | controller |
2026-02-24 18:36:39.683818 | controller | TASK [libvirt_manager : Collect DHCP options from VM definitions] **************
2026-02-24 18:36:39.683948 | controller | Tuesday 24 February 2026  18:36:39 +0000 (0:00:00.028)       0:01:08.316 ******
2026-02-24 18:36:39.728801 | controller | skipping: [instance] => (item=compute)
2026-02-24 18:36:39.728878 | controller | skipping: [instance]
2026-02-24 18:36:39.728963 | controller |
2026-02-24 18:36:39.729064 | controller | TASK [libvirt_manager : Generate DHCP option configuration for VM types] *******
2026-02-24 18:36:39.729160 | controller | Tuesday 24 February 2026  18:36:39 +0000 (0:00:00.045)       0:01:08.362 ******
2026-02-24 18:36:39.773324 | controller | skipping: [instance]
2026-02-24 18:36:39.773423 | controller |
2026-02-24 18:36:39.773549 | controller | TASK [libvirt_manager : Ensure some domains are local] *************************
2026-02-24 18:36:39.773644 | controller | Tuesday 24 February 2026  18:36:39 +0000 (0:00:00.044)       0:01:08.406 ******
2026-02-24 18:36:40.196688 | controller | changed: [instance]
2026-02-24 18:36:40.196726 | controller |
2026-02-24 18:36:40.196822 | controller | TASK [libvirt_manager : Ensure dnsmasq is reloaded now] ************************
2026-02-24 18:36:40.196910 | controller | Tuesday 24 February 2026  18:36:40 +0000 (0:00:00.412)       0:01:08.819 ******
2026-02-24 18:36:40.196982 | controller |
2026-02-24 18:36:40.197062 | controller | RUNNING HANDLER [libvirt_manager : Restart firewalld] **************************
2026-02-24 18:36:40.197147 | controller | Tuesday 24 February 2026  18:36:40 +0000 (0:00:00.010)       0:01:08.829 ******
2026-02-24 18:36:40.934725 | controller | changed: [instance]
2026-02-24 18:36:40.934786 | controller |
2026-02-24 18:36:40.935020 | controller | RUNNING HANDLER [dnsmasq : Restart dnsmasq] ************************************
2026-02-24 18:36:41.331219 | controller | Tuesday 24 February 2026  18:36:40 +0000 (0:00:00.737)       0:01:09.567 ******
2026-02-24 18:36:41.331271 | controller | changed: [instance]
2026-02-24 18:36:41.331304 | controller |
2026-02-24 18:36:41.331591 | controller | RUNNING HANDLER [dnsmasq : Reload dnsmasq] *************************************
2026-02-24 18:36:42.699761 | controller | Tuesday 24 February 2026  18:36:41 +0000 (0:00:00.396)       0:01:09.964 ******
2026-02-24 18:36:42.699837 | controller | changed: [instance]
2026-02-24 18:36:42.699868 | controller |
2026-02-24 18:36:42.699878 | controller | TASK [libvirt_manager : Create group inventories] ******************************
2026-02-24 18:36:42.700042 | controller | Tuesday 24 February 2026  18:36:42 +0000 (0:00:01.368)       0:01:11.332 ******
2026-02-24 18:36:43.156556 | controller | changed: [instance] => (item=compute)
2026-02-24 18:36:43.156648 | controller |
2026-02-24 18:36:43.156668 | controller | TASK [libvirt_manager : Create "all" group inventory file] *********************
2026-02-24 18:36:43.156766 | controller | Tuesday 24 February 2026  18:36:43 +0000 (0:00:00.456)       0:01:11.789 ******
2026-02-24 18:36:43.219505 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_all_group_inventory.yml for instance
2026-02-24 18:36:43.415922 | controller |
2026-02-24 18:36:43.415964 | controller | TASK [libvirt_manager : Check if all-group.yml already exists] *****************
2026-02-24 18:36:43.415973 | controller | Tuesday 24 February 2026  18:36:43 +0000 (0:00:00.063)       0:01:11.852 ******
2026-02-24 18:36:43.415984 | controller | ok: [instance]
2026-02-24 18:36:43.436691 | controller |
2026-02-24 18:36:43.436777 | controller | TASK [libvirt_manager : Slurp existing all-group.yml if it exists] *************
2026-02-24 18:36:43.436788 | controller | Tuesday 24 February 2026  18:36:43 +0000 (0:00:00.196)       0:01:12.048 ******
2026-02-24 18:36:43.436807 | controller | skipping: [instance]
2026-02-24 18:36:43.825750 | controller |
2026-02-24 18:36:43.825798 | controller | TASK [libvirt_manager : Create new "all" group inventory file from template] ***
2026-02-24 18:36:43.825807 | controller | Tuesday 24 February 2026  18:36:43 +0000 (0:00:00.021)       0:01:12.069 ******
2026-02-24 18:36:43.825818 | controller | changed: [instance]
2026-02-24 18:36:43.825871 | controller |
2026-02-24 18:36:43.825902 | controller | TASK [libvirt_manager : Slurp newly created all-group.yml] *********************
2026-02-24 18:36:43.847695 | controller | Tuesday 24 February 2026  18:36:43 +0000 (0:00:00.388)       0:01:12.458 ******
2026-02-24 18:36:43.847784 | controller | skipping: [instance]
2026-02-24 18:36:43.875961 | controller |
2026-02-24 18:36:43.875990 | controller | TASK [libvirt_manager : Write merged all-group.yml] ****************************
2026-02-24 18:36:43.875998 | controller | Tuesday 24 February 2026  18:36:43 +0000 (0:00:00.022)       0:01:12.480 ******
2026-02-24 18:36:43.876008 | controller | skipping: [instance]
2026-02-24 18:36:43.925562 | controller |
2026-02-24 18:36:43.925591 | controller | TASK [libvirt_manager : Ensure storage pool is present.] ***********************
2026-02-24 18:36:43.925599 | controller | Tuesday 24 February 2026  18:36:43 +0000 (0:00:00.028)       0:01:12.509 ******
2026-02-24 18:36:43.925609 | controller | skipping: [instance]
2026-02-24 18:36:43.925687 | controller |
2026-02-24 18:36:43.925706 | controller | TASK [libvirt_manager : Ensure images are present] *****************************
2026-02-24 18:36:43.925717 | controller | Tuesday 24 February 2026  18:36:43 +0000 (0:00:00.049)       0:01:12.558 ******
2026-02-24 18:36:44.019626 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/get_image.yml for instance => (item=compute)
2026-02-24 18:36:44.019736 | controller |
2026-02-24 18:36:44.019745 | controller | TASK [libvirt_manager : Ensure directory exists] *******************************
2026-02-24 18:36:44.019756 | controller | Tuesday 24 February 2026  18:36:44 +0000 (0:00:00.093)       0:01:12.652 ******
2026-02-24 18:36:44.047937 | controller | skipping: [instance]
2026-02-24 18:36:44.047971 | controller |
2026-02-24 18:36:44.048090 | controller | TASK [libvirt_manager : Check if base image exists] ****************************
2026-02-24 18:36:44.048190 | controller | Tuesday 24 February 2026  18:36:44 +0000 (0:00:00.028)       0:01:12.681 ******
2026-02-24 18:36:44.076124 | controller | skipping: [instance]
2026-02-24 18:36:44.076207 | controller |
2026-02-24 18:36:44.076334 | controller | TASK [libvirt_manager : Download base image] ***********************************
2026-02-24 18:36:44.076481 | controller | Tuesday 24 February 2026  18:36:44 +0000 (0:00:00.028)       0:01:12.709 ******
2026-02-24 18:36:44.100693 | controller | skipping: [instance]
2026-02-24 18:36:44.100798 | controller |
2026-02-24 18:36:44.100987 | controller | TASK [libvirt_manager : Check image] *******************************************
2026-02-24 18:36:44.101055 | controller | Tuesday 24 February 2026  18:36:44 +0000 (0:00:00.024)       0:01:12.734 ******
2026-02-24 18:36:44.122675 | controller | skipping: [instance]
2026-02-24 18:36:44.122742 | controller |
2026-02-24 18:36:44.122824 | controller | TASK [libvirt_manager : Assert image status] ***********************************
2026-02-24 18:36:44.122947 | controller | Tuesday 24 February 2026  18:36:44 +0000 (0:00:00.021)       0:01:12.756 ******
2026-02-24 18:36:44.141970 | controller | skipping: [instance]
2026-02-24 18:36:44.142057 | controller |
2026-02-24 18:36:44.142154 | controller | TASK [libvirt_manager : Ensure image access rights] ****************************
2026-02-24 18:36:44.142260 | controller | Tuesday 24 February 2026  18:36:44 +0000 (0:00:00.019)       0:01:12.775 ******
2026-02-24 18:36:44.166295 | controller | skipping: [instance]
2026-02-24 18:36:44.166393 | controller |
2026-02-24 18:36:44.166567 | controller | TASK [libvirt_manager : Get ssh key state] *************************************
2026-02-24 18:36:44.166693 | controller | Tuesday 24 February 2026  18:36:44 +0000 (0:00:00.024)       0:01:12.799 ******
2026-02-24 18:36:44.353707 | controller | ok: [instance]
2026-02-24 18:36:44.353822 | controller |
2026-02-24 18:36:44.354326 | controller | TASK [libvirt_manager : Create temporary ssh keypair] **************************
2026-02-24 18:36:44.798509 | controller | Tuesday 24 February 2026  18:36:44 +0000 (0:00:00.187)       0:01:12.986 ******
2026-02-24 18:36:44.798556 | controller | changed: [instance]
2026-02-24 18:36:44.798579 | controller |
2026-02-24 18:36:44.798681 | controller | TASK [libvirt_manager : Slurp public key for later use] ************************
2026-02-24 18:36:44.798777 | controller | Tuesday 24 February 2026  18:36:44 +0000 (0:00:00.444)       0:01:13.431 ******
2026-02-24 18:36:45.092577 | controller | ok: [instance]
2026-02-24 18:36:45.092626 | controller |
2026-02-24 18:36:45.092740 | controller | TASK [libvirt_manager : Slurp private key for later use] ***********************
2026-02-24 18:36:45.092832 | controller | Tuesday 24 February 2026  18:36:45 +0000 (0:00:00.294)       0:01:13.725 ******
2026-02-24 18:36:45.280049 | controller | ok: [instance]
2026-02-24 18:36:45.280121 | controller |
2026-02-24 18:36:45.280208 | controller | TASK [libvirt_manager : Inject cifmw_reproducer_key.pub in hypervisor authorized_keys] ***
2026-02-24 18:36:45.280291 | controller | Tuesday 24 February 2026  18:36:45 +0000 (0:00:00.187)       0:01:13.913 ******
2026-02-24 18:36:45.703834 | controller | changed: [instance]
2026-02-24 18:36:45.703893 | controller |
2026-02-24 18:36:45.704159 | controller | TASK [libvirt_manager : Create fact holding network data for VMs] **************
2026-02-24 18:36:45.704721 | controller | Tuesday 24 February 2026  18:36:45 +0000 (0:00:00.423)       0:01:14.336 ******
2026-02-24 18:36:45.734013 | controller | ok: [instance]
2026-02-24 18:36:45.734076 | controller |
2026-02-24 18:36:45.734163 | controller | TASK [libvirt_manager : List existing networks] ********************************
2026-02-24 18:36:45.734249 | controller | Tuesday 24 February 2026  18:36:45 +0000 (0:00:00.030)       0:01:14.367 ******
2026-02-24 18:36:45.992929 | controller | ok: [instance]
2026-02-24 18:36:45.992986 | controller |
2026-02-24 18:36:45.993101 | controller | TASK [libvirt_manager : Gather pool fact] **************************************
2026-02-24 18:36:45.993200 | controller | Tuesday 24 February 2026  18:36:45 +0000 (0:00:00.258)       0:01:14.625 ******
2026-02-24 18:36:46.406270 | controller | ok: [instance]
2026-02-24 18:36:46.406321 | controller |
2026-02-24 18:36:46.406367 | controller | TASK [libvirt_manager : Create and run VMs] ************************************
2026-02-24 18:36:46.406494 | controller | Tuesday 24 February 2026  18:36:46 +0000 (0:00:00.413)       0:01:15.039 ******
2026-02-24 18:36:46.546003 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_vms.yml for instance => (item={'key': 'compute-0', 'value': 'compute'})
2026-02-24 18:36:46.546060 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_vms.yml for instance => (item={'key': 'compute-1', 'value': 'compute'})
2026-02-24 18:36:46.546133 | controller |
2026-02-24 18:36:46.546226 | controller | TASK [libvirt_manager : Create VM image for compute-0] *************************
2026-02-24 18:36:46.546314 | controller | Tuesday 24 February 2026  18:36:46 +0000 (0:00:00.140)       0:01:15.179 ******
2026-02-24 18:36:46.836862 | controller | changed: [instance]
2026-02-24 18:36:46.836911 | controller |
2026-02-24 18:36:46.836982 | controller | TASK [libvirt_manager : Ensure file ownership and rights for compute-0] ********
2026-02-24 18:36:46.837082 | controller | Tuesday 24 February 2026  18:36:46 +0000 (0:00:00.290)       0:01:15.469 ******
2026-02-24 18:36:47.123085 | controller | changed: [instance]
2026-02-24 18:36:47.123140 | controller |
2026-02-24 18:36:47.123205 | controller | TASK [libvirt_manager : Define VMs for type compute-0] *************************
2026-02-24 18:36:47.123312 | controller | Tuesday 24 February 2026  18:36:47 +0000 (0:00:00.286)       0:01:15.755 ******
2026-02-24 18:36:47.532229 | controller | changed: [instance]
2026-02-24 18:36:47.532282 | controller |
2026-02-24 18:36:47.532418 | controller | TASK [libvirt_manager : Attach listed networks to the VMs compute-0] ***********
2026-02-24 18:36:47.532554 | controller | Tuesday 24 February 2026  18:36:47 +0000 (0:00:00.409)       0:01:16.165 ******
2026-02-24 18:36:47.565827 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/net_to_vms.yml for instance
2026-02-24 18:36:47.565922 | controller |
2026-02-24 18:36:47.566035 | controller | TASK [libvirt_manager : Attach {{ vm_item }} to {{ net_item }}] ****************
2026-02-24 18:36:47.566136 | controller | Tuesday 24 February 2026  18:36:47 +0000 (0:00:00.034)       0:01:16.199 ******
2026-02-24 18:36:47.606964 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/attach_interface.yml for instance => (item=public)
2026-02-24 18:36:47.607016 | controller |
2026-02-24 18:36:47.607066 | controller | TASK [libvirt_manager : Get virtual network information] ***********************
2026-02-24 18:36:47.607164 | controller | Tuesday 24 February 2026  18:36:47 +0000 (0:00:00.040)       0:01:16.240 ******
2026-02-24 18:36:47.876874 | controller | ok: [instance]
2026-02-24 18:36:47.877003 | controller |
2026-02-24 18:36:47.877101 | controller | TASK [libvirt_manager : Create network to bridge mapping] **********************
2026-02-24 18:36:47.877115 | controller | Tuesday 24 February 2026  18:36:47 +0000 (0:00:00.269)       0:01:16.509 ******
2026-02-24 18:36:47.934652 | controller | ok: [instance] => (item=crc)
2026-02-24 18:36:47.934749 | controller | ok: [instance] => (item=cifmw-public)
2026-02-24 18:36:47.934865 | controller | ok: [instance] => (item=default)
2026-02-24 18:36:47.934950 | controller |
2026-02-24 18:36:47.935033 | controller | TASK [libvirt_manager : Dump domain xml] ***************************************
2026-02-24 18:36:47.935119 | controller | Tuesday 24 February 2026  18:36:47 +0000 (0:00:00.058)       0:01:16.567 ******
2026-02-24 18:36:48.195293 | controller | ok: [instance]
2026-02-24 18:36:48.195340 | controller |
2026-02-24 18:36:48.195496 | controller | TASK [libvirt_manager : Extract networks from XML] *****************************
2026-02-24 18:36:48.195605 | controller | Tuesday 24 February 2026  18:36:48 +0000 (0:00:00.260)       0:01:16.828 ******
2026-02-24 18:36:48.432458 | controller | ok: [instance]
2026-02-24 18:36:48.432519 | controller |
2026-02-24 18:36:48.432632 | controller | TASK [libvirt_manager : Attach interface public on cifmw-compute-0] ************
2026-02-24 18:36:48.432724 | controller | Tuesday 24 February 2026  18:36:48 +0000 (0:00:00.236)       0:01:17.065 ******
2026-02-24 18:36:48.763961 | controller | changed: [instance]
2026-02-24 18:36:48.764081 | controller |
2026-02-24 18:36:48.764094 | controller | TASK [libvirt_manager : Attach spines/leafs networks to the VMs compute-0] *****
2026-02-24 18:36:48.764209 | controller | Tuesday 24 February 2026  18:36:48 +0000 (0:00:00.331)       0:01:17.397 ******
2026-02-24 18:36:48.796772 | controller | skipping: [instance]
2026-02-24 18:36:48.796815 | controller |
2026-02-24 18:36:48.796905 | controller | TASK [libvirt_manager : Create the requested extra disks for compute-0] ********
2026-02-24 18:36:48.796994 | controller | Tuesday 24 February 2026  18:36:48 +0000 (0:00:00.032)       0:01:17.429 ******
2026-02-24 18:36:48.834846 | controller | skipping: [instance]
2026-02-24 18:36:48.834925 | controller |
2026-02-24 18:36:48.835039 | controller | TASK [libvirt_manager : Find volume attachments for VM compute-0] **************
2026-02-24 18:36:48.835151 | controller | Tuesday 24 February 2026  18:36:48 +0000 (0:00:00.038)       0:01:17.468 ******
2026-02-24 18:36:48.866489 | controller | skipping: [instance]
2026-02-24 18:36:48.866555 | controller |
2026-02-24 18:36:48.866678 | controller | TASK [libvirt_manager : Attach volumes for VM compute-0] ***********************
2026-02-24 18:36:48.866768 | controller | Tuesday 24 February 2026  18:36:48 +0000 (0:00:00.031)       0:01:17.499 ******
2026-02-24 18:36:48.895898 | controller | skipping: [instance]
2026-02-24 18:36:48.895975 | controller |
2026-02-24 18:36:48.896076 | controller | TASK [libvirt_manager : Get VM UUID] *******************************************
2026-02-24 18:36:48.896173 | controller | Tuesday 24 February 2026  18:36:48 +0000 (0:00:00.029)       0:01:17.529 ******
2026-02-24 18:36:49.144667 | controller | changed: [instance]
2026-02-24 18:36:49.144708 | controller |
2026-02-24 18:36:49.144791 | controller | TASK [libvirt_manager : Inject UUID in dataset] ********************************
2026-02-24 18:36:49.144882 | controller | Tuesday 24 February 2026  18:36:49 +0000 (0:00:00.248)       0:01:17.777 ******
2026-02-24 18:36:49.186365 | controller | ok: [instance]
2026-02-24 18:36:49.186489 | controller |
2026-02-24 18:36:49.186606 | controller | TASK [libvirt_manager : Create cloud-init ISO] *********************************
2026-02-24 18:36:49.186701 | controller | Tuesday 24 February 2026  18:36:49 +0000 (0:00:00.042)       0:01:17.819 ******
2026-02-24 18:36:49.214341 | controller | skipping: [instance]
2026-02-24 18:36:49.214458 | controller |
2026-02-24 18:36:49.214563 | controller | TASK [libvirt_manager : Attach cloud-init ISO if exists] ***********************
2026-02-24 18:36:49.214656 | controller | Tuesday 24 February 2026  18:36:49 +0000 (0:00:00.028)       0:01:17.847 ******
2026-02-24 18:36:49.242767 | controller | skipping: [instance]
2026-02-24 18:36:49.242855 | controller |
2026-02-24 18:36:49.242988 | controller | TASK [libvirt_manager : Attach additional devices if specified] ****************
2026-02-24 18:36:49.243098 | controller | Tuesday 24 February 2026  18:36:49 +0000 (0:00:00.028)       0:01:17.876 ******
2026-02-24 18:36:49.295491 | controller | skipping: [instance]
2026-02-24 18:36:49.295586 | controller |
2026-02-24 18:36:49.295687 | controller | TASK [libvirt_manager : Configure boot order for compute-0] ********************
2026-02-24 18:36:49.295779 | controller | Tuesday 24 February 2026  18:36:49 +0000 (0:00:00.052)       0:01:17.929 ******
2026-02-24 18:36:49.329582 | controller | skipping: [instance]
2026-02-24 18:36:49.329654 | controller |
2026-02-24 18:36:49.329748 | controller | TASK [libvirt_manager : Create VM image for compute-1] *************************
2026-02-24 18:36:49.329838 | controller | Tuesday 24 February 2026  18:36:49 +0000 (0:00:00.033)       0:01:17.962 ******
2026-02-24 18:36:49.616652 | controller | changed: [instance]
2026-02-24 18:36:49.616701 | controller |
2026-02-24 18:36:49.616781 | controller | TASK [libvirt_manager : Ensure file ownership and rights for compute-1] ********
2026-02-24 18:36:49.616875 | controller | Tuesday 24 February 2026  18:36:49 +0000 (0:00:00.286)       0:01:18.249 ******
2026-02-24 18:36:49.865939 | controller | changed: [instance]
2026-02-24 18:36:49.866000 | controller |
2026-02-24 18:36:49.866090 | controller | TASK [libvirt_manager : Define VMs for type compute-1] *************************
2026-02-24 18:36:49.866179 | controller | Tuesday 24 February 2026  18:36:49 +0000 (0:00:00.249)       0:01:18.499 ******
2026-02-24 18:36:50.198334 | controller | changed: [instance]
2026-02-24 18:36:50.198392 | controller |
2026-02-24 18:36:50.199103 | controller | TASK [libvirt_manager : Attach listed networks to the VMs compute-1] ***********
2026-02-24 18:36:50.230188 | controller | Tuesday 24 February 2026  18:36:50 +0000 (0:00:00.332)       0:01:18.831 ******
2026-02-24 18:36:50.230240 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/net_to_vms.yml for instance
2026-02-24 18:36:50.230264 | controller |
2026-02-24 18:36:50.230386 | controller | TASK [libvirt_manager : Attach {{ vm_item }} to {{ net_item }}] ****************
2026-02-24 18:36:50.230493 | controller | Tuesday 24 February 2026  18:36:50 +0000 (0:00:00.031)       0:01:18.863 ******
2026-02-24 18:36:50.272422 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/attach_interface.yml for instance => (item=public)
2026-02-24 18:36:50.272502 | controller |
2026-02-24 18:36:50.272634 | controller | TASK [libvirt_manager : Get virtual network information] ***********************
2026-02-24 18:36:50.272748 | controller | Tuesday 24 February 2026  18:36:50 +0000 (0:00:00.042)       0:01:18.905 ******
2026-02-24 18:36:50.545657 | controller | ok: [instance]
2026-02-24 18:36:50.545706 | controller |
2026-02-24 18:36:50.545790 | controller | TASK [libvirt_manager : Create network to bridge mapping] **********************
2026-02-24 18:36:50.545887 | controller | Tuesday 24 February 2026  18:36:50 +0000 (0:00:00.272)       0:01:19.178 ******
2026-02-24 18:36:50.600969 | controller | ok: [instance] => (item=crc)
2026-02-24 18:36:50.601058 | controller | ok: [instance] => (item=cifmw-public)
2026-02-24 18:36:50.601155 | controller | ok: [instance] => (item=default)
2026-02-24 18:36:50.601243 | controller |
2026-02-24 18:36:50.601354 | controller | TASK [libvirt_manager : Dump domain xml] ***************************************
2026-02-24 18:36:50.601477 | controller | Tuesday 24 February 2026  18:36:50 +0000 (0:00:00.055)       0:01:19.233 ******
2026-02-24 18:36:50.888104 | controller | ok: [instance]
2026-02-24 18:36:50.888153 | controller |
2026-02-24 18:36:50.888161 | controller | TASK [libvirt_manager : Extract networks from XML] *****************************
2026-02-24 18:36:50.888169 | controller | Tuesday 24 February 2026  18:36:50 +0000 (0:00:00.287)       0:01:19.521 ******
2026-02-24 18:36:51.093934 | controller | ok: [instance]
2026-02-24 18:36:51.094001 | controller |
2026-02-24 18:36:51.094096 | controller | TASK [libvirt_manager : Attach interface public on cifmw-compute-1] ************
2026-02-24 18:36:51.094699 | controller | Tuesday 24 February 2026  18:36:51 +0000 (0:00:00.206)       0:01:19.727 ******
2026-02-24 18:36:51.409548 | controller | changed: [instance]
2026-02-24 18:36:51.409604 | controller |
2026-02-24 18:36:51.409686 | controller | TASK [libvirt_manager : Attach spines/leafs networks to the VMs compute-1] *****
2026-02-24 18:36:51.409774 | controller | Tuesday 24 February 2026  18:36:51 +0000 (0:00:00.315)       0:01:20.042 ******
2026-02-24 18:36:51.435135 | controller | skipping: [instance]
2026-02-24 18:36:51.435176 | controller |
2026-02-24 18:36:51.435290 | controller | TASK [libvirt_manager : Create the requested extra disks for compute-1] ********
2026-02-24 18:36:51.435378 | controller | Tuesday 24 February 2026  18:36:51 +0000 (0:00:00.025)       0:01:20.068 ******
2026-02-24 18:36:51.470684 | controller | skipping: [instance]
2026-02-24 18:36:51.470931 | controller |
2026-02-24 18:36:51.471081 | controller | TASK [libvirt_manager : Find volume attachments for VM compute-1] **************
2026-02-24 18:36:51.471096 | controller | Tuesday 24 February 2026  18:36:51 +0000 (0:00:00.035)       0:01:20.104 ******
2026-02-24 18:36:51.499922 | controller | skipping: [instance]
2026-02-24 18:36:51.500027 | controller |
2026-02-24 18:36:51.500248 | controller | TASK [libvirt_manager : Attach volumes for VM compute-1] ***********************
2026-02-24 18:36:51.500283 | controller | Tuesday 24 February 2026  18:36:51 +0000 (0:00:00.029)       0:01:20.133 ******
2026-02-24 18:36:51.529804 | controller | skipping: [instance]
2026-02-24 18:36:51.529909 | controller |
2026-02-24 18:36:51.530035 | controller | TASK [libvirt_manager : Get VM UUID] *******************************************
2026-02-24 18:36:51.530159 | controller | Tuesday 24 February 2026  18:36:51 +0000 (0:00:00.029)       0:01:20.163 ******
2026-02-24 18:36:51.776846 | controller | changed: [instance]
2026-02-24 18:36:51.776905 | controller |
2026-02-24 18:36:51.776984 | controller | TASK [libvirt_manager : Inject UUID in dataset] ********************************
2026-02-24 18:36:51.777080 | controller | Tuesday 24 February 2026  18:36:51 +0000 (0:00:00.246)       0:01:20.410 ******
2026-02-24 18:36:51.814750 | controller | ok: [instance]
2026-02-24 18:36:51.814883 | controller |
2026-02-24 18:36:51.815039 | controller | TASK [libvirt_manager : Create cloud-init ISO] *********************************
2026-02-24 18:36:51.815190 | controller | Tuesday 24 February 2026  18:36:51 +0000 (0:00:00.038)       0:01:20.448 ******
2026-02-24 18:36:51.836674 | controller | skipping: [instance]
2026-02-24 18:36:51.836726 | controller |
2026-02-24 18:36:51.836850 | controller | TASK [libvirt_manager : Attach cloud-init ISO if exists] ***********************
2026-02-24 18:36:51.836930 | controller | Tuesday 24 February 2026  18:36:51 +0000 (0:00:00.022)       0:01:20.470 ******
2026-02-24 18:36:51.857485 | controller | skipping: [instance]
2026-02-24 18:36:51.857578 | controller |
2026-02-24 18:36:51.857676 | controller | TASK [libvirt_manager : Attach additional devices if specified] ****************
2026-02-24 18:36:51.857772 | controller | Tuesday 24 February 2026  18:36:51 +0000 (0:00:00.020)       0:01:20.491 ******
2026-02-24 18:36:51.902714 | controller | skipping: [instance]
2026-02-24 18:36:51.902908 | controller |
2026-02-24 18:36:51.902968 | controller | TASK [libvirt_manager : Configure boot order for compute-1] ********************
2026-02-24 18:36:51.927269 | controller | Tuesday 24 February 2026  18:36:51 +0000 (0:00:00.044)       0:01:20.536 ******
2026-02-24 18:36:51.927290 | controller | skipping: [instance]
2026-02-24 18:36:51.968143 | controller |
2026-02-24 18:36:51.968168 | controller | TASK [libvirt_manager : Start (power-on) VMs] **********************************
2026-02-24 18:36:51.968178 | controller | Tuesday 24 February 2026  18:36:51 +0000 (0:00:00.024)       0:01:20.560 ******
2026-02-24 18:36:51.968192 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/start_vms.yml for instance
2026-02-24 18:36:52.334041 | controller |
2026-02-24 18:36:52.334083 | controller | TASK [libvirt_manager : Refresh oooq_pool before starting VMs] *****************
2026-02-24 18:36:52.334092 | controller | Tuesday 24 February 2026  18:36:51 +0000 (0:00:00.040)       0:01:20.601 ******
2026-02-24 18:36:52.334104 | controller | ok: [instance] => (item=crc)
2026-02-24 18:36:53.410639 | controller |
2026-02-24 18:36:53.410683 | controller | TASK [libvirt_manager : Start VMs for type {{ vm_type }}] **********************
2026-02-24 18:36:53.410693 | controller | Tuesday 24 February 2026  18:36:52 +0000 (0:00:00.365)       0:01:20.966 ******
2026-02-24 18:36:53.410706 | controller | skipping: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
2026-02-24 18:36:53.466063 | controller | skipping: [instance] => (item={'key': 'compute-1', 'value': 'compute'})
2026-02-24 18:36:53.466088 | controller | skipping: [instance]
2026-02-24 18:36:53.466096 | controller |
2026-02-24 18:36:53.466102 | controller | TASK [libvirt_manager : Wait for SSH on started VMs] ***************************
2026-02-24 18:36:53.466108 | controller | Tuesday 24 February 2026  18:36:53 +0000 (0:00:01.076)       0:01:22.043 ******
2026-02-24 18:36:53.466118 | controller | skipping: [instance] => (item=compute-0.utility)
2026-02-24 18:36:53.466193 | controller | skipping: [instance] => (item=compute-1.utility)
2026-02-24 18:36:53.466205 | controller | skipping: [instance]
2026-02-24 18:36:53.466354 | controller |
2026-02-24 18:36:53.466477 | controller | TASK [libvirt_manager : Ensure we get SSH on nodes] ****************************
2026-02-24 18:36:53.466599 | controller | Tuesday 24 February 2026  18:36:53 +0000 (0:00:00.055)       0:01:22.099 ******
2026-02-24 18:36:53.499199 | controller | skipping: [instance] => (item={'changed': False, 'skipped': True, 'skip_reason': 'Conditional result was False', 'false_condition': "vm_data.disk_file_name != 'blank'", '_vm': {'key': 'compute-0', 'value': 'compute'}, 'ansible_loop_var': '_vm'})
2026-02-24 18:36:53.550021 | controller | skipping: [instance] => (item={'changed': False, 'skipped': True, 'skip_reason': 'Conditional result was False', 'false_condition': "vm_data.disk_file_name != 'blank'", '_vm': {'key': 'compute-1', 'value': 'compute'}, 'ansible_loop_var': '_vm'})
2026-02-24 18:36:53.550055 | controller | skipping: [instance]
2026-02-24 18:36:53.550064 | controller |
2026-02-24 18:36:53.550070 | controller | TASK [libvirt_manager : Configure managed VMs] *********************************
2026-02-24 18:36:53.550076 | controller | Tuesday 24 February 2026  18:36:53 +0000 (0:00:00.032)       0:01:22.131 ******
2026-02-24 18:36:53.550088 | controller | skipping: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
2026-02-24 18:36:53.601542 | controller | skipping: [instance] => (item={'key': 'compute-1', 'value': 'compute'})
2026-02-24 18:36:53.601575 | controller | skipping: [instance]
2026-02-24 18:36:53.601583 | controller |
2026-02-24 18:36:53.601589 | controller | TASK [Create VBMC entity] ******************************************************
2026-02-24 18:36:53.601595 | controller | Tuesday 24 February 2026  18:36:53 +0000 (0:00:00.051)       0:01:22.182 ******
2026-02-24 18:36:53.601604 | controller | skipping: [instance] => (item=compute-0)
2026-02-24 18:36:53.601631 | controller | skipping: [instance] => (item=compute-1)
2026-02-24 18:36:53.601637 | controller | skipping: [instance]
2026-02-24 18:36:53.601642 | controller |
2026-02-24 18:36:53.601660 | controller | TASK [libvirt_manager : List running virtual machines.] ************************
2026-02-24 18:36:53.601679 | controller | Tuesday 24 February 2026  18:36:53 +0000 (0:00:00.051)       0:01:22.234 ******
2026-02-24 18:36:53.860402 | controller | ok: [instance]
2026-02-24 18:36:53.860531 | controller |
2026-02-24 18:36:53.860642 | controller | TASK [libvirt_manager : Dump UUIDs] ********************************************
2026-02-24 18:36:53.860753 | controller | Tuesday 24 February 2026  18:36:53 +0000 (0:00:00.258)       0:01:22.493 ******
2026-02-24 18:36:54.281978 | controller | changed: [instance]
2026-02-24 18:36:54.282027 | controller |
2026-02-24 18:36:54.282051 | controller | TASK [Ensure fresh vbmc listing] ***********************************************
2026-02-24 18:36:54.282135 | controller | Tuesday 24 February 2026  18:36:54 +0000 (0:00:00.421)       0:01:22.915 ******
2026-02-24 18:36:54.326629 | controller | skipping: [instance]
2026-02-24 18:36:54.326680 | controller |
2026-02-24 18:36:54.326765 | controller | TASK [libvirt_manager : Update vbmc related fact] ******************************
2026-02-24 18:36:54.326847 | controller | Tuesday 24 February 2026  18:36:54 +0000 (0:00:00.045)       0:01:22.960 ******
2026-02-24 18:36:54.369914 | controller | skipping: [instance]
2026-02-24 18:36:54.370082 | controller |
2026-02-24 18:36:54.370223 | controller | TASK [libvirt_manager : Dump vbmc known hosts] *********************************
2026-02-24 18:36:54.370385 | controller | Tuesday 24 February 2026  18:36:54 +0000 (0:00:00.042)       0:01:23.002 ******
2026-02-24 18:36:54.408948 | controller | skipping: [instance]
2026-02-24 18:36:54.409012 | controller |
2026-02-24 18:36:54.409109 | controller | TASK [libvirt_manager : Copy authorized_keys] **********************************
2026-02-24 18:36:54.409194 | controller | Tuesday 24 February 2026  18:36:54 +0000 (0:00:00.039)       0:01:23.042 ******
2026-02-24 18:36:54.437898 | controller | skipping: [instance]
2026-02-24 18:36:54.437973 | controller |
2026-02-24 18:36:54.438074 | controller | TASK [libvirt_manager : Enable root access on CRC] *****************************
2026-02-24 18:36:54.438175 | controller | Tuesday 24 February 2026  18:36:54 +0000 (0:00:00.028)       0:01:23.071 ******
2026-02-24 18:36:54.473667 | controller | skipping: [instance]
2026-02-24 18:36:54.473775 | controller |
2026-02-24 18:36:54.473878 | controller | TASK [Generate baremetal-info fact] ********************************************
2026-02-24 18:36:54.473980 | controller | Tuesday 24 February 2026  18:36:54 +0000 (0:00:00.035)       0:01:23.107 ******
2026-02-24 18:36:54.548836 | controller |
2026-02-24 18:36:54.548967 | controller | TASK [reproducer : Ensure directories exist] ***********************************
2026-02-24 18:36:54.549118 | controller | Tuesday 24 February 2026  18:36:54 +0000 (0:00:00.075)       0:01:23.182 ******
2026-02-24 18:36:55.001864 | controller | changed: [instance] => (item=parameters)
2026-02-24 18:36:55.001922 | controller | ok: [instance] => (item=artifacts)
2026-02-24 18:36:55.002010 | controller |
2026-02-24 18:36:55.002102 | controller | TASK [reproducer : Convert VBMC list into a dict for better usage] *************
2026-02-24 18:36:55.002195 | controller | Tuesday 24 February 2026  18:36:54 +0000 (0:00:00.452)       0:01:23.634 ******
2026-02-24 18:36:55.050059 | controller | skipping: [instance]
2026-02-24 18:36:55.050096 | controller |
2026-02-24 18:36:55.050107 | controller | TASK [reproducer : Check if baremetal-info.yml exists] *************************
2026-02-24 18:36:55.050143 | controller | Tuesday 24 February 2026  18:36:55 +0000 (0:00:00.048)       0:01:23.683 ******
2026-02-24 18:36:55.277680 | controller | ok: [instance]
2026-02-24 18:36:55.277726 | controller |
2026-02-24 18:36:55.277736 | controller | TASK [reproducer : Get content of baremetal-info file] *************************
2026-02-24 18:36:55.278253 | controller | Tuesday 24 February 2026  18:36:55 +0000 (0:00:00.227)       0:01:23.910 ******
2026-02-24 18:36:55.301271 | controller | skipping: [instance]
2026-02-24 18:36:55.301358 | controller |
2026-02-24 18:36:55.301506 | controller | TASK [reproducer : Interpret remote file content as yaml] **********************
2026-02-24 18:36:55.301601 | controller | Tuesday 24 February 2026  18:36:55 +0000 (0:00:00.024)       0:01:23.934 ******
2026-02-24 18:36:55.345317 | controller | skipping: [instance]
2026-02-24 18:36:55.345462 | controller |
2026-02-24 18:36:55.345629 | controller | TASK [reproducer : Slurp content of: /home/zuul/ci-framework-data/artifacts/interfaces-info.yml] ***
2026-02-24 18:36:55.345763 | controller | Tuesday 24 February 2026  18:36:55 +0000 (0:00:00.044)       0:01:23.978 ******
2026-02-24 18:36:55.384456 | controller | skipping: [instance]
2026-02-24 18:36:55.384564 | controller |
2026-02-24 18:36:55.384657 | controller | TASK [reproducer : Set cifmw_libvirt_manager_mac_map fact from /home/zuul/ci-framework-data/artifacts/interfaces-info.yml] ***
2026-02-24 18:36:55.384758 | controller | Tuesday 24 February 2026  18:36:55 +0000 (0:00:00.039)       0:01:24.017 ******
2026-02-24 18:36:55.418420 | controller | skipping: [instance]
2026-02-24 18:36:55.418523 | controller |
2026-02-24 18:36:55.418602 | controller | TASK [reproducer : Generate libvirt_manager_bm_info_data fact] *****************
2026-02-24 18:36:55.418613 | controller | Tuesday 24 February 2026  18:36:55 +0000 (0:00:00.033)       0:01:24.051 ******
2026-02-24 18:36:55.497426 | controller | ok: [instance] => (item={'key': 'cifmw-compute-0', 'value': '20f8929e-571d-583f-969c-f0d6357022c1'})
2026-02-24 18:36:55.497562 | controller | ok: [instance] => (item={'key': 'cifmw-compute-1', 'value': 'f40ec783-79a5-5186-b9a6-30fad0c33e27'})
2026-02-24 18:36:55.497697 | controller |
2026-02-24 18:36:55.497829 | controller | TASK [reproducer : Output baremetal info file] *********************************
2026-02-24 18:36:55.497955 | controller | Tuesday 24 February 2026  18:36:55 +0000 (0:00:00.079)       0:01:24.130 ******
2026-02-24 18:36:55.854946 | controller | changed: [instance]
2026-02-24 18:36:55.855010 | controller |
2026-02-24 18:36:55.855047 | controller | TASK [reproducer : Output ironic_nodes to file] ********************************
2026-02-24 18:36:55.855144 | controller | Tuesday 24 February 2026  18:36:55 +0000 (0:00:00.357)       0:01:24.487 ******
2026-02-24 18:36:55.897088 | controller | skipping: [instance]
2026-02-24 18:36:55.897135 | controller |
2026-02-24 18:36:55.897262 | controller | TASK [Run Sushy Emulator role against OCP] *************************************
2026-02-24 18:36:55.897360 | controller | Tuesday 24 February 2026  18:36:55 +0000 (0:00:00.042)       0:01:24.530 ******
2026-02-24 18:36:55.967368 | controller |
2026-02-24 18:36:55.967502 | controller | TASK [sushy_emulator : Create Sushy Emulator resource directory] ***************
2026-02-24 18:36:55.967607 | controller | Tuesday 24 February 2026  18:36:55 +0000 (0:00:00.070)       0:01:24.600 ******
2026-02-24 18:36:56.191772 | controller | changed: [instance]
2026-02-24 18:36:56.191870 | controller |
2026-02-24 18:36:56.191904 | controller | TASK [sushy_emulator : Install required packages] ******************************
2026-02-24 18:36:56.191975 | controller | Tuesday 24 February 2026  18:36:56 +0000 (0:00:00.223)       0:01:24.824 ******
2026-02-24 18:36:59.940627 | controller | changed: [instance]
2026-02-24 18:36:59.940732 | controller |
2026-02-24 18:36:59.940745 | controller | TASK [sushy_emulator : Get ingresses domain] ***********************************
2026-02-24 18:36:59.940836 | controller | Tuesday 24 February 2026  18:36:59 +0000 (0:00:03.749)       0:01:28.573 ******
2026-02-24 18:37:00.640026 | controller | changed: [instance]
2026-02-24 18:37:00.640178 | controller |
2026-02-24 18:37:00.640258 | controller | TASK [sushy_emulator : Set sushy url for ocp installation] *********************
2026-02-24 18:37:00.640270 | controller | Tuesday 24 February 2026  18:37:00 +0000 (0:00:00.699)       0:01:29.273 ******
2026-02-24 18:37:00.668690 | controller | ok: [instance]
2026-02-24 18:37:00.668787 | controller |
2026-02-24 18:37:00.668914 | controller | TASK [sushy_emulator : Create ssh key for Sushy Emulator] **********************
2026-02-24 18:37:00.669088 | controller | Tuesday 24 February 2026  18:37:00 +0000 (0:00:00.028)       0:01:29.301 ******
2026-02-24 18:37:00.950720 | controller | changed: [instance]
2026-02-24 18:37:00.950804 | controller |
2026-02-24 18:37:00.950917 | controller | TASK [sushy_emulator : Slurp private ssh key for later use] ********************
2026-02-24 18:37:00.951018 | controller | Tuesday 24 February 2026  18:37:00 +0000 (0:00:00.282)       0:01:29.583 ******
2026-02-24 18:37:01.147326 | controller | ok: [instance]
2026-02-24 18:37:01.147479 | controller |
2026-02-24 18:37:01.147607 | controller | TASK [sushy_emulator : Allow Sushy Emulator key] *******************************
2026-02-24 18:37:01.147716 | controller | Tuesday 24 February 2026  18:37:01 +0000 (0:00:00.195)       0:01:29.779 ******
2026-02-24 18:37:02.616093 | controller | changed: [instance -> controller-0(192.168.26.96)]
2026-02-24 18:37:02.616461 | controller |
2026-02-24 18:37:02.880360 | controller | TASK [sushy_emulator : Run ssh-keyscan] ****************************************
2026-02-24 18:37:02.880408 | controller | Tuesday 24 February 2026  18:37:02 +0000 (0:00:01.467)       0:01:31.247 ******
2026-02-24 18:37:02.880434 | controller | changed: [instance]
2026-02-24 18:37:03.291751 | controller |
2026-02-24 18:37:03.291817 | controller | TASK [sushy_emulator : Write known hosts for later use] ************************
2026-02-24 18:37:03.291828 | controller | Tuesday 24 February 2026  18:37:02 +0000 (0:00:00.265)       0:01:31.513 ******
2026-02-24 18:37:03.291843 | controller | changed: [instance]
2026-02-24 18:37:03.291882 | controller |
2026-02-24 18:37:03.291902 | controller | TASK [sushy_emulator : Ensure file exists: /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
2026-02-24 18:37:03.322918 | controller | Tuesday 24 February 2026  18:37:03 +0000 (0:00:00.411)       0:01:31.924 ******
2026-02-24 18:37:03.322966 | controller | skipping: [instance]
2026-02-24 18:37:03.322988 | controller |
2026-02-24 18:37:03.322996 | controller | TASK [sushy_emulator : Slurp content of: /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
2026-02-24 18:37:03.323076 | controller | Tuesday 24 February 2026  18:37:03 +0000 (0:00:00.031)       0:01:31.956 ******
2026-02-24 18:37:03.361468 | controller | skipping: [instance]
2026-02-24 18:37:03.361517 | controller |
2026-02-24 18:37:03.361527 | controller | TASK [sushy_emulator : Set cifmw_libvirt_manager_uuids fact from /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
2026-02-24 18:37:03.361667 | controller | Tuesday 24 February 2026  18:37:03 +0000 (0:00:00.038)       0:01:31.994 ******
2026-02-24 18:37:03.393977 | controller | skipping: [instance]
2026-02-24 18:37:03.436754 | controller |
2026-02-24 18:37:03.436804 | controller | TASK [sushy_emulator : Generate list of filtered VMs] **************************
2026-02-24 18:37:03.436814 | controller | Tuesday 24 February 2026  18:37:03 +0000 (0:00:00.032)       0:01:32.027 ******
2026-02-24 18:37:03.436828 | controller | ok: [instance]
2026-02-24 18:37:03.459389 | controller |
2026-02-24 18:37:03.459432 | controller | TASK [sushy_emulator : Get Openstack instance UUIDs] ***************************
2026-02-24 18:37:03.459468 | controller | Tuesday 24 February 2026  18:37:03 +0000 (0:00:00.042)       0:01:32.069 ******
2026-02-24 18:37:03.459483 | controller | skipping: [instance]
2026-02-24 18:37:03.480945 | controller |
2026-02-24 18:37:03.480986 | controller | TASK [sushy_emulator : Set instance_uuid variable for openstack driver] ********
2026-02-24 18:37:03.480996 | controller | Tuesday 24 February 2026  18:37:03 +0000 (0:00:00.022)       0:01:32.092 ******
2026-02-24 18:37:03.481008 | controller | skipping: [instance]
2026-02-24 18:37:03.501665 | controller |
2026-02-24 18:37:03.501727 | controller | TASK [sushy_emulator : Base64 encode openstack clouds.yaml file] ***************
2026-02-24 18:37:03.501736 | controller | Tuesday 24 February 2026  18:37:03 +0000 (0:00:00.021)       0:01:32.114 ******
2026-02-24 18:37:03.501750 | controller | skipping: [instance]
2026-02-24 18:37:03.711021 | controller |
2026-02-24 18:37:03.711058 | controller | TASK [sushy_emulator : Generate htpasswd string] *******************************
2026-02-24 18:37:03.711066 | controller | Tuesday 24 February 2026  18:37:03 +0000 (0:00:00.020)       0:01:32.134 ******
2026-02-24 18:37:03.711077 | controller | changed: [instance]
2026-02-24 18:37:03.711096 | controller |
2026-02-24 18:37:03.711178 | controller | TASK [sushy_emulator : Write sushy emulator resource loop] *********************
2026-02-24 18:37:03.711321 | controller | Tuesday 24 February 2026  18:37:03 +0000 (0:00:00.209)       0:01:32.344 ******
2026-02-24 18:37:05.491393 | controller | changed: [instance] => (item=secret)
2026-02-24 18:37:05.516610 | controller | changed: [instance] => (item=configmap)
2026-02-24 18:37:05.516675 | controller | changed: [instance] => (item=pod)
2026-02-24 18:37:05.516686 | controller | changed: [instance] => (item=service)
2026-02-24 18:37:05.516694 | controller | changed: [instance] => (item=route)
2026-02-24 18:37:05.516702 | controller |
2026-02-24 18:37:05.516711 | controller | TASK [sushy_emulator : Write sushy emulator config] ****************************
2026-02-24 18:37:05.516720 | controller | Tuesday 24 February 2026  18:37:05 +0000 (0:00:01.779)       0:01:34.123 ******
2026-02-24 18:37:05.516737 | controller | skipping: [instance]
2026-02-24 18:37:05.543559 | controller |
2026-02-24 18:37:05.543591 | controller | TASK [sushy_emulator : Write htpasswd string to file] **************************
2026-02-24 18:37:05.543600 | controller | Tuesday 24 February 2026  18:37:05 +0000 (0:00:00.025)       0:01:34.148 ******
2026-02-24 18:37:05.543620 | controller | skipping: [instance]
2026-02-24 18:37:06.514660 | controller |
2026-02-24 18:37:06.514721 | controller | TASK [sushy_emulator : Create the sushy-emulator namespace] ********************
2026-02-24 18:37:06.514731 | controller | Tuesday 24 February 2026  18:37:05 +0000 (0:00:00.027)       0:01:34.176 ******
2026-02-24 18:37:06.514747 | controller | changed: [instance]
2026-02-24 18:37:07.278679 | controller |
2026-02-24 18:37:07.278715 | controller | TASK [sushy_emulator : Check if router pod is running in openshift-ingress namespace] ***
2026-02-24 18:37:07.278724 | controller | Tuesday 24 February 2026  18:37:06 +0000 (0:00:00.970)       0:01:35.146 ******
2026-02-24 18:37:07.278734 | controller | ok: [instance]
2026-02-24 18:37:07.278760 | controller |
2026-02-24 18:37:07.278782 | controller | TASK [sushy_emulator : Apply Sushy Emulator resources] *************************
2026-02-24 18:37:07.278902 | controller | Tuesday 24 February 2026  18:37:07 +0000 (0:00:00.764)       0:01:35.911 ******
2026-02-24 18:37:09.858641 | controller | changed: [instance] => (item=secret)
2026-02-24 18:37:09.858707 | controller | changed: [instance] => (item=configmap)
2026-02-24 18:37:09.858890 | controller | changed: [instance] => (item=service)
2026-02-24 18:37:09.858928 | controller | changed: [instance] => (item=route)
2026-02-24 18:37:09.859140 | controller |
2026-02-24 18:37:09.859374 | controller | TASK [sushy_emulator : Apply Sushy Emulator pod resource] **********************
2026-02-24 18:37:09.859482 | controller | Tuesday 24 February 2026  18:37:09 +0000 (0:00:02.579)       0:01:38.491 ******
2026-02-24 18:41:50.138601 | RUN END RESULT_TIMED_OUT: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2026-02-24 18:41:50.139386 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2026-02-24 18:41:50.621249 | 
2026-02-24 18:41:50.621363 | PLAY [Run ci/playbooks/collect-logs.yml]
2026-02-24 18:41:50.640250 | 
2026-02-24 18:41:50.640338 | TASK [Filter out host if needed]
2026-02-24 18:41:50.648045 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2026-02-24 18:41:50.652055 | 
2026-02-24 18:41:50.652116 | TASK [Ensure file is present]
2026-02-24 18:41:51.035277 | controller | ok
2026-02-24 18:41:51.041580 | 
2026-02-24 18:41:51.041644 | TASK [Manage molecule report file]
2026-02-24 18:41:51.064145 | [controller] Waiting on logger
2026-02-24 18:41:56.219925 | [controller] Waiting on logger
2026-02-24 18:42:06.651943 | [controller] Waiting on logger
2026-02-24 18:42:17.084100 | [controller] Waiting on logger
2026-02-24 18:42:21.074523 | [Zuul] Log Stream did not terminate
2026-02-24 18:42:21.074728 | controller | skipping: Conditional result was False
2026-02-24 18:42:21.080122 | 
2026-02-24 18:42:21.080187 | TASK [Check if we get ci-framework-data basedir]
2026-02-24 18:42:21.372488 | controller | ok
2026-02-24 18:42:21.377465 | 
2026-02-24 18:42:21.377528 | TASK [Create ci-framework-data log directory for zuul]
2026-02-24 18:42:21.751627 | controller | changed
2026-02-24 18:42:21.756536 | 
2026-02-24 18:42:21.756600 | TASK [Copy ci-framework interesting files]
2026-02-24 18:42:22.780032 | [controller] Waiting on logger
2026-02-24 18:42:31.612013 | [controller] Waiting on logger
2026-02-24 18:42:38.893627 | controller | changed
2026-02-24 18:42:38.898851 | 
2026-02-24 18:42:38.898917 | TASK [Get SELinux listing]
2026-02-24 18:42:43.923133 | controller | changed
2026-02-24 18:42:43.928761 | 
2026-02-24 18:42:43.928832 | TASK [Generate log index]
2026-02-24 18:42:44.091728 | [controller] Waiting on logger
2026-02-24 18:42:45.255630 | controller | changed
2026-02-24 18:42:45.260343 | 
2026-02-24 18:42:45.260413 | TASK [Get some env related data]
2026-02-24 18:42:45.283733 | [controller] Waiting on logger
2026-02-24 18:42:59.772162 | [controller] Waiting on logger
2026-02-24 18:43:09.152662 | [controller] Waiting on logger
2026-02-24 18:43:16.699419 | [Zuul] Log Stream did not terminate
2026-02-24 18:43:16.699692 | controller | changed
2026-02-24 18:43:16.704647 | 
2026-02-24 18:43:16.704702 | TASK [Generate list of logs to collect in home directory]
2026-02-24 18:43:17.066241 | controller | ok: All paths examined
2026-02-24 18:43:17.071104 | 
2026-02-24 18:43:17.071156 | LOOP [Copy logs from home directory]
2026-02-24 18:43:17.722275 | controller | changed:
2026-02-24 18:43:17.722539 | controller | {
2026-02-24 18:43:17.722569 | controller |   "atime": 1743544925.4788878,
2026-02-24 18:43:17.722589 | controller |   "ctime": 1743545329.1409318,
2026-02-24 18:43:17.722606 | controller |   "dev": 64513,
2026-02-24 18:43:17.722622 | controller |   "gid": 1000,
2026-02-24 18:43:17.722637 | controller |   "gr_name": "zuul",
2026-02-24 18:43:17.722652 | controller |   "inode": 4518807,
2026-02-24 18:43:17.722667 | controller |   "isblk": false,
2026-02-24 18:43:17.722682 | controller |   "ischr": false,
2026-02-24 18:43:17.722696 | controller |   "isdir": false,
2026-02-24 18:43:17.722713 | controller |   "isfifo": false,
2026-02-24 18:43:17.722727 | controller |   "isgid": false,
2026-02-24 18:43:17.722741 | controller |   "islnk": false,
2026-02-24 18:43:17.722755 | controller |   "isreg": true,
2026-02-24 18:43:17.722769 | controller |   "issock": false,
2026-02-24 18:43:17.722782 | controller |   "isuid": false,
2026-02-24 18:43:17.722795 | controller |   "mode": "0644",
2026-02-24 18:43:17.722809 | controller |   "mtime": 1743545329.1409318,
2026-02-24 18:43:17.722824 | controller |   "nlink": 1,
2026-02-24 18:43:17.722840 | controller |   "path": "/home/zuul/crc-setup.log",
2026-02-24 18:43:17.722862 | controller |   "pw_name": "zuul",
2026-02-24 18:43:17.722885 | controller |   "rgrp": true,
2026-02-24 18:43:17.722905 | controller |   "roth": true,
2026-02-24 18:43:17.722925 | controller |   "rusr": true,
2026-02-24 18:43:17.722945 | controller |   "size": 4108,
2026-02-24 18:43:17.722964 | controller |   "uid": 1000,
2026-02-24 18:43:17.722984 | controller |   "wgrp": false,
2026-02-24 18:43:17.723004 | controller |   "woth": false,
2026-02-24 18:43:17.723024 | controller |   "wusr": true,
2026-02-24 18:43:17.723042 | controller |   "xgrp": false,
2026-02-24 18:43:17.723061 | controller |   "xoth": false,
2026-02-24 18:43:17.723080 | controller |   "xusr": false
2026-02-24 18:43:17.723099 | controller | }
2026-02-24 18:43:18.385748 | controller | changed:
2026-02-24 18:43:18.385803 | controller | {
2026-02-24 18:43:18.385827 | controller |   "atime": 1743545331.0429637,
2026-02-24 18:43:18.385845 | controller |   "ctime": 1743545842.0111232,
2026-02-24 18:43:18.385861 | controller |   "dev": 64513,
2026-02-24 18:43:18.385876 | controller |   "gid": 1000,
2026-02-24 18:43:18.385891 | controller |   "gr_name": "zuul",
2026-02-24 18:43:18.385905 | controller |   "inode": 4194437,
2026-02-24 18:43:18.385919 | controller |   "isblk": false,
2026-02-24 18:43:18.385933 | controller |   "ischr": false,
2026-02-24 18:43:18.385948 | controller |   "isdir": false,
2026-02-24 18:43:18.385964 | controller |   "isfifo": false,
2026-02-24 18:43:18.385979 | controller |   "isgid": false,
2026-02-24 18:43:18.385993 | controller |   "islnk": false,
2026-02-24 18:43:18.386007 | controller |   "isreg": true,
2026-02-24 18:43:18.386021 | controller |   "issock": false,
2026-02-24 18:43:18.386034 | controller |   "isuid": false,
2026-02-24 18:43:18.386047 | controller |   "mode": "0644",
2026-02-24 18:43:18.386060 | controller |   "mtime": 1743545842.0111232,
2026-02-24 18:43:18.386074 | controller |   "nlink": 1,
2026-02-24 18:43:18.386087 | controller |   "path": "/home/zuul/crc-start.log",
2026-02-24 18:43:18.386100 | controller |   "pw_name": "zuul",
2026-02-24 18:43:18.386113 | controller |   "rgrp": true,
2026-02-24 18:43:18.386125 | controller |   "roth": true,
2026-02-24 18:43:18.386138 | controller |   "rusr": true,
2026-02-24 18:43:18.386151 | controller |   "size": 4023,
2026-02-24 18:43:18.386163 | controller |   "uid": 1000,
2026-02-24 18:43:18.386176 | controller |   "wgrp": false,
2026-02-24 18:43:18.386188 | controller |   "woth": false,
2026-02-24 18:43:18.386201 | controller |   "wusr": true,
2026-02-24 18:43:18.386213 | controller |   "xgrp": false,
2026-02-24 18:43:18.386226 | controller |   "xoth": false,
2026-02-24 18:43:18.386243 | controller |   "xusr": false
2026-02-24 18:43:18.386257 | controller | }
2026-02-24 18:43:19.037625 | controller | changed:
2026-02-24 18:43:19.037682 | controller | {
2026-02-24 18:43:19.037707 | controller |   "atime": 1771956813.3663604,
2026-02-24 18:43:19.037726 | controller |   "ctime": 1771956829.562596,
2026-02-24 18:43:19.037742 | controller |   "dev": 64513,
2026-02-24 18:43:19.037758 | controller |   "gid": 1000,
2026-02-24 18:43:19.037772 | controller |   "gr_name": "zuul",
2026-02-24 18:43:19.037786 | controller |   "inode": 4685787,
2026-02-24 18:43:19.037800 | controller |   "isblk": false,
2026-02-24 18:43:19.037813 | controller |   "ischr": false,
2026-02-24 18:43:19.037826 | controller |   "isdir": false,
2026-02-24 18:43:19.037840 | controller |   "isfifo": false,
2026-02-24 18:43:19.037854 | controller |   "isgid": false,
2026-02-24 18:43:19.037867 | controller |   "islnk": false,
2026-02-24 18:43:19.037884 | controller |   "isreg": true,
2026-02-24 18:43:19.037898 | controller |   "issock": false,
2026-02-24 18:43:19.037912 | controller |   "isuid": false,
2026-02-24 18:43:19.037925 | controller |   "mode": "0644",
2026-02-24 18:43:19.037938 | controller |   "mtime": 1771956829.562596,
2026-02-24 18:43:19.037952 | controller |   "nlink": 1,
2026-02-24 18:43:19.037965 | controller |   "path": "/home/zuul/ansible.log",
2026-02-24 18:43:19.037979 | controller |   "pw_name": "zuul",
2026-02-24 18:43:19.037992 | controller |   "rgrp": true,
2026-02-24 18:43:19.038005 | controller |   "roth": true,
2026-02-24 18:43:19.038019 | controller |   "rusr": true,
2026-02-24 18:43:19.038031 | controller |   "size": 6749,
2026-02-24 18:43:19.038045 | controller |   "uid": 1000,
2026-02-24 18:43:19.038058 | controller |   "wgrp": false,
2026-02-24 18:43:19.038072 | controller |   "woth": false,
2026-02-24 18:43:19.038085 | controller |   "wusr": true,
2026-02-24 18:43:19.038099 | controller |   "xgrp": false,
2026-02-24 18:43:19.038112 | controller |   "xoth": false,
2026-02-24 18:43:19.038125 | controller |   "xusr": false
2026-02-24 18:43:19.038138 | controller | }
2026-02-24 18:43:19.050789 | 
2026-02-24 18:43:19.050891 | TASK [Copy crio stats log file]
2026-02-24 18:43:19.064471 | controller | skipping: Conditional result was False
2026-02-24 18:43:19.069190 | 
2026-02-24 18:43:19.069250 | TASK [Get SELinux related data]
2026-02-24 18:43:19.088495 | [controller] Waiting on logger
2026-02-24 18:43:29.532040 | [controller] Waiting on logger
2026-02-24 18:43:39.964152 | [controller] Waiting on logger
2026-02-24 18:43:49.308171 | [controller] Waiting on logger
2026-02-24 18:43:49.410088 | [Zuul] Log Stream did not terminate
2026-02-24 18:43:49.410347 | controller | ERROR
2026-02-24 18:43:49.410468 | controller | {
2026-02-24 18:43:49.410498 | controller |   "delta": "0:00:00.012286",
2026-02-24 18:43:49.410518 | controller |   "end": "2026-02-24 18:43:19.382783",
2026-02-24 18:43:49.410536 | controller |   "msg": "non-zero return code",
2026-02-24 18:43:49.410551 | controller |   "rc": 1,
2026-02-24 18:43:49.410567 | controller |   "start": "2026-02-24 18:43:19.370497"
2026-02-24 18:43:49.410582 | controller | }
2026-02-24 18:43:49.410605 | controller | ERROR: Ignoring Errors
2026-02-24 18:43:49.415480 | 
2026-02-24 18:43:49.415539 | TASK [Create system configuration directory]
2026-02-24 18:43:49.708574 | controller | changed
2026-02-24 18:43:49.713623 | 
2026-02-24 18:43:49.713687 | TASK [Get some of the system configurations]
2026-02-24 18:43:54.739637 | controller | changed
2026-02-24 18:43:54.744358 | 
2026-02-24 18:43:54.744426 | TASK [Copy generated documentation if available]
2026-02-24 18:43:54.757573 | controller | skipping: Conditional result was False
2026-02-24 18:43:54.763208 | 
2026-02-24 18:43:54.763264 | TASK [Copy generated AsciiDoc documentation if available]
2026-02-24 18:43:54.776221 | controller | skipping: Conditional result was False
2026-02-24 18:43:54.781063 | 
2026-02-24 18:43:54.781119 | TASK [Compress logs bigger than 2MB]
2026-02-24 18:43:54.802810 | [controller] Waiting on logger
2026-02-24 18:43:59.910023 | controller | changed
2026-02-24 18:43:59.914827 | 
2026-02-24 18:43:59.914885 | TASK [Copy files from workspace on node]
2026-02-24 18:43:59.932633 | controller | ok
2026-02-24 18:43:59.953173 | 
2026-02-24 18:43:59.953236 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-24 18:43:59.966487 | controller | skipping: Conditional result was False
2026-02-24 18:43:59.971764 | 
2026-02-24 18:43:59.971825 | TASK [fetch-output : Set log path for single node]
2026-02-24 18:43:59.989702 | controller | ok
2026-02-24 18:43:59.994126 | 
2026-02-24 18:43:59.994187 | LOOP [fetch-output : Ensure local output dirs]
2026-02-24 18:44:00.176911 | controller -> localhost | ok: "/var/lib/zuul/builds/bb9a4d59823d4873bdd7d877a891d312/work/logs"
2026-02-24 18:44:00.177118 | controller -> localhost | changed: All items complete
2026-02-24 18:44:00.177147 | 
2026-02-24 18:44:00.337417 | controller -> localhost | changed: "/var/lib/zuul/builds/bb9a4d59823d4873bdd7d877a891d312/work/artifacts"
2026-02-24 18:44:00.499814 | controller -> localhost | changed: "/var/lib/zuul/builds/bb9a4d59823d4873bdd7d877a891d312/work/docs"
2026-02-24 18:44:00.508711 | 
2026-02-24 18:44:00.508778 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-24 18:44:00.828071 | [controller] Waiting on logger
2026-02-24 18:44:01.147694 | controller | changed:
2026-02-24 18:44:01.147778 | controller | .d..t...... ./
2026-02-24 18:44:01.147806 | controller | >f+++++++++ README.html
2026-02-24 18:44:01.147826 | controller | >f+++++++++ ansible-execution.log
2026-02-24 18:44:01.147844 | controller | >f+++++++++ ansible.log
2026-02-24 18:44:01.147861 | controller | >f+++++++++ crc-setup.log
2026-02-24 18:44:01.147877 | controller | >f+++++++++ crc-start.log
2026-02-24 18:44:01.147893 | controller | >f+++++++++ dmesg.log
2026-02-24 18:44:01.147910 | controller | >f+++++++++ installed-pkgs.log
2026-02-24 18:44:01.147926 | controller | >f+++++++++ python.log
2026-02-24 18:44:01.147942 | controller | >f+++++++++ registries.conf
2026-02-24 18:44:01.147957 | controller | >f+++++++++ selinux-denials.log
2026-02-24 18:44:01.147971 | controller | >f+++++++++ selinux-listing.log
2026-02-24 18:44:01.147986 | controller | cd+++++++++ ci-framework-data/
2026-02-24 18:44:01.148001 | controller | cd+++++++++ ci-framework-data/artifacts/
2026-02-24 18:44:01.148016 | controller | >f+++++++++ ci-framework-data/artifacts/debug_cifmw_libvirt_manager_layout.yml
2026-02-24 18:44:01.148031 | controller | >f+++++++++ ci-framework-data/artifacts/debug_network_data.yml
2026-02-24 18:44:01.148046 | controller | >f+++++++++ ci-framework-data/artifacts/debug_pub_net_value.txt
2026-02-24 18:44:01.148060 | controller | >f+++++++++ ci-framework-data/artifacts/interfaces-info.yml
2026-02-24 18:44:01.148074 | controller | >f+++++++++ ci-framework-data/artifacts/libvirt-uuids.yml
2026-02-24 18:44:01.148088 | controller | >f+++++++++ ci-framework-data/artifacts/net-map-def-patch.yml
2026-02-24 18:44:01.148102 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2026-02-24 18:44:01.148117 | controller | cd+++++++++ ci-framework-data/artifacts/nmstate/
2026-02-24 18:44:01.148132 | controller | >f+++++++++ ci-framework-data/artifacts/nmstate/instance-final-state.yaml
2026-02-24 18:44:01.148147 | controller | >f+++++++++ ci-framework-data/artifacts/nmstate/instance-state.yaml
2026-02-24 18:44:01.148161 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2026-02-24 18:44:01.148178 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2026-02-24 18:44:01.148194 | controller | cd+++++++++ ci-framework-data/artifacts/repositories/
2026-02-24 18:44:01.148208 | controller | >f+++++++++ ci-framework-data/artifacts/repositories/delorean.repo.md5
2026-02-24 18:44:01.148223 | controller | cd+++++++++ ci-framework-data/artifacts/sushy_emulator/
2026-02-24 18:44:01.148237 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/configmap.yaml
2026-02-24 18:44:01.148252 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/known_hosts
2026-02-24 18:44:01.148272 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/pod.yaml
2026-02-24 18:44:01.148287 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/route.yaml
2026-02-24 18:44:01.148337 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/secret.yaml
2026-02-24 18:44:01.148358 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/service.yaml
2026-02-24 18:44:01.148383 | controller | cd+++++++++ ci-framework-data/logs/
2026-02-24 18:44:01.148401 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2026-02-24 18:44:01.148416 | controller | cd+++++++++ registries.conf.d/
2026-02-24 18:44:01.148431 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2026-02-24 18:44:01.148446 | controller | cd+++++++++ system-config/
2026-02-24 18:44:01.148460 | controller | cd+++++++++ system-config/libvirt/
2026-02-24 18:44:01.148480 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2026-02-24 18:44:01.148494 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2026-02-24 18:44:01.148507 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf
2026-02-24 18:44:01.148520 | controller | >f+++++++++ system-config/libvirt/network.conf
2026-02-24 18:44:01.148534 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf
2026-02-24 18:44:01.148547 | controller | >f+++++++++ system-config/libvirt/qemu.conf
2026-02-24 18:44:01.148561 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf
2026-02-24 18:44:01.148575 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf
2026-02-24 18:44:01.148588 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf
2026-02-24 18:44:01.148601 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf
2026-02-24 18:44:01.148615 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf
2026-02-24 18:44:01.148631 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf
2026-02-24 18:44:01.148646 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf
2026-02-24 18:44:01.148660 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf
2026-02-24 18:44:01.148674 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf
2026-02-24 18:44:01.148688 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf
2026-02-24 18:44:01.617766 | controller | changed: .d..t...... ./
2026-02-24 18:44:02.083833 | controller | changed: .d..t...... ./
2026-02-24 18:44:02.099499 | 
2026-02-24 18:44:02.099572 | TASK [Return artifact to Zuul]
2026-02-24 18:44:02.112493 | controller | skipping: Conditional result was False
2026-02-24 18:44:02.130924 | 
2026-02-24 18:44:02.130981 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2026-02-24 18:44:02.131070 | 
2026-02-24 18:44:02.131096 | PLAY RECAP
2026-02-24 18:44:02.131132 | controller | ok: 16 changed: 12 unreachable: 0 failed: 0 skipped: 6 rescued: 0 ignored: 1
2026-02-24 18:44:02.131152 | 
2026-02-24 18:44:02.199428 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2026-02-24 18:44:02.200178 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2026-02-24 18:44:02.666718 | 
2026-02-24 18:44:02.666815 | PLAY [all]
2026-02-24 18:44:02.683445 | 
2026-02-24 18:44:02.683514 | TASK [include_role : fetch-output]
2026-02-24 18:44:02.711538 | controller | ok
2026-02-24 18:44:02.727963 | 
2026-02-24 18:44:02.728049 | TASK [fetch-output : Set log path for multiple nodes]
2026-02-24 18:44:02.762063 | controller | skipping: Conditional result was False
2026-02-24 18:44:02.767577 | 
2026-02-24 18:44:02.767642 | TASK [fetch-output : Set log path for single node]
2026-02-24 18:44:02.795099 | controller | ok
2026-02-24 18:44:02.799554 | 
2026-02-24 18:44:02.799618 | LOOP [fetch-output : Ensure local output dirs]
2026-02-24 18:44:03.092042 | controller -> localhost | ok: "/var/lib/zuul/builds/bb9a4d59823d4873bdd7d877a891d312/work/logs"
2026-02-24 18:44:03.260460 | controller -> localhost | ok: "/var/lib/zuul/builds/bb9a4d59823d4873bdd7d877a891d312/work/artifacts"
2026-02-24 18:44:03.423562 | controller -> localhost | ok: "/var/lib/zuul/builds/bb9a4d59823d4873bdd7d877a891d312/work/docs"
2026-02-24 18:44:03.436260 | 
2026-02-24 18:44:03.436365 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-02-24 18:44:04.039457 | controller | ok
2026-02-24 18:44:04.039643 | controller | ok: All items complete
2026-02-24 18:44:04.039673 | 
2026-02-24 18:44:04.507540 | controller | ok
2026-02-24 18:44:04.979497 | controller | ok
2026-02-24 18:44:04.990439 | 
2026-02-24 18:44:04.990543 | TASK [include_role : fetch-output-openshift]
2026-02-24 18:44:05.004137 | controller | skipping: Conditional result was False
2026-02-24 18:44:05.009461 | 
2026-02-24 18:44:05.009527 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-02-24 18:44:05.329719 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.005662
2026-02-24 18:44:05.505639 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.005294
2026-02-24 18:44:05.532210 | 
2026-02-24 18:44:05.532340 | PLAY [all]
2026-02-24 18:44:05.545314 | 
2026-02-24 18:44:05.545388 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-02-24 18:44:06.020188 | controller | changed
2026-02-24 18:44:06.039860 | 
2026-02-24 18:44:06.039915 | PLAY RECAP
2026-02-24 18:44:06.039957 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2026-02-24 18:44:06.039979 | 
2026-02-24 18:44:06.106334 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2026-02-24 18:44:06.107033 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2026-02-24 18:44:06.611846 | 
2026-02-24 18:44:06.611975 | PLAY [localhost]
2026-02-24 18:44:06.627749 | 
2026-02-24 18:44:06.627823 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-02-24 18:44:06.897763 | localhost | changed
2026-02-24 18:44:06.902086 | 
2026-02-24 18:44:06.902157 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-02-24 18:44:06.918886 | localhost | ok
2026-02-24 18:44:06.925979 | 
2026-02-24 18:44:06.926049 | TASK [add-fileserver : Create SSH private key tempfile]
2026-02-24 18:44:07.195846 | localhost | changed
2026-02-24 18:44:07.201091 | 
2026-02-24 18:44:07.201162 | TASK [add-fileserver : Create SSH private key from secret]
2026-02-24 18:44:07.714258 | localhost | changed
2026-02-24 18:44:07.719085 | 
2026-02-24 18:44:07.719153 | TASK [add-fileserver : Add fileserver ssh key]
2026-02-24 18:44:08.029593 | localhost | Identity added: /var/lib/zuul/builds/bb9a4d59823d4873bdd7d877a891d312/work/tmp/ansible.g_1zjeyo (/var/lib/zuul/builds/bb9a4d59823d4873bdd7d877a891d312/work/tmp/ansible.g_1zjeyo)
2026-02-24 18:44:08.029756 | localhost | ok: Runtime: 0:00:00.006076
2026-02-24 18:44:08.033908 | 
2026-02-24 18:44:08.033979 | TASK [add-fileserver : Remove SSH private key from disk]
2026-02-24 18:44:08.243132 | localhost | ok: Runtime: 0:00:00.003833
2026-02-24 18:44:08.247674 | 
2026-02-24 18:44:08.247742 | TASK [add-fileserver : Add fileserver to inventory]
2026-02-24 18:44:08.295837 | localhost | changed
2026-02-24 18:44:08.300380 | 
2026-02-24 18:44:08.300442 | TASK [add-fileserver : Add fileserver server to known hosts]
2026-02-24 18:44:08.579995 | localhost | changed
2026-02-24 18:44:08.599196 | 
2026-02-24 18:44:08.599255 | PLAY [localhost]
2026-02-24 18:44:08.609896 | 
2026-02-24 18:44:08.609961 | TASK [Generate bulk log download script]
2026-02-24 18:44:08.627729 | localhost | ok
2026-02-24 18:44:08.638623 | 
2026-02-24 18:44:08.638690 | TASK [local-log-download : Check API endpoint is defined]
2026-02-24 18:44:08.665004 | localhost | ok: All assertions passed
2026-02-24 18:44:08.669228 | 
2026-02-24 18:44:08.669313 | TASK [local-log-download : Create download script]
2026-02-24 18:44:08.995487 | localhost -> localhost | changed
2026-02-24 18:44:09.003677 | 
2026-02-24 18:44:09.003744 | TASK [Register quick-download link]
2026-02-24 18:44:09.019902 | localhost | ok
2026-02-24 18:44:09.052133 | 
2026-02-24 18:44:09.052196 | PLAY [logserver.rdoproject.org]
2026-02-24 18:44:09.061527 | 
2026-02-24 18:44:09.061588 | TASK [Set zuul-log-path fact]
2026-02-24 18:44:09.076506 | logserver.rdoproject.org | ok
2026-02-24 18:44:09.084925 | 
2026-02-24 18:44:09.084991 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-02-24 18:44:09.110697 | logserver.rdoproject.org | ok
2026-02-24 18:44:09.115747 | 
2026-02-24 18:44:09.115812 | TASK [upload-logs : Create log directories]
2026-02-24 18:44:10.886429 | logserver.rdoproject.org | changed
2026-02-24 18:44:10.889546 | 
2026-02-24 18:44:10.889615 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-02-24 18:44:11.095473 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004532
2026-02-24 18:44:11.099790 | 
2026-02-24 18:44:11.099858 | TASK [upload-logs : Upload logs to log server]
2026-02-24 18:44:12.648001 | logserver.rdoproject.org | Output suppressed because no_log was given
2026-02-24 18:44:12.650500 | 
2026-02-24 18:44:12.650559 | LOOP [upload-logs : Compress console log and json output]
2026-02-24 18:44:12.684363 | logserver.rdoproject.org | skipping: Conditional result was False
2026-02-24 18:44:12.692142 | logserver.rdoproject.org | skipping: Conditional result was False
2026-02-24 18:44:12.696541 | 
2026-02-24 18:44:12.696622 | LOOP [upload-logs : Upload compressed console log and json output]
2026-02-24 18:44:12.727669 | logserver.rdoproject.org | skipping: Conditional result was False
2026-02-24 18:44:12.727876 | 
2026-02-24 18:44:12.732123 | logserver.rdoproject.org | skipping: Conditional result was False
2026-02-24 18:44:12.742504 | 
2026-02-24 18:44:12.742582 | LOOP [upload-logs : Upload console log and json output]