2026-01-20 16:42:06.672708 | Job console starting...
2026-01-20 16:42:06.887688 | Updating repositories
2026-01-20 16:42:07.600016 | Preparing job workspace
2026-01-20 16:42:17.233746 | Running Ansible setup...
2026-01-20 16:42:21.028228 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2026-01-20 16:42:21.603942 | 
2026-01-20 16:42:21.604048 | PLAY [localhost]
2026-01-20 16:42:21.621358 | 
2026-01-20 16:42:21.621440 | TASK [Gathering Facts]
2026-01-20 16:42:22.457586 | localhost | ok
2026-01-20 16:42:22.471258 | 
2026-01-20 16:42:22.471400 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2026-01-20 16:42:22.935995 | localhost -> localhost | changed
2026-01-20 16:42:22.941521 | 
2026-01-20 16:42:22.941607 | TASK [log-inventory : Copy ansible inventory to logs dir]
2026-01-20 16:42:23.737433 | localhost -> localhost | changed
2026-01-20 16:42:23.745861 | 
2026-01-20 16:42:23.745934 | TASK [Setup log path fact]
2026-01-20 16:42:23.773765 | localhost | ok
2026-01-20 16:42:23.785735 | 
2026-01-20 16:42:23.785823 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-20 16:42:23.817052 | localhost | ok
2026-01-20 16:42:23.825250 | 
2026-01-20 16:42:23.825358 | TASK [emit-job-header : Print job information]
2026-01-20 16:42:23.853465 | # Job Information
2026-01-20 16:42:23.854081 | Ansible Version: 2.15.12
2026-01-20 16:42:23.854145 | Job: cifmw-molecule-sushy_emulator
2026-01-20 16:42:23.854174 | Pipeline: github-check
2026-01-20 16:42:23.854197 | Executor: ibm-bm4-ze.softwarefactory-project.io
2026-01-20 16:42:23.854218 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3451
2026-01-20 16:42:23.854239 | Log URL (when completed): https://logserver.rdoproject.org/4e8/rdoproject.org/4e813e18561b4a31ae159dbd9d8d0118/
2026-01-20 16:42:23.854258 | Event ID: 1110c990-f61e-11f0-91a3-9d3a1ada832b
2026-01-20 16:42:23.857985 | 
2026-01-20 16:42:23.858056 | LOOP [emit-job-header : Print node information]
2026-01-20 16:42:23.958536 | localhost | ok:
2026-01-20 16:42:23.958688 | localhost | # Node Information
2026-01-20 16:42:23.958717 | localhost | Inventory Hostname: controller
2026-01-20 16:42:23.958743 | localhost | Hostname: np0005589199
2026-01-20 16:42:23.958764 | localhost | Username: zuul
2026-01-20 16:42:23.958785 | localhost | Distro: CentOS 9
2026-01-20 16:42:23.958805 | localhost | Provider: ibm-bm4-nodepool
2026-01-20 16:42:23.958824 | localhost | Region: regionOne
2026-01-20 16:42:23.958841 | localhost | Label: centos-9-stream-crc-2-48-0-xl-ibm
2026-01-20 16:42:23.958859 | localhost | Product Name: OpenStack Compute
2026-01-20 16:42:23.958876 | localhost | Interface IP: 192.168.26.219
2026-01-20 16:42:23.981088 | 
2026-01-20 16:42:23.981198 | PLAY [all]
2026-01-20 16:42:23.988107 | 
2026-01-20 16:42:23.988185 | TASK [Gather network facts]
2026-01-20 16:42:24.458614 | controller | ok
2026-01-20 16:42:24.489658 | 
2026-01-20 16:42:24.489755 | TASK [include_role : start-zuul-console]
2026-01-20 16:42:24.518630 | controller | ok
2026-01-20 16:42:24.530126 | 
2026-01-20 16:42:24.530191 | TASK [start-zuul-console : Start zuul_console daemon.]
2026-01-20 16:42:24.927856 | controller | ok
2026-01-20 16:42:24.937278 | 
2026-01-20 16:42:24.937367 | TASK [include_role : add-build-sshkey]
2026-01-20 16:42:24.954737 | controller | ok
2026-01-20 16:42:24.972811 | 
2026-01-20 16:42:24.972890 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2026-01-20 16:42:25.182312 | controller -> localhost | ok
2026-01-20 16:42:25.188408 | 
2026-01-20 16:42:25.188473 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2026-01-20 16:42:25.217078 | controller | ok
2026-01-20 16:42:25.235587 | controller | included: /var/lib/zuul/builds/4e813e18561b4a31ae159dbd9d8d0118/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2026-01-20 16:42:25.242155 | 
2026-01-20 16:42:25.242222 | TASK [add-build-sshkey : Create Temp SSH key]
2026-01-20 16:42:25.815245 | controller -> localhost | Generating public/private rsa key pair.
2026-01-20 16:42:25.815460 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/4e813e18561b4a31ae159dbd9d8d0118/work/4e813e18561b4a31ae159dbd9d8d0118_id_rsa.
2026-01-20 16:42:25.815496 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/4e813e18561b4a31ae159dbd9d8d0118/work/4e813e18561b4a31ae159dbd9d8d0118_id_rsa.pub.
2026-01-20 16:42:25.815521 | controller -> localhost | The key fingerprint is:
2026-01-20 16:42:25.815544 | controller -> localhost | SHA256:4fOCmd5la0z2Y54E2TIhJK9srRiiz5yJfaYVQiQDlHA zuul-build-sshkey
2026-01-20 16:42:25.815566 | controller -> localhost | The key's randomart image is:
2026-01-20 16:42:25.815586 | controller -> localhost | +---[RSA 3072]----+
2026-01-20 16:42:25.815605 | controller -> localhost | |O.E   . .        |
2026-01-20 16:42:25.815625 | controller -> localhost | | *     +         |
2026-01-20 16:42:25.815644 | controller -> localhost | |  .     + .      |
2026-01-20 16:42:25.815664 | controller -> localhost | | .   . + o +     |
2026-01-20 16:42:25.815683 | controller -> localhost | |  o o + S = .    |
2026-01-20 16:42:25.815702 | controller -> localhost | | . o = = oo+     |
2026-01-20 16:42:25.815721 | controller -> localhost | |.   o = .++..    |
2026-01-20 16:42:25.815740 | controller -> localhost | | * +o. . +oo+.   |
2026-01-20 16:42:25.815759 | controller -> localhost | |. O+  . ...oo.   |
2026-01-20 16:42:25.815778 | controller -> localhost | +----[SHA256]-----+
2026-01-20 16:42:25.815834 | controller -> localhost | ok: Runtime: 0:00:00.181140
2026-01-20 16:42:25.828381 | 
2026-01-20 16:42:25.828449 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2026-01-20 16:42:25.872414 | controller | ok
2026-01-20 16:42:25.888022 | controller | included: /var/lib/zuul/builds/4e813e18561b4a31ae159dbd9d8d0118/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2026-01-20 16:42:25.901786 | 
2026-01-20 16:42:25.901872 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2026-01-20 16:42:25.925843 | controller | skipping: Conditional result was False
2026-01-20 16:42:25.932594 | 
2026-01-20 16:42:25.932664 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2026-01-20 16:42:26.440792 | controller | changed
2026-01-20 16:42:26.446574 | 
2026-01-20 16:42:26.446686 | TASK [add-build-sshkey : Make sure user has a .ssh]
2026-01-20 16:42:26.707469 | controller | ok
2026-01-20 16:42:26.713919 | 
2026-01-20 16:42:26.714111 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2026-01-20 16:42:27.826705 | controller | changed
2026-01-20 16:42:27.836008 | 
2026-01-20 16:42:27.836083 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2026-01-20 16:42:28.913897 | controller | changed
2026-01-20 16:42:28.919067 | 
2026-01-20 16:42:28.919157 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2026-01-20 16:42:28.933060 | controller | skipping: Conditional result was False
2026-01-20 16:42:28.942687 | 
2026-01-20 16:42:28.942769 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2026-01-20 16:42:29.283170 | controller -> localhost | changed
2026-01-20 16:42:29.293228 | 
2026-01-20 16:42:29.293335 | TASK [add-build-sshkey : Add back temp key]
2026-01-20 16:42:29.599174 | controller -> localhost | Identity added: /var/lib/zuul/builds/4e813e18561b4a31ae159dbd9d8d0118/work/4e813e18561b4a31ae159dbd9d8d0118_id_rsa (zuul-build-sshkey)
2026-01-20 16:42:29.599435 | controller -> localhost | ok: Runtime: 0:00:00.007635
2026-01-20 16:42:29.606407 | 
2026-01-20 16:42:29.606476 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2026-01-20 16:42:29.973185 | controller | ok
2026-01-20 16:42:29.978168 | 
2026-01-20 16:42:29.978235 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2026-01-20 16:42:30.001759 | controller | skipping: Conditional result was False
2026-01-20 16:42:30.011936 | 
2026-01-20 16:42:30.012003 | TASK [include_role : validate-host]
2026-01-20 16:42:30.031137 | controller | ok
2026-01-20 16:42:30.054550 | 
2026-01-20 16:42:30.054640 | TASK [validate-host : Define zuul_info_dir fact]
2026-01-20 16:42:30.083552 | controller | ok
2026-01-20 16:42:30.088791 | 
2026-01-20 16:42:30.088873 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2026-01-20 16:42:30.318644 | controller -> localhost | ok
2026-01-20 16:42:30.341919 | 
2026-01-20 16:42:30.342009 | TASK [validate-host : Collect information about the host]
2026-01-20 16:42:31.028415 | controller | ok
2026-01-20 16:42:31.043570 | 
2026-01-20 16:42:31.043761 | TASK [validate-host : Sanitize hostname]
2026-01-20 16:42:31.091989 | controller | ok
2026-01-20 16:42:31.097063 | 
2026-01-20 16:42:31.097148 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2026-01-20 16:42:31.486887 | controller -> localhost | changed
2026-01-20 16:42:31.496139 | 
2026-01-20 16:42:31.496216 | TASK [validate-host : Collect information about zuul worker]
2026-01-20 16:42:31.879866 | controller | ok
2026-01-20 16:42:31.885124 | 
2026-01-20 16:42:31.885194 | TASK [validate-host : Write out all zuul information for each host]
2026-01-20 16:42:32.294738 | controller -> localhost | changed
2026-01-20 16:42:32.304740 | 
2026-01-20 16:42:32.304821 | TASK [include_role : prepare-workspace-openshift]
2026-01-20 16:42:32.318147 | controller | skipping: Conditional result was False
2026-01-20 16:42:32.323779 | 
2026-01-20 16:42:32.323850 | TASK [include_role : remove-zuul-sshkey]
2026-01-20 16:42:32.337240 | controller | skipping: Conditional result was False
2026-01-20 16:42:32.342290 | 
2026-01-20 16:42:32.342381 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2026-01-20 16:42:32.611109 | controller | ok: "logs"
2026-01-20 16:42:32.611369 | controller | ok: All items complete
2026-01-20 16:42:32.611406 | 
2026-01-20 16:42:32.847405 | controller | ok: "artifacts"
2026-01-20 16:42:33.087379 | controller | ok: "docs"
2026-01-20 16:42:33.097047 | 
2026-01-20 16:42:33.097154 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2026-01-20 16:42:33.355896 | controller | changed: "logs"
2026-01-20 16:42:33.586650 | controller | changed: "artifacts"
2026-01-20 16:42:33.819550 | controller | changed: "docs"
2026-01-20 16:42:33.858762 | 
2026-01-20 16:42:33.858847 | PLAY RECAP
2026-01-20 16:42:33.858895 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2026-01-20 16:42:33.858924 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-20 16:42:33.858944 | 
2026-01-20 16:42:33.983340 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2026-01-20 16:42:33.984006 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2026-01-20 16:42:34.787289 | 
2026-01-20 16:42:34.787420 | PLAY [all]
2026-01-20 16:42:34.808017 | 
2026-01-20 16:42:34.808107 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2026-01-20 16:42:34.866727 | controller | ok
2026-01-20 16:42:34.872258 | 
2026-01-20 16:42:34.872375 | TASK [mirror-info-fork : Create /etc/ci]
2026-01-20 16:42:35.283772 | controller | changed
2026-01-20 16:42:35.295384 | 
2026-01-20 16:42:35.295475 | TASK [mirror-info-fork : Install ci_mirror script]
2026-01-20 16:42:36.624182 | controller | changed
2026-01-20 16:42:36.643537 | 
2026-01-20 16:42:36.643657 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2026-01-20 16:42:37.181919 | controller | changed:
2026-01-20 16:42:37.182100 | controller | {
2026-01-20 16:42:37.182137 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2026-01-20 16:42:37.182171 | controller | }
2026-01-20 16:42:37.458613 | controller | changed:
2026-01-20 16:42:37.458701 | controller | {
2026-01-20 16:42:37.458731 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2026-01-20 16:42:37.458754 | controller | }
2026-01-20 16:42:37.768395 | controller | changed:
2026-01-20 16:42:37.769549 | controller | {
2026-01-20 16:42:37.769587 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2026-01-20 16:42:37.769611 | controller | }
2026-01-20 16:42:38.075308 | controller | changed:
2026-01-20 16:42:38.075398 | controller | {
2026-01-20 16:42:38.075425 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2026-01-20 16:42:38.075447 | controller | }
2026-01-20 16:42:38.370602 | controller | changed:
2026-01-20 16:42:38.370745 | controller | {
2026-01-20 16:42:38.370789 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2026-01-20 16:42:38.370819 | controller | }
2026-01-20 16:42:38.669004 | controller | changed:
2026-01-20 16:42:38.669113 | controller | {
2026-01-20 16:42:38.669144 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2026-01-20 16:42:38.669167 | controller | }
2026-01-20 16:42:38.951918 | controller | changed:
2026-01-20 16:42:38.952017 | controller | {
2026-01-20 16:42:38.952051 | 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-01-20 16:42:38.952082 | controller | }
2026-01-20 16:42:39.237964 | controller | changed:
2026-01-20 16:42:39.238188 | controller | {
2026-01-20 16:42:39.238229 | 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-01-20 16:42:39.238255 | controller | }
2026-01-20 16:42:39.572730 | controller | changed:
2026-01-20 16:42:39.572812 | controller | {
2026-01-20 16:42:39.572839 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2026-01-20 16:42:39.572860 | controller | }
2026-01-20 16:42:39.851336 | controller | changed:
2026-01-20 16:42:39.851433 | controller | {
2026-01-20 16:42:39.851461 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2026-01-20 16:42:39.851483 | controller | }
2026-01-20 16:42:40.131817 | controller | changed:
2026-01-20 16:42:40.131910 | controller | {
2026-01-20 16:42:40.131937 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2026-01-20 16:42:40.131957 | controller | }
2026-01-20 16:42:40.417666 | controller | changed:
2026-01-20 16:42:40.417756 | controller | {
2026-01-20 16:42:40.417787 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2026-01-20 16:42:40.417810 | controller | }
2026-01-20 16:42:40.698744 | controller | changed:
2026-01-20 16:42:40.698823 | controller | {
2026-01-20 16:42:40.698849 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2026-01-20 16:42:40.698869 | controller | }
2026-01-20 16:42:40.984083 | controller | changed:
2026-01-20 16:42:40.984945 | controller | {
2026-01-20 16:42:40.984994 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2026-01-20 16:42:40.985019 | controller | }
2026-01-20 16:42:41.266507 | controller | changed:
2026-01-20 16:42:41.266594 | controller | {
2026-01-20 16:42:41.266620 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2026-01-20 16:42:41.266640 | controller | }
2026-01-20 16:42:41.560230 | controller | changed:
2026-01-20 16:42:41.560338 | controller | {
2026-01-20 16:42:41.560369 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2026-01-20 16:42:41.560390 | controller | }
2026-01-20 16:42:41.849005 | controller | changed:
2026-01-20 16:42:41.849157 | controller | {
2026-01-20 16:42:41.849189 | 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-01-20 16:42:41.849212 | controller | }
2026-01-20 16:42:42.127564 | controller | changed:
2026-01-20 16:42:42.127646 | controller | {
2026-01-20 16:42:42.127673 | 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-01-20 16:42:42.127701 | controller | }
2026-01-20 16:42:42.412157 | controller | changed:
2026-01-20 16:42:42.412408 | controller | {
2026-01-20 16:42:42.412446 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2026-01-20 16:42:42.412469 | controller | }
2026-01-20 16:42:42.697830 | controller | changed:
2026-01-20 16:42:42.697902 | controller | {
2026-01-20 16:42:42.697929 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2026-01-20 16:42:42.697950 | controller | }
2026-01-20 16:42:42.996263 | controller | changed:
2026-01-20 16:42:42.996381 | controller | {
2026-01-20 16:42:42.996410 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2026-01-20 16:42:42.996431 | controller | }
2026-01-20 16:42:43.285898 | controller | changed:
2026-01-20 16:42:43.285980 | controller | {
2026-01-20 16:42:43.286007 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2026-01-20 16:42:43.286030 | controller | }
2026-01-20 16:42:43.578830 | controller | changed:
2026-01-20 16:42:43.578911 | controller | {
2026-01-20 16:42:43.578938 | 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-01-20 16:42:43.578960 | controller | }
2026-01-20 16:42:43.864449 | controller | changed:
2026-01-20 16:42:43.864545 | controller | {
2026-01-20 16:42:43.864573 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2026-01-20 16:42:43.864595 | controller | }
2026-01-20 16:42:44.153669 | controller | changed:
2026-01-20 16:42:44.153762 | controller | {
2026-01-20 16:42:44.153790 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2026-01-20 16:42:44.153810 | controller | }
2026-01-20 16:42:44.443594 | controller | changed:
2026-01-20 16:42:44.443710 | controller | {
2026-01-20 16:42:44.443738 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2026-01-20 16:42:44.443759 | controller | }
2026-01-20 16:42:44.470762 | 
2026-01-20 16:42:44.470838 | TASK [Set timezone to UTC]
2026-01-20 16:42:44.948536 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2026-01-20 16:42:44.953738 | 
2026-01-20 16:42:44.953808 | TASK [Create nodepool directory]
2026-01-20 16:42:45.241261 | controller | changed
2026-01-20 16:42:45.247397 | 
2026-01-20 16:42:45.247483 | TASK [Create nodepool sub_nodes file]
2026-01-20 16:42:46.213977 | controller | changed
2026-01-20 16:42:46.220400 | 
2026-01-20 16:42:46.220518 | TASK [Create nodepool sub_nodes_private file]
2026-01-20 16:42:47.237107 | controller | changed
2026-01-20 16:42:47.248890 | 
2026-01-20 16:42:47.249025 | LOOP [Populate nodepool sub_nodes file]
2026-01-20 16:42:47.284628 | 
2026-01-20 16:42:47.284858 | LOOP [Populate nodepool sub_nodes_private file]
2026-01-20 16:42:47.317597 | 
2026-01-20 16:42:47.318155 | TASK [Create nodepool primary file]
2026-01-20 16:42:47.359792 | controller | skipping: Conditional result was False
2026-01-20 16:42:47.365288 | 
2026-01-20 16:42:47.365394 | TASK [Create nodepool node_private for this node]
2026-01-20 16:42:48.421765 | controller | changed
2026-01-20 16:42:48.427611 | 
2026-01-20 16:42:48.427697 | LOOP [Copy ssh keys to nodepool directory]
2026-01-20 16:42:48.832981 | controller | ok: Item: id_rsa Runtime: 0:00:00.004371
2026-01-20 16:42:48.833178 | 
2026-01-20 16:42:49.066671 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.005372
2026-01-20 16:42:49.075848 | 
2026-01-20 16:42:49.075951 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2026-01-20 16:42:50.051671 | controller | changed
2026-01-20 16:42:50.063624 | 
2026-01-20 16:42:50.063697 | TASK [Validate sudoers config after edits]
2026-01-20 16:42:50.344860 | controller | /etc/sudoers: parsed OK
2026-01-20 16:42:50.344936 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2026-01-20 16:42:50.344946 | controller | /etc/sudoers.d/zuul: parsed OK
2026-01-20 16:42:50.344953 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2026-01-20 16:42:50.591926 | controller | ok: Runtime: 0:00:00.007835
2026-01-20 16:42:50.597735 | 
2026-01-20 16:42:50.597800 | TASK [Show the environment passed in to job shell scripts]
2026-01-20 16:42:50.905845 | controller | SHELL=/bin/bash
2026-01-20 16:42:50.905911 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2026-01-20 16:42:50.905922 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2026-01-20 16:42:50.905929 | controller | ZUUL_CHANGES=rdo-jobs:master:refs/changes/88/58488/2^openstack-k8s-operators/ci-framework:main:refs/changes/51/3451/3b80a23c9439dd2e7554486894e6cc29bcabd667
2026-01-20 16:42:50.905938 | controller | PWD=/home/zuul
2026-01-20 16:42:50.905943 | controller | ZUUL_PIPELINE=github-check
2026-01-20 16:42:50.905949 | controller | LOGNAME=zuul
2026-01-20 16:42:50.906043 | controller | XDG_SESSION_TYPE=tty
2026-01-20 16:42:50.906053 | controller | _=/usr/bin/env
2026-01-20 16:42:50.906059 | controller | MOTD_SHOWN=pam
2026-01-20 16:42:50.906064 | controller | HOME=/home/zuul
2026-01-20 16:42:50.906069 | controller | LANG=en_US.UTF-8
2026-01-20 16:42:50.906075 | controller | SSH_CONNECTION=192.168.26.12 36538 192.168.26.219 22
2026-01-20 16:42:50.906081 | 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-01-20 16:42:50.906090 | controller | ZUUL_CHANGE_IDS=58488,2 3451,3b80a23c9439dd2e7554486894e6cc29bcabd667
2026-01-20 16:42:50.906095 | controller | WORKSPACE=/home/zuul/workspace
2026-01-20 16:42:50.906101 | controller | XDG_SESSION_CLASS=user
2026-01-20 16:42:50.906107 | controller | SELINUX_ROLE_REQUESTED=
2026-01-20 16:42:50.906113 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2026-01-20 16:42:50.906119 | controller | USER=zuul
2026-01-20 16:42:50.906124 | controller | ZUUL_VOTING=True
2026-01-20 16:42:50.906130 | controller | BUILD_TIMEOUT=1800000
2026-01-20 16:42:50.906135 | controller | SELINUX_USE_CURRENT_RANGE=
2026-01-20 16:42:50.906141 | controller | SHLVL=1
2026-01-20 16:42:50.906147 | controller | ZUUL_PATCHSET=3b80a23c9439dd2e7554486894e6cc29bcabd667
2026-01-20 16:42:50.906152 | controller | XDG_SESSION_ID=1
2026-01-20 16:42:50.906158 | controller | ZUUL_BRANCH=main
2026-01-20 16:42:50.906163 | controller | XDG_RUNTIME_DIR=/run/user/1000
2026-01-20 16:42:50.906169 | controller | SSH_CLIENT=192.168.26.12 36538 22
2026-01-20 16:42:50.906175 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2026-01-20 16:42:50.906180 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2026-01-20 16:42:50.906186 | controller | which_declare=declare -f
2026-01-20 16:42:50.906193 | 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-01-20 16:42:50.906199 | controller | SELINUX_LEVEL_REQUESTED=
2026-01-20 16:42:50.906204 | controller | ZUUL_CHANGE=3451
2026-01-20 16:42:50.906209 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2026-01-20 16:42:50.906215 | controller | ZUUL_UUID=4e813e18561b4a31ae159dbd9d8d0118
2026-01-20 16:42:50.906220 | controller | BASH_FUNC_which%%=() {  ( alias;
2026-01-20 16:42:50.906226 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2026-01-20 16:42:50.906232 | controller | }
2026-01-20 16:42:51.141082 | controller | ok: Runtime: 0:00:00.008628
2026-01-20 16:42:51.146938 | 
2026-01-20 16:42:51.147007 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2026-01-20 16:42:51.180780 | controller | skipping: Conditional result was False
2026-01-20 16:42:51.186911 | 
2026-01-20 16:42:51.186984 | TASK [Symlink /home/zuul-worker/workspace]
2026-01-20 16:42:51.757891 | controller | skipping: Conditional result was False
2026-01-20 16:42:51.763967 | 
2026-01-20 16:42:51.764038 | TASK [Ensure legacy workspace directory]
2026-01-20 16:42:52.016283 | controller | changed
2026-01-20 16:42:52.039467 | 
2026-01-20 16:42:52.039568 | PLAY RECAP
2026-01-20 16:42:52.039614 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2026-01-20 16:42:52.039637 | 
2026-01-20 16:42:52.131766 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2026-01-20 16:42:52.132525 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2026-01-20 16:42:52.664507 | 
2026-01-20 16:42:52.664628 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2026-01-20 16:42:52.687107 | 
2026-01-20 16:42:52.687193 | TASK [Create zuul-output directory]
2026-01-20 16:42:53.084512 | controller | changed
2026-01-20 16:42:53.090352 | 
2026-01-20 16:42:53.090429 | TASK [Slurp Zuul inventory test]
2026-01-20 16:42:53.367351 | controller -> localhost | ok
2026-01-20 16:42:53.373957 | 
2026-01-20 16:42:53.374026 | TASK [Save zuul inventory]
2026-01-20 16:42:54.636063 | controller | changed
2026-01-20 16:42:54.644022 | 
2026-01-20 16:42:54.644125 | TASK [Save zuul vars without the change_message]
2026-01-20 16:42:55.624584 | controller | changed
2026-01-20 16:42:55.643938 | 
2026-01-20 16:42:55.644017 | PLAY RECAP
2026-01-20 16:42:55.644066 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2026-01-20 16:42:55.644106 | 
2026-01-20 16:42:55.717785 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2026-01-20 16:42:55.718786 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2026-01-20 16:42:56.318288 | 
2026-01-20 16:42:56.318419 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2026-01-20 16:42:56.340188 | 
2026-01-20 16:42:56.340266 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2026-01-20 16:42:56.368808 | controller | ok
2026-01-20 16:42:56.387262 | 
2026-01-20 16:42:56.387369 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2026-01-20 16:42:56.420803 | controller | skipping: Conditional result was False
2026-01-20 16:42:56.426605 | 
2026-01-20 16:42:56.426676 | TASK [mirror-info-fork : Create /etc/ci]
2026-01-20 16:42:56.840108 | controller | ok
2026-01-20 16:42:56.846492 | 
2026-01-20 16:42:56.846619 | TASK [mirror-info-fork : Install ci_mirror script]
2026-01-20 16:42:57.837051 | controller | ok
2026-01-20 16:42:57.848254 | 
2026-01-20 16:42:57.848382 | TASK [Prepare workspace]
2026-01-20 16:42:57.866692 | controller | ok
2026-01-20 16:42:57.884632 | 
2026-01-20 16:42:57.884703 | TASK [prepare-workspace : Start zuul_console daemon.]
2026-01-20 16:42:58.231825 | controller | ok
2026-01-20 16:42:58.242414 | 
2026-01-20 16:42:58.242540 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2026-01-20 16:43:00.990701 | controller | Output suppressed because no_log was given
2026-01-20 16:43:01.000315 | 
2026-01-20 16:43:01.000392 | LOOP [Create zuul-output directory]
2026-01-20 16:43:01.259003 | controller | changed: "/home/zuul/ci-framework-data/logs"
2026-01-20 16:43:01.481657 | controller | ok: "/home/zuul/zuul-output/logs"
2026-01-20 16:43:01.495083 | 
2026-01-20 16:43:01.495202 | TASK [Install required packages]
2026-01-20 16:43:18.380804 | controller | ok: Nothing to do
2026-01-20 16:43:18.386073 | 
2026-01-20 16:43:18.386149 | TASK [Install venv]
2026-01-20 16:44:18.107443 | controller | changed
2026-01-20 16:44:18.134661 | 
2026-01-20 16:44:18.134762 | PLAY RECAP
2026-01-20 16:44:18.135304 | controller | ok: 7 changed: 3 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2026-01-20 16:44:18.135358 | 
2026-01-20 16:44:18.223785 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2026-01-20 16:44:18.224598 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2026-01-20 16:44:18.787832 | 
2026-01-20 16:44:18.787942 | PLAY [Run ci/playbooks/molecule-test.yml]
2026-01-20 16:44:18.809412 | 
2026-01-20 16:44:18.809513 | TASK [Gather required facts]
2026-01-20 16:44:19.357468 | controller | ok
2026-01-20 16:44:19.363045 | 
2026-01-20 16:44:19.363140 | TASK [Load environment var if instructed to]
2026-01-20 16:44:19.387068 | controller | skipping: Conditional result was False
2026-01-20 16:44:19.392698 | 
2026-01-20 16:44:19.392771 | TASK [Ensure group_vars dir exists]
2026-01-20 16:44:19.763011 | controller | ok
2026-01-20 16:44:19.768378 | 
2026-01-20 16:44:19.768448 | TASK [Print related variables]
2026-01-20 16:44:19.797614 | controller | ok:
2026-01-20 16:44:19.797765 | controller | mol_config_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config_local.yml
2026-01-20 16:44:19.797797 | controller | roles_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/sushy_emulator
2026-01-20 16:44:19.802664 | 
2026-01-20 16:44:19.802735 | TASK [Run molecule]
2026-01-20 16:44:20.834219 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2026-01-20 16:44:20.909675 | controller | INFO     Performing prerun with role_name_check=0...
2026-01-20 16:44:37.671590 | 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-01-20 16:44:37.672050 | 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-01-20 16:44:37.672460 | 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-01-20 16:44:37.672926 | 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-01-20 16:44:37.673379 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+3b80a23c was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 1.0.0+3b80a23c (/home/zuul/.ansible/collections/ansible_collections).
2026-01-20 16:44:37.673859 | 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-01-20 16:44:37.674290 | 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-01-20 16:44:37.674733 | 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-01-20 16:44:37.675184 | 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-01-20 16:44:37.675628 | 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-01-20 16:44:37.676095 | 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-01-20 16:44:37.676546 | 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-01-20 16:44:37.676994 | 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-01-20 16:44:37.677439 | 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-01-20 16:44:37.677917 | 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-01-20 16:44:37.687467 | controller | INFO     Running default > prepare
2026-01-20 16:44:38.354464 | controller |
2026-01-20 16:44:38.354549 | controller | PLAY [Prepare] *****************************************************************
2026-01-20 16:44:38.354561 | controller |
2026-01-20 16:44:38.354679 | controller | TASK [Gathering Facts] *********************************************************
2026-01-20 16:44:38.354814 | controller | Tuesday 20 January 2026  16:44:38 +0000 (0:00:00.013)       0:00:00.013 *******
2026-01-20 16:44:39.229271 | controller | ok: [instance]
2026-01-20 16:44:39.229348 | controller |
2026-01-20 16:44:39.229483 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2026-01-20 16:44:39.229632 | controller | Tuesday 20 January 2026  16:44:39 +0000 (0:00:00.875)       0:00:00.888 *******
2026-01-20 16:44:39.247143 | controller | skipping: [instance]
2026-01-20 16:44:39.247243 | controller |
2026-01-20 16:44:39.247371 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2026-01-20 16:44:39.247526 | controller | Tuesday 20 January 2026  16:44:39 +0000 (0:00:00.018)       0:00:00.907 *******
2026-01-20 16:44:39.289183 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2026-01-20 16:44:39.289311 | controller |
2026-01-20 16:44:39.289385 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2026-01-20 16:44:39.289511 | controller | Tuesday 20 January 2026  16:44:39 +0000 (0:00:00.041)       0:00:00.948 *******
2026-01-20 16:44:39.572746 | controller | ok: [instance]
2026-01-20 16:44:39.572830 | controller |
2026-01-20 16:44:39.572940 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2026-01-20 16:44:39.573047 | controller | Tuesday 20 January 2026  16:44:39 +0000 (0:00:00.283)       0:00:01.232 *******
2026-01-20 16:44:39.890762 | controller | ok: [instance]
2026-01-20 16:44:39.890841 | controller |
2026-01-20 16:44:39.890948 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2026-01-20 16:44:39.891051 | controller | Tuesday 20 January 2026  16:44:39 +0000 (0:00:00.318)       0:00:01.550 *******
2026-01-20 16:44:40.597104 | controller | ok: [instance] => (item=ubi-9-appstream)
2026-01-20 16:44:40.597150 | controller | ok: [instance] => (item=ubi-9-baseos)
2026-01-20 16:44:40.597268 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2026-01-20 16:44:40.597367 | controller |
2026-01-20 16:44:40.597472 | controller | TASK [Deploy repo-setup] *******************************************************
2026-01-20 16:44:40.597580 | controller | Tuesday 20 January 2026  16:44:40 +0000 (0:00:00.706)       0:00:02.256 *******
2026-01-20 16:44:40.658817 | controller |
2026-01-20 16:44:40.658950 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2026-01-20 16:44:40.659055 | controller | Tuesday 20 January 2026  16:44:40 +0000 (0:00:00.061)       0:00:02.318 *******
2026-01-20 16:44:41.210056 | controller | changed: [instance] => (item=tmp)
2026-01-20 16:44:41.210113 | controller | changed: [instance] => (item=artifacts/repositories)
2026-01-20 16:44:41.210223 | controller | changed: [instance] => (item=venv/repo_setup)
2026-01-20 16:44:41.210318 | controller |
2026-01-20 16:44:41.210422 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2026-01-20 16:44:41.210504 | controller | Tuesday 20 January 2026  16:44:41 +0000 (0:00:00.550)       0:00:02.869 *******
2026-01-20 16:44:42.055734 | controller | ok: [instance]
2026-01-20 16:44:42.056124 | controller |
2026-01-20 16:44:43.150894 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2026-01-20 16:44:43.150947 | controller | Tuesday 20 January 2026  16:44:42 +0000 (0:00:00.845)       0:00:03.715 *******
2026-01-20 16:44:43.150964 | controller | changed: [instance]
2026-01-20 16:44:51.109337 | controller |
2026-01-20 16:44:51.109378 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2026-01-20 16:44:51.109387 | controller | Tuesday 20 January 2026  16:44:43 +0000 (0:00:01.094)       0:00:04.810 *******
2026-01-20 16:44:51.109397 | controller | changed: [instance]
2026-01-20 16:44:51.817884 | controller |
2026-01-20 16:44:51.817922 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2026-01-20 16:44:51.817931 | controller | Tuesday 20 January 2026  16:44:51 +0000 (0:00:07.958)       0:00:12.768 *******
2026-01-20 16:44:51.817941 | controller | changed: [instance]
2026-01-20 16:44:51.817966 | controller |
2026-01-20 16:44:51.818147 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2026-01-20 16:44:51.841162 | controller | Tuesday 20 January 2026  16:44:51 +0000 (0:00:00.708)       0:00:13.477 *******
2026-01-20 16:44:51.841189 | controller | skipping: [instance]
2026-01-20 16:44:52.635433 | controller |
2026-01-20 16:44:52.635467 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2026-01-20 16:44:52.635475 | controller | Tuesday 20 January 2026  16:44:51 +0000 (0:00:00.023)       0:00:13.500 *******
2026-01-20 16:44:52.635485 | controller | changed: [instance]
2026-01-20 16:44:52.671840 | controller |
2026-01-20 16:44:52.671873 | controller | TASK [repo_setup : Get component repo] *****************************************
2026-01-20 16:44:52.671882 | controller | Tuesday 20 January 2026  16:44:52 +0000 (0:00:00.793)       0:00:14.294 *******
2026-01-20 16:44:52.671892 | controller | skipping: [instance]
2026-01-20 16:44:52.671917 | controller |
2026-01-20 16:44:52.671925 | controller | TASK [repo_setup : Rename component repo] **************************************
2026-01-20 16:44:52.672063 | controller | Tuesday 20 January 2026  16:44:52 +0000 (0:00:00.036)       0:00:14.331 *******
2026-01-20 16:44:52.709928 | controller | skipping: [instance]
2026-01-20 16:44:52.710131 | controller |
2026-01-20 16:44:52.710155 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2026-01-20 16:44:52.710166 | controller | Tuesday 20 January 2026  16:44:52 +0000 (0:00:00.037)       0:00:14.369 *******
2026-01-20 16:44:52.746639 | controller | skipping: [instance]
2026-01-20 16:44:53.284146 | controller |
2026-01-20 16:44:53.284190 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2026-01-20 16:44:53.284199 | controller | Tuesday 20 January 2026  16:44:52 +0000 (0:00:00.037)       0:00:14.406 *******
2026-01-20 16:44:53.284209 | controller | changed: [instance]
2026-01-20 16:44:53.724942 | controller |
2026-01-20 16:44:53.724983 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2026-01-20 16:44:53.724993 | controller | Tuesday 20 January 2026  16:44:53 +0000 (0:00:00.536)       0:00:14.942 *******
2026-01-20 16:44:53.725006 | controller | changed: [instance]
2026-01-20 16:44:53.754832 | controller |
2026-01-20 16:44:53.754864 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2026-01-20 16:44:53.754872 | controller | Tuesday 20 January 2026  16:44:53 +0000 (0:00:00.441)       0:00:15.384 *******
2026-01-20 16:44:53.754882 | controller | skipping: [instance]
2026-01-20 16:44:53.754905 | controller |
2026-01-20 16:44:53.755088 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2026-01-20 16:44:53.784552 | controller | Tuesday 20 January 2026  16:44:53 +0000 (0:00:00.030)       0:00:15.414 *******
2026-01-20 16:44:53.784578 | controller | skipping: [instance]
2026-01-20 16:44:53.813460 | controller |
2026-01-20 16:44:53.813477 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2026-01-20 16:44:53.813484 | controller | Tuesday 20 January 2026  16:44:53 +0000 (0:00:00.029)       0:00:15.444 *******
2026-01-20 16:44:53.813493 | controller | skipping: [instance]
2026-01-20 16:44:53.850851 | controller |
2026-01-20 16:44:53.850913 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2026-01-20 16:44:53.850924 | controller | Tuesday 20 January 2026  16:44:53 +0000 (0:00:00.028)       0:00:15.473 *******
2026-01-20 16:44:53.850941 | controller | ok: [instance]
2026-01-20 16:44:53.850982 | controller |
2026-01-20 16:44:53.850993 | controller | TASK [repo_setup : Create download directory] **********************************
2026-01-20 16:44:53.851062 | controller | Tuesday 20 January 2026  16:44:53 +0000 (0:00:00.037)       0:00:15.510 *******
2026-01-20 16:44:53.878703 | controller | skipping: [instance]
2026-01-20 16:44:53.905333 | controller |
2026-01-20 16:44:53.905354 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2026-01-20 16:44:53.905361 | controller | Tuesday 20 January 2026  16:44:53 +0000 (0:00:00.027)       0:00:15.538 *******
2026-01-20 16:44:53.905378 | controller | skipping: [instance]
2026-01-20 16:44:53.934945 | controller |
2026-01-20 16:44:53.934969 | controller | TASK [Download the RPM] ********************************************************
2026-01-20 16:44:53.934979 | controller | Tuesday 20 January 2026  16:44:53 +0000 (0:00:00.026)       0:00:15.565 *******
2026-01-20 16:44:53.934990 | controller | skipping: [instance]
2026-01-20 16:44:53.935164 | controller |
2026-01-20 16:44:53.935341 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2026-01-20 16:44:53.935508 | controller | Tuesday 20 January 2026  16:44:53 +0000 (0:00:00.029)       0:00:15.594 *******
2026-01-20 16:44:53.962535 | controller | skipping: [instance]
2026-01-20 16:44:53.962714 | controller |
2026-01-20 16:44:53.962938 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2026-01-20 16:44:53.963089 | controller | Tuesday 20 January 2026  16:44:53 +0000 (0:00:00.027)       0:00:15.622 *******
2026-01-20 16:44:53.989036 | controller | skipping: [instance]
2026-01-20 16:44:53.989227 | controller |
2026-01-20 16:44:53.989417 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2026-01-20 16:44:53.989622 | controller | Tuesday 20 January 2026  16:44:53 +0000 (0:00:00.026)       0:00:15.648 *******
2026-01-20 16:44:54.018870 | controller | skipping: [instance]
2026-01-20 16:44:54.019063 | controller |
2026-01-20 16:44:54.019249 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2026-01-20 16:44:54.019396 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.029)       0:00:15.678 *******
2026-01-20 16:44:54.046133 | controller | skipping: [instance]
2026-01-20 16:44:54.046291 | controller |
2026-01-20 16:44:54.046431 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2026-01-20 16:44:54.046627 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.027)       0:00:15.706 *******
2026-01-20 16:44:54.246896 | controller | ok: [instance]
2026-01-20 16:44:54.247029 | controller |
2026-01-20 16:44:54.247241 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2026-01-20 16:44:54.247349 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.200)       0:00:15.906 *******
2026-01-20 16:44:54.459252 | controller | changed: [instance]
2026-01-20 16:44:54.702458 | controller |
2026-01-20 16:44:54.702493 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2026-01-20 16:44:54.702502 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.212)       0:00:16.118 *******
2026-01-20 16:44:54.702512 | controller | changed: [instance]
2026-01-20 16:44:54.722561 | controller |
2026-01-20 16:44:54.722586 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2026-01-20 16:44:54.722593 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.243)       0:00:16.361 *******
2026-01-20 16:44:54.722603 | controller | skipping: [instance]
2026-01-20 16:44:54.743317 | controller |
2026-01-20 16:44:54.743339 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2026-01-20 16:44:54.743346 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.020)       0:00:16.382 *******
2026-01-20 16:44:54.743355 | controller | skipping: [instance]
2026-01-20 16:44:54.765228 | controller |
2026-01-20 16:44:54.765252 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2026-01-20 16:44:54.765260 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.020)       0:00:16.403 *******
2026-01-20 16:44:54.765276 | controller | skipping: [instance]
2026-01-20 16:44:54.786904 | controller |
2026-01-20 16:44:54.786944 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2026-01-20 16:44:54.786953 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.021)       0:00:16.424 *******
2026-01-20 16:44:54.786969 | controller | skipping: [instance]
2026-01-20 16:44:54.786997 | controller |
2026-01-20 16:44:54.787006 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2026-01-20 16:44:54.787113 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.021)       0:00:16.446 *******
2026-01-20 16:44:54.807954 | controller | skipping: [instance]
2026-01-20 16:44:54.808027 | controller |
2026-01-20 16:44:54.808049 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2026-01-20 16:44:54.808075 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.020)       0:00:16.467 *******
2026-01-20 16:44:54.829402 | controller | skipping: [instance]
2026-01-20 16:44:54.844163 | controller |
2026-01-20 16:44:54.844185 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2026-01-20 16:44:54.844195 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.021)       0:00:16.488 *******
2026-01-20 16:44:54.844206 | controller | skipping: [instance]
2026-01-20 16:44:54.844373 | controller |
2026-01-20 16:44:54.844517 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2026-01-20 16:44:54.844674 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.015)       0:00:16.504 *******
2026-01-20 16:44:54.872248 | controller | skipping: [instance]
2026-01-20 16:44:54.872573 | controller |
2026-01-20 16:44:54.872803 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2026-01-20 16:44:54.872955 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.028)       0:00:16.532 *******
2026-01-20 16:44:54.887893 | controller | skipping: [instance]
2026-01-20 16:44:54.888081 | controller |
2026-01-20 16:44:54.888257 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2026-01-20 16:44:54.888431 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.015)       0:00:16.547 *******
2026-01-20 16:44:54.908877 | controller | skipping: [instance]
2026-01-20 16:44:54.909068 | controller |
2026-01-20 16:44:54.909245 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2026-01-20 16:44:54.909415 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.020)       0:00:16.568 *******
2026-01-20 16:44:54.939126 | controller | skipping: [instance]
2026-01-20 16:44:54.939333 | controller |
2026-01-20 16:44:54.939515 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2026-01-20 16:44:54.939678 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.030)       0:00:16.599 *******
2026-01-20 16:44:54.968416 | controller | skipping: [instance]
2026-01-20 16:44:54.968596 | controller |
2026-01-20 16:44:54.968792 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2026-01-20 16:44:54.968948 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.029)       0:00:16.628 *******
2026-01-20 16:44:55.000172 | controller | skipping: [instance]
2026-01-20 16:44:55.000348 | controller |
2026-01-20 16:44:55.000518 | controller | TASK [test_deps : Install additional packages] *********************************
2026-01-20 16:44:55.000686 | controller | Tuesday 20 January 2026  16:44:54 +0000 (0:00:00.031)       0:00:16.660 *******
2026-01-20 16:44:55.029169 | controller | skipping: [instance]
2026-01-20 16:44:55.029331 | controller |
2026-01-20 16:44:55.029482 | controller | TASK [test_deps : Install selinux python libs] *********************************
2026-01-20 16:44:55.029684 | controller | Tuesday 20 January 2026  16:44:55 +0000 (0:00:00.028)       0:00:16.689 *******
2026-01-20 16:45:43.348930 | controller | ok: [instance]
2026-01-20 16:45:43.348975 | controller |
2026-01-20 16:45:43.348983 | controller | TASK [test_deps : Install python yaml libs] ************************************
2026-01-20 16:45:43.348992 | controller | Tuesday 20 January 2026  16:45:43 +0000 (0:00:48.318)       0:01:05.008 *******
2026-01-20 16:45:44.618230 | controller | ok: [instance]
2026-01-20 16:45:44.650337 | controller |
2026-01-20 16:45:44.650357 | controller | TASK [test_deps : Install extra packages] **************************************
2026-01-20 16:45:44.650365 | controller | Tuesday 20 January 2026  16:45:44 +0000 (0:00:01.269)       0:01:06.277 *******
2026-01-20 16:45:44.650374 | controller | skipping: [instance]
2026-01-20 16:48:24.255646 | controller |
2026-01-20 16:48:24.255681 | controller | TASK [Ensure CRC is started] ***************************************************
2026-01-20 16:48:24.255689 | controller | Tuesday 20 January 2026  16:45:44 +0000 (0:00:00.032)       0:01:06.309 *******
2026-01-20 16:48:24.255700 | controller | changed: [instance]
2026-01-20 16:48:24.576232 | controller |
2026-01-20 16:48:24.576266 | controller | TASK [Inject crc hostname/IP in hosts] *****************************************
2026-01-20 16:48:24.576275 | controller | Tuesday 20 January 2026  16:48:24 +0000 (0:02:39.604)       0:03:45.914 *******
2026-01-20 16:48:24.576286 | controller | changed: [instance]
2026-01-20 16:48:24.576405 | controller |
2026-01-20 16:48:24.576419 | controller | PLAY RECAP *********************************************************************
2026-01-20 16:48:24.576438 | controller | instance                   : ok=21   changed=11   unreachable=0    failed=0    skipped=30   rescued=0    ignored=0
2026-01-20 16:48:24.576453 | controller |
2026-01-20 16:48:24.576925 | controller | Tuesday 20 January 2026  16:48:24 +0000 (0:00:00.320)       0:03:46.235 *******
2026-01-20 16:48:24.576980 | controller | ===============================================================================
2026-01-20 16:48:24.576989 | controller | Ensure CRC is started ------------------------------------------------- 159.60s
2026-01-20 16:48:24.576995 | controller | test_deps : Install selinux python libs -------------------------------- 48.32s
2026-01-20 16:48:24.577000 | controller | repo_setup : Initialize python venv and install requirements ------------ 7.96s
2026-01-20 16:48:24.577007 | controller | test_deps : Install python yaml libs ------------------------------------ 1.27s
2026-01-20 16:48:24.577315 | controller | repo_setup : Get repo-setup repository ---------------------------------- 1.09s
2026-01-20 16:48:24.577528 | controller | Gathering Facts --------------------------------------------------------- 0.88s
2026-01-20 16:48:24.577538 | controller | repo_setup : Make sure git-core package is installed -------------------- 0.85s
2026-01-20 16:48:24.577543 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.79s
2026-01-20 16:48:24.577551 | controller | repo_setup : Install repo-setup package --------------------------------- 0.71s
2026-01-20 16:48:24.577612 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.71s
2026-01-20 16:48:24.577622 | controller | repo_setup : Ensure directories are present ----------------------------- 0.55s
2026-01-20 16:48:24.577813 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.54s
2026-01-20 16:48:24.578259 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.44s
2026-01-20 16:48:24.578274 | controller | Inject crc hostname/IP in hosts ----------------------------------------- 0.32s
2026-01-20 16:48:24.578465 | controller | test_deps : Disable ubi host subscription-manager integration ----------- 0.32s
2026-01-20 16:48:24.578474 | controller | test_deps : Detect mirrors file ----------------------------------------- 0.28s
2026-01-20 16:48:24.578479 | controller | repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist) --- 0.24s
2026-01-20 16:48:24.578485 | controller | repo_setup : Use RDO proxy mirrors -------------------------------------- 0.21s
2026-01-20 16:48:24.578492 | controller | repo_setup : Check for /etc/ci/mirror_info.sh --------------------------- 0.20s
2026-01-20 16:48:24.637996 | controller | Deploy repo-setup ------------------------------------------------------- 0.06s
2026-01-20 16:48:24.638037 | controller | INFO     Running default > converge
2026-01-20 16:48:25.094322 | controller |
2026-01-20 16:48:25.984721 | controller | PLAY [Converge] ****************************************************************
2026-01-20 16:48:25.984773 | controller |
2026-01-20 16:48:25.984785 | controller | TASK [Gathering Facts] *********************************************************
2026-01-20 16:48:25.984791 | controller | Tuesday 20 January 2026  16:48:25 +0000 (0:00:00.017)       0:00:00.017 *******
2026-01-20 16:48:25.984803 | controller | ok: [instance]
2026-01-20 16:48:26.006348 | controller |
2026-01-20 16:48:26.006389 | controller | TASK [Load networking_definition] **********************************************
2026-01-20 16:48:26.006398 | controller | Tuesday 20 January 2026  16:48:25 +0000 (0:00:00.891)       0:00:00.908 *******
2026-01-20 16:48:26.006409 | controller | ok: [instance]
2026-01-20 16:48:26.032322 | controller |
2026-01-20 16:48:26.032359 | controller | TASK [Check if new ssh keypair exists] *****************************************
2026-01-20 16:48:26.032367 | controller | Tuesday 20 January 2026  16:48:26 +0000 (0:00:00.021)       0:00:00.930 *******
2026-01-20 16:48:26.032380 | controller |
2026-01-20 16:48:26.032430 | controller | TASK [recognize_ssh_keypair : Check if id_ed25519 key exists] ******************
2026-01-20 16:48:26.032549 | controller | Tuesday 20 January 2026  16:48:26 +0000 (0:00:00.026)       0:00:00.956 *******
2026-01-20 16:48:26.329278 | controller | ok: [instance]
2026-01-20 16:48:26.329351 | controller |
2026-01-20 16:48:26.329459 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair exists] ******************
2026-01-20 16:48:26.329562 | controller | Tuesday 20 January 2026  16:48:26 +0000 (0:00:00.297)       0:00:01.253 *******
2026-01-20 16:48:26.349400 | controller | ok: [instance]
2026-01-20 16:48:26.349488 | controller |
2026-01-20 16:48:26.349610 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair does not exists] *********
2026-01-20 16:48:26.349742 | controller | Tuesday 20 January 2026  16:48:26 +0000 (0:00:00.020)       0:00:01.273 *******
2026-01-20 16:48:26.375231 | controller | skipping: [instance]
2026-01-20 16:48:26.375277 | controller |
2026-01-20 16:48:26.375394 | controller | TASK [Add the crc host dynamically] ********************************************
2026-01-20 16:48:26.375491 | controller | Tuesday 20 January 2026  16:48:26 +0000 (0:00:00.025)       0:00:01.299 *******
2026-01-20 16:48:26.396560 | controller | changed: [instance]
2026-01-20 16:48:26.396606 | controller |
2026-01-20 16:48:26.396736 | controller | TASK [Add ansible_host entry to "controller-0"] ********************************
2026-01-20 16:48:26.396893 | controller | Tuesday 20 January 2026  16:48:26 +0000 (0:00:00.021)       0:00:01.321 *******
2026-01-20 16:48:26.422741 | controller | changed: [instance]
2026-01-20 16:48:26.422832 | controller |
2026-01-20 16:48:26.422959 | controller | TASK [Add host key to controller-0] ********************************************
2026-01-20 16:48:26.423055 | controller | Tuesday 20 January 2026  16:48:26 +0000 (0:00:00.026)       0:00:01.347 *******
2026-01-20 16:48:26.755945 | controller | changed: [instance]
2026-01-20 16:48:26.756030 | controller |
2026-01-20 16:48:26.756163 | controller | TASK [libvirt_manager : Ensure output directory exists] ************************
2026-01-20 16:48:26.756287 | controller | Tuesday 20 January 2026  16:48:26 +0000 (0:00:00.333)       0:00:01.680 *******
2026-01-20 16:48:27.052141 | controller | ok: [instance]
2026-01-20 16:48:27.052239 | controller |
2026-01-20 16:48:27.052374 | controller | TASK [libvirt_manager : Get vmx/svm extensions from /proc/cpuinfo] *************
2026-01-20 16:48:27.052466 | controller | Tuesday 20 January 2026  16:48:27 +0000 (0:00:00.296)       0:00:01.976 *******
2026-01-20 16:48:27.232838 | controller | changed: [instance]
2026-01-20 16:48:27.232916 | controller |
2026-01-20 16:48:27.233031 | controller | TASK [libvirt_manager : Check if KVM is enabled] *******************************
2026-01-20 16:48:27.233190 | controller | Tuesday 20 January 2026  16:48:27 +0000 (0:00:00.180)       0:00:02.157 *******
2026-01-20 16:48:27.415576 | controller | ok: [instance]
2026-01-20 16:48:27.415639 | controller |
2026-01-20 16:48:27.416198 | controller | TASK [libvirt_manager : Fail if KVM not enabled] *******************************
2026-01-20 16:48:27.441831 | controller | Tuesday 20 January 2026  16:48:27 +0000 (0:00:00.182)       0:00:02.339 *******
2026-01-20 16:48:27.441869 | controller | skipping: [instance]
2026-01-20 16:48:27.441934 | controller |
2026-01-20 16:48:27.442060 | controller | TASK [libvirt_manager : Check if VMX virtualization] ***************************
2026-01-20 16:48:27.442214 | controller | Tuesday 20 January 2026  16:48:27 +0000 (0:00:00.026)       0:00:02.366 *******
2026-01-20 16:48:27.459560 | controller | skipping: [instance]
2026-01-20 16:48:27.459654 | controller |
2026-01-20 16:48:27.459779 | controller | TASK [libvirt_manager : Check if SVM virtualization] ***************************
2026-01-20 16:48:27.459885 | controller | Tuesday 20 January 2026  16:48:27 +0000 (0:00:00.017)       0:00:02.384 *******
2026-01-20 16:48:27.478935 | controller | ok: [instance]
2026-01-20 16:48:27.479042 | controller |
2026-01-20 16:48:27.479177 | controller | TASK [libvirt_manager : Enable VMX virtualization] *****************************
2026-01-20 16:48:27.479301 | controller | Tuesday 20 January 2026  16:48:27 +0000 (0:00:00.019)       0:00:02.403 *******
2026-01-20 16:48:27.509781 | controller | skipping: [instance]
2026-01-20 16:48:27.509868 | controller |
2026-01-20 16:48:27.509995 | controller | TASK [libvirt_manager : Install packages required for using KVM] ***************
2026-01-20 16:48:27.510130 | controller | Tuesday 20 January 2026  16:48:27 +0000 (0:00:00.030)       0:00:02.434 *******
2026-01-20 16:48:40.639428 | controller | changed: [instance]
2026-01-20 16:48:40.639499 | controller |
2026-01-20 16:48:40.639607 | controller | TASK [libvirt_manager : Create rules.d polkit folder] **************************
2026-01-20 16:48:40.639711 | controller | Tuesday 20 January 2026  16:48:40 +0000 (0:00:13.129)       0:00:15.563 *******
2026-01-20 16:48:40.850226 | controller | changed: [instance]
2026-01-20 16:48:40.850294 | controller |
2026-01-20 16:48:40.851880 | controller | TASK [libvirt_manager : Enable UNIX socket PolicyKit auth] *********************
2026-01-20 16:48:40.851984 | controller | Tuesday 20 January 2026  16:48:40 +0000 (0:00:00.210)       0:00:15.774 *******
2026-01-20 16:48:41.350874 | controller | changed: [instance]
2026-01-20 16:48:41.350969 | controller |
2026-01-20 16:48:41.351114 | controller | TASK [libvirt_manager : Restart service polkit service] ************************
2026-01-20 16:48:41.351183 | controller | Tuesday 20 January 2026  16:48:41 +0000 (0:00:00.500)       0:00:16.275 *******
2026-01-20 16:48:41.943989 | controller | changed: [instance]
2026-01-20 16:48:41.944142 | controller |
2026-01-20 16:48:41.944188 | controller | TASK [libvirt_manager : Remove directory for service override] *****************
2026-01-20 16:48:41.944292 | controller | Tuesday 20 January 2026  16:48:41 +0000 (0:00:00.593)       0:00:16.868 *******
2026-01-20 16:48:42.143296 | controller | ok: [instance]
2026-01-20 16:48:42.143372 | controller |
2026-01-20 16:48:42.143493 | controller | TASK [libvirt_manager : Reload systemctl and start/enable virtproxyd.service] ***
2026-01-20 16:48:42.143595 | controller | Tuesday 20 January 2026  16:48:42 +0000 (0:00:00.199)       0:00:17.067 *******
2026-01-20 16:48:42.831396 | controller | ok: [instance]
2026-01-20 16:48:42.831454 | controller |
2026-01-20 16:48:42.831589 | controller | TASK [libvirt_manager : Ensure firewalld service is up] ************************
2026-01-20 16:48:42.831693 | controller | Tuesday 20 January 2026  16:48:42 +0000 (0:00:00.688)       0:00:17.755 *******
2026-01-20 16:48:43.792913 | controller | changed: [instance]
2026-01-20 16:48:43.792960 | controller |
2026-01-20 16:48:43.793226 | controller | TASK [libvirt_manager : Ensure libvirt modular driver daemons are started.] ****
2026-01-20 16:48:43.876862 | controller | Tuesday 20 January 2026  16:48:43 +0000 (0:00:00.961)       0:00:18.717 *******
2026-01-20 16:48:43.876898 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=qemu)
2026-01-20 16:48:43.876926 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=interface)
2026-01-20 16:48:43.876933 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=network)
2026-01-20 16:48:43.876940 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nodedev)
2026-01-20 16:48:43.877057 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nwfilter)
2026-01-20 16:48:43.877115 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=secret)
2026-01-20 16:48:43.877401 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=storage)
2026-01-20 16:48:43.877434 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=proxy)
2026-01-20 16:48:43.877444 | controller |
2026-01-20 16:48:43.877578 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for qemu.] *********
2026-01-20 16:48:43.877919 | controller | Tuesday 20 January 2026  16:48:43 +0000 (0:00:00.083)       0:00:18.800 *******
2026-01-20 16:48:44.208591 | controller | ok: [instance]
2026-01-20 16:48:44.533299 | controller |
2026-01-20 16:48:44.533343 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for qemu.] **********
2026-01-20 16:48:44.533353 | controller | Tuesday 20 January 2026  16:48:44 +0000 (0:00:00.331)       0:00:19.132 *******
2026-01-20 16:48:44.533366 | controller | ok: [instance]
2026-01-20 16:48:44.533389 | controller |
2026-01-20 16:48:44.533463 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for qemu.] **************
2026-01-20 16:48:44.533564 | controller | Tuesday 20 January 2026  16:48:44 +0000 (0:00:00.324)       0:00:19.457 *******
2026-01-20 16:48:44.867609 | controller | ok: [instance]
2026-01-20 16:48:44.867661 | controller |
2026-01-20 16:48:44.867825 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for interface.] ****
2026-01-20 16:48:44.867956 | controller | Tuesday 20 January 2026  16:48:44 +0000 (0:00:00.334)       0:00:19.791 *******
2026-01-20 16:48:45.195675 | controller | ok: [instance]
2026-01-20 16:48:45.195726 | controller |
2026-01-20 16:48:45.195873 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for interface.] *****
2026-01-20 16:48:45.195975 | controller | Tuesday 20 January 2026  16:48:45 +0000 (0:00:00.328)       0:00:20.120 *******
2026-01-20 16:48:45.529828 | controller | ok: [instance]
2026-01-20 16:48:45.529884 | controller |
2026-01-20 16:48:45.529985 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for interface.] *********
2026-01-20 16:48:45.530087 | controller | Tuesday 20 January 2026  16:48:45 +0000 (0:00:00.334)       0:00:20.454 *******
2026-01-20 16:48:45.868302 | controller | ok: [instance]
2026-01-20 16:48:45.868702 | controller |
2026-01-20 16:48:46.229357 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for network.] ******
2026-01-20 16:48:46.229393 | controller | Tuesday 20 January 2026  16:48:45 +0000 (0:00:00.338)       0:00:20.792 *******
2026-01-20 16:48:46.229405 | controller | ok: [instance]
2026-01-20 16:48:46.595010 | controller |
2026-01-20 16:48:46.595071 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for network.] *******
2026-01-20 16:48:46.595080 | controller | Tuesday 20 January 2026  16:48:46 +0000 (0:00:00.360)       0:00:21.153 *******
2026-01-20 16:48:46.595091 | controller | ok: [instance]
2026-01-20 16:48:46.946166 | controller |
2026-01-20 16:48:46.946219 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for network.] ***********
2026-01-20 16:48:46.946232 | controller | Tuesday 20 January 2026  16:48:46 +0000 (0:00:00.365)       0:00:21.518 *******
2026-01-20 16:48:46.946243 | controller | ok: [instance]
2026-01-20 16:48:47.309489 | controller |
2026-01-20 16:48:47.309550 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nodedev.] ******
2026-01-20 16:48:47.309563 | controller | Tuesday 20 January 2026  16:48:46 +0000 (0:00:00.351)       0:00:21.869 *******
2026-01-20 16:48:47.309576 | controller | ok: [instance]
2026-01-20 16:48:47.309612 | controller |
2026-01-20 16:48:47.309626 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nodedev.] *******
2026-01-20 16:48:47.309716 | controller | Tuesday 20 January 2026  16:48:47 +0000 (0:00:00.363)       0:00:22.233 *******
2026-01-20 16:48:47.687486 | controller | ok: [instance]
2026-01-20 16:48:48.069422 | controller |
2026-01-20 16:48:48.069458 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nodedev.] ***********
2026-01-20 16:48:48.069481 | controller | Tuesday 20 January 2026  16:48:47 +0000 (0:00:00.377)       0:00:22.611 *******
2026-01-20 16:48:48.069494 | controller | ok: [instance]
2026-01-20 16:48:48.433375 | controller |
2026-01-20 16:48:48.433411 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nwfilter.] *****
2026-01-20 16:48:48.433419 | controller | Tuesday 20 January 2026  16:48:48 +0000 (0:00:00.382)       0:00:22.993 *******
2026-01-20 16:48:48.433429 | controller | ok: [instance]
2026-01-20 16:48:48.433640 | controller |
2026-01-20 16:48:48.433862 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nwfilter.] ******
2026-01-20 16:48:48.434054 | controller | Tuesday 20 January 2026  16:48:48 +0000 (0:00:00.364)       0:00:23.357 *******
2026-01-20 16:48:48.812077 | controller | ok: [instance]
2026-01-20 16:48:49.221388 | controller |
2026-01-20 16:48:49.221422 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nwfilter.] **********
2026-01-20 16:48:49.221430 | controller | Tuesday 20 January 2026  16:48:48 +0000 (0:00:00.374)       0:00:23.732 *******
2026-01-20 16:48:49.221440 | controller | ok: [instance]
2026-01-20 16:48:49.592401 | controller |
2026-01-20 16:48:49.592433 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for secret.] *******
2026-01-20 16:48:49.592442 | controller | Tuesday 20 January 2026  16:48:49 +0000 (0:00:00.408)       0:00:24.141 *******
2026-01-20 16:48:49.592452 | controller | ok: [instance]
2026-01-20 16:48:49.965872 | controller |
2026-01-20 16:48:49.965922 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for secret.] ********
2026-01-20 16:48:49.965937 | controller | Tuesday 20 January 2026  16:48:49 +0000 (0:00:00.375)       0:00:24.516 *******
2026-01-20 16:48:49.965954 | controller | ok: [instance]
2026-01-20 16:48:49.965995 | controller |
2026-01-20 16:48:49.966009 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for secret.] ************
2026-01-20 16:48:49.966039 | controller | Tuesday 20 January 2026  16:48:49 +0000 (0:00:00.370)       0:00:24.886 *******
2026-01-20 16:48:50.329497 | controller | ok: [instance]
2026-01-20 16:48:50.675736 | controller |
2026-01-20 16:48:50.675860 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for storage.] ******
2026-01-20 16:48:50.675871 | controller | Tuesday 20 January 2026  16:48:50 +0000 (0:00:00.366)       0:00:25.253 *******
2026-01-20 16:48:50.675894 | controller | ok: [instance]
2026-01-20 16:48:51.053911 | controller |
2026-01-20 16:48:51.053944 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for storage.] *******
2026-01-20 16:48:51.053952 | controller | Tuesday 20 January 2026  16:48:50 +0000 (0:00:00.346)       0:00:25.599 *******
2026-01-20 16:48:51.053962 | controller | ok: [instance]
2026-01-20 16:48:51.416467 | controller |
2026-01-20 16:48:51.416497 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for storage.] ***********
2026-01-20 16:48:51.416506 | controller | Tuesday 20 January 2026  16:48:51 +0000 (0:00:00.376)       0:00:25.976 *******
2026-01-20 16:48:51.416516 | controller | ok: [instance]
2026-01-20 16:48:51.767802 | controller |
2026-01-20 16:48:51.767833 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for proxy.] ********
2026-01-20 16:48:51.767842 | controller | Tuesday 20 January 2026  16:48:51 +0000 (0:00:00.361)       0:00:26.337 *******
2026-01-20 16:48:51.767853 | controller | ok: [instance]
2026-01-20 16:48:52.124852 | controller |
2026-01-20 16:48:52.124888 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for proxy.] *********
2026-01-20 16:48:52.124897 | controller | Tuesday 20 January 2026  16:48:51 +0000 (0:00:00.354)       0:00:26.691 *******
2026-01-20 16:48:52.124909 | controller | ok: [instance]
2026-01-20 16:48:52.470485 | controller |
2026-01-20 16:48:52.470582 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for proxy.] *************
2026-01-20 16:48:52.470593 | controller | Tuesday 20 January 2026  16:48:52 +0000 (0:00:00.357)       0:00:27.048 *******
2026-01-20 16:48:52.470615 | controller | ok: [instance]
2026-01-20 16:48:52.470666 | controller |
2026-01-20 16:48:52.470675 | controller | TASK [libvirt_manager : Manage service for older releases] *********************
2026-01-20 16:48:52.470857 | controller | Tuesday 20 January 2026  16:48:52 +0000 (0:00:00.346)       0:00:27.394 *******
2026-01-20 16:48:52.491562 | controller | skipping: [instance]
2026-01-20 16:48:52.491787 | controller |
2026-01-20 16:48:52.491809 | controller | TASK [libvirt_manager : Get libvirt group users] *******************************
2026-01-20 16:48:52.766424 | controller | Tuesday 20 January 2026  16:48:52 +0000 (0:00:00.020)       0:00:27.415 *******
2026-01-20 16:48:52.766551 | controller | ok: [instance]
2026-01-20 16:48:53.186665 | controller |
2026-01-20 16:48:53.186787 | controller | TASK [libvirt_manager : Add user if not exists in libvirt group] ***************
2026-01-20 16:48:53.186802 | controller | Tuesday 20 January 2026  16:48:52 +0000 (0:00:00.274)       0:00:27.690 *******
2026-01-20 16:48:53.186840 | controller | ok: [instance]
2026-01-20 16:48:53.549078 | controller |
2026-01-20 16:48:53.549246 | controller | TASK [libvirt_manager : Allow QEMU on home directory for the storage access] ***
2026-01-20 16:48:53.549264 | controller | Tuesday 20 January 2026  16:48:53 +0000 (0:00:00.419)       0:00:28.110 *******
2026-01-20 16:48:53.549299 | controller | changed: [instance]
2026-01-20 16:48:53.876179 | controller |
2026-01-20 16:48:53.876285 | controller | TASK [libvirt_manager : Inject system connection parameters in bashrc] *********
2026-01-20 16:48:53.876297 | controller | Tuesday 20 January 2026  16:48:53 +0000 (0:00:00.362)       0:00:28.472 *******
2026-01-20 16:48:53.876327 | controller | [WARNING]: Reset is not implemented for this connection
2026-01-20 16:48:53.889487 | controller | changed: [instance]
2026-01-20 16:48:53.969517 | controller |
2026-01-20 16:48:53.969597 | controller | TASK [libvirt_manager : Ensure we reload user env] *****************************
2026-01-20 16:48:53.969606 | controller | Tuesday 20 January 2026  16:48:53 +0000 (0:00:00.319)       0:00:28.792 *******
2026-01-20 16:48:53.969612 | controller |
2026-01-20 16:48:53.969618 | controller | TASK [Create virtual baremetal VMs] ********************************************
2026-01-20 16:48:53.969623 | controller | Tuesday 20 January 2026  16:48:53 +0000 (0:00:00.020)       0:00:28.813 *******
2026-01-20 16:48:53.969641 | controller |
2026-01-20 16:48:54.005392 | controller | TASK [libvirt_manager : Import layout generator if needed] *********************
2026-01-20 16:48:54.005466 | controller | Tuesday 20 January 2026  16:48:53 +0000 (0:00:00.080)       0:00:28.893 *******
2026-01-20 16:48:54.005490 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/generate_layout.yml for instance
2026-01-20 16:48:54.040838 | controller |
2026-01-20 16:48:54.040878 | controller | TASK [libvirt_manager : Chose right parameter for layout definition] ***********
2026-01-20 16:48:54.040890 | controller | Tuesday 20 January 2026  16:48:54 +0000 (0:00:00.035)       0:00:28.929 *******
2026-01-20 16:48:54.040906 | controller | ok: [instance]
2026-01-20 16:48:54.116320 | controller |
2026-01-20 16:48:54.116398 | controller | TASK [libvirt_manager : Patch the layout if needed] ****************************
2026-01-20 16:48:54.116408 | controller | Tuesday 20 January 2026  16:48:54 +0000 (0:00:00.035)       0:00:28.964 *******
2026-01-20 16:48:54.116426 | controller | skipping: [instance]
2026-01-20 16:48:54.594581 | controller |
2026-01-20 16:48:54.594617 | controller | TASK [libvirt_manager : Enable forwarding in the libvirt zone] *****************
2026-01-20 16:48:54.594626 | controller | Tuesday 20 January 2026  16:48:54 +0000 (0:00:00.075)       0:00:29.040 *******
2026-01-20 16:48:54.594637 | controller | changed: [instance]
2026-01-20 16:48:55.208409 | controller |
2026-01-20 16:48:55.208447 | controller | TASK [libvirt_manager : Enable masquerading for public traffic] ****************
2026-01-20 16:48:55.208461 | controller | Tuesday 20 January 2026  16:48:54 +0000 (0:00:00.478)       0:00:29.518 *******
2026-01-20 16:48:55.208471 | controller | changed: [instance]
2026-01-20 16:48:56.140200 | controller |
2026-01-20 16:48:56.140233 | controller | TASK [libvirt_manager : Ensure firewalld is restarts] **************************
2026-01-20 16:48:56.140242 | controller | Tuesday 20 January 2026  16:48:55 +0000 (0:00:00.601)       0:00:30.119 *******
2026-01-20 16:48:56.140252 | controller |
2026-01-20 16:48:56.140259 | controller | RUNNING HANDLER [libvirt_manager : Restart firewalld] **************************
2026-01-20 16:48:56.140264 | controller | Tuesday 20 January 2026  16:48:55 +0000 (0:00:00.012)       0:00:30.131 *******
2026-01-20 16:48:56.140277 | controller | changed: [instance]
2026-01-20 16:48:56.172166 | controller |
2026-01-20 16:48:56.172203 | controller | TASK [Deploy virtualbmc] *******************************************************
2026-01-20 16:48:56.172211 | controller | Tuesday 20 January 2026  16:48:56 +0000 (0:00:00.932)       0:00:31.064 *******
2026-01-20 16:48:56.172222 | controller | skipping: [instance]
2026-01-20 16:48:56.204665 | controller |
2026-01-20 16:48:56.204688 | controller | TASK [libvirt_manager : Let the project know we have vbmc available] ***********
2026-01-20 16:48:56.204695 | controller | Tuesday 20 January 2026  16:48:56 +0000 (0:00:00.032)       0:00:31.096 *******
2026-01-20 16:48:56.204705 | controller | skipping: [instance]
2026-01-20 16:48:56.799891 | controller |
2026-01-20 16:48:56.799926 | controller | TASK [libvirt_manager : Create needed workload directory] **********************
2026-01-20 16:48:56.799935 | controller | Tuesday 20 January 2026  16:48:56 +0000 (0:00:00.032)       0:00:31.128 *******
2026-01-20 16:48:56.799945 | controller | changed: [instance] => (item=workload)
2026-01-20 16:48:57.240822 | controller | changed: [instance] => (item=reproducer-inventory)
2026-01-20 16:48:57.240869 | controller | changed: [instance] => (item=volumes)
2026-01-20 16:48:57.240877 | controller |
2026-01-20 16:48:57.240883 | controller | TASK [libvirt_manager : Allow QEMU on workload directory] **********************
2026-01-20 16:48:57.240889 | controller | Tuesday 20 January 2026  16:48:56 +0000 (0:00:00.594)       0:00:31.723 *******
2026-01-20 16:48:57.240899 | controller | changed: [instance] => (item=workload)
2026-01-20 16:48:57.338901 | controller | changed: [instance] => (item=volumes)
2026-01-20 16:48:57.338957 | controller |
2026-01-20 16:48:57.338966 | controller | TASK [libvirt_manager : Generate networking data] ******************************
2026-01-20 16:48:57.338973 | controller | Tuesday 20 January 2026  16:48:57 +0000 (0:00:00.440)       0:00:32.164 *******
2026-01-20 16:48:57.338992 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/generate_networking_data.yml for instance
2026-01-20 16:48:57.339238 | controller |
2026-01-20 16:48:57.339456 | controller | TASK [libvirt_manager : Ensure fact is existing, and empty] ********************
2026-01-20 16:48:57.339666 | controller | Tuesday 20 January 2026  16:48:57 +0000 (0:00:00.097)       0:00:32.262 *******
2026-01-20 16:48:57.361040 | controller | ok: [instance]
2026-01-20 16:48:57.361254 | controller |
2026-01-20 16:48:57.361439 | controller | TASK [libvirt_manager : Check if we get an existing interfaces-info.yml] *******
2026-01-20 16:48:57.361634 | controller | Tuesday 20 January 2026  16:48:57 +0000 (0:00:00.023)       0:00:32.285 *******
2026-01-20 16:48:57.580366 | controller | ok: [instance]
2026-01-20 16:48:57.580636 | controller |
2026-01-20 16:48:57.580869 | controller | TASK [libvirt_manager : Load file if exists] ***********************************
2026-01-20 16:48:57.581090 | controller | Tuesday 20 January 2026  16:48:57 +0000 (0:00:00.215)       0:00:32.500 *******
2026-01-20 16:48:57.611053 | controller | skipping: [instance]
2026-01-20 16:48:57.611290 | controller |
2026-01-20 16:48:57.611487 | controller | TASK [libvirt_manager : Update fact with existing content] *********************
2026-01-20 16:48:57.611669 | controller | Tuesday 20 January 2026  16:48:57 +0000 (0:00:00.034)       0:00:32.535 *******
2026-01-20 16:48:57.643814 | controller | skipping: [instance]
2026-01-20 16:48:57.644037 | controller |
2026-01-20 16:48:57.644244 | controller | TASK [libvirt_manager : Generate VM list] **************************************
2026-01-20 16:48:57.644422 | controller | Tuesday 20 January 2026  16:48:57 +0000 (0:00:00.032)       0:00:32.567 *******
2026-01-20 16:48:57.701335 | controller | ok: [instance]
2026-01-20 16:48:57.701562 | controller |
2026-01-20 16:48:57.701804 | controller | TASK [libvirt_manager : Generate/update mapping all nodes] *********************
2026-01-20 16:48:57.702041 | controller | Tuesday 20 January 2026  16:48:57 +0000 (0:00:00.057)       0:00:32.625 *******
2026-01-20 16:48:57.807511 | controller | ok: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
2026-01-20 16:48:57.807773 | controller | ok: [instance] => (item={'key': 'compute-1', 'value': 'compute'})
2026-01-20 16:48:57.807971 | controller |
2026-01-20 16:48:57.808172 | controller | TASK [libvirt_manager : Append baremetal nodes if needed] **********************
2026-01-20 16:48:57.808348 | controller | Tuesday 20 January 2026  16:48:57 +0000 (0:00:00.106)       0:00:32.731 *******
2026-01-20 16:48:57.844319 | controller | skipping: [instance]
2026-01-20 16:48:57.844546 | controller |
2026-01-20 16:48:57.844848 | controller | TASK [libvirt_manager : Dump MAC mapping] **************************************
2026-01-20 16:48:57.845040 | controller | Tuesday 20 January 2026  16:48:57 +0000 (0:00:00.036)       0:00:32.768 *******
2026-01-20 16:48:58.240051 | controller | changed: [instance]
2026-01-20 16:48:58.240313 | controller |
2026-01-20 16:48:58.240530 | controller | TASK [libvirt_manager : Inject all VMs in the inventory] ***********************
2026-01-20 16:48:58.240710 | controller | Tuesday 20 January 2026  16:48:58 +0000 (0:00:00.392)       0:00:33.161 *******
2026-01-20 16:48:58.342307 | controller | changed: [instance] => (item=Adding compute-0 to computes)
2026-01-20 16:48:58.342537 | controller | changed: [instance] => (item=Adding compute-1 to computes)
2026-01-20 16:48:58.342717 | controller |
2026-01-20 16:48:58.342924 | controller | TASK [networking_mapper : Check for Networking Definition file existence] ******
2026-01-20 16:48:58.343107 | controller | Tuesday 20 January 2026  16:48:58 +0000 (0:00:00.104)       0:00:33.265 *******
2026-01-20 16:48:58.369625 | controller | skipping: [instance]
2026-01-20 16:48:58.369843 | controller |
2026-01-20 16:48:58.370037 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2026-01-20 16:48:58.370247 | controller | Tuesday 20 January 2026  16:48:58 +0000 (0:00:00.028)       0:00:33.294 *******
2026-01-20 16:48:58.394748 | controller | skipping: [instance]
2026-01-20 16:48:58.421401 | controller |
2026-01-20 16:48:58.421425 | controller | TASK [networking_mapper : Check for interfaces info file existence] ************
2026-01-20 16:48:58.421433 | controller | Tuesday 20 January 2026  16:48:58 +0000 (0:00:00.024)       0:00:33.318 *******
2026-01-20 16:48:58.421442 | controller | skipping: [instance]
2026-01-20 16:48:58.447909 | controller |
2026-01-20 16:48:58.447932 | controller | TASK [networking_mapper : Load the interfaces info from file] ******************
2026-01-20 16:48:58.447940 | controller | Tuesday 20 January 2026  16:48:58 +0000 (0:00:00.026)       0:00:33.345 *******
2026-01-20 16:48:58.447949 | controller | skipping: [instance]
2026-01-20 16:48:58.468302 | controller |
2026-01-20 16:48:58.468319 | controller | TASK [networking_mapper : Ensure local fact is empty] **************************
2026-01-20 16:48:58.468338 | controller | Tuesday 20 January 2026  16:48:58 +0000 (0:00:00.026)       0:00:33.372 *******
2026-01-20 16:48:58.468349 | controller | ok: [instance]
2026-01-20 16:48:58.564805 | controller |
2026-01-20 16:48:58.564826 | controller | TASK [networking_mapper : Set the input Networking Definition and patch it if needed] ***
2026-01-20 16:48:58.564834 | controller | Tuesday 20 January 2026  16:48:58 +0000 (0:00:00.020)       0:00:33.392 *******
2026-01-20 16:48:58.564846 | 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-01-20 16:48:58.588852 | controller |
2026-01-20 16:48:58.588871 | controller | TASK [networking_mapper : Gather facts if requested] ***************************
2026-01-20 16:48:58.588885 | controller | Tuesday 20 January 2026  16:48:58 +0000 (0:00:00.096)       0:00:33.489 *******
2026-01-20 16:48:58.588894 | controller | skipping: [instance]
2026-01-20 16:48:58.809383 | controller |
2026-01-20 16:48:58.809414 | controller | TASK [networking_mapper : Ensure CI infrastructure dir exists] *****************
2026-01-20 16:48:58.809422 | controller | Tuesday 20 January 2026  16:48:58 +0000 (0:00:00.023)       0:00:33.512 *******
2026-01-20 16:48:58.809432 | controller | changed: [instance]
2026-01-20 16:48:59.253037 | controller |
2026-01-20 16:48:59.253069 | controller | TASK [networking_mapper : Write the Networking Definition to file] *************
2026-01-20 16:48:59.253078 | controller | Tuesday 20 January 2026  16:48:58 +0000 (0:00:00.218)       0:00:33.730 *******
2026-01-20 16:48:59.253088 | controller | changed: [instance]
2026-01-20 16:48:59.304872 | controller |
2026-01-20 16:48:59.304895 | controller | TASK [networking_mapper : Call the networking mapper] **************************
2026-01-20 16:48:59.304903 | controller | Tuesday 20 January 2026  16:48:59 +0000 (0:00:00.446)       0:00:34.176 *******
2026-01-20 16:48:59.304912 | controller | ok: [instance]
2026-01-20 16:48:59.326516 | controller |
2026-01-20 16:48:59.326538 | controller | TASK [networking_mapper : Set networking mapper facts] *************************
2026-01-20 16:48:59.326547 | controller | Tuesday 20 January 2026  16:48:59 +0000 (0:00:00.052)       0:00:34.229 *******
2026-01-20 16:48:59.326558 | controller | ok: [instance]
2026-01-20 16:48:59.720391 | controller |
2026-01-20 16:48:59.720426 | controller | TASK [networking_mapper : Write the Networking Environment Definition to file] ***
2026-01-20 16:48:59.720435 | controller | Tuesday 20 January 2026  16:48:59 +0000 (0:00:00.021)       0:00:34.250 *******
2026-01-20 16:48:59.720446 | controller | changed: [instance]
2026-01-20 16:48:59.795083 | controller |
2026-01-20 16:48:59.795118 | controller | TASK [libvirt_manager : Manage networks if needed] *****************************
2026-01-20 16:48:59.795143 | controller | Tuesday 20 January 2026  16:48:59 +0000 (0:00:00.393)       0:00:34.644 *******
2026-01-20 16:48:59.795159 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_networks.yml for instance
2026-01-20 16:48:59.837097 | controller |
2026-01-20 16:48:59.837138 | controller | TASK [libvirt_manager : Define the localized variables for performing the tasks here.] ***
2026-01-20 16:48:59.837147 | controller | Tuesday 20 January 2026  16:48:59 +0000 (0:00:00.074)       0:00:34.718 *******
2026-01-20 16:48:59.837157 | controller | ok: [instance] => (item=public)
2026-01-20 16:49:00.178116 | controller |
2026-01-20 16:49:00.178167 | controller | TASK [libvirt_manager : Ensure networks are defined] ***************************
2026-01-20 16:49:00.178176 | controller | Tuesday 20 January 2026  16:48:59 +0000 (0:00:00.042)       0:00:34.760 *******
2026-01-20 16:49:00.178185 | controller | changed: [instance] => (item=cifmw-public)
2026-01-20 16:49:00.500005 | controller |
2026-01-20 16:49:00.500037 | controller | TASK [libvirt_manager : Ensure networks are created/started] *******************
2026-01-20 16:49:00.500045 | controller | Tuesday 20 January 2026  16:49:00 +0000 (0:00:00.338)       0:00:35.099 *******
2026-01-20 16:49:00.500055 | controller | ok: [instance] => (item=cifmw-public)
2026-01-20 16:49:00.740922 | controller |
2026-01-20 16:49:00.740953 | controller | TASK [libvirt_manager : Ensure networks are active] ****************************
2026-01-20 16:49:00.740969 | controller | Tuesday 20 January 2026  16:49:00 +0000 (0:00:00.324)       0:00:35.424 *******
2026-01-20 16:49:00.740979 | controller | ok: [instance] => (item=cifmw-public)
2026-01-20 16:49:00.977696 | controller |
2026-01-20 16:49:00.977730 | controller | TASK [libvirt_manager : Ensure networks enabled to autostart] ******************
2026-01-20 16:49:00.977738 | controller | Tuesday 20 January 2026  16:49:00 +0000 (0:00:00.240)       0:00:35.665 *******
2026-01-20 16:49:00.977749 | controller | changed: [instance] => (item=cifmw-public)
2026-01-20 16:49:01.035658 | controller |
2026-01-20 16:49:01.035690 | controller | TASK [libvirt_manager : Add a dummy interface to bridges if required] **********
2026-01-20 16:49:01.035699 | controller | Tuesday 20 January 2026  16:49:00 +0000 (0:00:00.236)       0:00:35.901 *******
2026-01-20 16:49:01.035709 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_networks_dummy_interfaces.yml for instance
2026-01-20 16:49:01.227847 | controller |
2026-01-20 16:49:01.227879 | controller | TASK [libvirt_manager : Fetch present bridge interfaces] ***********************
2026-01-20 16:49:01.227887 | controller | Tuesday 20 January 2026  16:49:01 +0000 (0:00:00.057)       0:00:35.959 *******
2026-01-20 16:49:01.227898 | controller | ok: [instance]
2026-01-20 16:49:01.228100 | controller |
2026-01-20 16:49:01.228115 | controller | TASK [libvirt_manager : Fetch bridges ports link info] *************************
2026-01-20 16:49:01.441885 | controller | Tuesday 20 January 2026  16:49:01 +0000 (0:00:00.192)       0:00:36.151 *******
2026-01-20 16:49:01.441924 | controller | ok: [instance] => (item=cifmw-public)
2026-01-20 16:49:01.516166 | controller |
2026-01-20 16:49:01.516199 | controller | TASK [Create dummy interfaces to ensure bridges are UP] ************************
2026-01-20 16:49:01.516215 | controller | Tuesday 20 January 2026  16:49:01 +0000 (0:00:00.213)       0:00:36.365 *******
2026-01-20 16:49:01.516225 | controller |
2026-01-20 16:49:01.555045 | controller | TASK [ci_nmstate : Ensure we have needed facts] ********************************
2026-01-20 16:49:01.555079 | controller | Tuesday 20 January 2026  16:49:01 +0000 (0:00:00.074)       0:00:36.440 *******
2026-01-20 16:49:01.555095 | controller | skipping: [instance]
2026-01-20 16:49:06.698497 | controller |
2026-01-20 16:49:06.698536 | controller | TASK [ci_nmstate : Install required packages on instance] **********************
2026-01-20 16:49:06.698549 | controller | Tuesday 20 January 2026  16:49:01 +0000 (0:00:00.039)       0:00:36.479 *******
2026-01-20 16:49:06.698559 | controller | changed: [instance]
2026-01-20 16:49:06.938873 | controller |
2026-01-20 16:49:06.938910 | controller | TASK [ci_nmstate : Create the target NMstate dump directory] *******************
2026-01-20 16:49:06.938918 | controller | Tuesday 20 January 2026  16:49:06 +0000 (0:00:05.142)       0:00:41.622 *******
2026-01-20 16:49:06.938929 | controller | changed: [instance]
2026-01-20 16:49:07.386027 | controller |
2026-01-20 16:49:07.386060 | controller | TASK [ci_nmstate : Save nmstate state for instance] ****************************
2026-01-20 16:49:07.386068 | controller | Tuesday 20 January 2026  16:49:06 +0000 (0:00:00.240)       0:00:41.862 *******
2026-01-20 16:49:07.386079 | controller | changed: [instance]
2026-01-20 16:49:07.386492 | controller |
2026-01-20 16:49:09.536299 | controller | TASK [ci_nmstate : Apply the desidered state on instance] **********************
2026-01-20 16:49:09.536395 | controller | Tuesday 20 January 2026  16:49:07 +0000 (0:00:00.444)       0:00:42.306 *******
2026-01-20 16:49:09.536409 | controller | changed: [instance]
2026-01-20 16:49:09.983722 | controller |
2026-01-20 16:49:09.983789 | controller | TASK [ci_nmstate : Save nmstate debugging data for instance] *******************
2026-01-20 16:49:09.983806 | controller | Tuesday 20 January 2026  16:49:09 +0000 (0:00:02.150)       0:00:44.456 *******
2026-01-20 16:49:09.983822 | controller | changed: [instance]
2026-01-20 16:49:10.020197 | controller |
2026-01-20 16:49:10.020218 | controller | TASK [Create extra network configuration] **************************************
2026-01-20 16:49:10.020226 | controller | Tuesday 20 January 2026  16:49:09 +0000 (0:00:00.450)       0:00:44.907 *******
2026-01-20 16:49:10.020236 | controller | skipping: [instance]
2026-01-20 16:49:10.050520 | controller |
2026-01-20 16:49:10.050550 | controller | TASK [libvirt_manager : Ensure extra networks is in correct zone] **************
2026-01-20 16:49:10.050560 | controller | Tuesday 20 January 2026  16:49:10 +0000 (0:00:00.036)       0:00:44.944 *******
2026-01-20 16:49:10.050678 | controller | skipping: [instance]
2026-01-20 16:49:10.570523 | controller |
2026-01-20 16:49:10.570569 | controller | TASK [libvirt_manager : Refresh networking facts on host] **********************
2026-01-20 16:49:10.570578 | controller | Tuesday 20 January 2026  16:49:10 +0000 (0:00:00.030)       0:00:44.974 *******
2026-01-20 16:49:10.570598 | controller | ok: [instance]
2026-01-20 16:49:10.718984 | controller |
2026-01-20 16:49:10.719029 | controller | TASK [libvirt_manager : Build needed network/dnsmasq related content] **********
2026-01-20 16:49:10.719042 | controller | Tuesday 20 January 2026  16:49:10 +0000 (0:00:00.519)       0:00:45.494 *******
2026-01-20 16:49:10.719054 | controller | ok: [instance] => (item=cifmw-public)
2026-01-20 16:49:12.250979 | controller |
2026-01-20 16:49:12.251014 | controller | TASK [dnsmasq : Install needed packages] ***************************************
2026-01-20 16:49:12.251023 | controller | Tuesday 20 January 2026  16:49:10 +0000 (0:00:00.148)       0:00:45.642 *******
2026-01-20 16:49:12.251033 | controller | ok: [instance]
2026-01-20 16:49:12.251530 | controller |
2026-01-20 16:49:16.842744 | controller | TASK [dnsmasq : Ensure SELinux knows about the new files and directories] ******
2026-01-20 16:49:16.842803 | controller | Tuesday 20 January 2026  16:49:12 +0000 (0:00:01.532)       0:00:47.174 *******
2026-01-20 16:49:16.842816 | controller | changed: [instance] => (item={'target': '/etc/cifmw-dnsmasq.conf', 'setype': 'dnsmasq_etc_t'})
2026-01-20 16:49:17.095844 | controller | changed: [instance] => (item={'target': '/etc/cifmw-dnsmasq.d(/.*)?', 'setype': 'dnsmasq_etc_t'})
2026-01-20 16:49:17.095887 | controller | changed: [instance] => (item={'target': '/var/run/cifmw-dnsmasq.pid', 'setype': 'dnsmasq_var_run_t'})
2026-01-20 16:49:17.095901 | controller |
2026-01-20 16:49:17.095909 | controller | TASK [dnsmasq : Manage configuration directory] ********************************
2026-01-20 16:49:17.095915 | controller | Tuesday 20 January 2026  16:49:16 +0000 (0:00:04.591)       0:00:51.765 *******
2026-01-20 16:49:17.095926 | controller | changed: [instance]
2026-01-20 16:49:17.096388 | controller |
2026-01-20 16:49:17.556130 | controller | TASK [dnsmasq : Manage systemd unit file] **************************************
2026-01-20 16:49:17.556203 | controller | Tuesday 20 January 2026  16:49:17 +0000 (0:00:00.254)       0:00:52.019 *******
2026-01-20 16:49:17.556220 | controller | changed: [instance]
2026-01-20 16:49:18.042235 | controller |
2026-01-20 16:49:18.042276 | controller | TASK [dnsmasq : Manage base configuration file] ********************************
2026-01-20 16:49:18.042302 | controller | Tuesday 20 January 2026  16:49:17 +0000 (0:00:00.459)       0:00:52.479 *******
2026-01-20 16:49:18.042313 | controller | changed: [instance]
2026-01-20 16:49:18.078840 | controller |
2026-01-20 16:49:18.078884 | controller | TASK [dnsmasq : Render listener configuration] *********************************
2026-01-20 16:49:18.078897 | controller | Tuesday 20 January 2026  16:49:18 +0000 (0:00:00.486)       0:00:52.965 *******
2026-01-20 16:49:18.078914 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/listener.yml for instance
2026-01-20 16:49:18.079032 | controller |
2026-01-20 16:49:18.079044 | controller | TASK [dnsmasq : Create listener configuration file] ****************************
2026-01-20 16:49:18.079053 | controller | Tuesday 20 January 2026  16:49:18 +0000 (0:00:00.036)       0:00:53.002 *******
2026-01-20 16:49:18.580411 | controller | changed: [instance]
2026-01-20 16:49:18.602987 | controller |
2026-01-20 16:49:18.603031 | controller | TASK [dnsmasq : Remove listener configuration file] ****************************
2026-01-20 16:49:18.603041 | controller | Tuesday 20 January 2026  16:49:18 +0000 (0:00:00.500)       0:00:53.503 *******
2026-01-20 16:49:18.603053 | controller | skipping: [instance]
2026-01-20 16:49:18.642473 | controller |
2026-01-20 16:49:18.642504 | controller | TASK [dnsmasq : Render dns configuration] **************************************
2026-01-20 16:49:18.642512 | controller | Tuesday 20 January 2026  16:49:18 +0000 (0:00:00.023)       0:00:53.526 *******
2026-01-20 16:49:18.642523 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/dns.yml for instance
2026-01-20 16:49:19.087734 | controller |
2026-01-20 16:49:19.087786 | controller | TASK [dnsmasq : Create dns configuration file] *********************************
2026-01-20 16:49:19.087796 | controller | Tuesday 20 January 2026  16:49:18 +0000 (0:00:00.039)       0:00:53.566 *******
2026-01-20 16:49:19.087820 | controller | changed: [instance]
2026-01-20 16:49:19.113902 | controller |
2026-01-20 16:49:19.113931 | controller | TASK [dnsmasq : Remove dns configuration file] *********************************
2026-01-20 16:49:19.113940 | controller | Tuesday 20 January 2026  16:49:19 +0000 (0:00:00.444)       0:00:54.011 *******
2026-01-20 16:49:19.113950 | controller | skipping: [instance]
2026-01-20 16:49:19.114232 | controller |
2026-01-20 16:49:19.114247 | controller | TASK [dnsmasq : Add localhost addresses from defined dnsmasq listen addresses to loopback interface] ***
2026-01-20 16:49:19.399812 | controller | Tuesday 20 January 2026  16:49:19 +0000 (0:00:00.026)       0:00:54.038 *******
2026-01-20 16:49:19.399866 | controller | ok: [instance] => (item=127.0.0.2)
2026-01-20 16:49:20.359095 | controller |
2026-01-20 16:49:20.359135 | controller | TASK [dnsmasq : Enable and start service] **************************************
2026-01-20 16:49:20.359144 | controller | Tuesday 20 January 2026  16:49:19 +0000 (0:00:00.285)       0:00:54.323 *******
2026-01-20 16:49:20.359155 | controller | changed: [instance]
2026-01-20 16:49:20.382091 | controller |
2026-01-20 16:49:20.382122 | controller | TASK [dnsmasq : Stop service] **************************************************
2026-01-20 16:49:20.382130 | controller | Tuesday 20 January 2026  16:49:20 +0000 (0:00:00.955)       0:00:55.278 *******
2026-01-20 16:49:20.382140 | controller | skipping: [instance]
2026-01-20 16:49:20.405403 | controller |
2026-01-20 16:49:20.405435 | controller | TASK [dnsmasq : Remove unit file] **********************************************
2026-01-20 16:49:20.405443 | controller | Tuesday 20 January 2026  16:49:20 +0000 (0:00:00.027)       0:00:55.306 *******
2026-01-20 16:49:20.405453 | controller | skipping: [instance]
2026-01-20 16:49:20.443232 | controller |
2026-01-20 16:49:20.443259 | controller | TASK [dnsmasq : Remove main configuration files] *******************************
2026-01-20 16:49:20.443266 | controller | Tuesday 20 January 2026  16:49:20 +0000 (0:00:00.023)       0:00:55.329 *******
2026-01-20 16:49:20.443276 | controller | skipping: [instance] => (item=/etc/cifmw-dnsmasq.conf)
2026-01-20 16:49:20.537183 | controller | skipping: [instance] => (item=/etc/cifmw-dnsmasq.d)
2026-01-20 16:49:20.537214 | controller | skipping: [instance]
2026-01-20 16:49:20.537222 | controller |
2026-01-20 16:49:20.537228 | controller | TASK [Create dnsmasq networks] *************************************************
2026-01-20 16:49:20.537233 | controller | Tuesday 20 January 2026  16:49:20 +0000 (0:00:00.037)       0:00:55.366 *******
2026-01-20 16:49:20.537243 | controller |
2026-01-20 16:49:20.599039 | controller | TASK [dnsmasq : Assert mandatory parameter] ************************************
2026-01-20 16:49:20.599077 | controller | Tuesday 20 January 2026  16:49:20 +0000 (0:00:00.093)       0:00:55.460 *******
2026-01-20 16:49:20.599091 | controller | ok: [instance] => changed=false
2026-01-20 16:49:20.599342 | controller |   msg: All assertions passed
2026-01-20 16:49:20.599530 | controller |
2026-01-20 16:49:20.599727 | controller | TASK [dnsmasq : Assert mandatory parameters for new network] *******************
2026-01-20 16:49:20.599936 | controller | Tuesday 20 January 2026  16:49:20 +0000 (0:00:00.061)       0:00:55.521 *******
2026-01-20 16:49:20.650402 | controller | ok: [instance] => changed=false
2026-01-20 16:49:20.650631 | controller |   msg: All assertions passed
2026-01-20 16:49:20.650884 | controller |
2026-01-20 16:49:20.651117 | controller | TASK [dnsmasq : Create network] ************************************************
2026-01-20 16:49:20.651343 | controller | Tuesday 20 January 2026  16:49:20 +0000 (0:00:00.052)       0:00:55.574 *******
2026-01-20 16:49:21.218023 | controller | changed: [instance]
2026-01-20 16:49:21.248474 | controller |
2026-01-20 16:49:21.248511 | controller | TASK [dnsmasq : Remove network] ************************************************
2026-01-20 16:49:21.248527 | controller | Tuesday 20 January 2026  16:49:21 +0000 (0:00:00.566)       0:00:56.141 *******
2026-01-20 16:49:21.248538 | controller | skipping: [instance]
2026-01-20 16:49:21.283474 | controller |
2026-01-20 16:49:21.283511 | controller | TASK [dnsmasq : Remove dhcp host files] ****************************************
2026-01-20 16:49:21.283519 | controller | Tuesday 20 January 2026  16:49:21 +0000 (0:00:00.030)       0:00:56.172 *******
2026-01-20 16:49:21.283534 | controller | skipping: [instance]
2026-01-20 16:49:21.323236 | controller |
2026-01-20 16:49:21.323275 | controller | TASK [Deploy radvd for IPv6 router advertisements] *****************************
2026-01-20 16:49:21.323301 | controller | Tuesday 20 January 2026  16:49:21 +0000 (0:00:00.034)       0:00:56.207 *******
2026-01-20 16:49:21.323314 | controller | skipping: [instance]
2026-01-20 16:49:21.708802 | controller |
2026-01-20 16:49:21.708842 | controller | TASK [libvirt_manager : Ensure network is in correct zone] *********************
2026-01-20 16:49:21.708855 | controller | Tuesday 20 January 2026  16:49:21 +0000 (0:00:00.039)       0:00:56.247 *******
2026-01-20 16:49:21.708868 | controller | changed: [instance] => (item=cifmw-public)
2026-01-20 16:49:21.747222 | controller |
2026-01-20 16:49:21.747264 | controller | TASK [libvirt_manager : Extract IP address from network bridges] ***************
2026-01-20 16:49:21.747277 | controller | Tuesday 20 January 2026  16:49:21 +0000 (0:00:00.385)       0:00:56.632 *******
2026-01-20 16:49:21.747292 | 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-01-20 16:49:22.134880 | controller |
2026-01-20 16:49:22.134924 | controller | TASK [libvirt_manager : Extract IP address from network bridges] ***************
2026-01-20 16:49:22.134934 | controller | Tuesday 20 January 2026  16:49:21 +0000 (0:00:00.038)       0:00:56.670 *******
2026-01-20 16:49:22.134949 | controller | ok: [instance]
2026-01-20 16:49:22.135476 | controller |
2026-01-20 16:49:22.181270 | controller | TASK [libvirt_manager : Set network_bridge_info fact with network and address] ***
2026-01-20 16:49:22.181315 | controller | Tuesday 20 January 2026  16:49:22 +0000 (0:00:00.387)       0:00:57.058 *******
2026-01-20 16:49:22.181333 | controller | ok: [instance]
2026-01-20 16:49:22.688367 | controller |
2026-01-20 16:49:22.688421 | controller | TASK [libvirt_manager : Output _network_data] **********************************
2026-01-20 16:49:22.688431 | controller | Tuesday 20 January 2026  16:49:22 +0000 (0:00:00.046)       0:00:57.104 *******
2026-01-20 16:49:22.688443 | controller | changed: [instance]
2026-01-20 16:49:23.131850 | controller |
2026-01-20 16:49:23.131968 | controller | TASK [libvirt_manager : Output pub_net] ****************************************
2026-01-20 16:49:23.131978 | controller | Tuesday 20 January 2026  16:49:22 +0000 (0:00:00.506)       0:00:57.611 *******
2026-01-20 16:49:23.131988 | controller | changed: [instance]
2026-01-20 16:49:23.596882 | controller |
2026-01-20 16:49:23.596935 | controller | TASK [libvirt_manager : Output _cifmw_libvirt_manager_layout] ******************
2026-01-20 16:49:23.596946 | controller | Tuesday 20 January 2026  16:49:23 +0000 (0:00:00.444)       0:00:58.055 *******
2026-01-20 16:49:23.596957 | controller | changed: [instance]
2026-01-20 16:49:23.724900 | controller |
2026-01-20 16:49:23.724955 | controller | TASK [libvirt_manager : Expose patch for networking_mapper] ********************
2026-01-20 16:49:23.724966 | controller | Tuesday 20 January 2026  16:49:23 +0000 (0:00:00.464)       0:00:58.520 *******
2026-01-20 16:49:23.724982 | controller | ok: [instance]
2026-01-20 16:49:24.195371 | controller |
2026-01-20 16:49:24.195423 | controller | TASK [libvirt_manager : Save networking_mapper patch] **************************
2026-01-20 16:49:24.195432 | controller | Tuesday 20 January 2026  16:49:23 +0000 (0:00:00.127)       0:00:58.648 *******
2026-01-20 16:49:24.195445 | controller | changed: [instance]
2026-01-20 16:49:24.232271 | controller |
2026-01-20 16:49:24.232313 | controller | TASK [networking_mapper : Check for Networking Definition file existence] ******
2026-01-20 16:49:24.232321 | controller | Tuesday 20 January 2026  16:49:24 +0000 (0:00:00.465)       0:00:59.113 *******
2026-01-20 16:49:24.232337 | controller | skipping: [instance]
2026-01-20 16:49:24.263498 | controller |
2026-01-20 16:49:24.263539 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2026-01-20 16:49:24.263548 | controller | Tuesday 20 January 2026  16:49:24 +0000 (0:00:00.042)       0:00:59.155 *******
2026-01-20 16:49:24.263558 | controller | skipping: [instance]
2026-01-20 16:49:24.295107 | controller |
2026-01-20 16:49:24.295139 | controller | TASK [networking_mapper : Check for interfaces info file existence] ************
2026-01-20 16:49:24.295147 | controller | Tuesday 20 January 2026  16:49:24 +0000 (0:00:00.031)       0:00:59.187 *******
2026-01-20 16:49:24.295158 | controller | skipping: [instance]
2026-01-20 16:49:24.336958 | controller |
2026-01-20 16:49:24.336991 | controller | TASK [networking_mapper : Load the interfaces info from file] ******************
2026-01-20 16:49:24.337000 | controller | Tuesday 20 January 2026  16:49:24 +0000 (0:00:00.031)       0:00:59.219 *******
2026-01-20 16:49:24.337028 | controller | skipping: [instance]
2026-01-20 16:49:24.362053 | controller |
2026-01-20 16:49:24.362081 | controller | TASK [networking_mapper : Ensure local fact is empty] **************************
2026-01-20 16:49:24.362090 | controller | Tuesday 20 January 2026  16:49:24 +0000 (0:00:00.041)       0:00:59.260 *******
2026-01-20 16:49:24.362100 | controller | ok: [instance]
2026-01-20 16:49:24.458526 | controller |
2026-01-20 16:49:24.458567 | controller | TASK [networking_mapper : Set the input Networking Definition and patch it if needed] ***
2026-01-20 16:49:24.458580 | controller | Tuesday 20 January 2026  16:49:24 +0000 (0:00:00.025)       0:00:59.285 *******
2026-01-20 16:49:24.458593 | 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-01-20 16:49:24.479809 | controller | ok: [instance] => (item={'networks': {'public': {'network-v4': '192.168.100.0/24'}}, 'group-templates': {'computes': {'networks': {'public': None}}}})
2026-01-20 16:49:24.479849 | controller |
2026-01-20 16:49:24.479862 | controller | TASK [networking_mapper : Gather facts if requested] ***************************
2026-01-20 16:49:24.479870 | controller | Tuesday 20 January 2026  16:49:24 +0000 (0:00:00.096)       0:00:59.382 *******
2026-01-20 16:49:24.479882 | controller | skipping: [instance]
2026-01-20 16:49:24.730300 | controller |
2026-01-20 16:49:24.730347 | controller | TASK [networking_mapper : Ensure CI infrastructure dir exists] *****************
2026-01-20 16:49:24.730361 | controller | Tuesday 20 January 2026  16:49:24 +0000 (0:00:00.021)       0:00:59.403 *******
2026-01-20 16:49:24.730376 | controller | ok: [instance]
2026-01-20 16:49:25.243467 | controller |
2026-01-20 16:49:25.243511 | controller | TASK [networking_mapper : Write the Networking Definition to file] *************
2026-01-20 16:49:25.243521 | controller | Tuesday 20 January 2026  16:49:24 +0000 (0:00:00.249)       0:00:59.653 *******
2026-01-20 16:49:25.243538 | controller | changed: [instance]
2026-01-20 16:49:25.310229 | controller |
2026-01-20 16:49:25.310274 | controller | TASK [networking_mapper : Call the networking mapper] **************************
2026-01-20 16:49:25.310289 | controller | Tuesday 20 January 2026  16:49:25 +0000 (0:00:00.513)       0:01:00.166 *******
2026-01-20 16:49:25.310302 | controller | ok: [instance]
2026-01-20 16:49:25.343407 | controller |
2026-01-20 16:49:25.343434 | controller | TASK [networking_mapper : Set networking mapper facts] *************************
2026-01-20 16:49:25.343447 | controller | Tuesday 20 January 2026  16:49:25 +0000 (0:00:00.066)       0:01:00.233 *******
2026-01-20 16:49:25.343462 | controller | ok: [instance]
2026-01-20 16:49:25.861090 | controller |
2026-01-20 16:49:25.861132 | controller | TASK [networking_mapper : Write the Networking Environment Definition to file] ***
2026-01-20 16:49:25.861142 | controller | Tuesday 20 January 2026  16:49:25 +0000 (0:00:00.033)       0:01:00.267 *******
2026-01-20 16:49:25.861154 | controller | changed: [instance]
2026-01-20 16:49:25.887802 | controller |
2026-01-20 16:49:25.887837 | controller | TASK [libvirt_manager : Be sure to save current state of networking_mapper environment] ***
2026-01-20 16:49:25.887846 | controller | Tuesday 20 January 2026  16:49:25 +0000 (0:00:00.513)       0:01:00.780 *******
2026-01-20 16:49:25.887858 | controller | ok: [instance]
2026-01-20 16:49:25.909992 | controller |
2026-01-20 16:49:25.910024 | controller | TASK [libvirt_manager : Unset patch] *******************************************
2026-01-20 16:49:25.910032 | controller | Tuesday 20 January 2026  16:49:25 +0000 (0:00:00.030)       0:01:00.811 *******
2026-01-20 16:49:25.910046 | controller | ok: [instance]
2026-01-20 16:49:25.934040 | controller |
2026-01-20 16:49:25.934066 | controller | TASK [libvirt_manager : Initialize empty _lm_dhcp_entries fact] ****************
2026-01-20 16:49:25.934080 | controller | Tuesday 20 January 2026  16:49:25 +0000 (0:00:00.022)       0:01:00.834 *******
2026-01-20 16:49:25.934090 | controller | ok: [instance]
2026-01-20 16:49:25.977895 | controller |
2026-01-20 16:49:25.977932 | controller | TASK [libvirt_manager : Reserve IPs on networks] *******************************
2026-01-20 16:49:25.977941 | controller | Tuesday 20 January 2026  16:49:25 +0000 (0:00:00.023)       0:01:00.858 *******
2026-01-20 16:49:25.977958 | 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-01-20 16:49:26.061810 | 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-01-20 16:49:26.061843 | controller |
2026-01-20 16:49:26.061851 | controller | TASK [libvirt_manager : Loop on host IPs] **************************************
2026-01-20 16:49:26.061858 | controller | Tuesday 20 January 2026  16:49:25 +0000 (0:00:00.043)       0:01:00.901 *******
2026-01-20 16:49:26.061868 | controller | skipping: [instance] => (item=compute-0 - ctlplane)
2026-01-20 16:49:26.185726 | controller | skipping: [instance] => (item=compute-1 - ctlplane)
2026-01-20 16:49:26.185782 | controller | skipping: [instance]
2026-01-20 16:49:26.185795 | controller |
2026-01-20 16:49:26.185802 | controller | TASK [libvirt_manager : Loop on host IPs] **************************************
2026-01-20 16:49:26.185809 | controller | Tuesday 20 January 2026  16:49:26 +0000 (0:00:00.083)       0:01:00.985 *******
2026-01-20 16:49:26.185820 | controller | ok: [instance] => (item=compute-0 - public)
2026-01-20 16:49:26.248464 | controller | ok: [instance] => (item=compute-1 - public)
2026-01-20 16:49:26.248506 | controller |
2026-01-20 16:49:26.248515 | controller | TASK [Inject DHCP entries for net {{ net_name }}] ******************************
2026-01-20 16:49:26.248522 | controller | Tuesday 20 January 2026  16:49:26 +0000 (0:00:00.123)       0:01:01.109 *******
2026-01-20 16:49:26.248533 | controller |
2026-01-20 16:49:26.291962 | controller | TASK [dnsmasq : Ensure we have the right data and type] ************************
2026-01-20 16:49:26.292007 | controller | Tuesday 20 January 2026  16:49:26 +0000 (0:00:00.062)       0:01:01.172 *******
2026-01-20 16:49:26.292020 | controller | ok: [instance]
2026-01-20 16:49:26.352877 | controller |
2026-01-20 16:49:26.352913 | controller | TASK [dnsmasq : Assert we have needed host data] *******************************
2026-01-20 16:49:26.352922 | controller | Tuesday 20 January 2026  16:49:26 +0000 (0:00:00.043)       0:01:01.215 *******
2026-01-20 16:49:26.352933 | controller | ok: [instance] => (item={'network': 'public', 'name': 'compute-0', 'state': 'present', 'mac': '52:54:00:5b:fb:48', 'ips': ['192.168.100.10', ''], 'tag': 'compute'})
2026-01-20 16:49:26.406842 | controller | ok: [instance] => (item={'network': 'public', 'name': 'compute-1', 'state': 'present', 'mac': '52:54:01:85:95:13', 'ips': ['192.168.100.11', ''], 'tag': 'compute'})
2026-01-20 16:49:26.406888 | controller |
2026-01-20 16:49:26.406898 | controller | TASK [dnsmasq : Ensure networks exists] ****************************************
2026-01-20 16:49:26.406905 | controller | Tuesday 20 January 2026  16:49:26 +0000 (0:00:00.060)       0:01:01.276 *******
2026-01-20 16:49:26.406921 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/_check_net_status.yml for instance => (item=public)
2026-01-20 16:49:26.609259 | controller |
2026-01-20 16:49:26.609299 | controller | TASK [dnsmasq : Check network file status] *************************************
2026-01-20 16:49:26.609309 | controller | Tuesday 20 January 2026  16:49:26 +0000 (0:00:00.053)       0:01:01.330 *******
2026-01-20 16:49:26.609320 | controller | ok: [instance]
2026-01-20 16:49:26.634061 | controller |
2026-01-20 16:49:26.634099 | controller | TASK [dnsmasq : Assert network exists] *****************************************
2026-01-20 16:49:26.634112 | controller | Tuesday 20 January 2026  16:49:26 +0000 (0:00:00.202)       0:01:01.532 *******
2026-01-20 16:49:26.634123 | controller | ok: [instance]
2026-01-20 16:49:26.654545 | controller |
2026-01-20 16:49:26.654582 | controller | TASK [dnsmasq : Initialize empty dhcp_host_entries] ****************************
2026-01-20 16:49:26.654591 | controller | Tuesday 20 January 2026  16:49:26 +0000 (0:00:00.025)       0:01:01.557 *******
2026-01-20 16:49:26.654602 | controller | ok: [instance]
2026-01-20 16:49:26.795879 | controller |
2026-01-20 16:49:26.795919 | controller | TASK [dnsmasq : Compute entry] *************************************************
2026-01-20 16:49:26.795928 | controller | Tuesday 20 January 2026  16:49:26 +0000 (0:00:00.020)       0:01:01.578 *******
2026-01-20 16:49:26.795939 | controller | ok: [instance] => (item={'network': 'public', 'name': 'compute-0', 'state': 'present', 'mac': '52:54:00:5b:fb:48', 'ips': ['192.168.100.10', ''], 'tag': 'compute'})
2026-01-20 16:49:26.835521 | controller | ok: [instance] => (item={'network': 'public', 'name': 'compute-1', 'state': 'present', 'mac': '52:54:01:85:95:13', 'ips': ['192.168.100.11', ''], 'tag': 'compute'})
2026-01-20 16:49:26.835554 | controller |
2026-01-20 16:49:26.835562 | controller | TASK [dnsmasq : Create add/remove sets] ****************************************
2026-01-20 16:49:26.835568 | controller | Tuesday 20 January 2026  16:49:26 +0000 (0:00:00.140)       0:01:01.719 *******
2026-01-20 16:49:26.835578 | controller | ok: [instance]
2026-01-20 16:49:27.685069 | controller |
2026-01-20 16:49:27.685110 | controller | TASK [dnsmasq : Add DHCP entries] **********************************************
2026-01-20 16:49:27.685123 | controller | Tuesday 20 January 2026  16:49:26 +0000 (0:00:00.040)       0:01:01.759 *******
2026-01-20 16:49:27.685136 | controller | changed: [instance] => (item={'file': 'public_compute-0_52:54:00:5b:fb:48', 'entry': 'set:compute,52:54:00:5b:fb:48,192.168.100.10,compute-0', 'state': 'present'})
2026-01-20 16:49:27.709183 | controller | changed: [instance] => (item={'file': 'public_compute-1_52:54:01:85:95:13', 'entry': 'set:compute,52:54:01:85:95:13,192.168.100.11,compute-1', 'state': 'present'})
2026-01-20 16:49:27.709217 | controller |
2026-01-20 16:49:27.709225 | controller | TASK [dnsmasq : Remove DHCP entries] *******************************************
2026-01-20 16:49:27.709232 | controller | Tuesday 20 January 2026  16:49:27 +0000 (0:00:00.848)       0:01:02.608 *******
2026-01-20 16:49:27.709242 | controller | skipping: [instance]
2026-01-20 16:49:27.856071 | controller |
2026-01-20 16:49:27.856121 | controller | TASK [libvirt_manager : Create per-network and .utility DNS entries] ***********
2026-01-20 16:49:27.856135 | controller | Tuesday 20 January 2026  16:49:27 +0000 (0:00:00.024)       0:01:02.633 *******
2026-01-20 16:49:27.856146 | controller | ok: [instance] => (item=compute-0)
2026-01-20 16:49:27.936724 | controller | ok: [instance] => (item=compute-1)
2026-01-20 16:49:27.936790 | controller |
2026-01-20 16:49:27.936804 | controller | TASK [Inject VMs in the .utility zone] *****************************************
2026-01-20 16:49:27.936811 | controller | Tuesday 20 January 2026  16:49:27 +0000 (0:00:00.145)       0:01:02.778 *******
2026-01-20 16:49:27.936822 | controller |
2026-01-20 16:49:28.017651 | controller | TASK [dnsmasq : Assert we have needed host record data] ************************
2026-01-20 16:49:28.017689 | controller | Tuesday 20 January 2026  16:49:27 +0000 (0:00:00.081)       0:01:02.860 *******
2026-01-20 16:49:28.017702 | controller | ok: [instance]
2026-01-20 16:49:28.135389 | controller |
2026-01-20 16:49:28.135443 | controller | TASK [dnsmasq : Assert each address element have needed data] ******************
2026-01-20 16:49:28.135452 | controller | Tuesday 20 January 2026  16:49:28 +0000 (0:00:00.081)       0:01:02.941 *******
2026-01-20 16:49:28.135469 | 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-01-20 16:49:29.675483 | controller | ok: [instance] => (item={'names': ['compute-0.ctlplane.local', 'compute-0.ctlplane.local'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
2026-01-20 16:49:29.675531 | controller | ok: [instance] => (item={'names': ['compute-0.public.local', 'compute-0.public.local'], 'ips': ['192.168.100.10', ''], 'state': 'present'})
2026-01-20 16:49:29.675539 | 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-01-20 16:49:29.675546 | controller | ok: [instance] => (item={'names': ['compute-1.ctlplane.local', 'compute-1.ctlplane.local'], 'ips': ['192.168.122.11', ''], 'state': 'present'})
2026-01-20 16:49:29.675551 | controller | ok: [instance] => (item={'names': ['compute-1.public.local', 'compute-1.public.local'], 'ips': ['192.168.100.11', ''], 'state': 'present'})
2026-01-20 16:49:29.675557 | controller |
2026-01-20 16:49:29.675563 | controller | TASK [dnsmasq : Add/Remove address] ********************************************
2026-01-20 16:49:29.675569 | controller | Tuesday 20 January 2026  16:49:28 +0000 (0:00:00.116)       0:01:03.057 *******
2026-01-20 16:49:29.675580 | 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-01-20 16:49:29.697856 | controller | changed: [instance] => (item={'names': ['compute-0.ctlplane.local', 'compute-0.ctlplane.local'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
2026-01-20 16:49:29.697885 | controller | changed: [instance] => (item={'names': ['compute-0.public.local', 'compute-0.public.local'], 'ips': ['192.168.100.10', ''], 'state': 'present'})
2026-01-20 16:49:29.697894 | 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-01-20 16:49:29.697904 | controller | changed: [instance] => (item={'names': ['compute-1.ctlplane.local', 'compute-1.ctlplane.local'], 'ips': ['192.168.122.11', ''], 'state': 'present'})
2026-01-20 16:49:29.697911 | controller | changed: [instance] => (item={'names': ['compute-1.public.local', 'compute-1.public.local'], 'ips': ['192.168.100.11', ''], 'state': 'present'})
2026-01-20 16:49:29.697917 | controller |
2026-01-20 16:49:29.697923 | controller | TASK [libvirt_manager : Initialize empty _lm_dhcp_options fact] ****************
2026-01-20 16:49:29.697932 | controller | Tuesday 20 January 2026  16:49:29 +0000 (0:00:01.540)       0:01:04.598 *******
2026-01-20 16:49:29.697950 | controller | ok: [instance]
2026-01-20 16:49:29.698102 | controller |
2026-01-20 16:49:29.698118 | controller | TASK [libvirt_manager : Collect DHCP options from VM definitions] **************
2026-01-20 16:49:29.698129 | controller | Tuesday 20 January 2026  16:49:29 +0000 (0:00:00.023)       0:01:04.621 *******
2026-01-20 16:49:29.740019 | controller | skipping: [instance] => (item=compute)
2026-01-20 16:49:29.777629 | controller | skipping: [instance]
2026-01-20 16:49:29.777664 | controller |
2026-01-20 16:49:29.777676 | controller | TASK [libvirt_manager : Generate DHCP option configuration for VM types] *******
2026-01-20 16:49:29.777685 | controller | Tuesday 20 January 2026  16:49:29 +0000 (0:00:00.041)       0:01:04.663 *******
2026-01-20 16:49:29.777696 | controller | skipping: [instance]
2026-01-20 16:49:30.226527 | controller |
2026-01-20 16:49:30.226575 | controller | TASK [libvirt_manager : Ensure some domains are local] *************************
2026-01-20 16:49:30.226590 | controller | Tuesday 20 January 2026  16:49:29 +0000 (0:00:00.037)       0:01:04.701 *******
2026-01-20 16:49:30.226602 | controller | changed: [instance]
2026-01-20 16:49:31.209417 | controller |
2026-01-20 16:49:31.209463 | controller | TASK [libvirt_manager : Ensure dnsmasq is reloaded now] ************************
2026-01-20 16:49:31.209472 | controller | Tuesday 20 January 2026  16:49:30 +0000 (0:00:00.435)       0:01:05.137 *******
2026-01-20 16:49:31.209478 | controller |
2026-01-20 16:49:31.209484 | controller | RUNNING HANDLER [libvirt_manager : Restart firewalld] **************************
2026-01-20 16:49:31.209489 | controller | Tuesday 20 January 2026  16:49:30 +0000 (0:00:00.012)       0:01:05.149 *******
2026-01-20 16:49:31.209499 | controller | changed: [instance]
2026-01-20 16:49:31.601555 | controller |
2026-01-20 16:49:31.601600 | controller | RUNNING HANDLER [dnsmasq : Restart dnsmasq] ************************************
2026-01-20 16:49:31.601615 | controller | Tuesday 20 January 2026  16:49:31 +0000 (0:00:00.982)       0:01:06.132 *******
2026-01-20 16:49:31.601627 | controller | changed: [instance]
2026-01-20 16:49:32.041650 | controller |
2026-01-20 16:49:32.041692 | controller | RUNNING HANDLER [dnsmasq : Reload dnsmasq] *************************************
2026-01-20 16:49:32.041708 | controller | Tuesday 20 January 2026  16:49:31 +0000 (0:00:00.389)       0:01:06.521 *******
2026-01-20 16:49:32.041724 | controller | changed: [instance]
2026-01-20 16:49:32.545732 | controller |
2026-01-20 16:49:32.545791 | controller | TASK [libvirt_manager : Create group inventories] ******************************
2026-01-20 16:49:32.545800 | controller | Tuesday 20 January 2026  16:49:32 +0000 (0:00:00.443)       0:01:06.964 *******
2026-01-20 16:49:32.545816 | controller | changed: [instance] => (item=compute)
2026-01-20 16:49:32.624516 | controller |
2026-01-20 16:49:32.624565 | controller | TASK [libvirt_manager : Create "all" group inventory file] *********************
2026-01-20 16:49:32.624578 | controller | Tuesday 20 January 2026  16:49:32 +0000 (0:00:00.504)       0:01:07.469 *******
2026-01-20 16:49:32.624592 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_all_group_inventory.yml for instance
2026-01-20 16:49:32.849216 | controller |
2026-01-20 16:49:32.849253 | controller | TASK [libvirt_manager : Check if all-group.yml already exists] *****************
2026-01-20 16:49:32.849262 | controller | Tuesday 20 January 2026  16:49:32 +0000 (0:00:00.078)       0:01:07.547 *******
2026-01-20 16:49:32.849272 | controller | ok: [instance]
2026-01-20 16:49:32.880480 | controller |
2026-01-20 16:49:32.880515 | controller | TASK [libvirt_manager : Slurp existing all-group.yml if it exists] *************
2026-01-20 16:49:32.880529 | controller | Tuesday 20 January 2026  16:49:32 +0000 (0:00:00.224)       0:01:07.772 *******
2026-01-20 16:49:32.880539 | controller | skipping: [instance]
2026-01-20 16:49:33.372664 | controller |
2026-01-20 16:49:33.372719 | controller | TASK [libvirt_manager : Create new "all" group inventory file from template] ***
2026-01-20 16:49:33.372729 | controller | Tuesday 20 January 2026  16:49:32 +0000 (0:00:00.031)       0:01:07.804 *******
2026-01-20 16:49:33.372745 | controller | changed: [instance]
2026-01-20 16:49:33.404792 | controller |
2026-01-20 16:49:33.404826 | controller | TASK [libvirt_manager : Slurp newly created all-group.yml] *********************
2026-01-20 16:49:33.404835 | controller | Tuesday 20 January 2026  16:49:33 +0000 (0:00:00.491)       0:01:08.295 *******
2026-01-20 16:49:33.404849 | controller | skipping: [instance]
2026-01-20 16:49:33.441805 | controller |
2026-01-20 16:49:33.441830 | controller | TASK [libvirt_manager : Write merged all-group.yml] ****************************
2026-01-20 16:49:33.441838 | controller | Tuesday 20 January 2026  16:49:33 +0000 (0:00:00.032)       0:01:08.328 *******
2026-01-20 16:49:33.441848 | controller | skipping: [instance]
2026-01-20 16:49:33.497319 | controller |
2026-01-20 16:49:33.497341 | controller | TASK [libvirt_manager : Ensure storage pool is present.] ***********************
2026-01-20 16:49:33.497348 | controller | Tuesday 20 January 2026  16:49:33 +0000 (0:00:00.036)       0:01:08.365 *******
2026-01-20 16:49:33.497363 | controller | skipping: [instance]
2026-01-20 16:49:33.607321 | controller |
2026-01-20 16:49:33.607349 | controller | TASK [libvirt_manager : Ensure images are present] *****************************
2026-01-20 16:49:33.607368 | controller | Tuesday 20 January 2026  16:49:33 +0000 (0:00:00.055)       0:01:08.421 *******
2026-01-20 16:49:33.607380 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/get_image.yml for instance => (item=compute)
2026-01-20 16:49:33.633910 | controller |
2026-01-20 16:49:33.633930 | controller | TASK [libvirt_manager : Ensure directory exists] *******************************
2026-01-20 16:49:33.633937 | controller | Tuesday 20 January 2026  16:49:33 +0000 (0:00:00.109)       0:01:08.530 *******
2026-01-20 16:49:33.633947 | controller | skipping: [instance]
2026-01-20 16:49:33.656258 | controller |
2026-01-20 16:49:33.656282 | controller | TASK [libvirt_manager : Check if base image exists] ****************************
2026-01-20 16:49:33.656289 | controller | Tuesday 20 January 2026  16:49:33 +0000 (0:00:00.027)       0:01:08.558 *******
2026-01-20 16:49:33.656298 | controller | skipping: [instance]
2026-01-20 16:49:33.684658 | controller |
2026-01-20 16:49:33.684690 | controller | TASK [libvirt_manager : Download base image] ***********************************
2026-01-20 16:49:33.684700 | controller | Tuesday 20 January 2026  16:49:33 +0000 (0:00:00.022)       0:01:08.580 *******
2026-01-20 16:49:33.684711 | controller | skipping: [instance]
2026-01-20 16:49:33.718156 | controller |
2026-01-20 16:49:33.718195 | controller | TASK [libvirt_manager : Check image] *******************************************
2026-01-20 16:49:33.718203 | controller | Tuesday 20 January 2026  16:49:33 +0000 (0:00:00.028)       0:01:08.608 *******
2026-01-20 16:49:33.718212 | controller | skipping: [instance]
2026-01-20 16:49:33.749398 | controller |
2026-01-20 16:49:33.749420 | controller | TASK [libvirt_manager : Assert image status] ***********************************
2026-01-20 16:49:33.749428 | controller | Tuesday 20 January 2026  16:49:33 +0000 (0:00:00.033)       0:01:08.642 *******
2026-01-20 16:49:33.749437 | controller | skipping: [instance]
2026-01-20 16:49:33.780078 | controller |
2026-01-20 16:49:33.780102 | controller | TASK [libvirt_manager : Ensure image access rights] ****************************
2026-01-20 16:49:33.780111 | controller | Tuesday 20 January 2026  16:49:33 +0000 (0:00:00.031)       0:01:08.673 *******
2026-01-20 16:49:33.780119 | controller | skipping: [instance]
2026-01-20 16:49:34.020918 | controller |
2026-01-20 16:49:34.020971 | controller | TASK [libvirt_manager : Get ssh key state] *************************************
2026-01-20 16:49:34.020982 | controller | Tuesday 20 January 2026  16:49:33 +0000 (0:00:00.030)       0:01:08.703 *******
2026-01-20 16:49:34.020997 | controller | ok: [instance]
2026-01-20 16:49:34.587940 | controller |
2026-01-20 16:49:34.587991 | controller | TASK [libvirt_manager : Create temporary ssh keypair] **************************
2026-01-20 16:49:34.588004 | controller | Tuesday 20 January 2026  16:49:34 +0000 (0:00:00.240)       0:01:08.944 *******
2026-01-20 16:49:34.588017 | controller | changed: [instance]
2026-01-20 16:49:34.951764 | controller |
2026-01-20 16:49:34.951808 | controller | TASK [libvirt_manager : Slurp public key for later use] ************************
2026-01-20 16:49:34.951817 | controller | Tuesday 20 January 2026  16:49:34 +0000 (0:00:00.567)       0:01:09.511 *******
2026-01-20 16:49:34.951838 | controller | ok: [instance]
2026-01-20 16:49:35.204209 | controller |
2026-01-20 16:49:35.204256 | controller | TASK [libvirt_manager : Slurp private key for later use] ***********************
2026-01-20 16:49:35.204264 | controller | Tuesday 20 January 2026  16:49:34 +0000 (0:00:00.355)       0:01:09.867 *******
2026-01-20 16:49:35.204281 | controller | ok: [instance]
2026-01-20 16:49:35.703681 | controller |
2026-01-20 16:49:35.703721 | controller | TASK [libvirt_manager : Inject cifmw_reproducer_key.pub in hypervisor authorized_keys] ***
2026-01-20 16:49:35.703730 | controller | Tuesday 20 January 2026  16:49:35 +0000 (0:00:00.254)       0:01:10.122 *******
2026-01-20 16:49:35.703742 | controller | changed: [instance]
2026-01-20 16:49:35.735205 | controller |
2026-01-20 16:49:35.735247 | controller | TASK [libvirt_manager : Create fact holding network data for VMs] **************
2026-01-20 16:49:35.735256 | controller | Tuesday 20 January 2026  16:49:35 +0000 (0:00:00.505)       0:01:10.627 *******
2026-01-20 16:49:35.735268 | controller | ok: [instance]
2026-01-20 16:49:36.047816 | controller |
2026-01-20 16:49:36.047870 | controller | TASK [libvirt_manager : List existing networks] ********************************
2026-01-20 16:49:36.047883 | controller | Tuesday 20 January 2026  16:49:35 +0000 (0:00:00.031)       0:01:10.658 *******
2026-01-20 16:49:36.047896 | controller | ok: [instance]
2026-01-20 16:49:36.448597 | controller |
2026-01-20 16:49:36.448639 | controller | TASK [libvirt_manager : Gather pool fact] **************************************
2026-01-20 16:49:36.448648 | controller | Tuesday 20 January 2026  16:49:36 +0000 (0:00:00.308)       0:01:10.967 *******
2026-01-20 16:49:36.448659 | controller | ok: [instance]
2026-01-20 16:49:36.560881 | controller |
2026-01-20 16:49:36.560916 | controller | TASK [libvirt_manager : Create and run VMs] ************************************
2026-01-20 16:49:36.560929 | controller | Tuesday 20 January 2026  16:49:36 +0000 (0:00:00.405)       0:01:11.372 *******
2026-01-20 16:49:36.560948 | 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-01-20 16:49:36.888841 | 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-01-20 16:49:36.888875 | controller |
2026-01-20 16:49:36.888883 | controller | TASK [libvirt_manager : Create VM image for compute-0] *************************
2026-01-20 16:49:36.888890 | controller | Tuesday 20 January 2026  16:49:36 +0000 (0:00:00.112)       0:01:11.484 *******
2026-01-20 16:49:36.888900 | controller | changed: [instance]
2026-01-20 16:49:37.148774 | controller |
2026-01-20 16:49:37.148815 | controller | TASK [libvirt_manager : Ensure file ownership and rights for compute-0] ********
2026-01-20 16:49:37.148824 | controller | Tuesday 20 January 2026  16:49:36 +0000 (0:00:00.327)       0:01:11.812 *******
2026-01-20 16:49:37.148839 | controller | changed: [instance]
2026-01-20 16:49:37.690731 | controller |
2026-01-20 16:49:37.690794 | controller | TASK [libvirt_manager : Define VMs for type compute-0] *************************
2026-01-20 16:49:37.690803 | controller | Tuesday 20 January 2026  16:49:37 +0000 (0:00:00.259)       0:01:12.072 *******
2026-01-20 16:49:37.690814 | controller | changed: [instance]
2026-01-20 16:49:37.721898 | controller |
2026-01-20 16:49:37.721925 | controller | TASK [libvirt_manager : Attach listed networks to the VMs compute-0] ***********
2026-01-20 16:49:37.721933 | controller | Tuesday 20 January 2026  16:49:37 +0000 (0:00:00.541)       0:01:12.613 *******
2026-01-20 16:49:37.721954 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/net_to_vms.yml for instance
2026-01-20 16:49:37.760837 | controller |
2026-01-20 16:49:37.760861 | controller | TASK [libvirt_manager : Attach {{ vm_item }} to {{ net_item }}] ****************
2026-01-20 16:49:37.760869 | controller | Tuesday 20 January 2026  16:49:37 +0000 (0:00:00.032)       0:01:12.646 *******
2026-01-20 16:49:37.760879 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/attach_interface.yml for instance => (item=public)
2026-01-20 16:49:38.056005 | controller |
2026-01-20 16:49:38.056043 | controller | TASK [libvirt_manager : Get virtual network information] ***********************
2026-01-20 16:49:38.056051 | controller | Tuesday 20 January 2026  16:49:37 +0000 (0:00:00.038)       0:01:12.685 *******
2026-01-20 16:49:38.056062 | controller | ok: [instance]
2026-01-20 16:49:38.113950 | controller |
2026-01-20 16:49:38.113992 | controller | TASK [libvirt_manager : Create network to bridge mapping] **********************
2026-01-20 16:49:38.114010 | controller | Tuesday 20 January 2026  16:49:38 +0000 (0:00:00.294)       0:01:12.979 *******
2026-01-20 16:49:38.114027 | controller | ok: [instance] => (item=cifmw-public)
2026-01-20 16:49:38.402253 | controller | ok: [instance] => (item=default)
2026-01-20 16:49:38.402343 | controller | ok: [instance] => (item=crc)
2026-01-20 16:49:38.402352 | controller |
2026-01-20 16:49:38.402358 | controller | TASK [libvirt_manager : Dump domain xml] ***************************************
2026-01-20 16:49:38.402364 | controller | Tuesday 20 January 2026  16:49:38 +0000 (0:00:00.057)       0:01:13.037 *******
2026-01-20 16:49:38.402375 | controller | ok: [instance]
2026-01-20 16:49:38.652620 | controller |
2026-01-20 16:49:38.652665 | controller | TASK [libvirt_manager : Extract networks from XML] *****************************
2026-01-20 16:49:38.652674 | controller | Tuesday 20 January 2026  16:49:38 +0000 (0:00:00.288)       0:01:13.325 *******
2026-01-20 16:49:38.652685 | controller | ok: [instance]
2026-01-20 16:49:39.008311 | controller |
2026-01-20 16:49:39.008348 | controller | TASK [libvirt_manager : Attach interface public on cifmw-compute-0] ************
2026-01-20 16:49:39.008357 | controller | Tuesday 20 January 2026  16:49:38 +0000 (0:00:00.250)       0:01:13.576 *******
2026-01-20 16:49:39.008368 | controller | changed: [instance]
2026-01-20 16:49:39.034473 | controller |
2026-01-20 16:49:39.034509 | controller | TASK [libvirt_manager : Attach spines/leafs networks to the VMs compute-0] *****
2026-01-20 16:49:39.034518 | controller | Tuesday 20 January 2026  16:49:39 +0000 (0:00:00.355)       0:01:13.932 *******
2026-01-20 16:49:39.034528 | controller | skipping: [instance]
2026-01-20 16:49:39.067625 | controller |
2026-01-20 16:49:39.067648 | controller | TASK [libvirt_manager : Create the requested extra disks for compute-0] ********
2026-01-20 16:49:39.067657 | controller | Tuesday 20 January 2026  16:49:39 +0000 (0:00:00.026)       0:01:13.958 *******
2026-01-20 16:49:39.067666 | controller | skipping: [instance]
2026-01-20 16:49:39.101510 | controller |
2026-01-20 16:49:39.101536 | controller | TASK [libvirt_manager : Find volume attachments for VM compute-0] **************
2026-01-20 16:49:39.101546 | controller | Tuesday 20 January 2026  16:49:39 +0000 (0:00:00.033)       0:01:13.991 *******
2026-01-20 16:49:39.101558 | controller | skipping: [instance]
2026-01-20 16:49:39.132964 | controller |
2026-01-20 16:49:39.132993 | controller | TASK [libvirt_manager : Attach volumes for VM compute-0] ***********************
2026-01-20 16:49:39.133006 | controller | Tuesday 20 January 2026  16:49:39 +0000 (0:00:00.033)       0:01:14.025 *******
2026-01-20 16:49:39.133016 | controller | skipping: [instance]
2026-01-20 16:49:39.408005 | controller |
2026-01-20 16:49:39.408052 | controller | TASK [libvirt_manager : Get VM UUID] *******************************************
2026-01-20 16:49:39.408060 | controller | Tuesday 20 January 2026  16:49:39 +0000 (0:00:00.031)       0:01:14.056 *******
2026-01-20 16:49:39.408071 | controller | changed: [instance]
2026-01-20 16:49:39.459171 | controller |
2026-01-20 16:49:39.459237 | controller | TASK [libvirt_manager : Inject UUID in dataset] ********************************
2026-01-20 16:49:39.459246 | controller | Tuesday 20 January 2026  16:49:39 +0000 (0:00:00.274)       0:01:14.331 *******
2026-01-20 16:49:39.459258 | controller | ok: [instance]
2026-01-20 16:49:39.490409 | controller |
2026-01-20 16:49:39.490446 | controller | TASK [libvirt_manager : Create cloud-init ISO] *********************************
2026-01-20 16:49:39.490453 | controller | Tuesday 20 January 2026  16:49:39 +0000 (0:00:00.051)       0:01:14.382 *******
2026-01-20 16:49:39.490463 | controller | skipping: [instance]
2026-01-20 16:49:39.521729 | controller |
2026-01-20 16:49:39.521770 | controller | TASK [libvirt_manager : Attach cloud-init ISO if exists] ***********************
2026-01-20 16:49:39.521781 | controller | Tuesday 20 January 2026  16:49:39 +0000 (0:00:00.031)       0:01:14.414 *******
2026-01-20 16:49:39.521791 | controller | skipping: [instance]
2026-01-20 16:49:39.581010 | controller |
2026-01-20 16:49:39.581041 | controller | TASK [libvirt_manager : Attach additional devices if specified] ****************
2026-01-20 16:49:39.581050 | controller | Tuesday 20 January 2026  16:49:39 +0000 (0:00:00.031)       0:01:14.445 *******
2026-01-20 16:49:39.581059 | controller | skipping: [instance]
2026-01-20 16:49:39.627492 | controller |
2026-01-20 16:49:39.627542 | controller | TASK [libvirt_manager : Configure boot order for compute-0] ********************
2026-01-20 16:49:39.627550 | controller | Tuesday 20 January 2026  16:49:39 +0000 (0:00:00.059)       0:01:14.504 *******
2026-01-20 16:49:39.627561 | controller | skipping: [instance]
2026-01-20 16:49:39.627816 | controller |
2026-01-20 16:49:39.627999 | controller | TASK [libvirt_manager : Create VM image for compute-1] *************************
2026-01-20 16:49:39.628146 | controller | Tuesday 20 January 2026  16:49:39 +0000 (0:00:00.046)       0:01:14.551 *******
2026-01-20 16:49:39.933977 | controller | changed: [instance]
2026-01-20 16:49:40.235971 | controller |
2026-01-20 16:49:40.236023 | controller | TASK [libvirt_manager : Ensure file ownership and rights for compute-1] ********
2026-01-20 16:49:40.236037 | controller | Tuesday 20 January 2026  16:49:39 +0000 (0:00:00.300)       0:01:14.852 *******
2026-01-20 16:49:40.236051 | controller | changed: [instance]
2026-01-20 16:49:40.625955 | controller |
2026-01-20 16:49:40.625997 | controller | TASK [libvirt_manager : Define VMs for type compute-1] *************************
2026-01-20 16:49:40.626006 | controller | Tuesday 20 January 2026  16:49:40 +0000 (0:00:00.304)       0:01:15.156 *******
2026-01-20 16:49:40.626037 | controller | changed: [instance]
2026-01-20 16:49:40.662917 | controller |
2026-01-20 16:49:40.662955 | controller | TASK [libvirt_manager : Attach listed networks to the VMs compute-1] ***********
2026-01-20 16:49:40.662963 | controller | Tuesday 20 January 2026  16:49:40 +0000 (0:00:00.392)       0:01:15.549 *******
2026-01-20 16:49:40.662975 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/net_to_vms.yml for instance
2026-01-20 16:49:40.705402 | controller |
2026-01-20 16:49:40.705433 | controller | TASK [libvirt_manager : Attach {{ vm_item }} to {{ net_item }}] ****************
2026-01-20 16:49:40.705446 | controller | Tuesday 20 January 2026  16:49:40 +0000 (0:00:00.037)       0:01:15.586 *******
2026-01-20 16:49:40.705457 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/attach_interface.yml for instance => (item=public)
2026-01-20 16:49:41.002697 | controller |
2026-01-20 16:49:41.002743 | controller | TASK [libvirt_manager : Get virtual network information] ***********************
2026-01-20 16:49:41.002779 | controller | Tuesday 20 January 2026  16:49:40 +0000 (0:00:00.042)       0:01:15.629 *******
2026-01-20 16:49:41.002796 | controller | ok: [instance]
2026-01-20 16:49:41.066066 | controller |
2026-01-20 16:49:41.066119 | controller | TASK [libvirt_manager : Create network to bridge mapping] **********************
2026-01-20 16:49:41.066128 | controller | Tuesday 20 January 2026  16:49:40 +0000 (0:00:00.296)       0:01:15.925 *******
2026-01-20 16:49:41.066140 | controller | ok: [instance] => (item=cifmw-public)
2026-01-20 16:49:41.385877 | controller | ok: [instance] => (item=default)
2026-01-20 16:49:41.385914 | controller | ok: [instance] => (item=crc)
2026-01-20 16:49:41.385922 | controller |
2026-01-20 16:49:41.385928 | controller | TASK [libvirt_manager : Dump domain xml] ***************************************
2026-01-20 16:49:41.385935 | controller | Tuesday 20 January 2026  16:49:41 +0000 (0:00:00.063)       0:01:15.989 *******
2026-01-20 16:49:41.385945 | controller | ok: [instance]
2026-01-20 16:49:41.626274 | controller |
2026-01-20 16:49:41.626321 | controller | TASK [libvirt_manager : Extract networks from XML] *****************************
2026-01-20 16:49:41.626330 | controller | Tuesday 20 January 2026  16:49:41 +0000 (0:00:00.320)       0:01:16.309 *******
2026-01-20 16:49:41.626350 | controller | ok: [instance]
2026-01-20 16:49:42.025174 | controller |
2026-01-20 16:49:42.025240 | controller | TASK [libvirt_manager : Attach interface public on cifmw-compute-1] ************
2026-01-20 16:49:42.025249 | controller | Tuesday 20 January 2026  16:49:41 +0000 (0:00:00.239)       0:01:16.549 *******
2026-01-20 16:49:42.025260 | controller | changed: [instance]
2026-01-20 16:49:42.055683 | controller |
2026-01-20 16:49:42.055717 | controller | TASK [libvirt_manager : Attach spines/leafs networks to the VMs compute-1] *****
2026-01-20 16:49:42.055732 | controller | Tuesday 20 January 2026  16:49:42 +0000 (0:00:00.396)       0:01:16.946 *******
2026-01-20 16:49:42.055747 | controller | skipping: [instance]
2026-01-20 16:49:42.091176 | controller |
2026-01-20 16:49:42.091235 | controller | TASK [libvirt_manager : Create the requested extra disks for compute-1] ********
2026-01-20 16:49:42.091244 | controller | Tuesday 20 January 2026  16:49:42 +0000 (0:00:00.033)       0:01:16.979 *******
2026-01-20 16:49:42.091255 | controller | skipping: [instance]
2026-01-20 16:49:42.124241 | controller |
2026-01-20 16:49:42.124303 | controller | TASK [libvirt_manager : Find volume attachments for VM compute-1] **************
2026-01-20 16:49:42.124312 | controller | Tuesday 20 January 2026  16:49:42 +0000 (0:00:00.034)       0:01:17.014 *******
2026-01-20 16:49:42.124326 | controller | skipping: [instance]
2026-01-20 16:49:42.124344 | controller |
2026-01-20 16:49:42.124352 | controller | TASK [libvirt_manager : Attach volumes for VM compute-1] ***********************
2026-01-20 16:49:42.124379 | controller | Tuesday 20 January 2026  16:49:42 +0000 (0:00:00.033)       0:01:17.048 *******
2026-01-20 16:49:42.154199 | controller | skipping: [instance]
2026-01-20 16:49:42.154288 | controller |
2026-01-20 16:49:42.154404 | controller | TASK [libvirt_manager : Get VM UUID] *******************************************
2026-01-20 16:49:42.154519 | controller | Tuesday 20 January 2026  16:49:42 +0000 (0:00:00.030)       0:01:17.078 *******
2026-01-20 16:49:42.429169 | controller | changed: [instance]
2026-01-20 16:49:42.429281 | controller |
2026-01-20 16:49:42.429403 | controller | TASK [libvirt_manager : Inject UUID in dataset] ********************************
2026-01-20 16:49:42.429547 | controller | Tuesday 20 January 2026  16:49:42 +0000 (0:00:00.274)       0:01:17.353 *******
2026-01-20 16:49:42.476535 | controller | ok: [instance]
2026-01-20 16:49:42.476625 | controller |
2026-01-20 16:49:42.476778 | controller | TASK [libvirt_manager : Create cloud-init ISO] *********************************
2026-01-20 16:49:42.476916 | controller | Tuesday 20 January 2026  16:49:42 +0000 (0:00:00.047)       0:01:17.400 *******
2026-01-20 16:49:42.507398 | controller | skipping: [instance]
2026-01-20 16:49:42.507456 | controller |
2026-01-20 16:49:42.507587 | controller | TASK [libvirt_manager : Attach cloud-init ISO if exists] ***********************
2026-01-20 16:49:42.507689 | controller | Tuesday 20 January 2026  16:49:42 +0000 (0:00:00.031)       0:01:17.431 *******
2026-01-20 16:49:42.540102 | controller | skipping: [instance]
2026-01-20 16:49:42.540182 | controller |
2026-01-20 16:49:42.540462 | controller | TASK [libvirt_manager : Attach additional devices if specified] ****************
2026-01-20 16:49:42.540495 | controller | Tuesday 20 January 2026  16:49:42 +0000 (0:00:00.032)       0:01:17.464 *******
2026-01-20 16:49:42.593892 | controller | skipping: [instance]
2026-01-20 16:49:42.594027 | controller |
2026-01-20 16:49:42.594196 | controller | TASK [libvirt_manager : Configure boot order for compute-1] ********************
2026-01-20 16:49:42.594335 | controller | Tuesday 20 January 2026  16:49:42 +0000 (0:00:00.053)       0:01:17.517 *******
2026-01-20 16:49:42.626802 | controller | skipping: [instance]
2026-01-20 16:49:42.626975 | controller |
2026-01-20 16:49:42.627066 | controller | TASK [libvirt_manager : Start (power-on) VMs] **********************************
2026-01-20 16:49:42.627234 | controller | Tuesday 20 January 2026  16:49:42 +0000 (0:00:00.033)       0:01:17.551 *******
2026-01-20 16:49:42.678309 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/start_vms.yml for instance
2026-01-20 16:49:42.678374 | controller |
2026-01-20 16:49:42.678520 | controller | TASK [libvirt_manager : Refresh oooq_pool before starting VMs] *****************
2026-01-20 16:49:42.678620 | controller | Tuesday 20 January 2026  16:49:42 +0000 (0:00:00.050)       0:01:17.602 *******
2026-01-20 16:49:42.976445 | controller | ok: [instance] => (item=crc)
2026-01-20 16:49:42.976528 | controller |
2026-01-20 16:49:42.976702 | controller | TASK [libvirt_manager : Start VMs for type {{ vm_type }}] **********************
2026-01-20 16:49:42.976889 | controller | Tuesday 20 January 2026  16:49:42 +0000 (0:00:00.298)       0:01:17.900 *******
2026-01-20 16:49:44.037695 | controller | skipping: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
2026-01-20 16:49:44.037802 | controller | skipping: [instance] => (item={'key': 'compute-1', 'value': 'compute'})
2026-01-20 16:49:44.037931 | controller | skipping: [instance]
2026-01-20 16:49:44.038048 | controller |
2026-01-20 16:49:44.038178 | controller | TASK [libvirt_manager : Wait for SSH on started VMs] ***************************
2026-01-20 16:49:44.038343 | controller | Tuesday 20 January 2026  16:49:44 +0000 (0:00:01.060)       0:01:18.961 *******
2026-01-20 16:49:44.106120 | controller | skipping: [instance] => (item=compute-0.utility)
2026-01-20 16:49:44.106182 | controller | skipping: [instance] => (item=compute-1.utility)
2026-01-20 16:49:44.106281 | controller | skipping: [instance]
2026-01-20 16:49:44.106392 | controller |
2026-01-20 16:49:44.106509 | controller | TASK [libvirt_manager : Ensure we get SSH on nodes] ****************************
2026-01-20 16:49:44.106674 | controller | Tuesday 20 January 2026  16:49:44 +0000 (0:00:00.064)       0:01:19.025 *******
2026-01-20 16:49:44.146243 | 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-01-20 16:49:44.146368 | 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-01-20 16:49:44.146507 | controller | skipping: [instance]
2026-01-20 16:49:44.146624 | controller |
2026-01-20 16:49:44.146741 | controller | TASK [libvirt_manager : Configure managed VMs] *********************************
2026-01-20 16:49:44.146881 | controller | Tuesday 20 January 2026  16:49:44 +0000 (0:00:00.044)       0:01:19.070 *******
2026-01-20 16:49:44.195947 | controller | skipping: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
2026-01-20 16:49:44.196048 | controller | skipping: [instance] => (item={'key': 'compute-1', 'value': 'compute'})
2026-01-20 16:49:44.196167 | controller | skipping: [instance]
2026-01-20 16:49:44.196314 | controller |
2026-01-20 16:49:44.196427 | controller | TASK [Create VBMC entity] ******************************************************
2026-01-20 16:49:44.196552 | controller | Tuesday 20 January 2026  16:49:44 +0000 (0:00:00.049)       0:01:19.120 *******
2026-01-20 16:49:44.242942 | controller | skipping: [instance] => (item=compute-0)
2026-01-20 16:49:44.243055 | controller | skipping: [instance] => (item=compute-1)
2026-01-20 16:49:44.243223 | controller | skipping: [instance]
2026-01-20 16:49:44.243360 | controller |
2026-01-20 16:49:44.243466 | controller | TASK [libvirt_manager : List running virtual machines.] ************************
2026-01-20 16:49:44.243557 | controller | Tuesday 20 January 2026  16:49:44 +0000 (0:00:00.047)       0:01:19.167 *******
2026-01-20 16:49:44.509799 | controller | ok: [instance]
2026-01-20 16:49:44.509879 | controller |
2026-01-20 16:49:44.510026 | controller | TASK [libvirt_manager : Dump UUIDs] ********************************************
2026-01-20 16:49:44.510150 | controller | Tuesday 20 January 2026  16:49:44 +0000 (0:00:00.266)       0:01:19.433 *******
2026-01-20 16:49:44.930560 | controller | changed: [instance]
2026-01-20 16:49:44.930641 | controller |
2026-01-20 16:49:44.930797 | controller | TASK [Ensure fresh vbmc listing] ***********************************************
2026-01-20 16:49:44.930930 | controller | Tuesday 20 January 2026  16:49:44 +0000 (0:00:00.420)       0:01:19.854 *******
2026-01-20 16:49:44.971379 | controller | skipping: [instance]
2026-01-20 16:49:44.971486 | controller |
2026-01-20 16:49:44.971614 | controller | TASK [libvirt_manager : Update vbmc related fact] ******************************
2026-01-20 16:49:44.971719 | controller | Tuesday 20 January 2026  16:49:44 +0000 (0:00:00.041)       0:01:19.895 *******
2026-01-20 16:49:45.010719 | controller | skipping: [instance]
2026-01-20 16:49:45.010841 | controller |
2026-01-20 16:49:45.010993 | controller | TASK [libvirt_manager : Dump vbmc known hosts] *********************************
2026-01-20 16:49:45.011119 | controller | Tuesday 20 January 2026  16:49:45 +0000 (0:00:00.039)       0:01:19.935 *******
2026-01-20 16:49:45.047953 | controller | skipping: [instance]
2026-01-20 16:49:45.048050 | controller |
2026-01-20 16:49:45.048159 | controller | TASK [libvirt_manager : Copy authorized_keys] **********************************
2026-01-20 16:49:45.048280 | controller | Tuesday 20 January 2026  16:49:45 +0000 (0:00:00.037)       0:01:19.972 *******
2026-01-20 16:49:45.077749 | controller | skipping: [instance]
2026-01-20 16:49:45.077852 | controller |
2026-01-20 16:49:45.077963 | controller | TASK [libvirt_manager : Enable root access on CRC] *****************************
2026-01-20 16:49:45.078097 | controller | Tuesday 20 January 2026  16:49:45 +0000 (0:00:00.029)       0:01:20.002 *******
2026-01-20 16:49:45.114852 | controller | skipping: [instance]
2026-01-20 16:49:45.114915 | controller |
2026-01-20 16:49:45.115063 | controller | TASK [Generate baremetal-info fact] ********************************************
2026-01-20 16:49:45.115174 | controller | Tuesday 20 January 2026  16:49:45 +0000 (0:00:00.037)       0:01:20.039 *******
2026-01-20 16:49:45.196599 | controller |
2026-01-20 16:49:45.196703 | controller | TASK [reproducer : Ensure directories exist] ***********************************
2026-01-20 16:49:45.196839 | controller | Tuesday 20 January 2026  16:49:45 +0000 (0:00:00.081)       0:01:20.121 *******
2026-01-20 16:49:45.662227 | controller | changed: [instance] => (item=parameters)
2026-01-20 16:49:45.662346 | controller | ok: [instance] => (item=artifacts)
2026-01-20 16:49:45.662469 | controller |
2026-01-20 16:49:45.662608 | controller | TASK [reproducer : Convert VBMC list into a dict for better usage] *************
2026-01-20 16:49:45.662746 | controller | Tuesday 20 January 2026  16:49:45 +0000 (0:00:00.465)       0:01:20.586 *******
2026-01-20 16:49:45.702511 | controller | skipping: [instance]
2026-01-20 16:49:45.702601 | controller |
2026-01-20 16:49:45.702708 | controller | TASK [reproducer : Check if baremetal-info.yml exists] *************************
2026-01-20 16:49:45.702840 | controller | Tuesday 20 January 2026  16:49:45 +0000 (0:00:00.040)       0:01:20.626 *******
2026-01-20 16:49:45.935771 | controller | ok: [instance]
2026-01-20 16:49:45.935848 | controller |
2026-01-20 16:49:45.936072 | controller | TASK [reproducer : Get content of baremetal-info file] *************************
2026-01-20 16:49:45.936179 | controller | Tuesday 20 January 2026  16:49:45 +0000 (0:00:00.232)       0:01:20.859 *******
2026-01-20 16:49:45.962628 | controller | skipping: [instance]
2026-01-20 16:49:45.962717 | controller |
2026-01-20 16:49:45.962842 | controller | TASK [reproducer : Interpret remote file content as yaml] **********************
2026-01-20 16:49:45.962950 | controller | Tuesday 20 January 2026  16:49:45 +0000 (0:00:00.027)       0:01:20.887 *******
2026-01-20 16:49:46.011391 | controller | skipping: [instance]
2026-01-20 16:49:46.011512 | controller |
2026-01-20 16:49:46.011654 | controller | TASK [reproducer : Slurp content of: /home/zuul/ci-framework-data/artifacts/interfaces-info.yml] ***
2026-01-20 16:49:46.011776 | controller | Tuesday 20 January 2026  16:49:46 +0000 (0:00:00.048)       0:01:20.935 *******
2026-01-20 16:49:46.051970 | controller | skipping: [instance]
2026-01-20 16:49:46.052089 | controller |
2026-01-20 16:49:46.052229 | controller | TASK [reproducer : Set cifmw_libvirt_manager_mac_map fact from /home/zuul/ci-framework-data/artifacts/interfaces-info.yml] ***
2026-01-20 16:49:46.052351 | controller | Tuesday 20 January 2026  16:49:46 +0000 (0:00:00.040)       0:01:20.976 *******
2026-01-20 16:49:46.083220 | controller | skipping: [instance]
2026-01-20 16:49:46.083312 | controller |
2026-01-20 16:49:46.083435 | controller | TASK [reproducer : Generate libvirt_manager_bm_info_data fact] *****************
2026-01-20 16:49:46.083526 | controller | Tuesday 20 January 2026  16:49:46 +0000 (0:00:00.031)       0:01:21.007 *******
2026-01-20 16:49:46.169579 | controller | ok: [instance] => (item={'key': 'cifmw-compute-0', 'value': '20f8929e-571d-583f-969c-f0d6357022c1'})
2026-01-20 16:49:46.169713 | controller | ok: [instance] => (item={'key': 'cifmw-compute-1', 'value': 'f40ec783-79a5-5186-b9a6-30fad0c33e27'})
2026-01-20 16:49:46.169859 | controller |
2026-01-20 16:49:46.169986 | controller | TASK [reproducer : Output baremetal info file] *********************************
2026-01-20 16:49:46.170097 | controller | Tuesday 20 January 2026  16:49:46 +0000 (0:00:00.085)       0:01:21.093 *******
2026-01-20 16:49:46.589948 | controller | changed: [instance]
2026-01-20 16:49:46.590048 | controller |
2026-01-20 16:49:46.590211 | controller | TASK [reproducer : Output ironic_nodes to file] ********************************
2026-01-20 16:49:46.590352 | controller | Tuesday 20 January 2026  16:49:46 +0000 (0:00:00.420)       0:01:21.514 *******
2026-01-20 16:49:46.622024 | controller | skipping: [instance]
2026-01-20 16:49:46.622137 | controller |
2026-01-20 16:49:46.622261 | controller | TASK [Run Sushy Emulator role against OCP] *************************************
2026-01-20 16:49:46.622389 | controller | Tuesday 20 January 2026  16:49:46 +0000 (0:00:00.032)       0:01:21.546 *******
2026-01-20 16:49:46.713374 | controller |
2026-01-20 16:49:46.713453 | controller | TASK [sushy_emulator : Create Sushy Emulator resource directory] ***************
2026-01-20 16:49:46.713582 | controller | Tuesday 20 January 2026  16:49:46 +0000 (0:00:00.090)       0:01:21.637 *******
2026-01-20 16:49:46.943936 | controller | changed: [instance]
2026-01-20 16:49:46.944025 | controller |
2026-01-20 16:49:46.944168 | controller | TASK [sushy_emulator : Install required packages] ******************************
2026-01-20 16:49:46.944316 | controller | Tuesday 20 January 2026  16:49:46 +0000 (0:00:00.230)       0:01:21.867 *******
2026-01-20 16:49:51.072881 | controller | changed: [instance]
2026-01-20 16:49:51.073194 | controller |
2026-01-20 16:49:51.779822 | controller | TASK [sushy_emulator : Get ingresses domain] ***********************************
2026-01-20 16:49:51.783063 | controller | Tuesday 20 January 2026  16:49:51 +0000 (0:00:04.128)       0:01:25.996 *******
2026-01-20 16:49:51.783092 | controller | changed: [instance]
2026-01-20 16:49:51.806126 | controller |
2026-01-20 16:49:51.806158 | controller | TASK [sushy_emulator : Set sushy url for ocp installation] *********************
2026-01-20 16:49:51.806169 | controller | Tuesday 20 January 2026  16:49:51 +0000 (0:00:00.706)       0:01:26.703 *******
2026-01-20 16:49:51.806185 | controller | ok: [instance]
2026-01-20 16:49:52.147609 | controller |
2026-01-20 16:49:52.147668 | controller | TASK [sushy_emulator : Create ssh key for Sushy Emulator] **********************
2026-01-20 16:49:52.147678 | controller | Tuesday 20 January 2026  16:49:51 +0000 (0:00:00.026)       0:01:26.729 *******
2026-01-20 16:49:52.147696 | controller | changed: [instance]
2026-01-20 16:49:52.377054 | controller |
2026-01-20 16:49:52.377121 | controller | TASK [sushy_emulator : Slurp private ssh key for later use] ********************
2026-01-20 16:49:52.377131 | controller | Tuesday 20 January 2026  16:49:52 +0000 (0:00:00.341)       0:01:27.070 *******
2026-01-20 16:49:52.377143 | controller | ok: [instance]
2026-01-20 16:49:53.749416 | controller |
2026-01-20 16:49:53.749477 | controller | TASK [sushy_emulator : Allow Sushy Emulator key] *******************************
2026-01-20 16:49:53.749491 | controller | Tuesday 20 January 2026  16:49:52 +0000 (0:00:00.229)       0:01:27.300 *******
2026-01-20 16:49:53.749504 | controller | changed: [instance -> controller-0(192.168.26.219)]
2026-01-20 16:49:54.048570 | controller |
2026-01-20 16:49:54.048627 | controller | TASK [sushy_emulator : Run ssh-keyscan] ****************************************
2026-01-20 16:49:54.048636 | controller | Tuesday 20 January 2026  16:49:53 +0000 (0:00:01.368)       0:01:28.668 *******
2026-01-20 16:49:54.048654 | controller | changed: [instance]
2026-01-20 16:49:54.479856 | controller |
2026-01-20 16:49:54.479917 | controller | TASK [sushy_emulator : Write known hosts for later use] ************************
2026-01-20 16:49:54.479930 | controller | Tuesday 20 January 2026  16:49:54 +0000 (0:00:00.300)       0:01:28.969 *******
2026-01-20 16:49:54.479945 | controller | changed: [instance]
2026-01-20 16:49:54.513384 | controller |
2026-01-20 16:49:54.513421 | controller | TASK [sushy_emulator : Ensure file exists: /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
2026-01-20 16:49:54.513430 | controller | Tuesday 20 January 2026  16:49:54 +0000 (0:00:00.433)       0:01:29.402 *******
2026-01-20 16:49:54.513442 | controller | skipping: [instance]
2026-01-20 16:49:54.545380 | controller |
2026-01-20 16:49:54.545424 | controller | TASK [sushy_emulator : Slurp content of: /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
2026-01-20 16:49:54.545433 | controller | Tuesday 20 January 2026  16:49:54 +0000 (0:00:00.034)       0:01:29.437 *******
2026-01-20 16:49:54.545445 | controller | skipping: [instance]
2026-01-20 16:49:54.576823 | controller |
2026-01-20 16:49:54.576858 | controller | TASK [sushy_emulator : Set cifmw_libvirt_manager_uuids fact from /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
2026-01-20 16:49:54.576871 | controller | Tuesday 20 January 2026  16:49:54 +0000 (0:00:00.032)       0:01:29.469 *******
2026-01-20 16:49:54.576889 | controller | skipping: [instance]
2026-01-20 16:49:54.577353 | controller |
2026-01-20 16:49:54.625018 | controller | TASK [sushy_emulator : Generate list of filtered VMs] **************************
2026-01-20 16:49:54.625063 | controller | Tuesday 20 January 2026  16:49:54 +0000 (0:00:00.031)       0:01:29.501 *******
2026-01-20 16:49:54.625076 | controller | ok: [instance]
2026-01-20 16:49:54.647819 | controller |
2026-01-20 16:49:54.647848 | controller | TASK [sushy_emulator : Get Openstack instance UUIDs] ***************************
2026-01-20 16:49:54.647856 | controller | Tuesday 20 January 2026  16:49:54 +0000 (0:00:00.047)       0:01:29.548 *******
2026-01-20 16:49:54.647871 | controller | skipping: [instance]
2026-01-20 16:49:54.647923 | controller |
2026-01-20 16:49:54.647931 | controller | TASK [sushy_emulator : Set instance_uuid variable for openstack driver] ********
2026-01-20 16:49:54.647939 | controller | Tuesday 20 January 2026  16:49:54 +0000 (0:00:00.023)       0:01:29.572 *******
2026-01-20 16:49:54.669091 | controller | skipping: [instance]
2026-01-20 16:49:54.694095 | controller |
2026-01-20 16:49:54.694143 | controller | TASK [sushy_emulator : Base64 encode openstack clouds.yaml file] ***************
2026-01-20 16:49:54.694153 | controller | Tuesday 20 January 2026  16:49:54 +0000 (0:00:00.020)       0:01:29.592 *******
2026-01-20 16:49:54.694164 | controller | skipping: [instance]
2026-01-20 16:49:54.934798 | controller |
2026-01-20 16:49:54.934840 | controller | TASK [sushy_emulator : Generate htpasswd string] *******************************
2026-01-20 16:49:54.934853 | controller | Tuesday 20 January 2026  16:49:54 +0000 (0:00:00.024)       0:01:29.617 *******
2026-01-20 16:49:54.934869 | controller | changed: [instance]
2026-01-20 16:49:56.976748 | controller |
2026-01-20 16:49:56.976820 | controller | TASK [sushy_emulator : Write sushy emulator resource loop] *********************
2026-01-20 16:49:56.976829 | controller | Tuesday 20 January 2026  16:49:54 +0000 (0:00:00.240)       0:01:29.858 *******
2026-01-20 16:49:56.976843 | controller | changed: [instance] => (item=secret)
2026-01-20 16:49:57.001953 | controller | changed: [instance] => (item=configmap)
2026-01-20 16:49:57.001984 | controller | changed: [instance] => (item=pod)
2026-01-20 16:49:57.001993 | controller | changed: [instance] => (item=service)
2026-01-20 16:49:57.001998 | controller | changed: [instance] => (item=route)
2026-01-20 16:49:57.002008 | controller |
2026-01-20 16:49:57.002018 | controller | TASK [sushy_emulator : Write sushy emulator config] ****************************
2026-01-20 16:49:57.002025 | controller | Tuesday 20 January 2026  16:49:56 +0000 (0:00:02.036)       0:01:31.895 *******
2026-01-20 16:49:57.002038 | controller | skipping: [instance]
2026-01-20 16:49:57.028804 | controller |
2026-01-20 16:49:57.028833 | controller | TASK [sushy_emulator : Write htpasswd string to file] **************************
2026-01-20 16:49:57.028842 | controller | Tuesday 20 January 2026  16:49:56 +0000 (0:00:00.030)       0:01:31.925 *******
2026-01-20 16:49:57.028851 | controller | skipping: [instance]
2026-01-20 16:49:58.255313 | controller |
2026-01-20 16:49:58.255365 | controller | TASK [sushy_emulator : Create the sushy-emulator namespace] ********************
2026-01-20 16:49:58.255375 | controller | Tuesday 20 January 2026  16:49:57 +0000 (0:00:00.026)       0:01:31.952 *******
2026-01-20 16:49:58.255386 | controller | changed: [instance]
2026-01-20 16:51:29.585146 | controller |
2026-01-20 16:51:29.585189 | controller | TASK [sushy_emulator : Check if router pod is running in openshift-ingress namespace] ***
2026-01-20 16:51:29.585198 | controller | Tuesday 20 January 2026  16:49:58 +0000 (0:00:01.225)       0:01:33.178 *******
2026-01-20 16:51:29.585210 | controller | ok: [instance]
2026-01-20 16:51:32.394059 | controller |
2026-01-20 16:51:32.394106 | controller | TASK [sushy_emulator : Apply Sushy Emulator resources] *************************
2026-01-20 16:51:32.394114 | controller | Tuesday 20 January 2026  16:51:29 +0000 (0:01:31.330)       0:03:04.508 *******
2026-01-20 16:51:32.394126 | controller | changed: [instance] => (item=secret)
2026-01-20 16:52:43.305582 | controller | changed: [instance] => (item=configmap)
2026-01-20 16:52:43.305666 | controller | changed: [instance] => (item=service)
2026-01-20 16:52:43.305676 | controller | changed: [instance] => (item=route)
2026-01-20 16:52:43.305682 | controller |
2026-01-20 16:52:43.305688 | controller | TASK [sushy_emulator : Apply Sushy Emulator pod resource] **********************
2026-01-20 16:52:43.305694 | controller | Tuesday 20 January 2026  16:51:32 +0000 (0:00:02.807)       0:03:07.316 *******
2026-01-20 16:52:43.305721 | controller | [WARNING]: unknown field "spec.selector"
2026-01-20 16:52:43.305814 | controller | [WARNING]: unknown field
2026-01-20 16:52:43.305865 | controller | "spec.containers[0].readinessProbe.httpGet.initialDelaySeconds"
2026-01-20 16:52:43.306047 | controller | [WARNING]: unknown field
2026-01-20 16:52:43.306219 | controller | "spec.containers[0].readinessProbe.httpGet.periodSeconds"
2026-01-20 16:52:43.306382 | controller | [WARNING]: unknown field
2026-01-20 16:52:43.306502 | controller | "spec.containers[0].livenessProbe.httpGet.initialDelaySeconds"
2026-01-20 16:52:43.306634 | controller | [WARNING]: unknown field
2026-01-20 16:52:43.306746 | controller | "spec.containers[0].livenessProbe.httpGet.failureThreshold"
2026-01-20 16:52:43.306882 | controller | [WARNING]: unknown field
2026-01-20 16:52:43.307002 | controller | "spec.containers[0].livenessProbe.httpGet.periodSeconds"
2026-01-20 16:52:43.307112 | controller | [WARNING]: unknown field
2026-01-20 16:52:43.307222 | controller | "spec.containers[0].startupProbe.httpGet.failureThreshold"
2026-01-20 16:52:43.307333 | controller | [WARNING]: unknown field
2026-01-20 16:52:43.307460 | controller | "spec.containers[0].startupProbe.httpGet.initialDelaySeconds"
2026-01-20 16:52:43.312379 | controller | changed: [instance]
2026-01-20 16:52:43.312506 | controller |
2026-01-20 16:52:43.312681 | controller | TASK [podman : Ensure podman is installed] *************************************
2026-01-20 16:52:43.312875 | controller | Tuesday 20 January 2026  16:52:43 +0000 (0:01:10.920)       0:04:18.236 *******
2026-01-20 16:52:43.334714 | controller | skipping: [instance]
2026-01-20 16:52:43.334924 | controller |
2026-01-20 16:52:43.335097 | controller | TASK [podman : Enable loginctl linger for ansible_user_id] *********************
2026-01-20 16:52:43.335261 | controller | Tuesday 20 January 2026  16:52:43 +0000 (0:00:00.022)       0:04:18.259 *******
2026-01-20 16:52:43.362274 | controller | skipping: [instance]
2026-01-20 16:52:43.387260 | controller |
2026-01-20 16:52:43.387324 | controller | TASK [podman : Ensure subordinate UID entry exists for zuul] *******************
2026-01-20 16:52:43.387333 | controller | Tuesday 20 January 2026  16:52:43 +0000 (0:00:00.027)       0:04:18.286 *******
2026-01-20 16:52:43.387351 | controller | skipping: [instance]
2026-01-20 16:52:43.409959 | controller |
2026-01-20 16:52:43.410050 | controller | TASK [podman : Ensure subordinate GID entry exists for zuul] *******************
2026-01-20 16:52:43.410061 | controller | Tuesday 20 January 2026  16:52:43 +0000 (0:00:00.025)       0:04:18.311 *******
2026-01-20 16:52:43.410081 | controller | skipping: [instance]
2026-01-20 16:52:43.410088 | controller |
2026-01-20 16:52:43.410097 | controller | TASK [podman : Run podman system migrate if subuid/subgid files were changed] ***
2026-01-20 16:52:43.410233 | controller | Tuesday 20 January 2026  16:52:43 +0000 (0:00:00.022)       0:04:18.334 *******
2026-01-20 16:52:43.443539 | controller | skipping: [instance]
2026-01-20 16:52:43.443612 | controller |
2026-01-20 16:52:43.443726 | controller | TASK [sushy_emulator : Pull Sushy Emulator container image] ********************
2026-01-20 16:52:43.443854 | controller | Tuesday 20 January 2026  16:52:43 +0000 (0:00:00.033)       0:04:18.367 *******
2026-01-20 16:52:43.468897 | controller | skipping: [instance]
2026-01-20 16:52:43.469010 | controller |
2026-01-20 16:52:43.469149 | controller | TASK [sushy_emulator : Create and start Sushy Emulator container] **************
2026-01-20 16:52:43.469270 | controller | Tuesday 20 January 2026  16:52:43 +0000 (0:00:00.025)       0:04:18.393 *******
2026-01-20 16:52:43.498696 | controller | skipping: [instance]
2026-01-20 16:52:43.498795 | controller |
2026-01-20 16:52:43.498935 | controller | TASK [Verify connection to baremetal VMs via Sushy Emulator] *******************
2026-01-20 16:52:43.499040 | controller | Tuesday 20 January 2026  16:52:43 +0000 (0:00:00.029)       0:04:18.423 *******
2026-01-20 16:52:43.567481 | controller |
2026-01-20 16:52:43.567576 | controller | TASK [sushy_emulator : Load baremetal hosts from libvirt_manager_bm_info_data fact] ***
2026-01-20 16:52:43.567664 | controller | Tuesday 20 January 2026  16:52:43 +0000 (0:00:00.068)       0:04:18.491 *******
2026-01-20 16:52:43.620723 | controller | ok: [instance]
2026-01-20 16:52:43.620840 | controller |
2026-01-20 16:52:43.620968 | controller | TASK [sushy_emulator : Slurp content of: /home/zuul/ci-framework-data/parameters/baremetal-info.yml] ***
2026-01-20 16:52:43.621072 | controller | Tuesday 20 January 2026  16:52:43 +0000 (0:00:00.053)       0:04:18.545 *******
2026-01-20 16:52:43.651908 | controller | skipping: [instance]
2026-01-20 16:52:43.652015 | controller |
2026-01-20 16:52:43.652132 | controller | TASK [sushy_emulator : Set cifmw_baremetal_hosts fact from /home/zuul/ci-framework-data/parameters/baremetal-info.yml] ***
2026-01-20 16:52:43.652461 | controller | Tuesday 20 January 2026  16:52:43 +0000 (0:00:00.031)       0:04:18.576 *******
2026-01-20 16:52:43.681041 | controller | skipping: [instance]
2026-01-20 16:52:43.681125 | controller |
2026-01-20 16:52:43.681430 | controller | TASK [sushy_emulator : Test Sushy Emulator and connection to hypervisor libvirt socket] ***
2026-01-20 16:52:44.190258 | controller | Tuesday 20 January 2026  16:52:43 +0000 (0:00:00.029)       0:04:18.605 *******
2026-01-20 16:52:44.190328 | controller | fatal: [instance]: FAILED! => changed=false
2026-01-20 16:52:44.190523 | controller |   cache_control: private, max-age=0, no-cache, no-store
2026-01-20 16:52:44.190539 | controller |   content: |-
2026-01-20 16:52:44.190546 | controller |     <html>
2026-01-20 16:52:44.190554 | controller |       <head>
2026-01-20 16:52:44.190678 | controller |         <meta name="viewport" content="width=device-width, initial-scale=1">
2026-01-20 16:52:44.190692 | controller |
2026-01-20 16:52:44.190702 | controller |         <style type="text/css">
2026-01-20 16:52:44.190767 | controller |           body {
2026-01-20 16:52:44.191197 | controller |             font-family: "Helvetica Neue", Helvetica, Arial, sans-serif;
2026-01-20 16:52:44.191250 | controller |             line-height: 1.66666667;
2026-01-20 16:52:44.191258 | controller |             font-size: 16px;
2026-01-20 16:52:44.191264 | controller |             color: #333;
2026-01-20 16:52:44.191271 | controller |             background-color: #fff;
2026-01-20 16:52:44.191429 | controller |             margin: 2em 1em;
2026-01-20 16:52:44.191437 | controller |           }
2026-01-20 16:52:44.191540 | controller |           h1 {
2026-01-20 16:52:44.192157 | controller |             font-size: 28px;
2026-01-20 16:52:44.192175 | controller |             font-weight: 400;
2026-01-20 16:52:44.192182 | controller |           }
2026-01-20 16:52:44.192188 | controller |           p {
2026-01-20 16:52:44.192193 | controller |             margin: 0 0 10px;
2026-01-20 16:52:44.192198 | controller |           }
2026-01-20 16:52:44.192205 | controller |           .alert.alert-info {
2026-01-20 16:52:44.192383 | controller |             background-color: #F0F0F0;
2026-01-20 16:52:44.192720 | controller |             margin-top: 30px;
2026-01-20 16:52:44.192739 | controller |             padding: 30px;
2026-01-20 16:52:44.192990 | controller |           }
2026-01-20 16:52:44.193011 | controller |           .alert p {
2026-01-20 16:52:44.193018 | controller |             padding-left: 35px;
2026-01-20 16:52:44.193023 | controller |           }
2026-01-20 16:52:44.193029 | controller |           ul {
2026-01-20 16:52:44.193036 | controller |             padding-left: 51px;
2026-01-20 16:52:44.193193 | controller |             position: relative;
2026-01-20 16:52:44.193267 | controller |           }
2026-01-20 16:52:44.193275 | controller |           li {
2026-01-20 16:52:44.193905 | controller |             font-size: 14px;
2026-01-20 16:52:44.194007 | controller |             margin-bottom: 1em;
2026-01-20 16:52:44.194015 | controller |           }
2026-01-20 16:52:44.194020 | controller |           p.info {
2026-01-20 16:52:44.194026 | controller |             position: relative;
2026-01-20 16:52:44.194031 | controller |             font-size: 20px;
2026-01-20 16:52:44.194036 | controller |           }
2026-01-20 16:52:44.194043 | controller |           p.info:before, p.info:after {
2026-01-20 16:52:44.194157 | controller |             content: "";
2026-01-20 16:52:44.194183 | controller |             left: 0;
2026-01-20 16:52:44.196299 | controller |             position: absolute;
2026-01-20 16:52:44.196346 | controller |             top: 0;
2026-01-20 16:52:44.196366 | controller |           }
2026-01-20 16:52:44.196374 | controller |           p.info:before {
2026-01-20 16:52:44.196380 | controller |             background: #0066CC;
2026-01-20 16:52:44.196385 | controller |             border-radius: 16px;
2026-01-20 16:52:44.196391 | controller |             color: #fff;
2026-01-20 16:52:44.196397 | controller |             content: "i";
2026-01-20 16:52:44.196402 | controller |             font: bold 16px/24px serif;
2026-01-20 16:52:44.196413 | controller |             height: 24px;
2026-01-20 16:52:44.196418 | controller |             left: 0px;
2026-01-20 16:52:44.196424 | controller |             text-align: center;
2026-01-20 16:52:44.196429 | controller |             top: 4px;
2026-01-20 16:52:44.196435 | controller |             width: 24px;
2026-01-20 16:52:44.196440 | controller |           }
2026-01-20 16:52:44.196445 | controller |
2026-01-20 16:52:44.196451 | controller |           @media (min-width: 768px) {
2026-01-20 16:52:44.196457 | controller |             body {
2026-01-20 16:52:44.196469 | controller |               margin: 6em;
2026-01-20 16:52:44.196475 | controller |             }
2026-01-20 16:52:44.196480 | controller |           }
2026-01-20 16:52:44.196486 | controller |         </style>
2026-01-20 16:52:44.196494 | controller |       </head>
2026-01-20 16:52:44.196862 | controller |       <body>
2026-01-20 16:52:44.196927 | controller |         <div>
2026-01-20 16:52:44.196938 | controller |           <h1>Application is not available</h1>
2026-01-20 16:52:44.196944 | controller |           <p>The application is currently not serving requests at this endpoint. It may not have been started or is still starting.</p>
2026-01-20 16:52:44.196950 | controller |
2026-01-20 16:52:44.196958 | controller |           <div class="alert alert-info">
2026-01-20 16:52:44.197036 | controller |             <p class="info">
2026-01-20 16:52:44.197159 | controller |               Possible reasons you are seeing this page:
2026-01-20 16:52:44.197200 | controller |             </p>
2026-01-20 16:52:44.197340 | controller |             <ul>
2026-01-20 16:52:44.197388 | controller |               <li>
2026-01-20 16:52:44.197482 | controller |                 <strong>The host doesn't exist.</strong>
2026-01-20 16:52:44.197594 | controller |                 Make sure the hostname was typed correctly and that a route matching this hostname exists.
2026-01-20 16:52:44.197693 | controller |               </li>
2026-01-20 16:52:44.197807 | controller |               <li>
2026-01-20 16:52:44.197910 | controller |                 <strong>The host exists, but doesn't have a matching path.</strong>
2026-01-20 16:52:44.198013 | controller |                 Check if the URL path was typed correctly and that the route was created using the desired path.
2026-01-20 16:52:44.198104 | controller |               </li>
2026-01-20 16:52:44.198207 | controller |               <li>
2026-01-20 16:52:44.198303 | controller |                 <strong>Route and path matches, but all pods are down.</strong>
2026-01-20 16:52:44.198420 | controller |                 Make sure that the resources exposed by this route (pods, services, deployment configs, etc) have at least one pod running.
2026-01-20 16:52:44.198532 | controller |               </li>
2026-01-20 16:52:44.198609 | controller |             </ul>
2026-01-20 16:52:44.198701 | controller |           </div>
2026-01-20 16:52:44.198806 | controller |         </div>
2026-01-20 16:52:44.198897 | controller |       </body>
2026-01-20 16:52:44.198989 | controller |     </html>
2026-01-20 16:52:44.199081 | controller |   content_type: text/html
2026-01-20 16:52:44.199173 | controller |   elapsed: 0
2026-01-20 16:52:44.199274 | controller |   msg: 'Status code was 503 and not [200]: HTTP Error 503: Service Unavailable'
2026-01-20 16:52:44.199373 | controller |   pragma: no-cache
2026-01-20 16:52:44.199466 | controller |   redirected: false
2026-01-20 16:52:44.199557 | controller |   status: 503
2026-01-20 16:52:44.199654 | controller |   url: http://sushy-emulator.apps-crc.testing/redfish/v1/Managers
2026-01-20 16:52:44.199868 | controller |
2026-01-20 16:52:44.199953 | controller | PLAY RECAP *********************************************************************
2026-01-20 16:52:44.200062 | controller | instance                   : ok=209  changed=78   unreachable=0    failed=1    skipped=95   rescued=0    ignored=0
2026-01-20 16:52:44.200151 | controller |
2026-01-20 16:52:44.200244 | controller | Tuesday 20 January 2026  16:52:44 +0000 (0:00:00.515)       0:04:19.120 *******
2026-01-20 16:52:44.200336 | controller | ===============================================================================
2026-01-20 16:52:44.200463 | controller | sushy_emulator : Check if router pod is running in openshift-ingress namespace -- 91.33s
2026-01-20 16:52:44.200558 | controller | sushy_emulator : Apply Sushy Emulator pod resource --------------------- 70.92s
2026-01-20 16:52:44.200665 | controller | libvirt_manager : Install packages required for using KVM -------------- 13.13s
2026-01-20 16:52:44.200747 | controller | ci_nmstate : Install required packages on instance ---------------------- 5.14s
2026-01-20 16:52:44.200861 | controller | dnsmasq : Ensure SELinux knows about the new files and directories ------ 4.59s
2026-01-20 16:52:44.200954 | controller | sushy_emulator : Install required packages ------------------------------ 4.13s
2026-01-20 16:52:44.201045 | controller | sushy_emulator : Apply Sushy Emulator resources ------------------------- 2.81s
2026-01-20 16:52:44.201139 | controller | ci_nmstate : Apply the desidered state on instance ---------------------- 2.15s
2026-01-20 16:52:44.201232 | controller | sushy_emulator : Write sushy emulator resource loop --------------------- 2.04s
2026-01-20 16:52:44.201325 | controller | libvirt_manager : Restart firewalld ------------------------------------- 1.91s
2026-01-20 16:52:44.201430 | controller | dnsmasq : Add/Remove address -------------------------------------------- 1.54s
2026-01-20 16:52:44.201523 | controller | dnsmasq : Install needed packages --------------------------------------- 1.53s
2026-01-20 16:52:44.201626 | controller | sushy_emulator : Allow Sushy Emulator key ------------------------------- 1.37s
2026-01-20 16:52:44.201718 | controller | sushy_emulator : Create the sushy-emulator namespace -------------------- 1.23s
2026-01-20 16:52:44.201824 | controller | libvirt_manager : Start VMs for type {{ vm_type }} ---------------------- 1.06s
2026-01-20 16:52:44.201918 | controller | libvirt_manager : Ensure firewalld service is up ------------------------ 0.96s
2026-01-20 16:52:44.202009 | controller | dnsmasq : Enable and start service -------------------------------------- 0.96s
2026-01-20 16:52:44.202104 | controller | Gathering Facts --------------------------------------------------------- 0.89s
2026-01-20 16:52:44.202213 | controller | dnsmasq : Add DHCP entries ---------------------------------------------- 0.85s
2026-01-20 16:52:44.202294 | controller | sushy_emulator : Get ingresses domain ----------------------------------- 0.71s
2026-01-20 16:52:44.274974 | controller | CRITICAL Ansible return code was 2, command was: ['ansible-playbook', '--inventory', '/home/zuul/.cache/molecule/sushy_emulator/default/inventory', '--skip-tags', 'molecule-notest,notest', '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/sushy_emulator/molecule/default/converge.yml']
2026-01-20 16:52:44.275399 | controller | WARNING  An error occurred during the test sequence action: 'converge'. Cleaning up.
2026-01-20 16:52:44.284701 | controller | INFO     Running default > cleanup
2026-01-20 16:52:44.285178 | controller | WARNING  Skipping, cleanup playbook not configured.
2026-01-20 16:52:44.293166 | controller | INFO     Running default > destroy
2026-01-20 16:52:44.293485 | controller | WARNING  Skipping, instances are delegated.
2026-01-20 16:52:44.293825 | controller | INFO     Pruning extra files from scenario ephemeral directory
2026-01-20 16:52:44.295441 | controller | INFO     Writing /tmp/report.html report.
2026-01-20 16:52:44.412087 | [controller] Waiting on logger
2026-01-20 16:52:49.595979 | [controller] Waiting on logger
2026-01-20 16:53:00.027807 | [controller] Waiting on logger
2026-01-20 16:53:10.460072 | [controller] Waiting on logger
2026-01-20 16:53:14.392340 | [Zuul] Log Stream did not terminate
2026-01-20 16:53:14.392558 | controller | ERROR
2026-01-20 16:53:14.392647 | controller | {
2026-01-20 16:53:14.392684 | controller |   "delta": "0:08:24.177729",
2026-01-20 16:53:14.392707 | controller |   "end": "2026-01-20 16:52:44.372640",
2026-01-20 16:53:14.392728 | controller |   "msg": "non-zero return code",
2026-01-20 16:53:14.392747 | controller |   "rc": 1,
2026-01-20 16:53:14.392766 | controller |   "start": "2026-01-20 16:44:20.194911"
2026-01-20 16:53:14.392783 | controller | }
failure
2026-01-20 16:53:14.440710 | 
2026-01-20 16:53:14.440757 | PLAY RECAP
2026-01-20 16:53:14.440798 | controller | ok: 3 changed: 0 unreachable: 0 failed: 1 skipped: 1 rescued: 0 ignored: 0
2026-01-20 16:53:14.440819 | 
2026-01-20 16:53:14.498700 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2026-01-20 16:53:14.499461 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2026-01-20 16:53:15.014163 | 
2026-01-20 16:53:15.014260 | PLAY [Run ci/playbooks/collect-logs.yml]
2026-01-20 16:53:15.034052 | 
2026-01-20 16:53:15.034123 | TASK [Filter out host if needed]
2026-01-20 16:53:15.042516 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2026-01-20 16:53:15.046868 | 
2026-01-20 16:53:15.046935 | TASK [Ensure file is present]
2026-01-20 16:53:15.440944 | controller | ok
2026-01-20 16:53:15.446348 | 
2026-01-20 16:53:15.446414 | TASK [Manage molecule report file]
2026-01-20 16:53:15.466347 | [controller] Waiting on logger
2026-01-20 16:53:24.860148 | [controller] Waiting on logger
2026-01-20 16:53:35.293167 | [controller] Waiting on logger
2026-01-20 16:53:44.635787 | [controller] Waiting on logger
2026-01-20 16:53:45.879763 | [Zuul] Log Stream did not terminate
2026-01-20 16:53:45.879944 | controller | changed
2026-01-20 16:53:45.885049 | 
2026-01-20 16:53:45.885113 | TASK [Check if we get ci-framework-data basedir]
2026-01-20 16:53:46.207187 | controller | ok
2026-01-20 16:53:46.212191 | 
2026-01-20 16:53:46.212268 | TASK [Create ci-framework-data log directory for zuul]
2026-01-20 16:53:46.626581 | controller | changed
2026-01-20 16:53:46.632113 | 
2026-01-20 16:53:46.632195 | TASK [Copy ci-framework interesting files]
2026-01-20 16:53:46.652223 | [controller] Waiting on logger
2026-01-20 16:53:57.052084 | [controller] Waiting on logger
2026-01-20 16:54:06.432694 | [controller] Waiting on logger
2026-01-20 16:54:16.827901 | [controller] Waiting on logger
2026-01-20 16:54:16.944564 | [Zuul] Log Stream did not terminate
2026-01-20 16:54:16.944720 | controller | changed
2026-01-20 16:54:16.950036 | 
2026-01-20 16:54:16.950104 | TASK [Get SELinux listing]
2026-01-20 16:54:20.028006 | [controller] Waiting on logger
2026-01-20 16:54:26.283788 | controller | changed
2026-01-20 16:54:26.289474 | 
2026-01-20 16:54:26.289544 | TASK [Generate log index]
2026-01-20 16:54:27.412593 | controller | changed
2026-01-20 16:54:27.417370 | 
2026-01-20 16:54:27.417435 | TASK [Get some env related data]
2026-01-20 16:54:27.439063 | [controller] Waiting on logger
2026-01-20 16:54:37.883861 | [controller] Waiting on logger
2026-01-20 16:54:48.315850 | [controller] Waiting on logger
2026-01-20 16:54:57.660100 | [controller] Waiting on logger
2026-01-20 16:54:58.848174 | [Zuul] Log Stream did not terminate
2026-01-20 16:54:58.848454 | controller | changed
2026-01-20 16:54:58.853833 | 
2026-01-20 16:54:58.853896 | TASK [Generate list of logs to collect in home directory]
2026-01-20 16:54:59.225336 | controller | ok: All paths examined
2026-01-20 16:54:59.230678 | 
2026-01-20 16:54:59.230739 | LOOP [Copy logs from home directory]
2026-01-20 16:54:59.822413 | controller | changed:
2026-01-20 16:54:59.822645 | controller | {
2026-01-20 16:54:59.822683 | controller |   "atime": 1743544925.4788878,
2026-01-20 16:54:59.822711 | controller |   "ctime": 1743545329.1409318,
2026-01-20 16:54:59.822735 | controller |   "dev": 64513,
2026-01-20 16:54:59.822759 | controller |   "gid": 1000,
2026-01-20 16:54:59.822781 | controller |   "gr_name": "zuul",
2026-01-20 16:54:59.822819 | controller |   "inode": 4518807,
2026-01-20 16:54:59.822844 | controller |   "isblk": false,
2026-01-20 16:54:59.822867 | controller |   "ischr": false,
2026-01-20 16:54:59.822889 | controller |   "isdir": false,
2026-01-20 16:54:59.822911 | controller |   "isfifo": false,
2026-01-20 16:54:59.822931 | controller |   "isgid": false,
2026-01-20 16:54:59.822951 | controller |   "islnk": false,
2026-01-20 16:54:59.822970 | controller |   "isreg": true,
2026-01-20 16:54:59.822993 | controller |   "issock": false,
2026-01-20 16:54:59.823014 | controller |   "isuid": false,
2026-01-20 16:54:59.823033 | controller |   "mode": "0644",
2026-01-20 16:54:59.823053 | controller |   "mtime": 1743545329.1409318,
2026-01-20 16:54:59.823075 | controller |   "nlink": 1,
2026-01-20 16:54:59.823095 | controller |   "path": "/home/zuul/crc-setup.log",
2026-01-20 16:54:59.823116 | controller |   "pw_name": "zuul",
2026-01-20 16:54:59.823135 | controller |   "rgrp": true,
2026-01-20 16:54:59.823167 | controller |   "roth": true,
2026-01-20 16:54:59.823188 | controller |   "rusr": true,
2026-01-20 16:54:59.823209 | controller |   "size": 4108,
2026-01-20 16:54:59.823229 | controller |   "uid": 1000,
2026-01-20 16:54:59.823250 | controller |   "wgrp": false,
2026-01-20 16:54:59.823270 | controller |   "woth": false,
2026-01-20 16:54:59.823290 | controller |   "wusr": true,
2026-01-20 16:54:59.825352 | controller |   "xgrp": false,
2026-01-20 16:54:59.825449 | controller |   "xoth": false,
2026-01-20 16:54:59.825474 | controller |   "xusr": false
2026-01-20 16:54:59.825493 | controller | }
2026-01-20 16:55:00.355938 | controller | changed:
2026-01-20 16:55:00.356019 | controller | {
2026-01-20 16:55:00.356046 | controller |   "atime": 1743545331.0429637,
2026-01-20 16:55:00.356074 | controller |   "ctime": 1743545842.0111232,
2026-01-20 16:55:00.356093 | controller |   "dev": 64513,
2026-01-20 16:55:00.356111 | controller |   "gid": 1000,
2026-01-20 16:55:00.356128 | controller |   "gr_name": "zuul",
2026-01-20 16:55:00.356154 | controller |   "inode": 4194437,
2026-01-20 16:55:00.356209 | controller |   "isblk": false,
2026-01-20 16:55:00.356235 | controller |   "ischr": false,
2026-01-20 16:55:00.356252 | controller |   "isdir": false,
2026-01-20 16:55:00.356268 | controller |   "isfifo": false,
2026-01-20 16:55:00.356283 | controller |   "isgid": false,
2026-01-20 16:55:00.356317 | controller |   "islnk": false,
2026-01-20 16:55:00.356336 | controller |   "isreg": true,
2026-01-20 16:55:00.356364 | controller |   "issock": false,
2026-01-20 16:55:00.356379 | controller |   "isuid": false,
2026-01-20 16:55:00.356393 | controller |   "mode": "0644",
2026-01-20 16:55:00.356408 | controller |   "mtime": 1743545842.0111232,
2026-01-20 16:55:00.356422 | controller |   "nlink": 1,
2026-01-20 16:55:00.356436 | controller |   "path": "/home/zuul/crc-start.log",
2026-01-20 16:55:00.356451 | controller |   "pw_name": "zuul",
2026-01-20 16:55:00.356464 | controller |   "rgrp": true,
2026-01-20 16:55:00.356477 | controller |   "roth": true,
2026-01-20 16:55:00.356490 | controller |   "rusr": true,
2026-01-20 16:55:00.356503 | controller |   "size": 4023,
2026-01-20 16:55:00.356515 | controller |   "uid": 1000,
2026-01-20 16:55:00.356528 | controller |   "wgrp": false,
2026-01-20 16:55:00.356541 | controller |   "woth": false,
2026-01-20 16:55:00.356554 | controller |   "wusr": true,
2026-01-20 16:55:00.356567 | controller |   "xgrp": false,
2026-01-20 16:55:00.356580 | controller |   "xoth": false,
2026-01-20 16:55:00.356592 | controller |   "xusr": false
2026-01-20 16:55:00.356605 | controller | }
2026-01-20 16:55:00.905658 | controller | changed:
2026-01-20 16:55:00.905725 | controller | {
2026-01-20 16:55:00.905751 | controller |   "atime": 1768927441.6598063,
2026-01-20 16:55:00.905770 | controller |   "ctime": 1768927457.68103,
2026-01-20 16:55:00.905786 | controller |   "dev": 64513,
2026-01-20 16:55:00.905802 | controller |   "gid": 1000,
2026-01-20 16:55:00.905817 | controller |   "gr_name": "zuul",
2026-01-20 16:55:00.905833 | controller |   "inode": 4685816,
2026-01-20 16:55:00.905849 | controller |   "isblk": false,
2026-01-20 16:55:00.905866 | controller |   "ischr": false,
2026-01-20 16:55:00.905884 | controller |   "isdir": false,
2026-01-20 16:55:00.905900 | controller |   "isfifo": false,
2026-01-20 16:55:00.905915 | controller |   "isgid": false,
2026-01-20 16:55:00.905929 | controller |   "islnk": false,
2026-01-20 16:55:00.905943 | controller |   "isreg": true,
2026-01-20 16:55:00.905956 | controller |   "issock": false,
2026-01-20 16:55:00.905970 | controller |   "isuid": false,
2026-01-20 16:55:00.905983 | controller |   "mode": "0644",
2026-01-20 16:55:00.905996 | controller |   "mtime": 1768927457.68103,
2026-01-20 16:55:00.906010 | controller |   "nlink": 1,
2026-01-20 16:55:00.906023 | controller |   "path": "/home/zuul/ansible.log",
2026-01-20 16:55:00.906037 | controller |   "pw_name": "zuul",
2026-01-20 16:55:00.906050 | controller |   "rgrp": true,
2026-01-20 16:55:00.906066 | controller |   "roth": true,
2026-01-20 16:55:00.906081 | controller |   "rusr": true,
2026-01-20 16:55:00.906095 | controller |   "size": 6749,
2026-01-20 16:55:00.906110 | controller |   "uid": 1000,
2026-01-20 16:55:00.906124 | controller |   "wgrp": false,
2026-01-20 16:55:00.906137 | controller |   "woth": false,
2026-01-20 16:55:00.906163 | controller |   "wusr": true,
2026-01-20 16:55:00.906179 | controller |   "xgrp": false,
2026-01-20 16:55:00.906192 | controller |   "xoth": false,
2026-01-20 16:55:00.906205 | controller |   "xusr": false
2026-01-20 16:55:00.906219 | controller | }
2026-01-20 16:55:00.917430 | 
2026-01-20 16:55:00.917572 | TASK [Copy crio stats log file]
2026-01-20 16:55:00.931776 | controller | skipping: Conditional result was False
2026-01-20 16:55:00.938026 | 
2026-01-20 16:55:00.938093 | TASK [Get SELinux related data]
2026-01-20 16:55:00.959135 | [controller] Waiting on logger
2026-01-20 16:55:07.178927 | controller | ERROR
2026-01-20 16:55:07.179128 | controller | {
2026-01-20 16:55:07.179172 | controller |   "delta": "0:00:00.009279",
2026-01-20 16:55:07.179196 | controller |   "end": "2026-01-20 16:55:01.216414",
2026-01-20 16:55:07.179214 | controller |   "msg": "non-zero return code",
2026-01-20 16:55:07.179230 | controller |   "rc": 1,
2026-01-20 16:55:07.179249 | controller |   "start": "2026-01-20 16:55:01.207135"
2026-01-20 16:55:07.179266 | controller | }
2026-01-20 16:55:07.179289 | controller | ERROR: Ignoring Errors
2026-01-20 16:55:07.184469 | 
2026-01-20 16:55:07.184537 | TASK [Create system configuration directory]
2026-01-20 16:55:07.476264 | controller | changed
2026-01-20 16:55:07.481009 | 
2026-01-20 16:55:07.481075 | TASK [Get some of the system configurations]
2026-01-20 16:55:07.501236 | [controller] Waiting on logger
2026-01-20 16:55:17.883985 | [controller] Waiting on logger
2026-01-20 16:55:28.316054 | [controller] Waiting on logger
2026-01-20 16:55:37.659802 | [controller] Waiting on logger
2026-01-20 16:55:37.823242 | [Zuul] Log Stream did not terminate
2026-01-20 16:55:37.823510 | controller | changed
2026-01-20 16:55:37.828531 | 
2026-01-20 16:55:37.828595 | TASK [Copy generated documentation if available]
2026-01-20 16:55:37.842329 | controller | skipping: Conditional result was False
2026-01-20 16:55:37.847785 | 
2026-01-20 16:55:37.847848 | TASK [Copy generated AsciiDoc documentation if available]
2026-01-20 16:55:37.861330 | controller | skipping: Conditional result was False
2026-01-20 16:55:37.867008 | 
2026-01-20 16:55:37.867072 | TASK [Compress logs bigger than 2MB]
2026-01-20 16:55:40.988065 | [controller] Waiting on logger
2026-01-20 16:55:47.245797 | controller | changed
2026-01-20 16:55:47.251077 | 
2026-01-20 16:55:47.251169 | TASK [Copy files from workspace on node]
2026-01-20 16:55:47.269468 | controller | ok
2026-01-20 16:55:47.292064 | 
2026-01-20 16:55:47.292138 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-20 16:55:47.305760 | controller | skipping: Conditional result was False
2026-01-20 16:55:47.311575 | 
2026-01-20 16:55:47.311653 | TASK [fetch-output : Set log path for single node]
2026-01-20 16:55:47.340195 | controller | ok
2026-01-20 16:55:47.345132 | 
2026-01-20 16:55:47.345213 | LOOP [fetch-output : Ensure local output dirs]
2026-01-20 16:55:47.537878 | controller -> localhost | ok: "/var/lib/zuul/builds/4e813e18561b4a31ae159dbd9d8d0118/work/logs"
2026-01-20 16:55:47.538109 | controller -> localhost | changed: All items complete
2026-01-20 16:55:47.538140 | 
2026-01-20 16:55:47.716612 | controller -> localhost | changed: "/var/lib/zuul/builds/4e813e18561b4a31ae159dbd9d8d0118/work/artifacts"
2026-01-20 16:55:47.895491 | controller -> localhost | changed: "/var/lib/zuul/builds/4e813e18561b4a31ae159dbd9d8d0118/work/docs"
2026-01-20 16:55:47.913348 | 
2026-01-20 16:55:47.913459 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-20 16:55:48.574446 | controller | changed:
2026-01-20 16:55:48.574642 | controller | .d..t...... ./
2026-01-20 16:55:48.574674 | controller | >f+++++++++ README.html
2026-01-20 16:55:48.574695 | controller | >f+++++++++ ansible-execution.log
2026-01-20 16:55:48.574716 | controller | >f+++++++++ ansible.log
2026-01-20 16:55:48.574734 | controller | >f+++++++++ crc-setup.log
2026-01-20 16:55:48.574752 | controller | >f+++++++++ crc-start.log
2026-01-20 16:55:48.574769 | controller | >f+++++++++ dmesg.log
2026-01-20 16:55:48.574787 | controller | >f+++++++++ installed-pkgs.log
2026-01-20 16:55:48.574803 | controller | >f+++++++++ python.log
2026-01-20 16:55:48.574819 | controller | >f+++++++++ registries.conf
2026-01-20 16:55:48.574834 | controller | >f+++++++++ report.html
2026-01-20 16:55:48.574850 | controller | >f+++++++++ selinux-denials.log
2026-01-20 16:55:48.574866 | controller | >f+++++++++ selinux-listing.log
2026-01-20 16:55:48.574881 | controller | cd+++++++++ ci-framework-data/
2026-01-20 16:55:48.574896 | controller | cd+++++++++ ci-framework-data/artifacts/
2026-01-20 16:55:48.574911 | controller | >f+++++++++ ci-framework-data/artifacts/debug_cifmw_libvirt_manager_layout.yml
2026-01-20 16:55:48.574927 | controller | >f+++++++++ ci-framework-data/artifacts/debug_network_data.yml
2026-01-20 16:55:48.574942 | controller | >f+++++++++ ci-framework-data/artifacts/debug_pub_net_value.txt
2026-01-20 16:55:48.574956 | controller | >f+++++++++ ci-framework-data/artifacts/interfaces-info.yml
2026-01-20 16:55:48.574971 | controller | >f+++++++++ ci-framework-data/artifacts/libvirt-uuids.yml
2026-01-20 16:55:48.574986 | controller | >f+++++++++ ci-framework-data/artifacts/net-map-def-patch.yml
2026-01-20 16:55:48.575006 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2026-01-20 16:55:48.575022 | controller | cd+++++++++ ci-framework-data/artifacts/nmstate/
2026-01-20 16:55:48.575038 | controller | >f+++++++++ ci-framework-data/artifacts/nmstate/instance-final-state.yaml
2026-01-20 16:55:48.575053 | controller | >f+++++++++ ci-framework-data/artifacts/nmstate/instance-state.yaml
2026-01-20 16:55:48.575070 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2026-01-20 16:55:48.575087 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2026-01-20 16:55:48.575103 | controller | cd+++++++++ ci-framework-data/artifacts/repositories/
2026-01-20 16:55:48.575118 | controller | >f+++++++++ ci-framework-data/artifacts/repositories/delorean.repo.md5
2026-01-20 16:55:48.575134 | controller | cd+++++++++ ci-framework-data/artifacts/sushy_emulator/
2026-01-20 16:55:48.575161 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/configmap.yaml
2026-01-20 16:55:48.575181 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/known_hosts
2026-01-20 16:55:48.575197 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/pod.yaml
2026-01-20 16:55:48.575213 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/route.yaml
2026-01-20 16:55:48.575228 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/secret.yaml
2026-01-20 16:55:48.575244 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/service.yaml
2026-01-20 16:55:48.575261 | controller | cd+++++++++ ci-framework-data/logs/
2026-01-20 16:55:48.575276 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2026-01-20 16:55:48.575291 | controller | cd+++++++++ registries.conf.d/
2026-01-20 16:55:48.575329 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2026-01-20 16:55:48.575346 | controller | cd+++++++++ system-config/
2026-01-20 16:55:48.575361 | controller | cd+++++++++ system-config/libvirt/
2026-01-20 16:55:48.575376 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2026-01-20 16:55:48.575391 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2026-01-20 16:55:48.575406 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf
2026-01-20 16:55:48.575421 | controller | >f+++++++++ system-config/libvirt/network.conf
2026-01-20 16:55:48.575435 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf
2026-01-20 16:55:48.575449 | controller | >f+++++++++ system-config/libvirt/qemu.conf
2026-01-20 16:55:48.575466 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf
2026-01-20 16:55:48.575482 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf
2026-01-20 16:55:48.575497 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf
2026-01-20 16:55:48.575511 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf
2026-01-20 16:55:48.575525 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf
2026-01-20 16:55:48.575540 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf
2026-01-20 16:55:48.575554 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf
2026-01-20 16:55:48.575568 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf
2026-01-20 16:55:48.575583 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf
2026-01-20 16:55:48.575597 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf
2026-01-20 16:55:49.059703 | controller | changed: .d..t...... ./
2026-01-20 16:55:49.531457 | controller | changed: .d..t...... ./
2026-01-20 16:55:49.551564 | 
2026-01-20 16:55:49.551664 | TASK [Return artifact to Zuul]
2026-01-20 16:55:49.579695 | controller | ok
2026-01-20 16:55:49.598650 | 
2026-01-20 16:55:49.598706 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2026-01-20 16:55:49.598801 | 
2026-01-20 16:55:49.598829 | PLAY RECAP
2026-01-20 16:55:49.598863 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2026-01-20 16:55:49.598891 | 
2026-01-20 16:55:49.672612 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2026-01-20 16:55:49.673393 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2026-01-20 16:55:50.169398 | 
2026-01-20 16:55:50.169496 | PLAY [all]
2026-01-20 16:55:50.187428 | 
2026-01-20 16:55:50.187502 | TASK [include_role : fetch-output]
2026-01-20 16:55:50.215681 | controller | ok
2026-01-20 16:55:50.231859 | 
2026-01-20 16:55:50.231938 | TASK [fetch-output : Set log path for multiple nodes]
2026-01-20 16:55:50.275691 | controller | skipping: Conditional result was False
2026-01-20 16:55:50.281048 | 
2026-01-20 16:55:50.281119 | TASK [fetch-output : Set log path for single node]
2026-01-20 16:55:50.309249 | controller | ok
2026-01-20 16:55:50.314038 | 
2026-01-20 16:55:50.314109 | LOOP [fetch-output : Ensure local output dirs]
2026-01-20 16:55:50.626545 | controller -> localhost | ok: "/var/lib/zuul/builds/4e813e18561b4a31ae159dbd9d8d0118/work/logs"
2026-01-20 16:55:50.804195 | controller -> localhost | ok: "/var/lib/zuul/builds/4e813e18561b4a31ae159dbd9d8d0118/work/artifacts"
2026-01-20 16:55:50.980113 | controller -> localhost | ok: "/var/lib/zuul/builds/4e813e18561b4a31ae159dbd9d8d0118/work/docs"
2026-01-20 16:55:50.992627 | 
2026-01-20 16:55:50.992933 | LOOP [fetch-output : Collect logs, artifacts and docs]
2026-01-20 16:55:51.626140 | controller | ok
2026-01-20 16:55:51.626372 | controller | ok: All items complete
2026-01-20 16:55:51.626412 | 
2026-01-20 16:55:52.078413 | controller | ok
2026-01-20 16:55:52.548036 | controller | ok
2026-01-20 16:55:52.562075 | 
2026-01-20 16:55:52.562195 | TASK [include_role : fetch-output-openshift]
2026-01-20 16:55:52.575660 | controller | skipping: Conditional result was False
2026-01-20 16:55:52.581352 | 
2026-01-20 16:55:52.581422 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2026-01-20 16:55:52.912262 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006071
2026-01-20 16:55:53.095579 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006061
2026-01-20 16:55:53.124842 | 
2026-01-20 16:55:53.124928 | PLAY [all]
2026-01-20 16:55:53.138664 | 
2026-01-20 16:55:53.138734 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2026-01-20 16:55:53.624136 | controller | changed
2026-01-20 16:55:53.645729 | 
2026-01-20 16:55:53.645787 | PLAY RECAP
2026-01-20 16:55:53.645830 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2026-01-20 16:55:53.645854 | 
2026-01-20 16:55:53.714387 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2026-01-20 16:55:53.715058 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2026-01-20 16:55:54.258316 | 
2026-01-20 16:55:54.258423 | PLAY [localhost]
2026-01-20 16:55:54.275472 | 
2026-01-20 16:55:54.275546 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2026-01-20 16:55:54.566512 | localhost | changed
2026-01-20 16:55:54.570775 | 
2026-01-20 16:55:54.570851 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2026-01-20 16:55:54.588736 | localhost | ok
2026-01-20 16:55:54.596270 | 
2026-01-20 16:55:54.596353 | TASK [add-fileserver : Create SSH private key tempfile]
2026-01-20 16:55:54.886827 | localhost | changed
2026-01-20 16:55:54.892323 | 
2026-01-20 16:55:54.892393 | TASK [add-fileserver : Create SSH private key from secret]
2026-01-20 16:55:55.415657 | localhost | changed
2026-01-20 16:55:55.420282 | 
2026-01-20 16:55:55.420366 | TASK [add-fileserver : Add fileserver ssh key]
2026-01-20 16:55:55.740879 | localhost | Identity added: /var/lib/zuul/builds/4e813e18561b4a31ae159dbd9d8d0118/work/tmp/ansible.arhg7dyk (/var/lib/zuul/builds/4e813e18561b4a31ae159dbd9d8d0118/work/tmp/ansible.arhg7dyk)
2026-01-20 16:55:55.741022 | localhost | ok: Runtime: 0:00:00.006321
2026-01-20 16:55:55.745065 | 
2026-01-20 16:55:55.745136 | TASK [add-fileserver : Remove SSH private key from disk]
2026-01-20 16:55:55.954817 | localhost | ok: Runtime: 0:00:00.004116
2026-01-20 16:55:55.959471 | 
2026-01-20 16:55:55.959548 | TASK [add-fileserver : Add fileserver to inventory]
2026-01-20 16:55:56.007347 | localhost | changed
2026-01-20 16:55:56.012126 | 
2026-01-20 16:55:56.012206 | TASK [add-fileserver : Add fileserver server to known hosts]
2026-01-20 16:55:56.312487 | localhost | changed
2026-01-20 16:55:56.331824 | 
2026-01-20 16:55:56.331883 | PLAY [localhost]
2026-01-20 16:55:56.343118 | 
2026-01-20 16:55:56.343191 | TASK [Generate bulk log download script]
2026-01-20 16:55:56.361032 | localhost | ok
2026-01-20 16:55:56.372184 | 
2026-01-20 16:55:56.372252 | TASK [local-log-download : Check API endpoint is defined]
2026-01-20 16:55:56.399292 | localhost | ok: All assertions passed
2026-01-20 16:55:56.403679 | 
2026-01-20 16:55:56.403758 | TASK [local-log-download : Create download script]
2026-01-20 16:55:56.740572 | localhost -> localhost | changed
2026-01-20 16:55:56.749323 | 
2026-01-20 16:55:56.749404 | TASK [Register quick-download link]
2026-01-20 16:55:56.765821 | localhost | ok
2026-01-20 16:55:56.801237 | 
2026-01-20 16:55:56.801315 | PLAY [logserver.rdoproject.org]
2026-01-20 16:55:56.811146 | 
2026-01-20 16:55:56.811217 | TASK [Set zuul-log-path fact]
2026-01-20 16:55:56.826281 | logserver.rdoproject.org | ok
2026-01-20 16:55:56.834857 | 
2026-01-20 16:55:56.834922 | TASK [set-zuul-log-path-fact : Set log path for a build]
2026-01-20 16:55:56.860786 | logserver.rdoproject.org | ok
2026-01-20 16:55:56.866550 | 
2026-01-20 16:55:56.866619 | TASK [upload-logs : Create log directories]
2026-01-20 16:55:58.646437 | logserver.rdoproject.org | changed
2026-01-20 16:55:58.649559 | 
2026-01-20 16:55:58.649627 | TASK [upload-logs : Ensure logs are readable before uploading]
2026-01-20 16:55:58.865354 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004753
2026-01-20 16:55:58.869715 | 
2026-01-20 16:55:58.869783 | TASK [upload-logs : Upload logs to log server]
2026-01-20 16:56:00.283315 | logserver.rdoproject.org | Output suppressed because no_log was given
2026-01-20 16:56:00.286616 | 
2026-01-20 16:56:00.286705 | LOOP [upload-logs : Compress console log and json output]
2026-01-20 16:56:00.322865 | logserver.rdoproject.org | skipping: Conditional result was False
2026-01-20 16:56:00.330793 | logserver.rdoproject.org | skipping: Conditional result was False
2026-01-20 16:56:00.343705 | 
2026-01-20 16:56:00.343776 | LOOP [upload-logs : Upload compressed console log and json output]
2026-01-20 16:56:00.380173 | logserver.rdoproject.org | skipping: Conditional result was False
2026-01-20 16:56:00.380399 | 
2026-01-20 16:56:00.383690 | logserver.rdoproject.org | skipping: Conditional result was False
2026-01-20 16:56:00.390567 | 
2026-01-20 16:56:00.390637 | LOOP [upload-logs : Upload console log and json output]