2025-11-24 08:39:23.697884 | Job console starting...
2025-11-24 08:39:23.909181 | Updating repositories
2025-11-24 08:39:24.680064 | Preparing job workspace
2025-11-24 08:39:36.991077 | Running Ansible setup...
2025-11-24 08:39:42.216485 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-11-24 08:39:43.606834 | 
2025-11-24 08:39:43.608960 | PLAY [localhost]
2025-11-24 08:39:43.662338 | 
2025-11-24 08:39:43.662436 | TASK [Gathering Facts]
2025-11-24 08:39:45.642987 | localhost | ok
2025-11-24 08:39:45.663708 | 
2025-11-24 08:39:45.663807 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-11-24 08:39:46.474601 | localhost -> localhost | changed
2025-11-24 08:39:46.480781 | 
2025-11-24 08:39:46.480875 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-11-24 08:39:48.207762 | localhost -> localhost | changed
2025-11-24 08:39:48.215667 | 
2025-11-24 08:39:48.215736 | TASK [Setup log path fact]
2025-11-24 08:39:48.260632 | localhost | ok
2025-11-24 08:39:48.288761 | 
2025-11-24 08:39:48.288853 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-24 08:39:48.351444 | localhost | ok
2025-11-24 08:39:48.372138 | 
2025-11-24 08:39:48.372248 | TASK [emit-job-header : Print job information]
2025-11-24 08:39:48.429752 | # Job Information
2025-11-24 08:39:48.429883 | Ansible Version: 2.15.12
2025-11-24 08:39:48.429969 | Job: cifmw-molecule-sushy_emulator
2025-11-24 08:39:48.430001 | Pipeline: github-check
2025-11-24 08:39:48.430024 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-11-24 08:39:48.430043 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3451
2025-11-24 08:39:48.430063 | Log URL (when completed): https://logserver.rdoproject.org/839/rdoproject.org/8398fbba5c154ca589b23f07df8183ff/
2025-11-24 08:39:48.430083 | Event ID: 2dae9040-c910-11f0-818a-433f9d14d6bc
2025-11-24 08:39:48.433901 | 
2025-11-24 08:39:48.434052 | LOOP [emit-job-header : Print node information]
2025-11-24 08:39:48.549058 | localhost | ok:
2025-11-24 08:39:48.549206 | localhost | # Node Information
2025-11-24 08:39:48.549250 | localhost | Inventory Hostname: controller
2025-11-24 08:39:48.549277 | localhost | Hostname: np0005533224
2025-11-24 08:39:48.549299 | localhost | Username: zuul
2025-11-24 08:39:48.549321 | localhost | Distro: CentOS 9
2025-11-24 08:39:48.549340 | localhost | Provider: ibm-bm4-nodepool
2025-11-24 08:39:48.549359 | localhost | Region: regionOne
2025-11-24 08:39:48.549378 | localhost | Label: centos-9-stream-crc-2-48-0-xl-ibm
2025-11-24 08:39:48.549397 | localhost | Product Name: OpenStack Compute
2025-11-24 08:39:48.549415 | localhost | Interface IP: 192.168.26.172
2025-11-24 08:39:48.607571 | 
2025-11-24 08:39:48.607688 | PLAY [all]
2025-11-24 08:39:48.621351 | 
2025-11-24 08:39:48.621417 | TASK [Gather network facts]
2025-11-24 08:39:49.185122 | controller | ok
2025-11-24 08:39:49.227722 | 
2025-11-24 08:39:49.227813 | TASK [include_role : start-zuul-console]
2025-11-24 08:39:49.255771 | controller | ok
2025-11-24 08:39:49.269082 | 
2025-11-24 08:39:49.269152 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-11-24 08:39:49.906504 | controller | ok
2025-11-24 08:39:49.920323 | 
2025-11-24 08:39:49.920404 | TASK [include_role : add-build-sshkey]
2025-11-24 08:39:49.962161 | controller | ok
2025-11-24 08:39:49.984480 | 
2025-11-24 08:39:49.984567 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-11-24 08:39:50.385455 | controller -> localhost | ok
2025-11-24 08:39:50.391196 | 
2025-11-24 08:39:50.391284 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-11-24 08:39:50.449864 | controller | ok
2025-11-24 08:39:50.500859 | controller | included: /var/lib/zuul/builds/8398fbba5c154ca589b23f07df8183ff/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-11-24 08:39:50.529711 | 
2025-11-24 08:39:50.529811 | TASK [add-build-sshkey : Create Temp SSH key]
2025-11-24 08:39:51.892520 | controller -> localhost | Generating public/private rsa key pair.
2025-11-24 08:39:51.892719 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/8398fbba5c154ca589b23f07df8183ff/work/8398fbba5c154ca589b23f07df8183ff_id_rsa.
2025-11-24 08:39:51.892758 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/8398fbba5c154ca589b23f07df8183ff/work/8398fbba5c154ca589b23f07df8183ff_id_rsa.pub.
2025-11-24 08:39:51.892784 | controller -> localhost | The key fingerprint is:
2025-11-24 08:39:51.892806 | controller -> localhost | SHA256:ukpbZdPtg5n0oFsnBpz6QZywlN7biM2c47++8ggVPqA zuul-build-sshkey
2025-11-24 08:39:51.892827 | controller -> localhost | The key's randomart image is:
2025-11-24 08:39:51.892847 | controller -> localhost | +---[RSA 3072]----+
2025-11-24 08:39:51.892867 | controller -> localhost | |                 |
2025-11-24 08:39:51.892888 | controller -> localhost | |       .         |
2025-11-24 08:39:51.892925 | controller -> localhost | |      = .        |
2025-11-24 08:39:51.892954 | controller -> localhost | |     + O = .     |
2025-11-24 08:39:51.892976 | controller -> localhost | |    E o S + .    |
2025-11-24 08:39:51.892997 | controller -> localhost | |       % @ B     |
2025-11-24 08:39:51.893017 | controller -> localhost | |    . * @ O =    |
2025-11-24 08:39:51.893038 | controller -> localhost | |   . o =.B o .   |
2025-11-24 08:39:51.893058 | controller -> localhost | |    o.. ==*o     |
2025-11-24 08:39:51.893079 | controller -> localhost | +----[SHA256]-----+
2025-11-24 08:39:51.893125 | controller -> localhost | ok: Runtime: 0:00:00.438549
2025-11-24 08:39:51.898893 | 
2025-11-24 08:39:51.898983 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-11-24 08:39:51.947889 | controller | ok
2025-11-24 08:39:51.969747 | controller | included: /var/lib/zuul/builds/8398fbba5c154ca589b23f07df8183ff/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-11-24 08:39:52.002542 | 
2025-11-24 08:39:52.002659 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-11-24 08:39:52.057971 | controller | skipping: Conditional result was False
2025-11-24 08:39:52.064842 | 
2025-11-24 08:39:52.064948 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-11-24 08:39:52.729580 | controller | changed
2025-11-24 08:39:52.735104 | 
2025-11-24 08:39:52.735183 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-11-24 08:39:53.040996 | controller | ok
2025-11-24 08:39:53.047340 | 
2025-11-24 08:39:53.047429 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-11-24 08:39:54.348961 | controller | changed
2025-11-24 08:39:54.357058 | 
2025-11-24 08:39:54.357167 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-11-24 08:39:55.699262 | controller | changed
2025-11-24 08:39:55.705100 | 
2025-11-24 08:39:55.705169 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-11-24 08:39:55.751122 | controller | skipping: Conditional result was False
2025-11-24 08:39:55.756994 | 
2025-11-24 08:39:55.757069 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-11-24 08:39:56.354286 | controller -> localhost | changed
2025-11-24 08:39:56.434947 | 
2025-11-24 08:39:56.435082 | TASK [add-build-sshkey : Add back temp key]
2025-11-24 08:39:56.831122 | controller -> localhost | Identity added: /var/lib/zuul/builds/8398fbba5c154ca589b23f07df8183ff/work/8398fbba5c154ca589b23f07df8183ff_id_rsa (zuul-build-sshkey)
2025-11-24 08:39:56.831332 | controller -> localhost | ok: Runtime: 0:00:00.007395
2025-11-24 08:39:56.837209 | 
2025-11-24 08:39:56.837288 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-11-24 08:39:57.271506 | controller | ok
2025-11-24 08:39:57.276439 | 
2025-11-24 08:39:57.276508 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-11-24 08:39:57.314460 | controller | skipping: Conditional result was False
2025-11-24 08:39:57.328024 | 
2025-11-24 08:39:57.328122 | TASK [include_role : validate-host]
2025-11-24 08:39:57.379217 | controller | ok
2025-11-24 08:39:57.399822 | 
2025-11-24 08:39:57.399958 | TASK [validate-host : Define zuul_info_dir fact]
2025-11-24 08:39:57.446407 | controller | ok
2025-11-24 08:39:57.455868 | 
2025-11-24 08:39:57.455970 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-11-24 08:39:57.844346 | controller -> localhost | ok
2025-11-24 08:39:57.850163 | 
2025-11-24 08:39:57.850261 | TASK [validate-host : Collect information about the host]
2025-11-24 08:39:58.598313 | controller | ok
2025-11-24 08:39:58.615964 | 
2025-11-24 08:39:58.616070 | TASK [validate-host : Sanitize hostname]
2025-11-24 08:39:58.679819 | controller | ok
2025-11-24 08:39:58.684765 | 
2025-11-24 08:39:58.684834 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-11-24 08:39:59.298126 | controller -> localhost | changed
2025-11-24 08:39:59.303979 | 
2025-11-24 08:39:59.304054 | TASK [validate-host : Collect information about zuul worker]
2025-11-24 08:39:59.813327 | controller | ok
2025-11-24 08:39:59.819427 | 
2025-11-24 08:39:59.819537 | TASK [validate-host : Write out all zuul information for each host]
2025-11-24 08:40:00.472013 | controller -> localhost | changed
2025-11-24 08:40:00.483474 | 
2025-11-24 08:40:00.483555 | TASK [include_role : prepare-workspace-openshift]
2025-11-24 08:40:00.512149 | controller | skipping: Conditional result was False
2025-11-24 08:40:00.517321 | 
2025-11-24 08:40:00.517393 | TASK [include_role : remove-zuul-sshkey]
2025-11-24 08:40:00.541272 | controller | skipping: Conditional result was False
2025-11-24 08:40:00.547075 | 
2025-11-24 08:40:00.547149 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-11-24 08:40:00.804400 | controller | ok: "logs"
2025-11-24 08:40:00.804659 | controller | ok: All items complete
2025-11-24 08:40:00.804691 | 
2025-11-24 08:40:01.051425 | controller | ok: "artifacts"
2025-11-24 08:40:01.282355 | controller | ok: "docs"
2025-11-24 08:40:01.288898 | 
2025-11-24 08:40:01.289022 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-11-24 08:40:01.607055 | controller | changed: "logs"
2025-11-24 08:40:01.877043 | controller | changed: "artifacts"
2025-11-24 08:40:02.146609 | controller | changed: "docs"
2025-11-24 08:40:02.212017 | 
2025-11-24 08:40:02.212313 | PLAY RECAP
2025-11-24 08:40:02.212376 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-11-24 08:40:02.212408 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-24 08:40:02.212432 | 
2025-11-24 08:40:02.392133 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-11-24 08:40:02.392831 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-11-24 08:40:03.311369 | 
2025-11-24 08:40:03.311477 | PLAY [all]
2025-11-24 08:40:03.331989 | 
2025-11-24 08:40:03.332075 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-11-24 08:40:03.381103 | controller | ok
2025-11-24 08:40:03.388296 | 
2025-11-24 08:40:03.388389 | TASK [mirror-info-fork : Create /etc/ci]
2025-11-24 08:40:03.853825 | controller | changed
2025-11-24 08:40:03.862848 | 
2025-11-24 08:40:03.862967 | TASK [mirror-info-fork : Install ci_mirror script]
2025-11-24 08:40:05.481799 | controller | changed
2025-11-24 08:40:05.500749 | 
2025-11-24 08:40:05.500835 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-11-24 08:40:06.165207 | controller | changed:
2025-11-24 08:40:06.165377 | controller | {
2025-11-24 08:40:06.165411 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-11-24 08:40:06.165441 | controller | }
2025-11-24 08:40:06.483430 | controller | changed:
2025-11-24 08:40:06.483521 | controller | {
2025-11-24 08:40:06.483552 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-11-24 08:40:06.483587 | controller | }
2025-11-24 08:40:06.791428 | controller | changed:
2025-11-24 08:40:06.791514 | controller | {
2025-11-24 08:40:06.791547 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-11-24 08:40:06.791570 | controller | }
2025-11-24 08:40:07.128565 | controller | changed:
2025-11-24 08:40:07.128649 | controller | {
2025-11-24 08:40:07.128679 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-11-24 08:40:07.128701 | controller | }
2025-11-24 08:40:07.459438 | controller | changed:
2025-11-24 08:40:07.459576 | controller | {
2025-11-24 08:40:07.459613 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-11-24 08:40:07.459637 | controller | }
2025-11-24 08:40:07.736611 | controller | changed:
2025-11-24 08:40:07.736688 | controller | {
2025-11-24 08:40:07.736717 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-11-24 08:40:07.736739 | controller | }
2025-11-24 08:40:08.062618 | controller | changed:
2025-11-24 08:40:08.062712 | controller | {
2025-11-24 08:40:08.062741 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDLOQd4ZLtkZXQGY6UwAr/06ppWQK4fDO3HaqxPk98csyOCBXsliSKK39Bso828+5srIXiW7aI6aC9P5mwi4mUZlGPfJlQbfrcGvY+b/SocuvaGK+1RrHLoJCT52LBhwgrzlXio2jeksZeein8iaTrhsPrOAs7KggIL/rB9hEiB3NaOPWhhoCP4vlW6MEMExGcqB/1FVxXFBPnLkEyW0Lk7ycVflZl2ocRxbfjZi0+tI1Wlinp8PvSQSc/WVrAcDgKjc/mB4ODPOyYy3G8FHgfMsrXSDEyjBKgLKMsdCrAUcqJQWjkqXleXSYOV4q3pzL+9umK+q/e3P/bIoSFQzmJKTU1eDfuvPXmow9F5H54fii/Da7ezlMJ+wPGHJrRAkmzvMbALy7xwswLhZMkOGNtRcPqaKYRmIBKpw3o6bCTtcNUHOtOQnzwY8JzrM2eBWJBXAANYw+9/ho80JIiwhg29CFNpVBuHbql2YxJQNrnl90guN65rYNpDxdIluweyUf8= anbanerj@kaermorhen"
2025-11-24 08:40:08.062764 | controller | }
2025-11-24 08:40:08.390692 | controller | changed:
2025-11-24 08:40:08.390783 | controller | {
2025-11-24 08:40:08.390812 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC3VwV8Im9kRm49lt3tM36hj4Zv27FxGo4C1Q/0jqhzFmHY7RHbmeRr8ObhwWoHjXSozKWg8FL5ER0z3hTwL0W6lez3sL7hUaCmSuZmG5Hnl3x4vTSxDI9JZ/Y65rtYiiWQo2fC5xJhU/4+0e5e/pseCm8cKRSu+SaxhO+sd6FDojA2x1BzOzKiQRDy/1zWGp/cZkxcEuB1wHI5LMzN03c67vmbu+fhZRAUO4dQkvcnj2LrhQtpa+ytvnSjr8icMDosf1OsbSffwZFyHB/hfWGAfe0eIeSA2XPraxiPknXxiPKx2MJsaUTYbsZcm3EjFdHBBMumw5rBI74zLrMRvCO9GwBEmGT4rFng1nP+yw5DB8sn2zqpOsPg1LYRwCPOUveC13P6pgsZZPh812e8v5EKnETct+5XI3dVpdw6CnNiLwAyVAF15DJvBGT/u1k0Myg/bQn+Gv9k2MSj6LvQmf6WbZu2Wgjm30z3FyCneBqTL7mLF19YXzeC0ufHz5pnO1E= dasm@fedora"
2025-11-24 08:40:08.390835 | controller | }
2025-11-24 08:40:08.750160 | controller | changed:
2025-11-24 08:40:08.750273 | controller | {
2025-11-24 08:40:08.750303 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-11-24 08:40:08.750326 | controller | }
2025-11-24 08:40:09.047264 | controller | changed:
2025-11-24 08:40:09.047357 | controller | {
2025-11-24 08:40:09.047384 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-11-24 08:40:09.047407 | controller | }
2025-11-24 08:40:09.381979 | controller | changed:
2025-11-24 08:40:09.382103 | controller | {
2025-11-24 08:40:09.382131 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-11-24 08:40:09.382152 | controller | }
2025-11-24 08:40:09.708097 | controller | changed:
2025-11-24 08:40:09.708279 | controller | {
2025-11-24 08:40:09.708316 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-11-24 08:40:09.708348 | controller | }
2025-11-24 08:40:10.015270 | controller | changed:
2025-11-24 08:40:10.015355 | controller | {
2025-11-24 08:40:10.015382 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-11-24 08:40:10.015403 | controller | }
2025-11-24 08:40:10.330121 | controller | changed:
2025-11-24 08:40:10.330282 | controller | {
2025-11-24 08:40:10.330322 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-11-24 08:40:10.330351 | controller | }
2025-11-24 08:40:10.627350 | controller | changed:
2025-11-24 08:40:10.627440 | controller | {
2025-11-24 08:40:10.627468 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-11-24 08:40:10.627489 | controller | }
2025-11-24 08:40:10.938260 | controller | changed:
2025-11-24 08:40:10.938352 | controller | {
2025-11-24 08:40:10.938378 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-11-24 08:40:10.938397 | controller | }
2025-11-24 08:40:11.262733 | controller | changed:
2025-11-24 08:40:11.262825 | controller | {
2025-11-24 08:40:11.262853 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQCfNtF7NvKl915TGsGGoseUb06Hj8L/S4toWf0hExeY+F00woL6NvBlJD0nDct+P5a22I4EhvoQCRQ8reaPCm1lybR3uiRIJsj+8zkVvLwby9LXzfZorlNG9ofjd00FEmB09uW/YvTl6Q9XwwwX6tInzIOv3TMqTHHGOL74ibbj8J/FJR0cFEyj0z4WQRvtkh32xAHl83gbuINryMt0sqRI+clj2381NKL55DRLQrVw0gsfqqxiHAnXg21qWmc4J+b9e9kiuAFQjcjwTVkwJCcg3xbPwC/qokYRby/Y5S40UUd7/jEARGXT7RZgpzTuDd1oZiCVrnrqJNPaMNdVv5MLeFdf1B7iIe5aa/fGouX7AO4SdKhZUdnJmCFAGvjC6S3JMZ2wAcUl+OHnssfmdj7XL50cLo27vjuzMtLAgSqi6N99m92WCF2s8J9aVzszX7Xz9OKZCeGsiVJp3/NdABKzSEAyM9xBD/5Vho894Sav+otpySHe3p6RUTgbB5Zu8VyZRZ/UtB3ueXxyo764yrc6qWIDqrehm84Xm9g+/jpIBzGPl07NUNJpdt/6Sgf9RIKXw/7XypO5yZfUcuFNGTxLfqjTNrtgLZNcjfav6sSdVXVcMPL//XNuRdKmVFaO76eV/oGMQGr1fGcCD+N+CpI7+Q+fCNB6VFWG4nZFuI/Iuw== averdagu@redhat.com"
2025-11-24 08:40:11.262877 | controller | }
2025-11-24 08:40:11.581571 | controller | changed:
2025-11-24 08:40:11.581666 | controller | {
2025-11-24 08:40:11.581695 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDq8l27xI+QlQVdS4djp9ogSoyrNE2+Ox6vKPdhSNL1J3PE5w+WCSvMz9A5gnNuH810zwbekEApbxTze/gLQJwBHA52CChfURpXrFaxY7ePXRElwKAL3mJfzBWY/c5jnNL9TCVmFJTGZkFZP3Nh+BMgZvL6xBkt3WKm6Uq18qzd9XeKcZusrA+O+uLv1fVeQnadY9RIqOCyeFYCzLWrUfTyE8x/XG0hAWIM7qpnF2cALQS2h9n4hW5ybiUN790H08wf9hFwEf5nxY9Z9dVkPFQiTSGKNBzmnCXU9skxS/xhpFjJ5duGSZdtAHe9O+nGZm9c67hxgtf8e5PDuqAdXEv2cf6e3VBAt+Bz8EKI3yosTj0oZHfwr42Yzb1l/SKy14Rggsrc9KAQlrGXan6+u2jcQqqx7l+SWmnpFiWTV9u5cWj2IgOhApOitmRBPYqk9rE2usfO0hLn/Pj/R/Nau4803e1/EikdLE7Ps95s9mX5jRDjAoUa2JwFF5RsVFyL910= ashigupt@ashigupt.remote.csb"
2025-11-24 08:40:11.581725 | controller | }
2025-11-24 08:40:11.900784 | controller | changed:
2025-11-24 08:40:11.900873 | controller | {
2025-11-24 08:40:11.900900 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-11-24 08:40:11.900942 | controller | }
2025-11-24 08:40:12.194469 | controller | changed:
2025-11-24 08:40:12.194559 | controller | {
2025-11-24 08:40:12.194586 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-11-24 08:40:12.194608 | controller | }
2025-11-24 08:40:12.495631 | controller | changed:
2025-11-24 08:40:12.495724 | controller | {
2025-11-24 08:40:12.495753 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-11-24 08:40:12.495776 | controller | }
2025-11-24 08:40:12.805751 | controller | changed:
2025-11-24 08:40:12.805979 | controller | {
2025-11-24 08:40:12.806020 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-11-24 08:40:12.806044 | controller | }
2025-11-24 08:40:13.124315 | controller | changed:
2025-11-24 08:40:13.124400 | controller | {
2025-11-24 08:40:13.124428 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQDZdI7t1cxYx65heVI24HTV4F7oQLW1zyfxHreL2TIJKxjyrUUKIFEUmTutcBlJRLNT2Eoix6x1sOw9YrchloCLcn//SGfTElr9mSc5jbjb7QXEU+zJMhtxyEJ1Po3CUGnj7ckiIXw7wcawZtrEOAQ9pH3ExYCJcEMiyNjRQZCxT3tPK+S4B95EWh5Fsrz9CkwpjNRPPH7LigCeQTM3Wc7r97utAslBUUvYceDSLA7rMgkitJE38b7rZBeYzsGQ8YYUBjTCtehqQXxCRjizbHWaaZkBU+N3zkKB6n/iCNGIO690NK7A/qb6msTijiz1PeuM8ThOsi9qXnbX5v0PoTpcFSojV7NHAQ71f0XXuS43FhZctT+Dcx44dT8Fb5vJu2cJGrk+qF8ZgJYNpRS7gPg0EG2EqjK7JMf9ULdjSu0r+KlqIAyLvtzT4eOnQipoKlb/WG5D/0ohKv7OMQ352ggfkBFIQsRXyyTCT98Ft9juqPuahi3CAQmP4H9dyE+7+Kz437PEtsxLmfm6naNmWi7Ee1DqWPwS8rEajsm4sNM4wW9gdBboJQtc0uZw0DfLj1I9r3Mc8Ol0jYtz0yNQDSzVLrGCaJlC311trU70tZ+ZkAVV6Mn8lOhSbj1cK0lvSr6ZK4dgqGl3I1eTZJJhbLNdg7UOVaiRx9543+C/p/As7w== brjackma@redhat.com"
2025-11-24 08:40:13.124449 | controller | }
2025-11-24 08:40:13.440991 | controller | changed:
2025-11-24 08:40:13.441082 | controller | {
2025-11-24 08:40:13.441109 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-11-24 08:40:13.441130 | controller | }
2025-11-24 08:40:13.773018 | controller | changed:
2025-11-24 08:40:13.773112 | controller | {
2025-11-24 08:40:13.773139 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-11-24 08:40:13.773159 | controller | }
2025-11-24 08:40:14.063076 | controller | changed:
2025-11-24 08:40:14.063162 | controller | {
2025-11-24 08:40:14.063189 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-11-24 08:40:14.063209 | controller | }
2025-11-24 08:40:14.079365 | 
2025-11-24 08:40:14.079491 | TASK [Set timezone to UTC]
2025-11-24 08:40:14.599340 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-11-24 08:40:14.605091 | 
2025-11-24 08:40:14.605172 | TASK [Create nodepool directory]
2025-11-24 08:40:14.897184 | controller | changed
2025-11-24 08:40:14.902741 | 
2025-11-24 08:40:14.902811 | TASK [Create nodepool sub_nodes file]
2025-11-24 08:40:15.914142 | controller | changed
2025-11-24 08:40:15.920198 | 
2025-11-24 08:40:15.920288 | TASK [Create nodepool sub_nodes_private file]
2025-11-24 08:40:16.944921 | controller | changed
2025-11-24 08:40:16.950432 | 
2025-11-24 08:40:16.950505 | LOOP [Populate nodepool sub_nodes file]
2025-11-24 08:40:16.980123 | 
2025-11-24 08:40:16.980262 | LOOP [Populate nodepool sub_nodes_private file]
2025-11-24 08:40:17.010849 | 
2025-11-24 08:40:17.011005 | TASK [Create nodepool primary file]
2025-11-24 08:40:17.034647 | controller | skipping: Conditional result was False
2025-11-24 08:40:17.042772 | 
2025-11-24 08:40:17.042879 | TASK [Create nodepool node_private for this node]
2025-11-24 08:40:18.123496 | controller | changed
2025-11-24 08:40:18.129597 | 
2025-11-24 08:40:18.129674 | LOOP [Copy ssh keys to nodepool directory]
2025-11-24 08:40:18.547964 | controller | ok: Item: id_rsa Runtime: 0:00:00.005814
2025-11-24 08:40:18.548144 | 
2025-11-24 08:40:18.808071 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.006974
2025-11-24 08:40:18.818691 | 
2025-11-24 08:40:18.818803 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-11-24 08:40:19.900899 | controller | changed
2025-11-24 08:40:19.906125 | 
2025-11-24 08:40:19.906209 | TASK [Validate sudoers config after edits]
2025-11-24 08:40:20.197288 | controller | /etc/sudoers: parsed OK
2025-11-24 08:40:20.197369 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-11-24 08:40:20.197379 | controller | /etc/sudoers.d/zuul: parsed OK
2025-11-24 08:40:20.197385 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-11-24 08:40:20.438392 | controller | ok: Runtime: 0:00:00.007075
2025-11-24 08:40:20.444487 | 
2025-11-24 08:40:20.444553 | TASK [Show the environment passed in to job shell scripts]
2025-11-24 08:40:20.734986 | controller | SHELL=/bin/bash
2025-11-24 08:40:20.735043 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-11-24 08:40:20.735053 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-11-24 08:40:20.735060 | controller | ZUUL_CHANGES=rdo-jobs:master:refs/changes/88/58488/1^openstack-k8s-operators/ci-framework:main:refs/changes/51/3451/9e962b797235f287fc3e87d5e76ab3a88eb03cd8
2025-11-24 08:40:20.735067 | controller | PWD=/home/zuul
2025-11-24 08:40:20.735125 | controller | ZUUL_PIPELINE=github-check
2025-11-24 08:40:20.735133 | controller | LOGNAME=zuul
2025-11-24 08:40:20.735139 | controller | XDG_SESSION_TYPE=tty
2025-11-24 08:40:20.735144 | controller | _=/usr/bin/env
2025-11-24 08:40:20.735149 | controller | MOTD_SHOWN=pam
2025-11-24 08:40:20.735155 | controller | HOME=/home/zuul
2025-11-24 08:40:20.735160 | controller | LANG=en_US.UTF-8
2025-11-24 08:40:20.735165 | controller | SSH_CONNECTION=192.168.26.12 33544 192.168.26.172 22
2025-11-24 08:40:20.735170 | controller | TOX_TESTENV_PASSENV=ZUUL_UUID ZUUL_PROJECT ZUUL_SHORT_PROJECT_NAME ZUUL_PIPELINE ZUUL_VOTING WORKSPACE BUILD_TIMEOUT ZUUL_BRANCH ZUUL_CHANGES ZUUL_CHANGE_IDS ZUUL_CHANGE ZUUL_PATCHSET
2025-11-24 08:40:20.735178 | controller | ZUUL_CHANGE_IDS=58488,1 3451,9e962b797235f287fc3e87d5e76ab3a88eb03cd8
2025-11-24 08:40:20.735184 | controller | WORKSPACE=/home/zuul/workspace
2025-11-24 08:40:20.735189 | controller | XDG_SESSION_CLASS=user
2025-11-24 08:40:20.735194 | controller | SELINUX_ROLE_REQUESTED=
2025-11-24 08:40:20.735199 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-11-24 08:40:20.735205 | controller | USER=zuul
2025-11-24 08:40:20.735210 | controller | ZUUL_VOTING=True
2025-11-24 08:40:20.735215 | controller | BUILD_TIMEOUT=1800000
2025-11-24 08:40:20.735220 | controller | SELINUX_USE_CURRENT_RANGE=
2025-11-24 08:40:20.735226 | controller | SHLVL=1
2025-11-24 08:40:20.735231 | controller | ZUUL_PATCHSET=9e962b797235f287fc3e87d5e76ab3a88eb03cd8
2025-11-24 08:40:20.735236 | controller | XDG_SESSION_ID=1
2025-11-24 08:40:20.735241 | controller | ZUUL_BRANCH=main
2025-11-24 08:40:20.735246 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-11-24 08:40:20.735252 | controller | SSH_CLIENT=192.168.26.12 33544 22
2025-11-24 08:40:20.735257 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-11-24 08:40:20.735262 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-11-24 08:40:20.735268 | controller | which_declare=declare -f
2025-11-24 08:40:20.735274 | controller | PATH=/home/zuul/.crc/bin/oc:/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-11-24 08:40:20.735279 | controller | SELINUX_LEVEL_REQUESTED=
2025-11-24 08:40:20.735284 | controller | ZUUL_CHANGE=3451
2025-11-24 08:40:20.735289 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-11-24 08:40:20.735294 | controller | ZUUL_UUID=8398fbba5c154ca589b23f07df8183ff
2025-11-24 08:40:20.735301 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-11-24 08:40:20.735306 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-11-24 08:40:20.735312 | controller | }
2025-11-24 08:40:20.974215 | controller | ok: Runtime: 0:00:00.006594
2025-11-24 08:40:20.980593 | 
2025-11-24 08:40:20.980668 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-11-24 08:40:20.994596 | controller | skipping: Conditional result was False
2025-11-24 08:40:21.000612 | 
2025-11-24 08:40:21.000705 | TASK [Symlink /home/zuul-worker/workspace]
2025-11-24 08:40:21.559375 | controller | skipping: Conditional result was False
2025-11-24 08:40:21.565172 | 
2025-11-24 08:40:21.565265 | TASK [Ensure legacy workspace directory]
2025-11-24 08:40:21.836468 | controller | changed
2025-11-24 08:40:21.855806 | 
2025-11-24 08:40:21.855865 | PLAY RECAP
2025-11-24 08:40:21.855926 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-11-24 08:40:21.855958 | 
2025-11-24 08:40:21.990021 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-11-24 08:40:21.990809 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-11-24 08:40:22.509466 | 
2025-11-24 08:40:22.509590 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-11-24 08:40:22.540090 | 
2025-11-24 08:40:22.540188 | TASK [Create zuul-output directory]
2025-11-24 08:40:22.945829 | controller | changed
2025-11-24 08:40:22.951351 | 
2025-11-24 08:40:22.951434 | TASK [Slurp Zuul inventory test]
2025-11-24 08:40:23.253822 | controller -> localhost | ok
2025-11-24 08:40:23.260484 | 
2025-11-24 08:40:23.260557 | TASK [Save zuul inventory]
2025-11-24 08:40:24.622932 | controller | changed
2025-11-24 08:40:24.632016 | 
2025-11-24 08:40:24.632092 | TASK [Save zuul vars without the change_message]
2025-11-24 08:40:25.783603 | controller | changed
2025-11-24 08:40:25.812782 | 
2025-11-24 08:40:25.812860 | PLAY RECAP
2025-11-24 08:40:25.812906 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-11-24 08:40:25.813215 | 
2025-11-24 08:40:25.892008 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-11-24 08:40:25.892714 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-11-24 08:40:26.464597 | 
2025-11-24 08:40:26.464705 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-11-24 08:40:26.485416 | 
2025-11-24 08:40:26.485490 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-11-24 08:40:26.514506 | controller | ok
2025-11-24 08:40:26.531580 | 
2025-11-24 08:40:26.531667 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-11-24 08:40:26.575978 | controller | skipping: Conditional result was False
2025-11-24 08:40:26.582271 | 
2025-11-24 08:40:26.582373 | TASK [mirror-info-fork : Create /etc/ci]
2025-11-24 08:40:26.988622 | controller | ok
2025-11-24 08:40:26.994946 | 
2025-11-24 08:40:26.995020 | TASK [mirror-info-fork : Install ci_mirror script]
2025-11-24 08:40:28.050407 | controller | ok
2025-11-24 08:40:28.061461 | 
2025-11-24 08:40:28.061530 | TASK [Prepare workspace]
2025-11-24 08:40:28.081453 | controller | ok
2025-11-24 08:40:28.115219 | 
2025-11-24 08:40:28.115321 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-11-24 08:40:28.511119 | controller | ok
2025-11-24 08:40:28.517925 | 
2025-11-24 08:40:28.518003 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-11-24 08:40:31.392309 | controller | Output suppressed because no_log was given
2025-11-24 08:40:31.401719 | 
2025-11-24 08:40:31.401803 | LOOP [Create zuul-output directory]
2025-11-24 08:40:31.676080 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-11-24 08:40:31.910364 | controller | ok: "/home/zuul/zuul-output/logs"
2025-11-24 08:40:31.921347 | 
2025-11-24 08:40:31.921422 | TASK [Install required packages]
2025-11-24 08:41:10.669071 | controller | ok: Nothing to do
2025-11-24 08:41:10.674312 | 
2025-11-24 08:41:10.674402 | TASK [Install venv]
2025-11-24 08:42:08.508572 | controller | changed
2025-11-24 08:42:08.532702 | 
2025-11-24 08:42:08.532775 | PLAY RECAP
2025-11-24 08:42:08.532817 | controller | ok: 7 changed: 3 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-11-24 08:42:08.532840 | 
2025-11-24 08:42:08.609816 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-11-24 08:42:08.610625 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-11-24 08:42:09.154546 | 
2025-11-24 08:42:09.154661 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-11-24 08:42:09.176046 | 
2025-11-24 08:42:09.176158 | TASK [Gather required facts]
2025-11-24 08:42:09.732428 | controller | ok
2025-11-24 08:42:09.737796 | 
2025-11-24 08:42:09.737870 | TASK [Load environment var if instructed to]
2025-11-24 08:42:09.761575 | controller | skipping: Conditional result was False
2025-11-24 08:42:09.766892 | 
2025-11-24 08:42:09.766973 | TASK [Ensure group_vars dir exists]
2025-11-24 08:42:10.130573 | controller | ok
2025-11-24 08:42:10.135859 | 
2025-11-24 08:42:10.135971 | TASK [Print related variables]
2025-11-24 08:42:10.164686 | controller | ok:
2025-11-24 08:42:10.164834 | controller | mol_config_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config_local.yml
2025-11-24 08:42:10.164863 | controller | roles_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/sushy_emulator
2025-11-24 08:42:10.169685 | 
2025-11-24 08:42:10.169760 | TASK [Run molecule]
2025-11-24 08:42:11.167730 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-11-24 08:42:11.238594 | controller | INFO     Performing prerun with role_name_check=0...
2025-11-24 08:42:27.406353 | 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).
2025-11-24 08:42:27.406805 | 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).
2025-11-24 08:42:27.407254 | 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).
2025-11-24 08:42:27.407721 | 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).
2025-11-24 08:42:27.408199 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+9e962b79 was found installed in /home/zuul/.cache/ansible-compat/8baae2/collections/ansible_collections, only the first one will be used, 1.0.0+9e962b79 (/home/zuul/.ansible/collections/ansible_collections).
2025-11-24 08:42:27.408666 | 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).
2025-11-24 08:42:27.409100 | 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).
2025-11-24 08:42:27.409543 | 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).
2025-11-24 08:42:27.409991 | 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).
2025-11-24 08:42:27.410419 | 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).
2025-11-24 08:42:27.410879 | 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).
2025-11-24 08:42:27.411312 | 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).
2025-11-24 08:42:27.411770 | 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).
2025-11-24 08:42:27.412206 | 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).
2025-11-24 08:42:27.412668 | 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).
2025-11-24 08:42:27.421882 | controller | INFO     Running default > prepare
2025-11-24 08:42:28.083653 | controller |
2025-11-24 08:42:28.083782 | controller | PLAY [Prepare] *****************************************************************
2025-11-24 08:42:28.083890 | controller |
2025-11-24 08:42:28.084002 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:42:28.084104 | controller | Monday 24 November 2025  08:42:28 +0000 (0:00:00.013)       0:00:00.013 *******
2025-11-24 08:42:28.958435 | controller | ok: [instance]
2025-11-24 08:42:28.958520 | controller |
2025-11-24 08:42:28.958628 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-11-24 08:42:28.958768 | controller | Monday 24 November 2025  08:42:28 +0000 (0:00:00.875)       0:00:00.888 *******
2025-11-24 08:42:28.974643 | controller | skipping: [instance]
2025-11-24 08:42:28.974796 | controller |
2025-11-24 08:42:28.974926 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-11-24 08:42:28.975060 | controller | Monday 24 November 2025  08:42:28 +0000 (0:00:00.016)       0:00:00.905 *******
2025-11-24 08:42:29.013869 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-11-24 08:42:29.013943 | controller |
2025-11-24 08:42:29.014046 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-11-24 08:42:29.014155 | controller | Monday 24 November 2025  08:42:29 +0000 (0:00:00.038)       0:00:00.943 *******
2025-11-24 08:42:29.291756 | controller | ok: [instance]
2025-11-24 08:42:29.291838 | controller |
2025-11-24 08:42:29.291954 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-11-24 08:42:29.292145 | controller | Monday 24 November 2025  08:42:29 +0000 (0:00:00.278)       0:00:01.221 *******
2025-11-24 08:42:29.593893 | controller | ok: [instance]
2025-11-24 08:42:29.593962 | controller |
2025-11-24 08:42:29.594071 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-11-24 08:42:29.594179 | controller | Monday 24 November 2025  08:42:29 +0000 (0:00:00.302)       0:00:01.524 *******
2025-11-24 08:42:30.277353 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-11-24 08:42:30.277430 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-11-24 08:42:30.277556 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-11-24 08:42:30.277719 | controller |
2025-11-24 08:42:30.277832 | controller | TASK [Deploy repo-setup] *******************************************************
2025-11-24 08:42:30.277925 | controller | Monday 24 November 2025  08:42:30 +0000 (0:00:00.683)       0:00:02.207 *******
2025-11-24 08:42:30.337216 | controller |
2025-11-24 08:42:30.337302 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-11-24 08:42:30.337428 | controller | Monday 24 November 2025  08:42:30 +0000 (0:00:00.059)       0:00:02.267 *******
2025-11-24 08:42:30.856059 | controller | changed: [instance] => (item=tmp)
2025-11-24 08:42:30.856142 | controller | changed: [instance] => (item=artifacts/repositories)
2025-11-24 08:42:30.856242 | controller | changed: [instance] => (item=venv/repo_setup)
2025-11-24 08:42:30.856335 | controller |
2025-11-24 08:42:30.856439 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-11-24 08:42:30.856579 | controller | Monday 24 November 2025  08:42:30 +0000 (0:00:00.518)       0:00:02.786 *******
2025-11-24 08:42:31.680759 | controller | ok: [instance]
2025-11-24 08:42:31.680832 | controller |
2025-11-24 08:42:31.680844 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-11-24 08:42:31.680862 | controller | Monday 24 November 2025  08:42:31 +0000 (0:00:00.824)       0:00:03.610 *******
2025-11-24 08:42:32.758745 | controller | changed: [instance]
2025-11-24 08:42:32.758839 | controller |
2025-11-24 08:42:32.758867 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-11-24 08:42:32.758931 | controller | Monday 24 November 2025  08:42:32 +0000 (0:00:01.078)       0:00:04.688 *******
2025-11-24 08:42:40.929366 | controller | changed: [instance]
2025-11-24 08:42:41.716037 | controller |
2025-11-24 08:42:41.716086 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-11-24 08:42:41.716094 | controller | Monday 24 November 2025  08:42:40 +0000 (0:00:08.169)       0:00:12.858 *******
2025-11-24 08:42:41.716106 | controller | changed: [instance]
2025-11-24 08:42:41.739712 | controller |
2025-11-24 08:42:41.739741 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-11-24 08:42:41.739751 | controller | Monday 24 November 2025  08:42:41 +0000 (0:00:00.786)       0:00:13.645 *******
2025-11-24 08:42:41.739763 | controller | skipping: [instance]
2025-11-24 08:42:42.607373 | controller |
2025-11-24 08:42:42.607414 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-11-24 08:42:42.607423 | controller | Monday 24 November 2025  08:42:41 +0000 (0:00:00.024)       0:00:13.669 *******
2025-11-24 08:42:42.607434 | controller | changed: [instance]
2025-11-24 08:42:42.648408 | controller |
2025-11-24 08:42:42.648434 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-11-24 08:42:42.648442 | controller | Monday 24 November 2025  08:42:42 +0000 (0:00:00.867)       0:00:14.536 *******
2025-11-24 08:42:42.648451 | controller | skipping: [instance]
2025-11-24 08:42:42.688524 | controller |
2025-11-24 08:42:42.688559 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-11-24 08:42:42.688567 | controller | Monday 24 November 2025  08:42:42 +0000 (0:00:00.041)       0:00:14.578 *******
2025-11-24 08:42:42.688577 | controller | skipping: [instance]
2025-11-24 08:42:42.728279 | controller |
2025-11-24 08:42:42.728316 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-11-24 08:42:42.728326 | controller | Monday 24 November 2025  08:42:42 +0000 (0:00:00.039)       0:00:14.617 *******
2025-11-24 08:42:42.728339 | controller | skipping: [instance]
2025-11-24 08:42:43.313623 | controller |
2025-11-24 08:42:43.313675 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-11-24 08:42:43.313684 | controller | Monday 24 November 2025  08:42:42 +0000 (0:00:00.040)       0:00:14.658 *******
2025-11-24 08:42:43.313696 | controller | changed: [instance]
2025-11-24 08:42:43.799462 | controller |
2025-11-24 08:42:43.799538 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-11-24 08:42:43.799547 | controller | Monday 24 November 2025  08:42:43 +0000 (0:00:00.584)       0:00:15.242 *******
2025-11-24 08:42:43.799561 | controller | changed: [instance]
2025-11-24 08:42:43.836137 | controller |
2025-11-24 08:42:43.836169 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-11-24 08:42:43.836179 | controller | Monday 24 November 2025  08:42:43 +0000 (0:00:00.485)       0:00:15.728 *******
2025-11-24 08:42:43.836192 | controller | skipping: [instance]
2025-11-24 08:42:43.871204 | controller |
2025-11-24 08:42:43.871235 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-11-24 08:42:43.871245 | controller | Monday 24 November 2025  08:42:43 +0000 (0:00:00.037)       0:00:15.765 *******
2025-11-24 08:42:43.871269 | controller | skipping: [instance]
2025-11-24 08:42:43.908243 | controller |
2025-11-24 08:42:43.908271 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-11-24 08:42:43.908281 | controller | Monday 24 November 2025  08:42:43 +0000 (0:00:00.035)       0:00:15.801 *******
2025-11-24 08:42:43.908293 | controller | skipping: [instance]
2025-11-24 08:42:43.950569 | controller |
2025-11-24 08:42:43.950627 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-11-24 08:42:43.950640 | controller | Monday 24 November 2025  08:42:43 +0000 (0:00:00.037)       0:00:15.838 *******
2025-11-24 08:42:43.950653 | controller | ok: [instance]
2025-11-24 08:42:43.981742 | controller |
2025-11-24 08:42:43.981783 | controller | TASK [repo_setup : Create download directory] **********************************
2025-11-24 08:42:43.981793 | controller | Monday 24 November 2025  08:42:43 +0000 (0:00:00.042)       0:00:15.880 *******
2025-11-24 08:42:43.981806 | controller | skipping: [instance]
2025-11-24 08:42:43.981966 | controller |
2025-11-24 08:42:43.982108 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-11-24 08:42:43.982245 | controller | Monday 24 November 2025  08:42:43 +0000 (0:00:00.031)       0:00:15.911 *******
2025-11-24 08:42:44.019774 | controller | skipping: [instance]
2025-11-24 08:42:44.019995 | controller |
2025-11-24 08:42:44.020137 | controller | TASK [Download the RPM] ********************************************************
2025-11-24 08:42:44.020278 | controller | Monday 24 November 2025  08:42:44 +0000 (0:00:00.037)       0:00:15.949 *******
2025-11-24 08:42:44.057865 | controller | skipping: [instance]
2025-11-24 08:42:44.058063 | controller |
2025-11-24 08:42:44.058204 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-11-24 08:42:44.058341 | controller | Monday 24 November 2025  08:42:44 +0000 (0:00:00.038)       0:00:15.987 *******
2025-11-24 08:42:44.089231 | controller | skipping: [instance]
2025-11-24 08:42:44.089395 | controller |
2025-11-24 08:42:44.089555 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-11-24 08:42:44.089720 | controller | Monday 24 November 2025  08:42:44 +0000 (0:00:00.031)       0:00:16.019 *******
2025-11-24 08:42:44.119370 | controller | skipping: [instance]
2025-11-24 08:42:44.119550 | controller |
2025-11-24 08:42:44.119724 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-11-24 08:42:44.119867 | controller | Monday 24 November 2025  08:42:44 +0000 (0:00:00.030)       0:00:16.049 *******
2025-11-24 08:42:44.152405 | controller | skipping: [instance]
2025-11-24 08:42:44.152626 | controller |
2025-11-24 08:42:44.152795 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-11-24 08:42:44.152935 | controller | Monday 24 November 2025  08:42:44 +0000 (0:00:00.032)       0:00:16.082 *******
2025-11-24 08:42:44.190193 | controller | skipping: [instance]
2025-11-24 08:42:44.190389 | controller |
2025-11-24 08:42:44.190562 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-11-24 08:42:44.190728 | controller | Monday 24 November 2025  08:42:44 +0000 (0:00:00.037)       0:00:16.120 *******
2025-11-24 08:42:44.407747 | controller | ok: [instance]
2025-11-24 08:42:44.407844 | controller |
2025-11-24 08:42:44.407968 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-11-24 08:42:44.408083 | controller | Monday 24 November 2025  08:42:44 +0000 (0:00:00.217)       0:00:16.337 *******
2025-11-24 08:42:44.667155 | controller | changed: [instance]
2025-11-24 08:42:44.918447 | controller |
2025-11-24 08:42:44.918532 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-11-24 08:42:44.918542 | controller | Monday 24 November 2025  08:42:44 +0000 (0:00:00.259)       0:00:16.596 *******
2025-11-24 08:42:44.918556 | controller | changed: [instance]
2025-11-24 08:42:44.952978 | controller |
2025-11-24 08:42:44.953077 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-11-24 08:42:44.953086 | controller | Monday 24 November 2025  08:42:44 +0000 (0:00:00.250)       0:00:16.847 *******
2025-11-24 08:42:44.953102 | controller | skipping: [instance]
2025-11-24 08:42:44.980413 | controller |
2025-11-24 08:42:44.980457 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-11-24 08:42:44.980465 | controller | Monday 24 November 2025  08:42:44 +0000 (0:00:00.034)       0:00:16.881 *******
2025-11-24 08:42:44.980477 | controller | skipping: [instance]
2025-11-24 08:42:45.006302 | controller |
2025-11-24 08:42:45.006342 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-11-24 08:42:45.006350 | controller | Monday 24 November 2025  08:42:44 +0000 (0:00:00.028)       0:00:16.910 *******
2025-11-24 08:42:45.006370 | controller | skipping: [instance]
2025-11-24 08:42:45.032894 | controller |
2025-11-24 08:42:45.032938 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-11-24 08:42:45.032947 | controller | Monday 24 November 2025  08:42:45 +0000 (0:00:00.025)       0:00:16.936 *******
2025-11-24 08:42:45.032964 | controller | skipping: [instance]
2025-11-24 08:42:45.033169 | controller |
2025-11-24 08:42:45.033332 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-11-24 08:42:45.033475 | controller | Monday 24 November 2025  08:42:45 +0000 (0:00:00.026)       0:00:16.962 *******
2025-11-24 08:42:45.059970 | controller | skipping: [instance]
2025-11-24 08:42:45.060174 | controller |
2025-11-24 08:42:45.060350 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-11-24 08:42:45.060538 | controller | Monday 24 November 2025  08:42:45 +0000 (0:00:00.027)       0:00:16.990 *******
2025-11-24 08:42:45.086931 | controller | skipping: [instance]
2025-11-24 08:42:45.087162 | controller |
2025-11-24 08:42:45.087328 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-11-24 08:42:45.087475 | controller | Monday 24 November 2025  08:42:45 +0000 (0:00:00.026)       0:00:17.016 *******
2025-11-24 08:42:45.106405 | controller | skipping: [instance]
2025-11-24 08:42:45.106589 | controller |
2025-11-24 08:42:45.106771 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-11-24 08:42:45.106915 | controller | Monday 24 November 2025  08:42:45 +0000 (0:00:00.019)       0:00:17.036 *******
2025-11-24 08:42:45.140535 | controller | skipping: [instance]
2025-11-24 08:42:45.140797 | controller |
2025-11-24 08:42:45.140992 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-11-24 08:42:45.141152 | controller | Monday 24 November 2025  08:42:45 +0000 (0:00:00.033)       0:00:17.070 *******
2025-11-24 08:42:45.159931 | controller | skipping: [instance]
2025-11-24 08:42:45.160121 | controller |
2025-11-24 08:42:45.160264 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-11-24 08:42:45.160412 | controller | Monday 24 November 2025  08:42:45 +0000 (0:00:00.019)       0:00:17.090 *******
2025-11-24 08:42:45.182865 | controller | skipping: [instance]
2025-11-24 08:42:45.183055 | controller |
2025-11-24 08:42:45.183213 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-11-24 08:42:45.183345 | controller | Monday 24 November 2025  08:42:45 +0000 (0:00:00.022)       0:00:17.113 *******
2025-11-24 08:42:45.214848 | controller | skipping: [instance]
2025-11-24 08:42:45.215002 | controller |
2025-11-24 08:42:45.215144 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-11-24 08:42:45.215281 | controller | Monday 24 November 2025  08:42:45 +0000 (0:00:00.032)       0:00:17.145 *******
2025-11-24 08:42:45.250336 | controller | skipping: [instance]
2025-11-24 08:42:45.250533 | controller |
2025-11-24 08:42:45.250710 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-11-24 08:42:45.250857 | controller | Monday 24 November 2025  08:42:45 +0000 (0:00:00.035)       0:00:17.180 *******
2025-11-24 08:42:45.284432 | controller | skipping: [instance]
2025-11-24 08:42:45.284647 | controller |
2025-11-24 08:42:45.284801 | controller | TASK [test_deps : Install additional packages] *********************************
2025-11-24 08:42:45.284939 | controller | Monday 24 November 2025  08:42:45 +0000 (0:00:00.034)       0:00:17.214 *******
2025-11-24 08:42:45.322193 | controller | skipping: [instance]
2025-11-24 08:42:45.322402 | controller |
2025-11-24 08:42:45.322571 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-11-24 08:42:45.322731 | controller | Monday 24 November 2025  08:42:45 +0000 (0:00:00.037)       0:00:17.252 *******
2025-11-24 08:43:34.110164 | controller | ok: [instance]
2025-11-24 08:43:35.495452 | controller |
2025-11-24 08:43:35.495485 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-11-24 08:43:35.495493 | controller | Monday 24 November 2025  08:43:34 +0000 (0:00:48.787)       0:01:06.039 *******
2025-11-24 08:43:35.495517 | controller | ok: [instance]
2025-11-24 08:43:35.532345 | controller |
2025-11-24 08:43:35.532371 | controller | TASK [test_deps : Install extra packages] **************************************
2025-11-24 08:43:35.532378 | controller | Monday 24 November 2025  08:43:35 +0000 (0:00:01.385)       0:01:07.425 *******
2025-11-24 08:43:35.532389 | controller | skipping: [instance]
2025-11-24 08:53:00.388740 | controller |
2025-11-24 08:53:00.388963 | controller | TASK [Ensure CRC is started] ***************************************************
2025-11-24 08:53:00.388976 | controller | Monday 24 November 2025  08:43:35 +0000 (0:00:00.037)       0:01:07.462 *******
2025-11-24 08:53:00.388991 | controller | changed: [instance]
2025-11-24 08:53:00.730404 | controller |
2025-11-24 08:53:00.730445 | controller | TASK [Inject crc hostname/IP in hosts] *****************************************
2025-11-24 08:53:00.730453 | controller | Monday 24 November 2025  08:53:00 +0000 (0:09:24.850)       0:10:32.313 *******
2025-11-24 08:53:00.730465 | controller | changed: [instance]
2025-11-24 08:53:00.730777 | controller |
2025-11-24 08:53:00.730798 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:53:00.730823 | controller | instance                   : ok=21   changed=11   unreachable=0    failed=0    skipped=30   rescued=0    ignored=0
2025-11-24 08:53:00.730829 | controller |
2025-11-24 08:53:00.730844 | controller | Monday 24 November 2025  08:53:00 +0000 (0:00:00.346)       0:10:32.660 *******
2025-11-24 08:53:00.731672 | controller | ===============================================================================
2025-11-24 08:53:00.731835 | controller | Ensure CRC is started ------------------------------------------------- 564.85s
2025-11-24 08:53:00.731847 | controller | test_deps : Install selinux python libs -------------------------------- 48.79s
2025-11-24 08:53:00.731859 | controller | repo_setup : Initialize python venv and install requirements ------------ 8.17s
2025-11-24 08:53:00.731864 | controller | test_deps : Install python yaml libs ------------------------------------ 1.39s
2025-11-24 08:53:00.731870 | controller | repo_setup : Get repo-setup repository ---------------------------------- 1.08s
2025-11-24 08:53:00.731875 | controller | Gathering Facts --------------------------------------------------------- 0.88s
2025-11-24 08:53:00.731880 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.87s
2025-11-24 08:53:00.731885 | controller | repo_setup : Make sure git-core package is installed -------------------- 0.82s
2025-11-24 08:53:00.731893 | controller | repo_setup : Install repo-setup package --------------------------------- 0.79s
2025-11-24 08:53:00.732290 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.68s
2025-11-24 08:53:00.732312 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.58s
2025-11-24 08:53:00.732446 | controller | repo_setup : Ensure directories are present ----------------------------- 0.52s
2025-11-24 08:53:00.732456 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.49s
2025-11-24 08:53:00.732462 | controller | Inject crc hostname/IP in hosts ----------------------------------------- 0.35s
2025-11-24 08:53:00.732467 | controller | test_deps : Disable ubi host subscription-manager integration ----------- 0.30s
2025-11-24 08:53:00.732475 | controller | test_deps : Detect mirrors file ----------------------------------------- 0.28s
2025-11-24 08:53:00.732784 | controller | repo_setup : Use RDO proxy mirrors -------------------------------------- 0.26s
2025-11-24 08:53:00.732823 | controller | repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist) --- 0.25s
2025-11-24 08:53:00.799467 | controller | repo_setup : Check for /etc/ci/mirror_info.sh --------------------------- 0.22s
2025-11-24 08:53:00.799501 | controller | Deploy repo-setup ------------------------------------------------------- 0.06s
2025-11-24 08:53:00.799513 | controller | INFO     Running default > converge
2025-11-24 08:53:01.311293 | controller |
2025-11-24 08:53:02.209913 | controller | PLAY [Converge] ****************************************************************
2025-11-24 08:53:02.209950 | controller |
2025-11-24 08:53:02.209960 | controller | TASK [Gathering Facts] *********************************************************
2025-11-24 08:53:02.209967 | controller | Monday 24 November 2025  08:53:01 +0000 (0:00:00.019)       0:00:00.019 *******
2025-11-24 08:53:02.209979 | controller | ok: [instance]
2025-11-24 08:53:02.227726 | controller |
2025-11-24 08:53:02.227761 | controller | TASK [Load networking_definition] **********************************************
2025-11-24 08:53:02.227771 | controller | Monday 24 November 2025  08:53:02 +0000 (0:00:00.899)       0:00:00.919 *******
2025-11-24 08:53:02.227783 | controller | ok: [instance]
2025-11-24 08:53:02.227818 | controller |
2025-11-24 08:53:02.228044 | controller | TASK [Check if new ssh keypair exists] *****************************************
2025-11-24 08:53:02.252149 | controller | Monday 24 November 2025  08:53:02 +0000 (0:00:00.018)       0:00:00.937 *******
2025-11-24 08:53:02.252184 | controller |
2025-11-24 08:53:02.252426 | controller | TASK [recognize_ssh_keypair : Check if id_ed25519 key exists] ******************
2025-11-24 08:53:02.543250 | controller | Monday 24 November 2025  08:53:02 +0000 (0:00:00.024)       0:00:00.961 *******
2025-11-24 08:53:02.543327 | controller | ok: [instance]
2025-11-24 08:53:02.544254 | controller |
2025-11-24 08:53:02.544583 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair exists] ******************
2025-11-24 08:53:02.563338 | controller | Monday 24 November 2025  08:53:02 +0000 (0:00:00.290)       0:00:01.252 *******
2025-11-24 08:53:02.563387 | controller | ok: [instance]
2025-11-24 08:53:02.563408 | controller |
2025-11-24 08:53:02.563415 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair does not exists] *********
2025-11-24 08:53:02.563423 | controller | Monday 24 November 2025  08:53:02 +0000 (0:00:00.020)       0:00:01.272 *******
2025-11-24 08:53:02.585589 | controller | skipping: [instance]
2025-11-24 08:53:02.585683 | controller |
2025-11-24 08:53:02.585812 | controller | TASK [Add the crc host dynamically] ********************************************
2025-11-24 08:53:02.586072 | controller | Monday 24 November 2025  08:53:02 +0000 (0:00:00.022)       0:00:01.295 *******
2025-11-24 08:53:02.606629 | controller | changed: [instance]
2025-11-24 08:53:02.606762 | controller |
2025-11-24 08:53:02.606872 | controller | TASK [Add ansible_host entry to "controller-0"] ********************************
2025-11-24 08:53:02.606980 | controller | Monday 24 November 2025  08:53:02 +0000 (0:00:00.021)       0:00:01.316 *******
2025-11-24 08:53:02.634315 | controller | changed: [instance]
2025-11-24 08:53:02.634408 | controller |
2025-11-24 08:53:02.634533 | controller | TASK [Add host key to controller-0] ********************************************
2025-11-24 08:53:02.634681 | controller | Monday 24 November 2025  08:53:02 +0000 (0:00:00.027)       0:00:01.343 *******
2025-11-24 08:53:02.962200 | controller | changed: [instance]
2025-11-24 08:53:02.962276 | controller |
2025-11-24 08:53:02.962379 | controller | TASK [libvirt_manager : Ensure output directory exists] ************************
2025-11-24 08:53:02.962477 | controller | Monday 24 November 2025  08:53:02 +0000 (0:00:00.327)       0:00:01.671 *******
2025-11-24 08:53:03.251487 | controller | ok: [instance]
2025-11-24 08:53:03.251539 | controller |
2025-11-24 08:53:03.251642 | controller | TASK [libvirt_manager : Get vmx/svm extensions from /proc/cpuinfo] *************
2025-11-24 08:53:03.251745 | controller | Monday 24 November 2025  08:53:03 +0000 (0:00:00.289)       0:00:01.960 *******
2025-11-24 08:53:03.439461 | controller | changed: [instance]
2025-11-24 08:53:03.439529 | controller |
2025-11-24 08:53:03.439689 | controller | TASK [libvirt_manager : Check if KVM is enabled] *******************************
2025-11-24 08:53:03.439787 | controller | Monday 24 November 2025  08:53:03 +0000 (0:00:00.187)       0:00:02.148 *******
2025-11-24 08:53:03.625064 | controller | ok: [instance]
2025-11-24 08:53:03.625139 | controller |
2025-11-24 08:53:03.625276 | controller | TASK [libvirt_manager : Fail if KVM not enabled] *******************************
2025-11-24 08:53:03.625384 | controller | Monday 24 November 2025  08:53:03 +0000 (0:00:00.185)       0:00:02.334 *******
2025-11-24 08:53:03.653272 | controller | skipping: [instance]
2025-11-24 08:53:03.653361 | controller |
2025-11-24 08:53:03.653494 | controller | TASK [libvirt_manager : Check if VMX virtualization] ***************************
2025-11-24 08:53:03.653627 | controller | Monday 24 November 2025  08:53:03 +0000 (0:00:00.028)       0:00:02.362 *******
2025-11-24 08:53:03.669926 | controller | skipping: [instance]
2025-11-24 08:53:03.670018 | controller |
2025-11-24 08:53:03.670125 | controller | TASK [libvirt_manager : Check if SVM virtualization] ***************************
2025-11-24 08:53:03.670241 | controller | Monday 24 November 2025  08:53:03 +0000 (0:00:00.016)       0:00:02.379 *******
2025-11-24 08:53:03.690181 | controller | ok: [instance]
2025-11-24 08:53:03.690309 | controller |
2025-11-24 08:53:03.690438 | controller | TASK [libvirt_manager : Enable VMX virtualization] *****************************
2025-11-24 08:53:03.690562 | controller | Monday 24 November 2025  08:53:03 +0000 (0:00:00.020)       0:00:02.399 *******
2025-11-24 08:53:03.717162 | controller | skipping: [instance]
2025-11-24 08:53:03.717255 | controller |
2025-11-24 08:53:03.717364 | controller | TASK [libvirt_manager : Install packages required for using KVM] ***************
2025-11-24 08:53:03.717468 | controller | Monday 24 November 2025  08:53:03 +0000 (0:00:00.026)       0:00:02.426 *******
2025-11-24 08:53:13.314730 | controller | changed: [instance]
2025-11-24 08:53:13.314803 | controller |
2025-11-24 08:53:13.314919 | controller | TASK [libvirt_manager : Create rules.d polkit folder] **************************
2025-11-24 08:53:13.315028 | controller | Monday 24 November 2025  08:53:13 +0000 (0:00:09.597)       0:00:12.024 *******
2025-11-24 08:53:13.525771 | controller | changed: [instance]
2025-11-24 08:53:13.525845 | controller |
2025-11-24 08:53:13.526255 | controller | TASK [libvirt_manager : Enable UNIX socket PolicyKit auth] *********************
2025-11-24 08:53:14.031511 | controller | Monday 24 November 2025  08:53:13 +0000 (0:00:00.210)       0:00:12.234 *******
2025-11-24 08:53:14.031568 | controller | changed: [instance]
2025-11-24 08:53:14.031593 | controller |
2025-11-24 08:53:14.031712 | controller | TASK [libvirt_manager : Restart service polkit service] ************************
2025-11-24 08:53:14.031826 | controller | Monday 24 November 2025  08:53:14 +0000 (0:00:00.505)       0:00:12.740 *******
2025-11-24 08:53:14.629614 | controller | changed: [instance]
2025-11-24 08:53:14.629711 | controller |
2025-11-24 08:53:14.629752 | controller | TASK [libvirt_manager : Remove directory for service override] *****************
2025-11-24 08:53:14.825378 | controller | Monday 24 November 2025  08:53:14 +0000 (0:00:00.597)       0:00:13.338 *******
2025-11-24 08:53:14.825418 | controller | ok: [instance]
2025-11-24 08:53:15.500315 | controller |
2025-11-24 08:53:15.500350 | controller | TASK [libvirt_manager : Reload systemctl and start/enable virtproxyd.service] ***
2025-11-24 08:53:15.500358 | controller | Monday 24 November 2025  08:53:14 +0000 (0:00:00.195)       0:00:13.534 *******
2025-11-24 08:53:15.500369 | controller | ok: [instance]
2025-11-24 08:53:15.500417 | controller |
2025-11-24 08:53:15.500447 | controller | TASK [libvirt_manager : Ensure firewalld service is up] ************************
2025-11-24 08:53:15.500460 | controller | Monday 24 November 2025  08:53:15 +0000 (0:00:00.674)       0:00:14.209 *******
2025-11-24 08:53:16.445221 | controller | changed: [instance]
2025-11-24 08:53:16.527949 | controller |
2025-11-24 08:53:16.527998 | controller | TASK [libvirt_manager : Ensure libvirt modular driver daemons are started.] ****
2025-11-24 08:53:16.528007 | controller | Monday 24 November 2025  08:53:16 +0000 (0:00:00.944)       0:00:15.154 *******
2025-11-24 08:53:16.528021 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=qemu)
2025-11-24 08:53:16.529097 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=interface)
2025-11-24 08:53:16.529131 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=network)
2025-11-24 08:53:16.863263 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nodedev)
2025-11-24 08:53:16.863297 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nwfilter)
2025-11-24 08:53:16.863305 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=secret)
2025-11-24 08:53:16.863311 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=storage)
2025-11-24 08:53:16.863316 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=proxy)
2025-11-24 08:53:16.863321 | controller |
2025-11-24 08:53:16.863328 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for qemu.] *********
2025-11-24 08:53:16.863334 | controller | Monday 24 November 2025  08:53:16 +0000 (0:00:00.083)       0:00:15.237 *******
2025-11-24 08:53:16.863344 | controller | ok: [instance]
2025-11-24 08:53:17.189910 | controller |
2025-11-24 08:53:17.189948 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for qemu.] **********
2025-11-24 08:53:17.189957 | controller | Monday 24 November 2025  08:53:16 +0000 (0:00:00.335)       0:00:15.572 *******
2025-11-24 08:53:17.189970 | controller | ok: [instance]
2025-11-24 08:53:17.189998 | controller |
2025-11-24 08:53:17.190008 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for qemu.] **************
2025-11-24 08:53:17.190108 | controller | Monday 24 November 2025  08:53:17 +0000 (0:00:00.326)       0:00:15.899 *******
2025-11-24 08:53:17.510152 | controller | ok: [instance]
2025-11-24 08:53:17.843377 | controller |
2025-11-24 08:53:17.843407 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for interface.] ****
2025-11-24 08:53:17.843421 | controller | Monday 24 November 2025  08:53:17 +0000 (0:00:00.319)       0:00:16.219 *******
2025-11-24 08:53:17.843431 | controller | ok: [instance]
2025-11-24 08:53:17.843457 | controller |
2025-11-24 08:53:17.843761 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for interface.] *****
2025-11-24 08:53:19.168984 | controller | Monday 24 November 2025  08:53:17 +0000 (0:00:00.333)       0:00:16.552 *******
2025-11-24 08:53:19.169020 | controller | ok: [instance]
2025-11-24 08:53:19.169048 | controller |
2025-11-24 08:53:19.169359 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for interface.] *********
2025-11-24 08:53:19.506398 | controller | Monday 24 November 2025  08:53:19 +0000 (0:00:01.325)       0:00:17.878 *******
2025-11-24 08:53:19.506434 | controller | ok: [instance]
2025-11-24 08:53:19.506459 | controller |
2025-11-24 08:53:19.506468 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for network.] ******
2025-11-24 08:53:19.506613 | controller | Monday 24 November 2025  08:53:19 +0000 (0:00:00.337)       0:00:18.215 *******
2025-11-24 08:53:19.825393 | controller | ok: [instance]
2025-11-24 08:53:19.825439 | controller |
2025-11-24 08:53:19.825449 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for network.] *******
2025-11-24 08:53:19.825558 | controller | Monday 24 November 2025  08:53:19 +0000 (0:00:00.319)       0:00:18.534 *******
2025-11-24 08:53:20.150889 | controller | ok: [instance]
2025-11-24 08:53:20.477665 | controller |
2025-11-24 08:53:20.477707 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for network.] ***********
2025-11-24 08:53:20.477716 | controller | Monday 24 November 2025  08:53:20 +0000 (0:00:00.324)       0:00:18.859 *******
2025-11-24 08:53:20.477729 | controller | ok: [instance]
2025-11-24 08:53:20.477764 | controller |
2025-11-24 08:53:20.477772 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nodedev.] ******
2025-11-24 08:53:20.477874 | controller | Monday 24 November 2025  08:53:20 +0000 (0:00:00.327)       0:00:19.186 *******
2025-11-24 08:53:20.806699 | controller | ok: [instance]
2025-11-24 08:53:20.806782 | controller |
2025-11-24 08:53:20.806795 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nodedev.] *******
2025-11-24 08:53:20.806945 | controller | Monday 24 November 2025  08:53:20 +0000 (0:00:00.329)       0:00:19.516 *******
2025-11-24 08:53:21.135388 | controller | ok: [instance]
2025-11-24 08:53:21.135470 | controller |
2025-11-24 08:53:21.135576 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nodedev.] ***********
2025-11-24 08:53:21.135632 | controller | Monday 24 November 2025  08:53:21 +0000 (0:00:00.328)       0:00:19.844 *******
2025-11-24 08:53:21.471196 | controller | ok: [instance]
2025-11-24 08:53:21.471276 | controller |
2025-11-24 08:53:21.471289 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nwfilter.] *****
2025-11-24 08:53:21.471388 | controller | Monday 24 November 2025  08:53:21 +0000 (0:00:00.335)       0:00:20.180 *******
2025-11-24 08:53:21.799077 | controller | ok: [instance]
2025-11-24 08:53:21.799185 | controller |
2025-11-24 08:53:21.799194 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nwfilter.] ******
2025-11-24 08:53:21.799202 | controller | Monday 24 November 2025  08:53:21 +0000 (0:00:00.327)       0:00:20.508 *******
2025-11-24 08:53:22.130414 | controller | ok: [instance]
2025-11-24 08:53:22.130461 | controller |
2025-11-24 08:53:22.130672 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nwfilter.] **********
2025-11-24 08:53:22.452848 | controller | Monday 24 November 2025  08:53:22 +0000 (0:00:00.331)       0:00:20.839 *******
2025-11-24 08:53:22.452972 | controller | ok: [instance]
2025-11-24 08:53:22.453040 | controller |
2025-11-24 08:53:22.453051 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for secret.] *******
2025-11-24 08:53:22.453146 | controller | Monday 24 November 2025  08:53:22 +0000 (0:00:00.322)       0:00:21.162 *******
2025-11-24 08:53:22.782127 | controller | ok: [instance]
2025-11-24 08:53:22.782197 | controller |
2025-11-24 08:53:22.782343 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for secret.] ********
2025-11-24 08:53:22.782444 | controller | Monday 24 November 2025  08:53:22 +0000 (0:00:00.329)       0:00:21.491 *******
2025-11-24 08:53:23.117453 | controller | ok: [instance]
2025-11-24 08:53:23.117529 | controller |
2025-11-24 08:53:23.117651 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for secret.] ************
2025-11-24 08:53:23.117761 | controller | Monday 24 November 2025  08:53:23 +0000 (0:00:00.335)       0:00:21.826 *******
2025-11-24 08:53:23.455494 | controller | ok: [instance]
2025-11-24 08:53:23.455555 | controller |
2025-11-24 08:53:23.455677 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for storage.] ******
2025-11-24 08:53:23.455800 | controller | Monday 24 November 2025  08:53:23 +0000 (0:00:00.338)       0:00:22.165 *******
2025-11-24 08:53:23.780355 | controller | ok: [instance]
2025-11-24 08:53:23.780417 | controller |
2025-11-24 08:53:23.780544 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for storage.] *******
2025-11-24 08:53:23.780675 | controller | Monday 24 November 2025  08:53:23 +0000 (0:00:00.324)       0:00:22.489 *******
2025-11-24 08:53:24.106064 | controller | ok: [instance]
2025-11-24 08:53:24.106126 | controller |
2025-11-24 08:53:24.106234 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for storage.] ***********
2025-11-24 08:53:24.106346 | controller | Monday 24 November 2025  08:53:24 +0000 (0:00:00.325)       0:00:22.815 *******
2025-11-24 08:53:24.431688 | controller | ok: [instance]
2025-11-24 08:53:24.431733 | controller |
2025-11-24 08:53:24.431744 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for proxy.] ********
2025-11-24 08:53:24.431840 | controller | Monday 24 November 2025  08:53:24 +0000 (0:00:00.325)       0:00:23.141 *******
2025-11-24 08:53:25.761621 | controller | ok: [instance]
2025-11-24 08:53:25.761943 | controller |
2025-11-24 08:53:26.095877 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for proxy.] *********
2025-11-24 08:53:26.095915 | controller | Monday 24 November 2025  08:53:25 +0000 (0:00:01.330)       0:00:24.471 *******
2025-11-24 08:53:26.095929 | controller | ok: [instance]
2025-11-24 08:53:26.095956 | controller |
2025-11-24 08:53:26.095964 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for proxy.] *************
2025-11-24 08:53:26.415361 | controller | Monday 24 November 2025  08:53:26 +0000 (0:00:00.333)       0:00:24.805 *******
2025-11-24 08:53:26.415410 | controller | ok: [instance]
2025-11-24 08:53:26.415651 | controller |
2025-11-24 08:53:26.435549 | controller | TASK [libvirt_manager : Manage service for older releases] *********************
2025-11-24 08:53:26.435573 | controller | Monday 24 November 2025  08:53:26 +0000 (0:00:00.319)       0:00:25.124 *******
2025-11-24 08:53:26.435585 | controller | skipping: [instance]
2025-11-24 08:53:26.722366 | controller |
2025-11-24 08:53:26.722407 | controller | TASK [libvirt_manager : Get libvirt group users] *******************************
2025-11-24 08:53:26.722415 | controller | Monday 24 November 2025  08:53:26 +0000 (0:00:00.019)       0:00:25.144 *******
2025-11-24 08:53:26.722427 | controller | ok: [instance]
2025-11-24 08:53:26.722435 | controller |
2025-11-24 08:53:26.722570 | controller | TASK [libvirt_manager : Add user if not exists in libvirt group] ***************
2025-11-24 08:53:26.722680 | controller | Monday 24 November 2025  08:53:26 +0000 (0:00:00.286)       0:00:25.431 *******
2025-11-24 08:53:27.096196 | controller | ok: [instance]
2025-11-24 08:53:27.096320 | controller |
2025-11-24 08:53:27.096400 | controller | TASK [libvirt_manager : Allow QEMU on home directory for the storage access] ***
2025-11-24 08:53:27.096489 | controller | Monday 24 November 2025  08:53:27 +0000 (0:00:00.373)       0:00:25.805 *******
2025-11-24 08:53:27.403839 | controller | changed: [instance]
2025-11-24 08:53:27.403922 | controller |
2025-11-24 08:53:27.404031 | controller | TASK [libvirt_manager : Inject system connection parameters in bashrc] *********
2025-11-24 08:53:27.404141 | controller | Monday 24 November 2025  08:53:27 +0000 (0:00:00.307)       0:00:26.113 *******
2025-11-24 08:53:27.683651 | controller | [WARNING]: Reset is not implemented for this connection
2025-11-24 08:53:27.694103 | controller | changed: [instance]
2025-11-24 08:53:27.694524 | controller |
2025-11-24 08:53:27.694534 | controller | TASK [libvirt_manager : Ensure we reload user env] *****************************
2025-11-24 08:53:27.694541 | controller | Monday 24 November 2025  08:53:27 +0000 (0:00:00.274)       0:00:26.387 *******
2025-11-24 08:53:27.694549 | controller |
2025-11-24 08:53:27.763581 | controller | TASK [Create virtual baremetal VMs] ********************************************
2025-11-24 08:53:27.763634 | controller | Monday 24 November 2025  08:53:27 +0000 (0:00:00.016)       0:00:26.403 *******
2025-11-24 08:53:27.763653 | controller |
2025-11-24 08:53:27.763681 | controller | TASK [libvirt_manager : Import layout generator if needed] *********************
2025-11-24 08:53:27.763861 | controller | Monday 24 November 2025  08:53:27 +0000 (0:00:00.069)       0:00:26.473 *******
2025-11-24 08:53:27.793469 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/generate_layout.yml for instance
2025-11-24 08:53:27.793573 | controller |
2025-11-24 08:53:27.793741 | controller | TASK [libvirt_manager : Chose right parameter for layout definition] ***********
2025-11-24 08:53:27.793868 | controller | Monday 24 November 2025  08:53:27 +0000 (0:00:00.030)       0:00:26.503 *******
2025-11-24 08:53:27.825219 | controller | ok: [instance]
2025-11-24 08:53:27.825334 | controller |
2025-11-24 08:53:27.825466 | controller | TASK [libvirt_manager : Patch the layout if needed] ****************************
2025-11-24 08:53:27.825583 | controller | Monday 24 November 2025  08:53:27 +0000 (0:00:00.031)       0:00:26.534 *******
2025-11-24 08:53:27.888521 | controller | skipping: [instance]
2025-11-24 08:53:27.888596 | controller |
2025-11-24 08:53:27.888721 | controller | TASK [libvirt_manager : Enable forwarding in the libvirt zone] *****************
2025-11-24 08:53:27.889626 | controller | Monday 24 November 2025  08:53:27 +0000 (0:00:00.063)       0:00:26.598 *******
2025-11-24 08:53:28.301836 | controller | changed: [instance]
2025-11-24 08:53:28.302429 | controller |
2025-11-24 08:53:28.791405 | controller | TASK [libvirt_manager : Enable masquerading for public traffic] ****************
2025-11-24 08:53:28.791438 | controller | Monday 24 November 2025  08:53:28 +0000 (0:00:00.413)       0:00:27.011 *******
2025-11-24 08:53:28.791450 | controller | changed: [instance]
2025-11-24 08:53:28.791482 | controller |
2025-11-24 08:53:28.791654 | controller | TASK [libvirt_manager : Ensure firewalld is restarts] **************************
2025-11-24 08:53:28.791762 | controller | Monday 24 November 2025  08:53:28 +0000 (0:00:00.480)       0:00:27.491 *******
2025-11-24 08:53:28.791853 | controller |
2025-11-24 08:53:28.791960 | controller | RUNNING HANDLER [libvirt_manager : Restart firewalld] **************************
2025-11-24 08:53:28.792067 | controller | Monday 24 November 2025  08:53:28 +0000 (0:00:00.009)       0:00:27.500 *******
2025-11-24 08:53:29.568839 | controller | changed: [instance]
2025-11-24 08:53:29.601580 | controller |
2025-11-24 08:53:29.601622 | controller | TASK [Deploy virtualbmc] *******************************************************
2025-11-24 08:53:29.601633 | controller | Monday 24 November 2025  08:53:29 +0000 (0:00:00.777)       0:00:28.277 *******
2025-11-24 08:53:29.601643 | controller | skipping: [instance]
2025-11-24 08:53:29.601664 | controller |
2025-11-24 08:53:29.601825 | controller | TASK [libvirt_manager : Let the project know we have vbmc available] ***********
2025-11-24 08:53:29.601897 | controller | Monday 24 November 2025  08:53:29 +0000 (0:00:00.032)       0:00:28.310 *******
2025-11-24 08:53:29.633109 | controller | skipping: [instance]
2025-11-24 08:53:29.633177 | controller |
2025-11-24 08:53:29.633421 | controller | TASK [libvirt_manager : Create needed workload directory] **********************
2025-11-24 08:53:30.174844 | controller | Monday 24 November 2025  08:53:29 +0000 (0:00:00.032)       0:00:28.342 *******
2025-11-24 08:53:30.174899 | controller | changed: [instance] => (item=workload)
2025-11-24 08:53:30.174954 | controller | changed: [instance] => (item=reproducer-inventory)
2025-11-24 08:53:30.175065 | controller | changed: [instance] => (item=volumes)
2025-11-24 08:53:30.175161 | controller |
2025-11-24 08:53:30.175264 | controller | TASK [libvirt_manager : Allow QEMU on workload directory] **********************
2025-11-24 08:53:30.175399 | controller | Monday 24 November 2025  08:53:30 +0000 (0:00:00.541)       0:00:28.884 *******
2025-11-24 08:53:30.581014 | controller | changed: [instance] => (item=workload)
2025-11-24 08:53:30.581103 | controller | changed: [instance] => (item=volumes)
2025-11-24 08:53:30.581204 | controller |
2025-11-24 08:53:30.581331 | controller | TASK [libvirt_manager : Generate networking data] ******************************
2025-11-24 08:53:30.581447 | controller | Monday 24 November 2025  08:53:30 +0000 (0:00:00.406)       0:00:29.290 *******
2025-11-24 08:53:30.660612 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/generate_networking_data.yml for instance
2025-11-24 08:53:30.660724 | controller |
2025-11-24 08:53:30.660985 | controller | TASK [libvirt_manager : Ensure fact is existing, and empty] ********************
2025-11-24 08:53:30.678483 | controller | Monday 24 November 2025  08:53:30 +0000 (0:00:00.079)       0:00:29.370 *******
2025-11-24 08:53:30.678514 | controller | ok: [instance]
2025-11-24 08:53:30.678580 | controller |
2025-11-24 08:53:30.678709 | controller | TASK [libvirt_manager : Check if we get an existing interfaces-info.yml] *******
2025-11-24 08:53:30.678810 | controller | Monday 24 November 2025  08:53:30 +0000 (0:00:00.018)       0:00:29.388 *******
2025-11-24 08:53:30.868959 | controller | ok: [instance]
2025-11-24 08:53:30.869032 | controller |
2025-11-24 08:53:30.869141 | controller | TASK [libvirt_manager : Load file if exists] ***********************************
2025-11-24 08:53:30.869248 | controller | Monday 24 November 2025  08:53:30 +0000 (0:00:00.190)       0:00:29.578 *******
2025-11-24 08:53:30.896263 | controller | skipping: [instance]
2025-11-24 08:53:30.896374 | controller |
2025-11-24 08:53:30.896482 | controller | TASK [libvirt_manager : Update fact with existing content] *********************
2025-11-24 08:53:30.896591 | controller | Monday 24 November 2025  08:53:30 +0000 (0:00:00.027)       0:00:29.605 *******
2025-11-24 08:53:30.924079 | controller | skipping: [instance]
2025-11-24 08:53:30.924197 | controller |
2025-11-24 08:53:30.924358 | controller | TASK [libvirt_manager : Generate VM list] **************************************
2025-11-24 08:53:30.924503 | controller | Monday 24 November 2025  08:53:30 +0000 (0:00:00.027)       0:00:29.633 *******
2025-11-24 08:53:30.971928 | controller | ok: [instance]
2025-11-24 08:53:30.972029 | controller |
2025-11-24 08:53:30.972154 | controller | TASK [libvirt_manager : Generate/update mapping all nodes] *********************
2025-11-24 08:53:30.972287 | controller | Monday 24 November 2025  08:53:30 +0000 (0:00:00.047)       0:00:29.681 *******
2025-11-24 08:53:31.071635 | controller | ok: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
2025-11-24 08:53:31.071760 | controller | ok: [instance] => (item={'key': 'compute-1', 'value': 'compute'})
2025-11-24 08:53:31.071856 | controller |
2025-11-24 08:53:31.071958 | controller | TASK [libvirt_manager : Append baremetal nodes if needed] **********************
2025-11-24 08:53:31.072070 | controller | Monday 24 November 2025  08:53:31 +0000 (0:00:00.099)       0:00:29.781 *******
2025-11-24 08:53:31.104718 | controller | skipping: [instance]
2025-11-24 08:53:31.104808 | controller |
2025-11-24 08:53:31.104914 | controller | TASK [libvirt_manager : Dump MAC mapping] **************************************
2025-11-24 08:53:31.105016 | controller | Monday 24 November 2025  08:53:31 +0000 (0:00:00.033)       0:00:29.814 *******
2025-11-24 08:53:31.448151 | controller | changed: [instance]
2025-11-24 08:53:31.448204 | controller |
2025-11-24 08:53:31.448341 | controller | TASK [libvirt_manager : Inject all VMs in the inventory] ***********************
2025-11-24 08:53:31.448448 | controller | Monday 24 November 2025  08:53:31 +0000 (0:00:00.342)       0:00:30.157 *******
2025-11-24 08:53:31.540564 | controller | changed: [instance] => (item=Adding compute-0 to computes)
2025-11-24 08:53:31.540633 | controller | changed: [instance] => (item=Adding compute-1 to computes)
2025-11-24 08:53:31.540767 | controller |
2025-11-24 08:53:31.540872 | controller | TASK [networking_mapper : Check for Networking Definition file existence] ******
2025-11-24 08:53:31.540979 | controller | Monday 24 November 2025  08:53:31 +0000 (0:00:00.092)       0:00:30.250 *******
2025-11-24 08:53:31.568088 | controller | skipping: [instance]
2025-11-24 08:53:31.568183 | controller |
2025-11-24 08:53:31.568293 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2025-11-24 08:53:31.568556 | controller | Monday 24 November 2025  08:53:31 +0000 (0:00:00.027)       0:00:30.277 *******
2025-11-24 08:53:31.590337 | controller | skipping: [instance]
2025-11-24 08:53:31.590441 | controller |
2025-11-24 08:53:31.590548 | controller | TASK [networking_mapper : Check for interfaces info file existence] ************
2025-11-24 08:53:31.590662 | controller | Monday 24 November 2025  08:53:31 +0000 (0:00:00.022)       0:00:30.300 *******
2025-11-24 08:53:31.613321 | controller | skipping: [instance]
2025-11-24 08:53:31.613414 | controller |
2025-11-24 08:53:31.613515 | controller | TASK [networking_mapper : Load the interfaces info from file] ******************
2025-11-24 08:53:31.613615 | controller | Monday 24 November 2025  08:53:31 +0000 (0:00:00.022)       0:00:30.323 *******
2025-11-24 08:53:31.636442 | controller | skipping: [instance]
2025-11-24 08:53:31.636555 | controller |
2025-11-24 08:53:31.636679 | controller | TASK [networking_mapper : Ensure local fact is empty] **************************
2025-11-24 08:53:31.636800 | controller | Monday 24 November 2025  08:53:31 +0000 (0:00:00.023)       0:00:30.346 *******
2025-11-24 08:53:31.656741 | controller | ok: [instance]
2025-11-24 08:53:31.656833 | controller |
2025-11-24 08:53:31.656938 | controller | TASK [networking_mapper : Set the input Networking Definition and patch it if needed] ***
2025-11-24 08:53:31.657051 | controller | Monday 24 November 2025  08:53:31 +0000 (0:00:00.020)       0:00:30.366 *******
2025-11-24 08:53:31.725482 | 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': {}}}}})
2025-11-24 08:53:31.725694 | controller |
2025-11-24 08:53:31.725715 | controller | TASK [networking_mapper : Gather facts if requested] ***************************
2025-11-24 08:53:31.725857 | controller | Monday 24 November 2025  08:53:31 +0000 (0:00:00.068)       0:00:30.435 *******
2025-11-24 08:53:31.742721 | controller | skipping: [instance]
2025-11-24 08:53:31.742800 | controller |
2025-11-24 08:53:31.742923 | controller | TASK [networking_mapper : Ensure CI infrastructure dir exists] *****************
2025-11-24 08:53:31.743038 | controller | Monday 24 November 2025  08:53:31 +0000 (0:00:00.017)       0:00:30.452 *******
2025-11-24 08:53:31.945501 | controller | changed: [instance]
2025-11-24 08:53:31.945585 | controller |
2025-11-24 08:53:31.945721 | controller | TASK [networking_mapper : Write the Networking Definition to file] *************
2025-11-24 08:53:31.945824 | controller | Monday 24 November 2025  08:53:31 +0000 (0:00:00.202)       0:00:30.654 *******
2025-11-24 08:53:32.350332 | controller | changed: [instance]
2025-11-24 08:53:32.350375 | controller |
2025-11-24 08:53:32.350537 | controller | TASK [networking_mapper : Call the networking mapper] **************************
2025-11-24 08:53:32.350650 | controller | Monday 24 November 2025  08:53:32 +0000 (0:00:00.404)       0:00:31.059 *******
2025-11-24 08:53:32.400063 | controller | ok: [instance]
2025-11-24 08:53:32.400254 | controller |
2025-11-24 08:53:32.400267 | controller | TASK [networking_mapper : Set networking mapper facts] *************************
2025-11-24 08:53:32.400425 | controller | Monday 24 November 2025  08:53:32 +0000 (0:00:00.050)       0:00:31.109 *******
2025-11-24 08:53:32.421906 | controller | ok: [instance]
2025-11-24 08:53:32.422029 | controller |
2025-11-24 08:53:32.422178 | controller | TASK [networking_mapper : Write the Networking Environment Definition to file] ***
2025-11-24 08:53:32.422382 | controller | Monday 24 November 2025  08:53:32 +0000 (0:00:00.021)       0:00:31.131 *******
2025-11-24 08:53:32.804041 | controller | changed: [instance]
2025-11-24 08:53:32.804105 | controller |
2025-11-24 08:53:32.804213 | controller | TASK [libvirt_manager : Manage networks if needed] *****************************
2025-11-24 08:53:32.804337 | controller | Monday 24 November 2025  08:53:32 +0000 (0:00:00.382)       0:00:31.513 *******
2025-11-24 08:53:32.876780 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_networks.yml for instance
2025-11-24 08:53:32.876881 | controller |
2025-11-24 08:53:32.876997 | controller | TASK [libvirt_manager : Define the localized variables for performing the tasks here.] ***
2025-11-24 08:53:32.877102 | controller | Monday 24 November 2025  08:53:32 +0000 (0:00:00.072)       0:00:31.586 *******
2025-11-24 08:53:32.917320 | controller | ok: [instance] => (item=public)
2025-11-24 08:53:32.917391 | controller |
2025-11-24 08:53:32.917536 | controller | TASK [libvirt_manager : Ensure networks are defined] ***************************
2025-11-24 08:53:32.918231 | controller | Monday 24 November 2025  08:53:32 +0000 (0:00:00.040)       0:00:31.626 *******
2025-11-24 08:53:33.241518 | controller | changed: [instance] => (item=cifmw-public)
2025-11-24 08:53:33.241650 | controller |
2025-11-24 08:53:33.242056 | controller | TASK [libvirt_manager : Ensure networks are created/started] *******************
2025-11-24 08:53:33.547502 | controller | Monday 24 November 2025  08:53:33 +0000 (0:00:00.324)       0:00:31.950 *******
2025-11-24 08:53:33.547545 | controller | ok: [instance] => (item=cifmw-public)
2025-11-24 08:53:33.547574 | controller |
2025-11-24 08:53:33.547718 | controller | TASK [libvirt_manager : Ensure networks are active] ****************************
2025-11-24 08:53:33.547878 | controller | Monday 24 November 2025  08:53:33 +0000 (0:00:00.305)       0:00:32.256 *******
2025-11-24 08:53:33.772922 | controller | ok: [instance] => (item=cifmw-public)
2025-11-24 08:53:33.772997 | controller |
2025-11-24 08:53:33.773107 | controller | TASK [libvirt_manager : Ensure networks enabled to autostart] ******************
2025-11-24 08:53:33.773213 | controller | Monday 24 November 2025  08:53:33 +0000 (0:00:00.225)       0:00:32.482 *******
2025-11-24 08:53:34.001052 | controller | changed: [instance] => (item=cifmw-public)
2025-11-24 08:53:34.001329 | controller |
2025-11-24 08:53:34.001346 | controller | TASK [libvirt_manager : Add a dummy interface to bridges if required] **********
2025-11-24 08:53:34.001355 | controller | Monday 24 November 2025  08:53:33 +0000 (0:00:00.228)       0:00:32.710 *******
2025-11-24 08:53:34.058700 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_networks_dummy_interfaces.yml for instance
2025-11-24 08:53:34.058747 | controller |
2025-11-24 08:53:34.058830 | controller | TASK [libvirt_manager : Fetch present bridge interfaces] ***********************
2025-11-24 08:53:34.058931 | controller | Monday 24 November 2025  08:53:34 +0000 (0:00:00.057)       0:00:32.768 *******
2025-11-24 08:53:34.243252 | controller | ok: [instance]
2025-11-24 08:53:34.243369 | controller |
2025-11-24 08:53:34.243386 | controller | TASK [libvirt_manager : Fetch bridges ports link info] *************************
2025-11-24 08:53:34.243396 | controller | Monday 24 November 2025  08:53:34 +0000 (0:00:00.184)       0:00:32.952 *******
2025-11-24 08:53:34.454925 | controller | ok: [instance] => (item=cifmw-public)
2025-11-24 08:53:34.455421 | controller |
2025-11-24 08:53:34.524555 | controller | TASK [Create dummy interfaces to ensure bridges are UP] ************************
2025-11-24 08:53:34.524615 | controller | Monday 24 November 2025  08:53:34 +0000 (0:00:00.211)       0:00:33.164 *******
2025-11-24 08:53:34.524634 | controller |
2025-11-24 08:53:34.561086 | controller | TASK [ci_nmstate : Ensure we have needed facts] ********************************
2025-11-24 08:53:34.561125 | controller | Monday 24 November 2025  08:53:34 +0000 (0:00:00.069)       0:00:33.233 *******
2025-11-24 08:53:34.561140 | controller | skipping: [instance]
2025-11-24 08:53:34.561167 | controller |
2025-11-24 08:53:34.561177 | controller | TASK [ci_nmstate : Install required packages on instance] **********************
2025-11-24 08:53:34.561300 | controller | Monday 24 November 2025  08:53:34 +0000 (0:00:00.036)       0:00:33.270 *******
2025-11-24 08:53:39.451819 | controller | changed: [instance]
2025-11-24 08:53:39.451869 | controller |
2025-11-24 08:53:39.452012 | controller | TASK [ci_nmstate : Create the target NMstate dump directory] *******************
2025-11-24 08:53:39.452119 | controller | Monday 24 November 2025  08:53:39 +0000 (0:00:04.890)       0:00:38.161 *******
2025-11-24 08:53:39.645701 | controller | changed: [instance]
2025-11-24 08:53:39.646331 | controller |
2025-11-24 08:53:39.646355 | controller | TASK [ci_nmstate : Save nmstate state for instance] ****************************
2025-11-24 08:53:40.011789 | controller | Monday 24 November 2025  08:53:39 +0000 (0:00:00.193)       0:00:38.355 *******
2025-11-24 08:53:40.011832 | controller | changed: [instance]
2025-11-24 08:53:40.011855 | controller |
2025-11-24 08:53:40.011977 | controller | TASK [ci_nmstate : Apply the desidered state on instance] **********************
2025-11-24 08:53:40.012101 | controller | Monday 24 November 2025  08:53:40 +0000 (0:00:00.366)       0:00:38.721 *******
2025-11-24 08:53:41.912065 | controller | changed: [instance]
2025-11-24 08:53:41.912179 | controller |
2025-11-24 08:53:41.912314 | controller | TASK [ci_nmstate : Save nmstate debugging data for instance] *******************
2025-11-24 08:53:41.912437 | controller | Monday 24 November 2025  08:53:41 +0000 (0:00:01.900)       0:00:40.621 *******
2025-11-24 08:53:42.293565 | controller | changed: [instance]
2025-11-24 08:53:42.293635 | controller |
2025-11-24 08:53:42.293787 | controller | TASK [Create extra network configuration] **************************************
2025-11-24 08:53:42.293883 | controller | Monday 24 November 2025  08:53:42 +0000 (0:00:00.381)       0:00:41.002 *******
2025-11-24 08:53:42.326742 | controller | skipping: [instance]
2025-11-24 08:53:42.326845 | controller |
2025-11-24 08:53:42.326967 | controller | TASK [libvirt_manager : Ensure extra networks is in correct zone] **************
2025-11-24 08:53:42.327075 | controller | Monday 24 November 2025  08:53:42 +0000 (0:00:00.033)       0:00:41.036 *******
2025-11-24 08:53:42.355817 | controller | skipping: [instance]
2025-11-24 08:53:42.355903 | controller |
2025-11-24 08:53:42.356015 | controller | TASK [libvirt_manager : Refresh networking facts on host] **********************
2025-11-24 08:53:42.356124 | controller | Monday 24 November 2025  08:53:42 +0000 (0:00:00.029)       0:00:41.065 *******
2025-11-24 08:53:42.802008 | controller | ok: [instance]
2025-11-24 08:53:42.802158 | controller |
2025-11-24 08:53:42.802269 | controller | TASK [libvirt_manager : Build needed network/dnsmasq related content] **********
2025-11-24 08:53:42.802379 | controller | Monday 24 November 2025  08:53:42 +0000 (0:00:00.446)       0:00:41.511 *******
2025-11-24 08:53:42.933745 | controller | ok: [instance] => (item=cifmw-public)
2025-11-24 08:53:42.934059 | controller |
2025-11-24 08:53:44.185844 | controller | TASK [dnsmasq : Install needed packages] ***************************************
2025-11-24 08:53:44.185876 | controller | Monday 24 November 2025  08:53:42 +0000 (0:00:00.131)       0:00:41.643 *******
2025-11-24 08:53:44.185889 | controller | ok: [instance]
2025-11-24 08:53:48.005474 | controller |
2025-11-24 08:53:48.005514 | controller | TASK [dnsmasq : Ensure SELinux knows about the new files and directories] ******
2025-11-24 08:53:48.005522 | controller | Monday 24 November 2025  08:53:44 +0000 (0:00:01.251)       0:00:42.894 *******
2025-11-24 08:53:48.005533 | controller | changed: [instance] => (item={'target': '/etc/cifmw-dnsmasq.conf', 'setype': 'dnsmasq_etc_t'})
2025-11-24 08:53:48.005566 | controller | changed: [instance] => (item={'target': '/etc/cifmw-dnsmasq.d(/.*)?', 'setype': 'dnsmasq_etc_t'})
2025-11-24 08:53:48.006026 | controller | changed: [instance] => (item={'target': '/var/run/cifmw-dnsmasq.pid', 'setype': 'dnsmasq_var_run_t'})
2025-11-24 08:53:48.006065 | controller |
2025-11-24 08:53:48.228273 | controller | TASK [dnsmasq : Manage configuration directory] ********************************
2025-11-24 08:53:48.228335 | controller | Monday 24 November 2025  08:53:48 +0000 (0:00:03.819)       0:00:46.714 *******
2025-11-24 08:53:48.228351 | controller | changed: [instance]
2025-11-24 08:53:48.228481 | controller |
2025-11-24 08:53:48.228575 | controller | TASK [dnsmasq : Manage systemd unit file] **************************************
2025-11-24 08:53:48.228625 | controller | Monday 24 November 2025  08:53:48 +0000 (0:00:00.223)       0:00:46.937 *******
2025-11-24 08:53:48.609728 | controller | changed: [instance]
2025-11-24 08:53:48.609816 | controller |
2025-11-24 08:53:48.609834 | controller | TASK [dnsmasq : Manage base configuration file] ********************************
2025-11-24 08:53:48.609856 | controller | Monday 24 November 2025  08:53:48 +0000 (0:00:00.381)       0:00:47.318 *******
2025-11-24 08:53:49.007214 | controller | changed: [instance]
2025-11-24 08:53:49.037377 | controller |
2025-11-24 08:53:49.037412 | controller | TASK [dnsmasq : Render listener configuration] *********************************
2025-11-24 08:53:49.037421 | controller | Monday 24 November 2025  08:53:49 +0000 (0:00:00.397)       0:00:47.716 *******
2025-11-24 08:53:49.037433 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/listener.yml for instance
2025-11-24 08:53:49.037458 | controller |
2025-11-24 08:53:49.037467 | controller | TASK [dnsmasq : Create listener configuration file] ****************************
2025-11-24 08:53:49.037637 | controller | Monday 24 November 2025  08:53:49 +0000 (0:00:00.030)       0:00:47.746 *******
2025-11-24 08:53:49.434731 | controller | changed: [instance]
2025-11-24 08:53:49.434929 | controller |
2025-11-24 08:53:49.434949 | controller | TASK [dnsmasq : Remove listener configuration file] ****************************
2025-11-24 08:53:49.452436 | controller | Monday 24 November 2025  08:53:49 +0000 (0:00:00.397)       0:00:48.144 *******
2025-11-24 08:53:49.452499 | controller | skipping: [instance]
2025-11-24 08:53:49.452508 | controller |
2025-11-24 08:53:49.452519 | controller | TASK [dnsmasq : Render dns configuration] **************************************
2025-11-24 08:53:49.452527 | controller | Monday 24 November 2025  08:53:49 +0000 (0:00:00.017)       0:00:48.161 *******
2025-11-24 08:53:49.483859 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/dns.yml for instance
2025-11-24 08:53:49.870617 | controller |
2025-11-24 08:53:49.870655 | controller | TASK [dnsmasq : Create dns configuration file] *********************************
2025-11-24 08:53:49.870663 | controller | Monday 24 November 2025  08:53:49 +0000 (0:00:00.031)       0:00:48.193 *******
2025-11-24 08:53:49.870684 | controller | changed: [instance]
2025-11-24 08:53:49.870760 | controller |
2025-11-24 08:53:49.870812 | controller | TASK [dnsmasq : Remove dns configuration file] *********************************
2025-11-24 08:53:49.870913 | controller | Monday 24 November 2025  08:53:49 +0000 (0:00:00.386)       0:00:48.580 *******
2025-11-24 08:53:49.891259 | controller | skipping: [instance]
2025-11-24 08:53:50.110456 | controller |
2025-11-24 08:53:50.110488 | controller | TASK [dnsmasq : Add localhost addresses from defined dnsmasq listen addresses to loopback interface] ***
2025-11-24 08:53:50.110496 | controller | Monday 24 November 2025  08:53:49 +0000 (0:00:00.020)       0:00:48.600 *******
2025-11-24 08:53:50.110507 | controller | ok: [instance] => (item=127.0.0.2)
2025-11-24 08:53:50.850621 | controller |
2025-11-24 08:53:50.850653 | controller | TASK [dnsmasq : Enable and start service] **************************************
2025-11-24 08:53:50.850661 | controller | Monday 24 November 2025  08:53:50 +0000 (0:00:00.217)       0:00:48.818 *******
2025-11-24 08:53:50.850672 | controller | changed: [instance]
2025-11-24 08:53:50.870864 | controller |
2025-11-24 08:53:50.870898 | controller | TASK [dnsmasq : Stop service] **************************************************
2025-11-24 08:53:50.870906 | controller | Monday 24 November 2025  08:53:50 +0000 (0:00:00.741)       0:00:49.559 *******
2025-11-24 08:53:50.870916 | controller | skipping: [instance]
2025-11-24 08:53:50.891882 | controller |
2025-11-24 08:53:50.891914 | controller | TASK [dnsmasq : Remove unit file] **********************************************
2025-11-24 08:53:50.891922 | controller | Monday 24 November 2025  08:53:50 +0000 (0:00:00.020)       0:00:49.579 *******
2025-11-24 08:53:50.891932 | controller | skipping: [instance]
2025-11-24 08:53:50.922477 | controller |
2025-11-24 08:53:50.922521 | controller | TASK [dnsmasq : Remove main configuration files] *******************************
2025-11-24 08:53:50.922529 | controller | Monday 24 November 2025  08:53:50 +0000 (0:00:00.020)       0:00:49.600 *******
2025-11-24 08:53:50.922539 | controller | skipping: [instance] => (item=/etc/cifmw-dnsmasq.conf)
2025-11-24 08:53:50.924443 | controller | skipping: [instance] => (item=/etc/cifmw-dnsmasq.d)
2025-11-24 08:53:50.924464 | controller | skipping: [instance]
2025-11-24 08:53:50.999415 | controller |
2025-11-24 08:53:50.999454 | controller | TASK [Create dnsmasq networks] *************************************************
2025-11-24 08:53:50.999463 | controller | Monday 24 November 2025  08:53:50 +0000 (0:00:00.030)       0:00:49.631 *******
2025-11-24 08:53:50.999474 | controller |
2025-11-24 08:53:50.999543 | controller | TASK [dnsmasq : Assert mandatory parameter] ************************************
2025-11-24 08:53:50.999585 | controller | Monday 24 November 2025  08:53:50 +0000 (0:00:00.077)       0:00:49.708 *******
2025-11-24 08:53:51.029692 | controller | ok: [instance] => changed=false
2025-11-24 08:53:51.029774 | controller |   msg: All assertions passed
2025-11-24 08:53:51.029885 | controller |
2025-11-24 08:53:51.030001 | controller | TASK [dnsmasq : Assert mandatory parameters for new network] *******************
2025-11-24 08:53:51.030693 | controller | Monday 24 November 2025  08:53:51 +0000 (0:00:00.030)       0:00:49.739 *******
2025-11-24 08:53:51.068132 | controller | ok: [instance] => changed=false
2025-11-24 08:53:51.068286 | controller |   msg: All assertions passed
2025-11-24 08:53:51.068437 | controller |
2025-11-24 08:53:51.068595 | controller | TASK [dnsmasq : Create network] ************************************************
2025-11-24 08:53:51.068753 | controller | Monday 24 November 2025  08:53:51 +0000 (0:00:00.038)       0:00:49.777 *******
2025-11-24 08:53:51.547001 | controller | changed: [instance]
2025-11-24 08:53:51.564837 | controller |
2025-11-24 08:53:51.564863 | controller | TASK [dnsmasq : Remove network] ************************************************
2025-11-24 08:53:51.564879 | controller | Monday 24 November 2025  08:53:51 +0000 (0:00:00.478)       0:00:50.255 *******
2025-11-24 08:53:51.564890 | controller | skipping: [instance]
2025-11-24 08:53:51.564923 | controller |
2025-11-24 08:53:51.564932 | controller | TASK [dnsmasq : Remove dhcp host files] ****************************************
2025-11-24 08:53:51.565062 | controller | Monday 24 November 2025  08:53:51 +0000 (0:00:00.018)       0:00:50.274 *******
2025-11-24 08:53:51.589614 | controller | skipping: [instance]
2025-11-24 08:53:51.589714 | controller |
2025-11-24 08:53:51.589843 | controller | TASK [Deploy radvd for IPv6 router advertisements] *****************************
2025-11-24 08:53:51.589962 | controller | Monday 24 November 2025  08:53:51 +0000 (0:00:00.024)       0:00:50.299 *******
2025-11-24 08:53:51.620483 | controller | skipping: [instance]
2025-11-24 08:53:51.620576 | controller |
2025-11-24 08:53:51.620724 | controller | TASK [libvirt_manager : Ensure network is in correct zone] *********************
2025-11-24 08:53:51.620829 | controller | Monday 24 November 2025  08:53:51 +0000 (0:00:00.030)       0:00:50.330 *******
2025-11-24 08:53:51.946748 | controller | changed: [instance] => (item=cifmw-public)
2025-11-24 08:53:51.946838 | controller |
2025-11-24 08:53:51.946961 | controller | TASK [libvirt_manager : Extract IP address from network bridges] ***************
2025-11-24 08:53:51.946983 | controller | Monday 24 November 2025  08:53:51 +0000 (0:00:00.325)       0:00:50.655 *******
2025-11-24 08:53:51.976157 | 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)
2025-11-24 08:53:51.976210 | controller |
2025-11-24 08:53:51.976330 | controller | TASK [libvirt_manager : Extract IP address from network bridges] ***************
2025-11-24 08:53:51.976469 | controller | Monday 24 November 2025  08:53:51 +0000 (0:00:00.029)       0:00:50.685 *******
2025-11-24 08:53:52.280157 | controller | ok: [instance]
2025-11-24 08:53:52.280214 | controller |
2025-11-24 08:53:52.280354 | controller | TASK [libvirt_manager : Set network_bridge_info fact with network and address] ***
2025-11-24 08:53:52.280462 | controller | Monday 24 November 2025  08:53:52 +0000 (0:00:00.303)       0:00:50.989 *******
2025-11-24 08:53:52.315211 | controller | ok: [instance]
2025-11-24 08:53:52.315436 | controller |
2025-11-24 08:53:52.315558 | controller | TASK [libvirt_manager : Output _network_data] **********************************
2025-11-24 08:53:52.315692 | controller | Monday 24 November 2025  08:53:52 +0000 (0:00:00.035)       0:00:51.024 *******
2025-11-24 08:53:52.678010 | controller | changed: [instance]
2025-11-24 08:53:52.678159 | controller |
2025-11-24 08:53:52.678270 | controller | TASK [libvirt_manager : Output pub_net] ****************************************
2025-11-24 08:53:52.678410 | controller | Monday 24 November 2025  08:53:52 +0000 (0:00:00.362)       0:00:51.387 *******
2025-11-24 08:53:53.027357 | controller | changed: [instance]
2025-11-24 08:53:53.027421 | controller |
2025-11-24 08:53:53.027543 | controller | TASK [libvirt_manager : Output _cifmw_libvirt_manager_layout] ******************
2025-11-24 08:53:53.027679 | controller | Monday 24 November 2025  08:53:53 +0000 (0:00:00.349)       0:00:51.736 *******
2025-11-24 08:53:53.377747 | controller | changed: [instance]
2025-11-24 08:53:53.377966 | controller |
2025-11-24 08:53:53.378003 | controller | TASK [libvirt_manager : Expose patch for networking_mapper] ********************
2025-11-24 08:53:53.378031 | controller | Monday 24 November 2025  08:53:53 +0000 (0:00:00.349)       0:00:52.086 *******
2025-11-24 08:53:53.475444 | controller | ok: [instance]
2025-11-24 08:53:53.821724 | controller |
2025-11-24 08:53:53.821763 | controller | TASK [libvirt_manager : Save networking_mapper patch] **************************
2025-11-24 08:53:53.821772 | controller | Monday 24 November 2025  08:53:53 +0000 (0:00:00.097)       0:00:52.184 *******
2025-11-24 08:53:53.821782 | controller | changed: [instance]
2025-11-24 08:53:53.821809 | controller |
2025-11-24 08:53:53.821817 | controller | TASK [networking_mapper : Check for Networking Definition file existence] ******
2025-11-24 08:53:53.821945 | controller | Monday 24 November 2025  08:53:53 +0000 (0:00:00.346)       0:00:52.531 *******
2025-11-24 08:53:53.845145 | controller | skipping: [instance]
2025-11-24 08:53:53.845174 | controller |
2025-11-24 08:53:53.845184 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2025-11-24 08:53:53.845193 | controller | Monday 24 November 2025  08:53:53 +0000 (0:00:00.023)       0:00:52.554 *******
2025-11-24 08:53:53.868748 | controller | skipping: [instance]
2025-11-24 08:53:53.868862 | controller |
2025-11-24 08:53:53.868909 | controller | TASK [networking_mapper : Check for interfaces info file existence] ************
2025-11-24 08:53:53.869023 | controller | Monday 24 November 2025  08:53:53 +0000 (0:00:00.023)       0:00:52.578 *******
2025-11-24 08:53:53.894444 | controller | skipping: [instance]
2025-11-24 08:53:53.894510 | controller |
2025-11-24 08:53:53.894530 | controller | TASK [networking_mapper : Load the interfaces info from file] ******************
2025-11-24 08:53:53.894541 | controller | Monday 24 November 2025  08:53:53 +0000 (0:00:00.025)       0:00:52.603 *******
2025-11-24 08:53:53.918921 | controller | skipping: [instance]
2025-11-24 08:53:53.918952 | controller |
2025-11-24 08:53:53.918964 | controller | TASK [networking_mapper : Ensure local fact is empty] **************************
2025-11-24 08:53:53.918992 | controller | Monday 24 November 2025  08:53:53 +0000 (0:00:00.024)       0:00:52.628 *******
2025-11-24 08:53:53.938000 | controller | ok: [instance]
2025-11-24 08:53:53.938039 | controller |
2025-11-24 08:53:53.938294 | controller | TASK [networking_mapper : Set the input Networking Definition and patch it if needed] ***
2025-11-24 08:53:54.015560 | controller | Monday 24 November 2025  08:53:53 +0000 (0:00:00.019)       0:00:52.647 *******
2025-11-24 08:53:54.015589 | 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': {}}}}})
2025-11-24 08:53:54.033391 | controller | ok: [instance] => (item={'networks': {'public': {'network-v4': '192.168.100.0/24'}}, 'group-templates': {'computes': {'networks': {'public': None}}}})
2025-11-24 08:53:54.033423 | controller |
2025-11-24 08:53:54.033431 | controller | TASK [networking_mapper : Gather facts if requested] ***************************
2025-11-24 08:53:54.033438 | controller | Monday 24 November 2025  08:53:54 +0000 (0:00:00.077)       0:00:52.724 *******
2025-11-24 08:53:54.033448 | controller | skipping: [instance]
2025-11-24 08:53:54.033472 | controller |
2025-11-24 08:53:54.033480 | controller | TASK [networking_mapper : Ensure CI infrastructure dir exists] *****************
2025-11-24 08:53:54.033619 | controller | Monday 24 November 2025  08:53:54 +0000 (0:00:00.018)       0:00:52.743 *******
2025-11-24 08:53:54.243598 | controller | ok: [instance]
2025-11-24 08:53:54.648287 | controller |
2025-11-24 08:53:54.648333 | controller | TASK [networking_mapper : Write the Networking Definition to file] *************
2025-11-24 08:53:54.648342 | controller | Monday 24 November 2025  08:53:54 +0000 (0:00:00.209)       0:00:52.952 *******
2025-11-24 08:53:54.648352 | controller | changed: [instance]
2025-11-24 08:53:54.648390 | controller |
2025-11-24 08:53:54.648397 | controller | TASK [networking_mapper : Call the networking mapper] **************************
2025-11-24 08:53:54.648405 | controller | Monday 24 November 2025  08:53:54 +0000 (0:00:00.404)       0:00:53.357 *******
2025-11-24 08:53:54.701379 | controller | ok: [instance]
2025-11-24 08:53:54.701507 | controller |
2025-11-24 08:53:54.701549 | controller | TASK [networking_mapper : Set networking mapper facts] *************************
2025-11-24 08:53:54.701562 | controller | Monday 24 November 2025  08:53:54 +0000 (0:00:00.053)       0:00:53.410 *******
2025-11-24 08:53:54.724706 | controller | ok: [instance]
2025-11-24 08:53:54.724779 | controller |
2025-11-24 08:53:54.724794 | controller | TASK [networking_mapper : Write the Networking Environment Definition to file] ***
2025-11-24 08:53:54.724906 | controller | Monday 24 November 2025  08:53:54 +0000 (0:00:00.023)       0:00:53.434 *******
2025-11-24 08:53:55.144518 | controller | changed: [instance]
2025-11-24 08:53:55.144579 | controller |
2025-11-24 08:53:55.144717 | controller | TASK [libvirt_manager : Be sure to save current state of networking_mapper environment] ***
2025-11-24 08:53:55.144814 | controller | Monday 24 November 2025  08:53:55 +0000 (0:00:00.419)       0:00:53.853 *******
2025-11-24 08:53:55.167421 | controller | ok: [instance]
2025-11-24 08:53:55.167532 | controller |
2025-11-24 08:53:55.167674 | controller | TASK [libvirt_manager : Unset patch] *******************************************
2025-11-24 08:53:55.167811 | controller | Monday 24 November 2025  08:53:55 +0000 (0:00:00.023)       0:00:53.877 *******
2025-11-24 08:53:55.185648 | controller | ok: [instance]
2025-11-24 08:53:55.185755 | controller |
2025-11-24 08:53:55.185880 | controller | TASK [libvirt_manager : Initialize empty _lm_dhcp_entries fact] ****************
2025-11-24 08:53:55.186005 | controller | Monday 24 November 2025  08:53:55 +0000 (0:00:00.018)       0:00:53.895 *******
2025-11-24 08:53:55.204056 | controller | ok: [instance]
2025-11-24 08:53:55.204134 | controller |
2025-11-24 08:53:55.204266 | controller | TASK [libvirt_manager : Reserve IPs on networks] *******************************
2025-11-24 08:53:55.204404 | controller | Monday 24 November 2025  08:53:55 +0000 (0:00:00.018)       0:00:53.913 *******
2025-11-24 08:53:55.241662 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/reserve_dnsmasq_ips.yml for instance => (item=ctlplane)
2025-11-24 08:53:55.241798 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/reserve_dnsmasq_ips.yml for instance => (item=public)
2025-11-24 08:53:55.241934 | controller |
2025-11-24 08:53:55.242046 | controller | TASK [libvirt_manager : Loop on host IPs] **************************************
2025-11-24 08:53:55.242164 | controller | Monday 24 November 2025  08:53:55 +0000 (0:00:00.037)       0:00:53.951 *******
2025-11-24 08:53:55.307913 | controller | skipping: [instance] => (item=compute-0 - ctlplane)
2025-11-24 08:53:55.308039 | controller | skipping: [instance] => (item=compute-1 - ctlplane)
2025-11-24 08:53:55.308161 | controller | skipping: [instance]
2025-11-24 08:53:55.308269 | controller |
2025-11-24 08:53:55.308411 | controller | TASK [libvirt_manager : Loop on host IPs] **************************************
2025-11-24 08:53:55.308534 | controller | Monday 24 November 2025  08:53:55 +0000 (0:00:00.066)       0:00:54.017 *******
2025-11-24 08:53:55.410204 | controller | ok: [instance] => (item=compute-0 - public)
2025-11-24 08:53:55.410336 | controller | ok: [instance] => (item=compute-1 - public)
2025-11-24 08:53:55.410448 | controller |
2025-11-24 08:53:55.410555 | controller | TASK [Inject DHCP entries for net {{ net_name }}] ******************************
2025-11-24 08:53:55.410661 | controller | Monday 24 November 2025  08:53:55 +0000 (0:00:00.102)       0:00:54.119 *******
2025-11-24 08:53:55.464029 | controller |
2025-11-24 08:53:55.464157 | controller | TASK [dnsmasq : Ensure we have the right data and type] ************************
2025-11-24 08:53:55.464311 | controller | Monday 24 November 2025  08:53:55 +0000 (0:00:00.053)       0:00:54.173 *******
2025-11-24 08:53:55.500154 | controller | ok: [instance]
2025-11-24 08:53:55.500267 | controller |
2025-11-24 08:53:55.500408 | controller | TASK [dnsmasq : Assert we have needed host data] *******************************
2025-11-24 08:53:55.500528 | controller | Monday 24 November 2025  08:53:55 +0000 (0:00:00.036)       0:00:54.209 *******
2025-11-24 08:53:55.553586 | controller | ok: [instance] => (item={'network': 'public', 'name': 'compute-0', 'state': 'present', 'mac': '52:54:00:d8:2a:65', 'ips': ['192.168.100.10', ''], 'tag': 'compute'})
2025-11-24 08:53:55.553757 | controller | ok: [instance] => (item={'network': 'public', 'name': 'compute-1', 'state': 'present', 'mac': '52:54:01:91:42:66', 'ips': ['192.168.100.11', ''], 'tag': 'compute'})
2025-11-24 08:53:55.553874 | controller |
2025-11-24 08:53:55.553993 | controller | TASK [dnsmasq : Ensure networks exists] ****************************************
2025-11-24 08:53:55.554106 | controller | Monday 24 November 2025  08:53:55 +0000 (0:00:00.053)       0:00:54.263 *******
2025-11-24 08:53:55.597108 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/_check_net_status.yml for instance => (item=public)
2025-11-24 08:53:55.597228 | controller |
2025-11-24 08:53:55.597363 | controller | TASK [dnsmasq : Check network file status] *************************************
2025-11-24 08:53:55.597461 | controller | Monday 24 November 2025  08:53:55 +0000 (0:00:00.043)       0:00:54.306 *******
2025-11-24 08:53:55.777502 | controller | ok: [instance]
2025-11-24 08:53:55.777618 | controller |
2025-11-24 08:53:55.777746 | controller | TASK [dnsmasq : Assert network exists] *****************************************
2025-11-24 08:53:55.777865 | controller | Monday 24 November 2025  08:53:55 +0000 (0:00:00.180)       0:00:54.486 *******
2025-11-24 08:53:55.800643 | controller | ok: [instance]
2025-11-24 08:53:55.800746 | controller |
2025-11-24 08:53:55.800988 | controller | TASK [dnsmasq : Initialize empty dhcp_host_entries] ****************************
2025-11-24 08:53:55.801108 | controller | Monday 24 November 2025  08:53:55 +0000 (0:00:00.023)       0:00:54.510 *******
2025-11-24 08:53:55.820252 | controller | ok: [instance]
2025-11-24 08:53:55.820307 | controller |
2025-11-24 08:53:55.820446 | controller | TASK [dnsmasq : Compute entry] *************************************************
2025-11-24 08:53:55.820545 | controller | Monday 24 November 2025  08:53:55 +0000 (0:00:00.019)       0:00:54.529 *******
2025-11-24 08:53:55.948807 | controller | ok: [instance] => (item={'network': 'public', 'name': 'compute-0', 'state': 'present', 'mac': '52:54:00:d8:2a:65', 'ips': ['192.168.100.10', ''], 'tag': 'compute'})
2025-11-24 08:53:55.948893 | controller | ok: [instance] => (item={'network': 'public', 'name': 'compute-1', 'state': 'present', 'mac': '52:54:01:91:42:66', 'ips': ['192.168.100.11', ''], 'tag': 'compute'})
2025-11-24 08:53:55.948992 | controller |
2025-11-24 08:53:55.949097 | controller | TASK [dnsmasq : Create add/remove sets] ****************************************
2025-11-24 08:53:55.949183 | controller | Monday 24 November 2025  08:53:55 +0000 (0:00:00.128)       0:00:54.658 *******
2025-11-24 08:53:55.988292 | controller | ok: [instance]
2025-11-24 08:53:55.988389 | controller |
2025-11-24 08:53:55.988503 | controller | TASK [dnsmasq : Add DHCP entries] **********************************************
2025-11-24 08:53:55.988884 | controller | Monday 24 November 2025  08:53:55 +0000 (0:00:00.039)       0:00:54.697 *******
2025-11-24 08:53:56.729584 | controller | changed: [instance] => (item={'file': 'public_compute-0_52:54:00:d8:2a:65', 'entry': 'set:compute,52:54:00:d8:2a:65,192.168.100.10,compute-0', 'state': 'present'})
2025-11-24 08:53:56.729725 | controller | changed: [instance] => (item={'file': 'public_compute-1_52:54:01:91:42:66', 'entry': 'set:compute,52:54:01:91:42:66,192.168.100.11,compute-1', 'state': 'present'})
2025-11-24 08:53:56.729824 | controller |
2025-11-24 08:53:56.729934 | controller | TASK [dnsmasq : Remove DHCP entries] *******************************************
2025-11-24 08:53:56.730035 | controller | Monday 24 November 2025  08:53:56 +0000 (0:00:00.741)       0:00:55.438 *******
2025-11-24 08:53:56.753147 | controller | skipping: [instance]
2025-11-24 08:53:56.753259 | controller |
2025-11-24 08:53:56.753415 | controller | TASK [libvirt_manager : Create per-network and .utility DNS entries] ***********
2025-11-24 08:53:56.753546 | controller | Monday 24 November 2025  08:53:56 +0000 (0:00:00.023)       0:00:55.462 *******
2025-11-24 08:53:56.882435 | controller | ok: [instance] => (item=compute-0)
2025-11-24 08:53:56.882528 | controller | ok: [instance] => (item=compute-1)
2025-11-24 08:53:56.882650 | controller |
2025-11-24 08:53:56.882773 | controller | TASK [Inject VMs in the .utility zone] *****************************************
2025-11-24 08:53:56.882873 | controller | Monday 24 November 2025  08:53:56 +0000 (0:00:00.129)       0:00:55.591 *******
2025-11-24 08:53:56.972341 | controller |
2025-11-24 08:53:56.972472 | controller | TASK [dnsmasq : Assert we have needed host record data] ************************
2025-11-24 08:53:56.972592 | controller | Monday 24 November 2025  08:53:56 +0000 (0:00:00.090)       0:00:55.681 *******
2025-11-24 08:53:57.012575 | controller | ok: [instance]
2025-11-24 08:53:57.012682 | controller |
2025-11-24 08:53:57.012789 | controller | TASK [dnsmasq : Assert each address element have needed data] ******************
2025-11-24 08:53:57.012891 | controller | Monday 24 November 2025  08:53:57 +0000 (0:00:00.040)       0:00:55.722 *******
2025-11-24 08:53:57.112429 | controller | ok: [instance] => (item={'names': ['compute-0.utility', 'compute-0.instance', 'compute-0.utility', 'compute-0.instance'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
2025-11-24 08:53:57.112530 | controller | ok: [instance] => (item={'names': ['compute-0.ctlplane.local', 'compute-0.ctlplane.local'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
2025-11-24 08:53:57.112666 | controller | ok: [instance] => (item={'names': ['compute-0.public.local', 'compute-0.public.local'], 'ips': ['192.168.100.10', ''], 'state': 'present'})
2025-11-24 08:53:57.112784 | controller | ok: [instance] => (item={'names': ['compute-1.utility', 'compute-1.instance', 'compute-1.utility', 'compute-1.instance'], 'ips': ['192.168.122.11', ''], 'state': 'present'})
2025-11-24 08:53:57.112900 | controller | ok: [instance] => (item={'names': ['compute-1.ctlplane.local', 'compute-1.ctlplane.local'], 'ips': ['192.168.122.11', ''], 'state': 'present'})
2025-11-24 08:53:57.112994 | controller | ok: [instance] => (item={'names': ['compute-1.public.local', 'compute-1.public.local'], 'ips': ['192.168.100.11', ''], 'state': 'present'})
2025-11-24 08:53:57.113086 | controller |
2025-11-24 08:53:57.113188 | controller | TASK [dnsmasq : Add/Remove address] ********************************************
2025-11-24 08:53:57.113279 | controller | Monday 24 November 2025  08:53:57 +0000 (0:00:00.099)       0:00:55.822 *******
2025-11-24 08:53:58.451345 | controller | changed: [instance] => (item={'names': ['compute-0.utility', 'compute-0.instance', 'compute-0.utility', 'compute-0.instance'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
2025-11-24 08:53:58.451574 | controller | changed: [instance] => (item={'names': ['compute-0.ctlplane.local', 'compute-0.ctlplane.local'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
2025-11-24 08:53:58.451646 | controller | changed: [instance] => (item={'names': ['compute-0.public.local', 'compute-0.public.local'], 'ips': ['192.168.100.10', ''], 'state': 'present'})
2025-11-24 08:53:58.451662 | controller | changed: [instance] => (item={'names': ['compute-1.utility', 'compute-1.instance', 'compute-1.utility', 'compute-1.instance'], 'ips': ['192.168.122.11', ''], 'state': 'present'})
2025-11-24 08:53:58.452195 | controller | changed: [instance] => (item={'names': ['compute-1.ctlplane.local', 'compute-1.ctlplane.local'], 'ips': ['192.168.122.11', ''], 'state': 'present'})
2025-11-24 08:53:58.471644 | controller | changed: [instance] => (item={'names': ['compute-1.public.local', 'compute-1.public.local'], 'ips': ['192.168.100.11', ''], 'state': 'present'})
2025-11-24 08:53:58.471668 | controller |
2025-11-24 08:53:58.471676 | controller | TASK [libvirt_manager : Initialize empty _lm_dhcp_options fact] ****************
2025-11-24 08:53:58.471683 | controller | Monday 24 November 2025  08:53:58 +0000 (0:00:01.338)       0:00:57.160 *******
2025-11-24 08:53:58.471700 | controller | ok: [instance]
2025-11-24 08:53:58.471755 | controller |
2025-11-24 08:53:58.471766 | controller | TASK [libvirt_manager : Collect DHCP options from VM definitions] **************
2025-11-24 08:53:58.471864 | controller | Monday 24 November 2025  08:53:58 +0000 (0:00:00.020)       0:00:57.181 *******
2025-11-24 08:53:58.509919 | controller | skipping: [instance] => (item=compute)
2025-11-24 08:53:58.510066 | controller | skipping: [instance]
2025-11-24 08:53:58.510185 | controller |
2025-11-24 08:53:58.510320 | controller | TASK [libvirt_manager : Generate DHCP option configuration for VM types] *******
2025-11-24 08:53:58.510469 | controller | Monday 24 November 2025  08:53:58 +0000 (0:00:00.038)       0:00:57.219 *******
2025-11-24 08:53:58.544219 | controller | skipping: [instance]
2025-11-24 08:53:58.544313 | controller |
2025-11-24 08:53:58.544447 | controller | TASK [libvirt_manager : Ensure some domains are local] *************************
2025-11-24 08:53:58.544552 | controller | Monday 24 November 2025  08:53:58 +0000 (0:00:00.034)       0:00:57.253 *******
2025-11-24 08:53:58.942284 | controller | changed: [instance]
2025-11-24 08:53:58.942345 | controller |
2025-11-24 08:53:58.942467 | controller | TASK [libvirt_manager : Ensure dnsmasq is reloaded now] ************************
2025-11-24 08:53:58.942581 | controller | Monday 24 November 2025  08:53:58 +0000 (0:00:00.386)       0:00:57.640 *******
2025-11-24 08:53:58.942718 | controller |
2025-11-24 08:53:58.942807 | controller | RUNNING HANDLER [libvirt_manager : Restart firewalld] **************************
2025-11-24 08:53:58.942900 | controller | Monday 24 November 2025  08:53:58 +0000 (0:00:00.010)       0:00:57.651 *******
2025-11-24 08:53:59.801056 | controller | changed: [instance]
2025-11-24 08:53:59.801148 | controller |
2025-11-24 08:53:59.801268 | controller | RUNNING HANDLER [dnsmasq : Restart dnsmasq] ************************************
2025-11-24 08:53:59.801399 | controller | Monday 24 November 2025  08:53:59 +0000 (0:00:00.858)       0:00:58.510 *******
2025-11-24 08:54:01.163688 | controller | changed: [instance]
2025-11-24 08:54:01.163946 | controller |
2025-11-24 08:54:01.163967 | controller | RUNNING HANDLER [dnsmasq : Reload dnsmasq] *************************************
2025-11-24 08:54:01.163977 | controller | Monday 24 November 2025  08:54:01 +0000 (0:00:01.362)       0:00:59.872 *******
2025-11-24 08:54:01.524396 | controller | changed: [instance]
2025-11-24 08:54:01.524630 | controller |
2025-11-24 08:54:01.524677 | controller | TASK [libvirt_manager : Create group inventories] ******************************
2025-11-24 08:54:01.942693 | controller | Monday 24 November 2025  08:54:01 +0000 (0:00:00.360)       0:01:00.233 *******
2025-11-24 08:54:01.942750 | controller | changed: [instance] => (item=compute)
2025-11-24 08:54:01.942807 | controller |
2025-11-24 08:54:01.942839 | controller | TASK [libvirt_manager : Create "all" group inventory file] *********************
2025-11-24 08:54:01.942851 | controller | Monday 24 November 2025  08:54:01 +0000 (0:00:00.418)       0:01:00.651 *******
2025-11-24 08:54:02.369285 | controller | changed: [instance]
2025-11-24 08:54:02.408026 | controller |
2025-11-24 08:54:02.408060 | controller | TASK [libvirt_manager : Ensure storage pool is present.] ***********************
2025-11-24 08:54:02.408069 | controller | Monday 24 November 2025  08:54:02 +0000 (0:00:00.426)       0:01:01.078 *******
2025-11-24 08:54:02.408078 | controller | skipping: [instance]
2025-11-24 08:54:02.487844 | controller |
2025-11-24 08:54:02.487885 | controller | TASK [libvirt_manager : Ensure images are present] *****************************
2025-11-24 08:54:02.487894 | controller | Monday 24 November 2025  08:54:02 +0000 (0:00:00.039)       0:01:01.117 *******
2025-11-24 08:54:02.487904 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/get_image.yml for instance => (item=compute)
2025-11-24 08:54:02.509066 | controller |
2025-11-24 08:54:02.509092 | controller | TASK [libvirt_manager : Ensure directory exists] *******************************
2025-11-24 08:54:02.509102 | controller | Monday 24 November 2025  08:54:02 +0000 (0:00:00.079)       0:01:01.196 *******
2025-11-24 08:54:02.509114 | controller | skipping: [instance]
2025-11-24 08:54:02.528107 | controller |
2025-11-24 08:54:02.528153 | controller | TASK [libvirt_manager : Check if base image exists] ****************************
2025-11-24 08:54:02.528162 | controller | Monday 24 November 2025  08:54:02 +0000 (0:00:00.021)       0:01:01.218 *******
2025-11-24 08:54:02.528174 | controller | skipping: [instance]
2025-11-24 08:54:02.528239 | controller |
2025-11-24 08:54:02.528263 | controller | TASK [libvirt_manager : Download base image] ***********************************
2025-11-24 08:54:02.548242 | controller | Monday 24 November 2025  08:54:02 +0000 (0:00:00.019)       0:01:01.237 *******
2025-11-24 08:54:02.548281 | controller | skipping: [instance]
2025-11-24 08:54:02.548303 | controller |
2025-11-24 08:54:02.548490 | controller | TASK [libvirt_manager : Check image] *******************************************
2025-11-24 08:54:02.548517 | controller | Monday 24 November 2025  08:54:02 +0000 (0:00:00.020)       0:01:01.257 *******
2025-11-24 08:54:02.567920 | controller | skipping: [instance]
2025-11-24 08:54:02.568108 | controller |
2025-11-24 08:54:02.568279 | controller | TASK [libvirt_manager : Assert image status] ***********************************
2025-11-24 08:54:02.568469 | controller | Monday 24 November 2025  08:54:02 +0000 (0:00:00.019)       0:01:01.277 *******
2025-11-24 08:54:02.587515 | controller | skipping: [instance]
2025-11-24 08:54:02.587736 | controller |
2025-11-24 08:54:02.587921 | controller | TASK [libvirt_manager : Ensure image access rights] ****************************
2025-11-24 08:54:02.588087 | controller | Monday 24 November 2025  08:54:02 +0000 (0:00:00.019)       0:01:01.297 *******
2025-11-24 08:54:02.606960 | controller | skipping: [instance]
2025-11-24 08:54:02.607144 | controller |
2025-11-24 08:54:02.607318 | controller | TASK [libvirt_manager : Get ssh key state] *************************************
2025-11-24 08:54:02.607514 | controller | Monday 24 November 2025  08:54:02 +0000 (0:00:00.019)       0:01:01.316 *******
2025-11-24 08:54:02.790719 | controller | ok: [instance]
2025-11-24 08:54:03.233523 | controller |
2025-11-24 08:54:03.233569 | controller | TASK [libvirt_manager : Create temporary ssh keypair] **************************
2025-11-24 08:54:03.233578 | controller | Monday 24 November 2025  08:54:02 +0000 (0:00:00.182)       0:01:01.499 *******
2025-11-24 08:54:03.233590 | controller | changed: [instance]
2025-11-24 08:54:03.233624 | controller |
2025-11-24 08:54:03.233635 | controller | TASK [libvirt_manager : Slurp public key for later use] ************************
2025-11-24 08:54:03.233644 | controller | Monday 24 November 2025  08:54:03 +0000 (0:00:00.443)       0:01:01.942 *******
2025-11-24 08:54:03.536266 | controller | ok: [instance]
2025-11-24 08:54:03.537089 | controller |
2025-11-24 08:54:03.729181 | controller | TASK [libvirt_manager : Slurp private key for later use] ***********************
2025-11-24 08:54:03.729232 | controller | Monday 24 November 2025  08:54:03 +0000 (0:00:00.302)       0:01:02.245 *******
2025-11-24 08:54:03.729251 | controller | ok: [instance]
2025-11-24 08:54:03.729415 | controller |
2025-11-24 08:54:03.729708 | controller | TASK [libvirt_manager : Inject cifmw_reproducer_key.pub in hypervisor authorized_keys] ***
2025-11-24 08:54:03.729723 | controller | Monday 24 November 2025  08:54:03 +0000 (0:00:00.192)       0:01:02.438 *******
2025-11-24 08:54:04.153772 | controller | changed: [instance]
2025-11-24 08:54:04.153838 | controller |
2025-11-24 08:54:04.153971 | controller | TASK [libvirt_manager : Create fact holding network data for VMs] **************
2025-11-24 08:54:04.154075 | controller | Monday 24 November 2025  08:54:04 +0000 (0:00:00.423)       0:01:02.862 *******
2025-11-24 08:54:04.174503 | controller | ok: [instance]
2025-11-24 08:54:04.174584 | controller |
2025-11-24 08:54:04.174718 | controller | TASK [libvirt_manager : List existing networks] ********************************
2025-11-24 08:54:04.174836 | controller | Monday 24 November 2025  08:54:04 +0000 (0:00:00.021)       0:01:02.884 *******
2025-11-24 08:54:04.413537 | controller | ok: [instance]
2025-11-24 08:54:04.413615 | controller |
2025-11-24 08:54:04.413734 | controller | TASK [libvirt_manager : Gather pool fact] **************************************
2025-11-24 08:54:04.413844 | controller | Monday 24 November 2025  08:54:04 +0000 (0:00:00.238)       0:01:03.122 *******
2025-11-24 08:54:04.771100 | controller | ok: [instance]
2025-11-24 08:54:04.771432 | controller |
2025-11-24 08:54:04.856948 | controller | TASK [libvirt_manager : Create and run VMs] ************************************
2025-11-24 08:54:04.857003 | controller | Monday 24 November 2025  08:54:04 +0000 (0:00:00.357)       0:01:03.480 *******
2025-11-24 08:54:04.857020 | 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'})
2025-11-24 08:54:04.857202 | 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'})
2025-11-24 08:54:04.857230 | controller |
2025-11-24 08:54:04.857306 | controller | TASK [libvirt_manager : Create VM image for compute-0] *************************
2025-11-24 08:54:04.857473 | controller | Monday 24 November 2025  08:54:04 +0000 (0:00:00.085)       0:01:03.566 *******
2025-11-24 08:54:05.118499 | controller | changed: [instance]
2025-11-24 08:54:05.118614 | controller |
2025-11-24 08:54:05.118762 | controller | TASK [libvirt_manager : Ensure file ownership and rights for compute-0] ********
2025-11-24 08:54:05.118883 | controller | Monday 24 November 2025  08:54:05 +0000 (0:00:00.261)       0:01:03.827 *******
2025-11-24 08:54:05.350254 | controller | changed: [instance]
2025-11-24 08:54:05.350332 | controller |
2025-11-24 08:54:05.350465 | controller | TASK [libvirt_manager : Define VMs for type compute-0] *************************
2025-11-24 08:54:05.350570 | controller | Monday 24 November 2025  08:54:05 +0000 (0:00:00.231)       0:01:04.059 *******
2025-11-24 08:54:05.753451 | controller | changed: [instance]
2025-11-24 08:54:05.753518 | controller |
2025-11-24 08:54:05.753626 | controller | TASK [libvirt_manager : Attach listed networks to the VMs compute-0] ***********
2025-11-24 08:54:05.753739 | controller | Monday 24 November 2025  08:54:05 +0000 (0:00:00.403)       0:01:04.462 *******
2025-11-24 08:54:05.779861 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/net_to_vms.yml for instance
2025-11-24 08:54:05.779923 | controller |
2025-11-24 08:54:05.780168 | controller | TASK [libvirt_manager : Attach {{ vm_item }} to {{ net_item }}] ****************
2025-11-24 08:54:05.813878 | controller | Monday 24 November 2025  08:54:05 +0000 (0:00:00.026)       0:01:04.489 *******
2025-11-24 08:54:05.813925 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/attach_interface.yml for instance => (item=public)
2025-11-24 08:54:05.813937 | controller |
2025-11-24 08:54:05.814205 | controller | TASK [libvirt_manager : Get virtual network information] ***********************
2025-11-24 08:54:06.065965 | controller | Monday 24 November 2025  08:54:05 +0000 (0:00:00.033)       0:01:04.523 *******
2025-11-24 08:54:06.066000 | controller | ok: [instance]
2025-11-24 08:54:06.116622 | controller |
2025-11-24 08:54:06.116645 | controller | TASK [libvirt_manager : Create network to bridge mapping] **********************
2025-11-24 08:54:06.116653 | controller | Monday 24 November 2025  08:54:06 +0000 (0:00:00.251)       0:01:04.775 *******
2025-11-24 08:54:06.116663 | controller | ok: [instance] => (item=crc)
2025-11-24 08:54:06.352862 | controller | ok: [instance] => (item=cifmw-public)
2025-11-24 08:54:06.352894 | controller | ok: [instance] => (item=default)
2025-11-24 08:54:06.352902 | controller |
2025-11-24 08:54:06.352909 | controller | TASK [libvirt_manager : Dump domain xml] ***************************************
2025-11-24 08:54:06.352915 | controller | Monday 24 November 2025  08:54:06 +0000 (0:00:00.050)       0:01:04.825 *******
2025-11-24 08:54:06.352930 | controller | ok: [instance]
2025-11-24 08:54:06.569520 | controller |
2025-11-24 08:54:06.569559 | controller | TASK [libvirt_manager : Extract networks from XML] *****************************
2025-11-24 08:54:06.569568 | controller | Monday 24 November 2025  08:54:06 +0000 (0:00:00.236)       0:01:05.061 *******
2025-11-24 08:54:06.569579 | controller | ok: [instance]
2025-11-24 08:54:06.569616 | controller |
2025-11-24 08:54:06.569630 | controller | TASK [libvirt_manager : Attach interface public on cifmw-compute-0] ************
2025-11-24 08:54:06.569766 | controller | Monday 24 November 2025  08:54:06 +0000 (0:00:00.216)       0:01:05.278 *******
2025-11-24 08:54:06.872576 | controller | changed: [instance]
2025-11-24 08:54:06.872641 | controller |
2025-11-24 08:54:06.872793 | controller | TASK [libvirt_manager : Attach spines/leafs networks to the VMs compute-0] *****
2025-11-24 08:54:06.872901 | controller | Monday 24 November 2025  08:54:06 +0000 (0:00:00.303)       0:01:05.581 *******
2025-11-24 08:54:06.892955 | controller | skipping: [instance]
2025-11-24 08:54:06.893053 | controller |
2025-11-24 08:54:06.893163 | controller | TASK [libvirt_manager : Create the requested extra disks for compute-0] ********
2025-11-24 08:54:06.893273 | controller | Monday 24 November 2025  08:54:06 +0000 (0:00:00.020)       0:01:05.602 *******
2025-11-24 08:54:06.920306 | controller | skipping: [instance]
2025-11-24 08:54:06.920403 | controller |
2025-11-24 08:54:06.920525 | controller | TASK [libvirt_manager : Find volume attachments for VM compute-0] **************
2025-11-24 08:54:06.920624 | controller | Monday 24 November 2025  08:54:06 +0000 (0:00:00.027)       0:01:05.629 *******
2025-11-24 08:54:06.946627 | controller | skipping: [instance]
2025-11-24 08:54:06.946726 | controller |
2025-11-24 08:54:06.946845 | controller | TASK [libvirt_manager : Attach volumes for VM compute-0] ***********************
2025-11-24 08:54:06.946972 | controller | Monday 24 November 2025  08:54:06 +0000 (0:00:00.026)       0:01:05.656 *******
2025-11-24 08:54:06.971786 | controller | skipping: [instance]
2025-11-24 08:54:06.971882 | controller |
2025-11-24 08:54:06.971996 | controller | TASK [libvirt_manager : Get VM UUID] *******************************************
2025-11-24 08:54:06.972088 | controller | Monday 24 November 2025  08:54:06 +0000 (0:00:00.025)       0:01:05.681 *******
2025-11-24 08:54:07.205475 | controller | changed: [instance]
2025-11-24 08:54:07.205585 | controller |
2025-11-24 08:54:07.205734 | controller | TASK [libvirt_manager : Inject UUID in dataset] ********************************
2025-11-24 08:54:07.205839 | controller | Monday 24 November 2025  08:54:07 +0000 (0:00:00.233)       0:01:05.914 *******
2025-11-24 08:54:07.242164 | controller | ok: [instance]
2025-11-24 08:54:07.242260 | controller |
2025-11-24 08:54:07.242432 | controller | TASK [libvirt_manager : Create cloud-init ISO] *********************************
2025-11-24 08:54:07.242617 | controller | Monday 24 November 2025  08:54:07 +0000 (0:00:00.037)       0:01:05.951 *******
2025-11-24 08:54:07.262306 | controller | skipping: [instance]
2025-11-24 08:54:07.262415 | controller |
2025-11-24 08:54:07.262542 | controller | TASK [libvirt_manager : Attach cloud-init ISO if exists] ***********************
2025-11-24 08:54:07.262689 | controller | Monday 24 November 2025  08:54:07 +0000 (0:00:00.020)       0:01:05.971 *******
2025-11-24 08:54:07.282752 | controller | skipping: [instance]
2025-11-24 08:54:07.282863 | controller |
2025-11-24 08:54:07.282986 | controller | TASK [libvirt_manager : Attach additional devices if specified] ****************
2025-11-24 08:54:07.283121 | controller | Monday 24 November 2025  08:54:07 +0000 (0:00:00.020)       0:01:05.992 *******
2025-11-24 08:54:07.327798 | controller | skipping: [instance]
2025-11-24 08:54:07.327892 | controller |
2025-11-24 08:54:07.327987 | controller | TASK [libvirt_manager : Configure boot order for compute-0] ********************
2025-11-24 08:54:07.328092 | controller | Monday 24 November 2025  08:54:07 +0000 (0:00:00.044)       0:01:06.037 *******
2025-11-24 08:54:07.354735 | controller | skipping: [instance]
2025-11-24 08:54:07.354812 | controller |
2025-11-24 08:54:07.354825 | controller | TASK [libvirt_manager : Create VM image for compute-1] *************************
2025-11-24 08:54:07.354955 | controller | Monday 24 November 2025  08:54:07 +0000 (0:00:00.026)       0:01:06.064 *******
2025-11-24 08:54:07.607777 | controller | changed: [instance]
2025-11-24 08:54:07.607838 | controller |
2025-11-24 08:54:07.607955 | controller | TASK [libvirt_manager : Ensure file ownership and rights for compute-1] ********
2025-11-24 08:54:07.608055 | controller | Monday 24 November 2025  08:54:07 +0000 (0:00:00.252)       0:01:06.317 *******
2025-11-24 08:54:07.836380 | controller | changed: [instance]
2025-11-24 08:54:07.836744 | controller |
2025-11-24 08:54:08.131671 | controller | TASK [libvirt_manager : Define VMs for type compute-1] *************************
2025-11-24 08:54:08.131704 | controller | Monday 24 November 2025  08:54:07 +0000 (0:00:00.228)       0:01:06.545 *******
2025-11-24 08:54:08.131716 | controller | changed: [instance]
2025-11-24 08:54:08.131744 | controller |
2025-11-24 08:54:08.132014 | controller | TASK [libvirt_manager : Attach listed networks to the VMs compute-1] ***********
2025-11-24 08:54:08.158441 | controller | Monday 24 November 2025  08:54:08 +0000 (0:00:00.295)       0:01:06.841 *******
2025-11-24 08:54:08.158477 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/net_to_vms.yml for instance
2025-11-24 08:54:08.158506 | controller |
2025-11-24 08:54:08.158678 | controller | TASK [libvirt_manager : Attach {{ vm_item }} to {{ net_item }}] ****************
2025-11-24 08:54:08.158807 | controller | Monday 24 November 2025  08:54:08 +0000 (0:00:00.026)       0:01:06.867 *******
2025-11-24 08:54:08.192474 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/attach_interface.yml for instance => (item=public)
2025-11-24 08:54:08.437059 | controller |
2025-11-24 08:54:08.437108 | controller | TASK [libvirt_manager : Get virtual network information] ***********************
2025-11-24 08:54:08.437117 | controller | Monday 24 November 2025  08:54:08 +0000 (0:00:00.033)       0:01:06.901 *******
2025-11-24 08:54:08.437128 | controller | ok: [instance]
2025-11-24 08:54:08.485381 | controller |
2025-11-24 08:54:08.485419 | controller | TASK [libvirt_manager : Create network to bridge mapping] **********************
2025-11-24 08:54:08.485428 | controller | Monday 24 November 2025  08:54:08 +0000 (0:00:00.244)       0:01:07.146 *******
2025-11-24 08:54:08.485439 | controller | ok: [instance] => (item=crc)
2025-11-24 08:54:08.485542 | controller | ok: [instance] => (item=cifmw-public)
2025-11-24 08:54:08.485559 | controller | ok: [instance] => (item=default)
2025-11-24 08:54:08.485569 | controller |
2025-11-24 08:54:08.485576 | controller | TASK [libvirt_manager : Dump domain xml] ***************************************
2025-11-24 08:54:08.485583 | controller | Monday 24 November 2025  08:54:08 +0000 (0:00:00.048)       0:01:07.194 *******
2025-11-24 08:54:08.714745 | controller | ok: [instance]
2025-11-24 08:54:08.714839 | controller |
2025-11-24 08:54:08.714950 | controller | TASK [libvirt_manager : Extract networks from XML] *****************************
2025-11-24 08:54:08.715052 | controller | Monday 24 November 2025  08:54:08 +0000 (0:00:00.229)       0:01:07.424 *******
2025-11-24 08:54:08.932261 | controller | ok: [instance]
2025-11-24 08:54:08.932369 | controller |
2025-11-24 08:54:08.932488 | controller | TASK [libvirt_manager : Attach interface public on cifmw-compute-1] ************
2025-11-24 08:54:08.932610 | controller | Monday 24 November 2025  08:54:08 +0000 (0:00:00.217)       0:01:07.641 *******
2025-11-24 08:54:10.228530 | controller | changed: [instance]
2025-11-24 08:54:10.228616 | controller |
2025-11-24 08:54:10.228742 | controller | TASK [libvirt_manager : Attach spines/leafs networks to the VMs compute-1] *****
2025-11-24 08:54:10.228839 | controller | Monday 24 November 2025  08:54:10 +0000 (0:00:01.296)       0:01:08.937 *******
2025-11-24 08:54:10.249149 | controller | skipping: [instance]
2025-11-24 08:54:10.249242 | controller |
2025-11-24 08:54:10.249368 | controller | TASK [libvirt_manager : Create the requested extra disks for compute-1] ********
2025-11-24 08:54:10.249479 | controller | Monday 24 November 2025  08:54:10 +0000 (0:00:00.020)       0:01:08.958 *******
2025-11-24 08:54:10.275397 | controller | skipping: [instance]
2025-11-24 08:54:10.275583 | controller |
2025-11-24 08:54:10.275716 | controller | TASK [libvirt_manager : Find volume attachments for VM compute-1] **************
2025-11-24 08:54:10.275813 | controller | Monday 24 November 2025  08:54:10 +0000 (0:00:00.026)       0:01:08.985 *******
2025-11-24 08:54:10.302857 | controller | skipping: [instance]
2025-11-24 08:54:10.302949 | controller |
2025-11-24 08:54:10.303057 | controller | TASK [libvirt_manager : Attach volumes for VM compute-1] ***********************
2025-11-24 08:54:10.303168 | controller | Monday 24 November 2025  08:54:10 +0000 (0:00:00.027)       0:01:09.012 *******
2025-11-24 08:54:10.328873 | controller | skipping: [instance]
2025-11-24 08:54:10.328974 | controller |
2025-11-24 08:54:10.329101 | controller | TASK [libvirt_manager : Get VM UUID] *******************************************
2025-11-24 08:54:10.329220 | controller | Monday 24 November 2025  08:54:10 +0000 (0:00:00.025)       0:01:09.038 *******
2025-11-24 08:54:10.549287 | controller | changed: [instance]
2025-11-24 08:54:10.549423 | controller |
2025-11-24 08:54:10.549436 | controller | TASK [libvirt_manager : Inject UUID in dataset] ********************************
2025-11-24 08:54:10.549654 | controller | Monday 24 November 2025  08:54:10 +0000 (0:00:00.219)       0:01:09.258 *******
2025-11-24 08:54:10.585477 | controller | ok: [instance]
2025-11-24 08:54:10.585565 | controller |
2025-11-24 08:54:10.585690 | controller | TASK [libvirt_manager : Create cloud-init ISO] *********************************
2025-11-24 08:54:10.585799 | controller | Monday 24 November 2025  08:54:10 +0000 (0:00:00.036)       0:01:09.295 *******
2025-11-24 08:54:10.606759 | controller | skipping: [instance]
2025-11-24 08:54:10.606840 | controller |
2025-11-24 08:54:10.606950 | controller | TASK [libvirt_manager : Attach cloud-init ISO if exists] ***********************
2025-11-24 08:54:10.607067 | controller | Monday 24 November 2025  08:54:10 +0000 (0:00:00.021)       0:01:09.316 *******
2025-11-24 08:54:10.627220 | controller | skipping: [instance]
2025-11-24 08:54:10.627320 | controller |
2025-11-24 08:54:10.627462 | controller | TASK [libvirt_manager : Attach additional devices if specified] ****************
2025-11-24 08:54:10.627618 | controller | Monday 24 November 2025  08:54:10 +0000 (0:00:00.020)       0:01:09.336 *******
2025-11-24 08:54:10.671475 | controller | skipping: [instance]
2025-11-24 08:54:10.671578 | controller |
2025-11-24 08:54:10.671710 | controller | TASK [libvirt_manager : Configure boot order for compute-1] ********************
2025-11-24 08:54:10.671818 | controller | Monday 24 November 2025  08:54:10 +0000 (0:00:00.044)       0:01:09.381 *******
2025-11-24 08:54:10.696630 | controller | skipping: [instance]
2025-11-24 08:54:10.696739 | controller |
2025-11-24 08:54:10.696844 | controller | TASK [libvirt_manager : Start (power-on) VMs] **********************************
2025-11-24 08:54:10.696943 | controller | Monday 24 November 2025  08:54:10 +0000 (0:00:00.025)       0:01:09.406 *******
2025-11-24 08:54:10.737077 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/start_vms.yml for instance
2025-11-24 08:54:10.737526 | controller |
2025-11-24 08:54:10.991729 | controller | TASK [libvirt_manager : Refresh oooq_pool before starting VMs] *****************
2025-11-24 08:54:10.991765 | controller | Monday 24 November 2025  08:54:10 +0000 (0:00:00.040)       0:01:09.446 *******
2025-11-24 08:54:10.991779 | controller | ok: [instance] => (item=crc)
2025-11-24 08:54:10.991822 | controller |
2025-11-24 08:54:10.991924 | controller | TASK [libvirt_manager : Start VMs for type {{ vm_type }}] **********************
2025-11-24 08:54:10.992024 | controller | Monday 24 November 2025  08:54:10 +0000 (0:00:00.254)       0:01:09.701 *******
2025-11-24 08:54:12.040224 | controller | skipping: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
2025-11-24 08:54:12.040369 | controller | skipping: [instance] => (item={'key': 'compute-1', 'value': 'compute'})
2025-11-24 08:54:12.040543 | controller | skipping: [instance]
2025-11-24 08:54:12.040710 | controller |
2025-11-24 08:54:12.040856 | controller | TASK [libvirt_manager : Wait for SSH on started VMs] ***************************
2025-11-24 08:54:12.040989 | controller | Monday 24 November 2025  08:54:12 +0000 (0:00:01.047)       0:01:10.749 *******
2025-11-24 08:54:12.098987 | controller | skipping: [instance] => (item=compute-0.utility)
2025-11-24 08:54:12.099084 | controller | skipping: [instance] => (item=compute-1.utility)
2025-11-24 08:54:12.099265 | controller | skipping: [instance]
2025-11-24 08:54:12.099383 | controller |
2025-11-24 08:54:12.099398 | controller | TASK [libvirt_manager : Ensure we get SSH on nodes] ****************************
2025-11-24 08:54:12.099490 | controller | Monday 24 November 2025  08:54:12 +0000 (0:00:00.059)       0:01:10.808 *******
2025-11-24 08:54:12.132547 | 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'})
2025-11-24 08:54:12.132661 | 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'})
2025-11-24 08:54:12.132790 | controller | skipping: [instance]
2025-11-24 08:54:12.132882 | controller |
2025-11-24 08:54:12.132981 | controller | TASK [libvirt_manager : Configure managed VMs] *********************************
2025-11-24 08:54:12.133070 | controller | Monday 24 November 2025  08:54:12 +0000 (0:00:00.032)       0:01:10.841 *******
2025-11-24 08:54:12.179615 | controller | skipping: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
2025-11-24 08:54:12.179734 | controller | skipping: [instance] => (item={'key': 'compute-1', 'value': 'compute'})
2025-11-24 08:54:12.179853 | controller | skipping: [instance]
2025-11-24 08:54:12.179957 | controller |
2025-11-24 08:54:12.180071 | controller | TASK [Create VBMC entity] ******************************************************
2025-11-24 08:54:12.180175 | controller | Monday 24 November 2025  08:54:12 +0000 (0:00:00.047)       0:01:10.888 *******
2025-11-24 08:54:12.223469 | controller | skipping: [instance] => (item=compute-0)
2025-11-24 08:54:12.223624 | controller | skipping: [instance] => (item=compute-1)
2025-11-24 08:54:12.223794 | controller | skipping: [instance]
2025-11-24 08:54:12.223925 | controller |
2025-11-24 08:54:12.224023 | controller | TASK [libvirt_manager : List running virtual machines.] ************************
2025-11-24 08:54:12.224158 | controller | Monday 24 November 2025  08:54:12 +0000 (0:00:00.044)       0:01:10.933 *******
2025-11-24 08:54:12.497802 | controller | ok: [instance]
2025-11-24 08:54:12.497863 | controller |
2025-11-24 08:54:12.497987 | controller | TASK [libvirt_manager : Dump UUIDs] ********************************************
2025-11-24 08:54:12.498109 | controller | Monday 24 November 2025  08:54:12 +0000 (0:00:00.273)       0:01:11.207 *******
2025-11-24 08:54:12.865978 | controller | changed: [instance]
2025-11-24 08:54:12.866289 | controller |
2025-11-24 08:54:12.866488 | controller | TASK [Ensure fresh vbmc listing] ***********************************************
2025-11-24 08:54:12.866506 | controller | Monday 24 November 2025  08:54:12 +0000 (0:00:00.368)       0:01:11.575 *******
2025-11-24 08:54:12.900950 | controller | skipping: [instance]
2025-11-24 08:54:12.901343 | controller |
2025-11-24 08:54:12.935218 | controller | TASK [libvirt_manager : Update vbmc related fact] ******************************
2025-11-24 08:54:12.935242 | controller | Monday 24 November 2025  08:54:12 +0000 (0:00:00.035)       0:01:11.610 *******
2025-11-24 08:54:12.935254 | controller | skipping: [instance]
2025-11-24 08:54:12.935330 | controller |
2025-11-24 08:54:12.935493 | controller | TASK [libvirt_manager : Dump vbmc known hosts] *********************************
2025-11-24 08:54:12.935629 | controller | Monday 24 November 2025  08:54:12 +0000 (0:00:00.034)       0:01:11.644 *******
2025-11-24 08:54:12.968565 | controller | skipping: [instance]
2025-11-24 08:54:12.968681 | controller |
2025-11-24 08:54:12.968814 | controller | TASK [libvirt_manager : Copy authorized_keys] **********************************
2025-11-24 08:54:12.968935 | controller | Monday 24 November 2025  08:54:12 +0000 (0:00:00.033)       0:01:11.678 *******
2025-11-24 08:54:12.996686 | controller | skipping: [instance]
2025-11-24 08:54:12.996790 | controller |
2025-11-24 08:54:12.996909 | controller | TASK [libvirt_manager : Enable root access on CRC] *****************************
2025-11-24 08:54:12.997001 | controller | Monday 24 November 2025  08:54:12 +0000 (0:00:00.028)       0:01:11.706 *******
2025-11-24 08:54:13.027430 | controller | skipping: [instance]
2025-11-24 08:54:13.027556 | controller |
2025-11-24 08:54:13.027712 | controller | TASK [Generate baremetal-info fact] ********************************************
2025-11-24 08:54:13.027832 | controller | Monday 24 November 2025  08:54:13 +0000 (0:00:00.030)       0:01:11.737 *******
2025-11-24 08:54:13.100950 | controller |
2025-11-24 08:54:13.101070 | controller | TASK [reproducer : Ensure directories exist] ***********************************
2025-11-24 08:54:13.101215 | controller | Monday 24 November 2025  08:54:13 +0000 (0:00:00.073)       0:01:11.810 *******
2025-11-24 08:54:13.534075 | controller | changed: [instance] => (item=parameters)
2025-11-24 08:54:13.570395 | controller | ok: [instance] => (item=artifacts)
2025-11-24 08:54:13.570429 | controller |
2025-11-24 08:54:13.570438 | controller | TASK [reproducer : Convert VBMC list into a dict for better usage] *************
2025-11-24 08:54:13.570444 | controller | Monday 24 November 2025  08:54:13 +0000 (0:00:00.431)       0:01:12.242 *******
2025-11-24 08:54:13.570463 | controller | skipping: [instance]
2025-11-24 08:54:13.570520 | controller |
2025-11-24 08:54:13.570682 | controller | TASK [reproducer : Check if baremetal-info.yml exists] *************************
2025-11-24 08:54:13.570804 | controller | Monday 24 November 2025  08:54:13 +0000 (0:00:00.037)       0:01:12.279 *******
2025-11-24 08:54:13.777439 | controller | ok: [instance]
2025-11-24 08:54:13.777532 | controller |
2025-11-24 08:54:13.777675 | controller | TASK [reproducer : Get content of baremetal-info file] *************************
2025-11-24 08:54:13.777784 | controller | Monday 24 November 2025  08:54:13 +0000 (0:00:00.206)       0:01:12.486 *******
2025-11-24 08:54:13.798901 | controller | skipping: [instance]
2025-11-24 08:54:13.798960 | controller |
2025-11-24 08:54:13.799085 | controller | TASK [reproducer : Interpret remote file content as yaml] **********************
2025-11-24 08:54:13.799697 | controller | Monday 24 November 2025  08:54:13 +0000 (0:00:00.021)       0:01:12.508 *******
2025-11-24 08:54:13.838870 | controller | skipping: [instance]
2025-11-24 08:54:13.838979 | controller |
2025-11-24 08:54:13.839012 | controller | TASK [reproducer : Slurp content of: /home/zuul/ci-framework-data/artifacts/interfaces-info.yml] ***
2025-11-24 08:54:13.839166 | controller | Monday 24 November 2025  08:54:13 +0000 (0:00:00.039)       0:01:12.548 *******
2025-11-24 08:54:13.871121 | controller | skipping: [instance]
2025-11-24 08:54:13.871209 | controller |
2025-11-24 08:54:13.871328 | controller | TASK [reproducer : Set cifmw_libvirt_manager_mac_map fact from /home/zuul/ci-framework-data/artifacts/interfaces-info.yml] ***
2025-11-24 08:54:13.871458 | controller | Monday 24 November 2025  08:54:13 +0000 (0:00:00.032)       0:01:12.580 *******
2025-11-24 08:54:13.898182 | controller | skipping: [instance]
2025-11-24 08:54:13.898298 | controller |
2025-11-24 08:54:13.898466 | controller | TASK [reproducer : Generate libvirt_manager_bm_info_data fact] *****************
2025-11-24 08:54:13.898592 | controller | Monday 24 November 2025  08:54:13 +0000 (0:00:00.027)       0:01:12.607 *******
2025-11-24 08:54:13.966890 | controller | ok: [instance] => (item={'key': 'cifmw-compute-0', 'value': '6ba068ec-ffb7-445c-a563-2e6434f9aa53'})
2025-11-24 08:54:13.966958 | controller | ok: [instance] => (item={'key': 'cifmw-compute-1', 'value': 'bbbfb155-4553-4120-b0a8-a179c7fb525f'})
2025-11-24 08:54:13.967072 | controller |
2025-11-24 08:54:13.967191 | controller | TASK [reproducer : Output baremetal info file] *********************************
2025-11-24 08:54:13.967288 | controller | Monday 24 November 2025  08:54:13 +0000 (0:00:00.068)       0:01:12.676 *******
2025-11-24 08:54:14.315793 | controller | changed: [instance]
2025-11-24 08:54:14.315853 | controller |
2025-11-24 08:54:14.315945 | controller | TASK [reproducer : Output ironic_nodes to file] ********************************
2025-11-24 08:54:14.316041 | controller | Monday 24 November 2025  08:54:14 +0000 (0:00:00.348)       0:01:13.025 *******
2025-11-24 08:54:14.341064 | controller | skipping: [instance]
2025-11-24 08:54:14.341152 | controller |
2025-11-24 08:54:14.341264 | controller | TASK [Run Sushy Emulator role against OCP] *************************************
2025-11-24 08:54:14.342073 | controller | Monday 24 November 2025  08:54:14 +0000 (0:00:00.025)       0:01:13.050 *******
2025-11-24 08:54:14.416333 | controller |
2025-11-24 08:54:14.416492 | controller | TASK [sushy_emulator : Create Sushy Emulator resource directory] ***************
2025-11-24 08:54:14.620570 | controller | Monday 24 November 2025  08:54:14 +0000 (0:00:00.075)       0:01:13.125 *******
2025-11-24 08:54:14.620751 | controller | changed: [instance]
2025-11-24 08:54:14.620808 | controller |
2025-11-24 08:54:14.620818 | controller | TASK [sushy_emulator : Install required packages] ******************************
2025-11-24 08:54:14.620828 | controller | Monday 24 November 2025  08:54:14 +0000 (0:00:00.203)       0:01:13.329 *******
2025-11-24 08:54:18.350176 | controller | changed: [instance]
2025-11-24 08:54:18.350290 | controller |
2025-11-24 08:54:18.350408 | controller | TASK [sushy_emulator : Get ingresses domain] ***********************************
2025-11-24 08:54:18.350427 | controller | Monday 24 November 2025  08:54:18 +0000 (0:00:03.729)       0:01:17.059 *******
2025-11-24 08:54:18.997442 | controller | changed: [instance]
2025-11-24 08:54:18.997553 | controller |
2025-11-24 08:54:18.997596 | controller | TASK [sushy_emulator : Set sushy url for ocp installation] *********************
2025-11-24 08:54:18.997726 | controller | Monday 24 November 2025  08:54:18 +0000 (0:00:00.646)       0:01:17.706 *******
2025-11-24 08:54:19.021528 | controller | ok: [instance]
2025-11-24 08:54:19.021578 | controller |
2025-11-24 08:54:19.021743 | controller | TASK [sushy_emulator : Create ssh key for Sushy Emulator] **********************
2025-11-24 08:54:19.021851 | controller | Monday 24 November 2025  08:54:19 +0000 (0:00:00.024)       0:01:17.731 *******
2025-11-24 08:54:19.302350 | controller | changed: [instance]
2025-11-24 08:54:19.302409 | controller |
2025-11-24 08:54:19.302538 | controller | TASK [sushy_emulator : Slurp private ssh key for later use] ********************
2025-11-24 08:54:19.302672 | controller | Monday 24 November 2025  08:54:19 +0000 (0:00:00.280)       0:01:18.011 *******
2025-11-24 08:54:19.492548 | controller | ok: [instance]
2025-11-24 08:54:19.492970 | controller |
2025-11-24 08:54:20.719792 | controller | TASK [sushy_emulator : Allow Sushy Emulator key] *******************************
2025-11-24 08:54:20.719903 | controller | Monday 24 November 2025  08:54:19 +0000 (0:00:00.190)       0:01:18.201 *******
2025-11-24 08:54:20.719924 | controller | changed: [instance -> controller-0(192.168.26.172)]
2025-11-24 08:54:20.989927 | controller |
2025-11-24 08:54:20.989965 | controller | TASK [sushy_emulator : Run ssh-keyscan] ****************************************
2025-11-24 08:54:20.989973 | controller | Monday 24 November 2025  08:54:20 +0000 (0:00:01.226)       0:01:19.428 *******
2025-11-24 08:54:20.989986 | controller | changed: [instance]
2025-11-24 08:54:21.347186 | controller |
2025-11-24 08:54:21.347221 | controller | TASK [sushy_emulator : Write known hosts for later use] ************************
2025-11-24 08:54:21.347230 | controller | Monday 24 November 2025  08:54:20 +0000 (0:00:00.270)       0:01:19.698 *******
2025-11-24 08:54:21.347242 | controller | changed: [instance]
2025-11-24 08:54:21.347272 | controller |
2025-11-24 08:54:21.380294 | controller | TASK [sushy_emulator : Ensure file exists: /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
2025-11-24 08:54:21.380330 | controller | Monday 24 November 2025  08:54:21 +0000 (0:00:00.357)       0:01:20.056 *******
2025-11-24 08:54:21.380343 | controller | skipping: [instance]
2025-11-24 08:54:21.406667 | controller |
2025-11-24 08:54:21.406723 | controller | TASK [sushy_emulator : Slurp content of: /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
2025-11-24 08:54:21.406732 | controller | Monday 24 November 2025  08:54:21 +0000 (0:00:00.033)       0:01:20.089 *******
2025-11-24 08:54:21.406746 | controller | skipping: [instance]
2025-11-24 08:54:21.406830 | controller |
2025-11-24 08:54:21.406850 | controller | TASK [sushy_emulator : Set cifmw_libvirt_manager_uuids fact from /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
2025-11-24 08:54:21.406860 | controller | Monday 24 November 2025  08:54:21 +0000 (0:00:00.026)       0:01:20.115 *******
2025-11-24 08:54:21.429669 | controller | skipping: [instance]
2025-11-24 08:54:21.429837 | controller |
2025-11-24 08:54:21.430027 | controller | TASK [sushy_emulator : Generate list of filtered VMs] **************************
2025-11-24 08:54:21.430044 | controller | Monday 24 November 2025  08:54:21 +0000 (0:00:00.023)       0:01:20.139 *******
2025-11-24 08:54:21.470365 | controller | ok: [instance]
2025-11-24 08:54:21.470401 | controller |
2025-11-24 08:54:21.470412 | controller | TASK [sushy_emulator : Get Openstack instance UUIDs] ***************************
2025-11-24 08:54:21.470554 | controller | Monday 24 November 2025  08:54:21 +0000 (0:00:00.040)       0:01:20.179 *******
2025-11-24 08:54:21.490636 | controller | skipping: [instance]
2025-11-24 08:54:21.490903 | controller |
2025-11-24 08:54:21.490916 | controller | TASK [sushy_emulator : Set instance_uuid variable for openstack driver] ********
2025-11-24 08:54:21.512659 | controller | Monday 24 November 2025  08:54:21 +0000 (0:00:00.020)       0:01:20.200 *******
2025-11-24 08:54:21.512685 | controller | skipping: [instance]
2025-11-24 08:54:21.512918 | controller |
2025-11-24 08:54:21.532175 | controller | TASK [sushy_emulator : Base64 encode openstack clouds.yaml file] ***************
2025-11-24 08:54:21.532197 | controller | Monday 24 November 2025  08:54:21 +0000 (0:00:00.021)       0:01:20.222 *******
2025-11-24 08:54:21.532209 | controller | skipping: [instance]
2025-11-24 08:54:21.532306 | controller |
2025-11-24 08:54:21.532316 | controller | TASK [sushy_emulator : Generate htpasswd string] *******************************
2025-11-24 08:54:21.532372 | controller | Monday 24 November 2025  08:54:21 +0000 (0:00:00.019)       0:01:20.241 *******
2025-11-24 08:54:21.725691 | controller | changed: [instance]
2025-11-24 08:54:21.725839 | controller |
2025-11-24 08:54:21.725969 | controller | TASK [sushy_emulator : Write sushy emulator resource loop] *********************
2025-11-24 08:54:21.725982 | controller | Monday 24 November 2025  08:54:21 +0000 (0:00:00.193)       0:01:20.435 *******
2025-11-24 08:54:23.396710 | controller | changed: [instance] => (item=secret)
2025-11-24 08:54:23.396779 | controller | changed: [instance] => (item=configmap)
2025-11-24 08:54:23.396792 | controller | changed: [instance] => (item=pod)
2025-11-24 08:54:23.396798 | controller | changed: [instance] => (item=service)
2025-11-24 08:54:23.396804 | controller | changed: [instance] => (item=route)
2025-11-24 08:54:23.396809 | controller |
2025-11-24 08:54:23.396823 | controller | TASK [sushy_emulator : Write sushy emulator config] ****************************
2025-11-24 08:54:23.396832 | controller | Monday 24 November 2025  08:54:23 +0000 (0:00:01.670)       0:01:22.105 *******
2025-11-24 08:54:23.418524 | controller | skipping: [instance]
2025-11-24 08:54:23.418614 | controller |
2025-11-24 08:54:23.418631 | controller | TASK [sushy_emulator : Write htpasswd string to file] **************************
2025-11-24 08:54:23.418729 | controller | Monday 24 November 2025  08:54:23 +0000 (0:00:00.022)       0:01:22.128 *******
2025-11-24 08:54:23.441012 | controller | skipping: [instance]
2025-11-24 08:54:23.441280 | controller |
2025-11-24 08:54:24.552320 | controller | TASK [sushy_emulator : Create the sushy-emulator namespace] ********************
2025-11-24 08:54:24.552364 | controller | Monday 24 November 2025  08:54:23 +0000 (0:00:00.022)       0:01:22.150 *******
2025-11-24 08:54:24.552390 | controller | changed: [instance]
2025-11-24 08:54:25.314089 | controller |
2025-11-24 08:54:25.314134 | controller | TASK [sushy_emulator : Check if router pod is running in openshift-ingress namespace] ***
2025-11-24 08:54:25.314143 | controller | Monday 24 November 2025  08:54:24 +0000 (0:00:01.110)       0:01:23.261 *******
2025-11-24 08:54:25.314155 | controller | ok: [instance]
2025-11-24 08:54:25.314291 | controller |
2025-11-24 08:54:25.314368 | controller | TASK [sushy_emulator : Apply Sushy Emulator resources] *************************
2025-11-24 08:54:25.314428 | controller | Monday 24 November 2025  08:54:25 +0000 (0:00:00.762)       0:01:24.023 *******
2025-11-24 08:54:27.769145 | controller | changed: [instance] => (item=secret)
2025-11-24 08:54:58.433691 | controller | changed: [instance] => (item=configmap)
2025-11-24 08:54:58.433740 | controller | changed: [instance] => (item=service)
2025-11-24 08:54:58.433748 | controller | changed: [instance] => (item=route)
2025-11-24 08:54:58.433754 | controller |
2025-11-24 08:54:58.433760 | controller | TASK [sushy_emulator : Apply Sushy Emulator pod resource] **********************
2025-11-24 08:54:58.433766 | controller | Monday 24 November 2025  08:54:27 +0000 (0:00:02.454)       0:01:26.477 *******
2025-11-24 08:54:58.433776 | controller | [WARNING]: unknown field "spec.selector"
2025-11-24 08:54:58.434826 | controller | [WARNING]: unknown field
2025-11-24 08:54:58.435099 | controller | "spec.containers[0].readinessProbe.httpGet.initialDelaySeconds"
2025-11-24 08:54:58.435136 | controller | [WARNING]: unknown field
2025-11-24 08:54:58.435144 | controller | "spec.containers[0].readinessProbe.httpGet.periodSeconds"
2025-11-24 08:54:58.435156 | controller | [WARNING]: unknown field
2025-11-24 08:54:58.435194 | controller | "spec.containers[0].livenessProbe.httpGet.initialDelaySeconds"
2025-11-24 08:54:58.435203 | controller | [WARNING]: unknown field
2025-11-24 08:54:58.435210 | controller | "spec.containers[0].livenessProbe.httpGet.failureThreshold"
2025-11-24 08:54:58.435410 | controller | [WARNING]: unknown field
2025-11-24 08:54:58.435860 | controller | "spec.containers[0].livenessProbe.httpGet.periodSeconds"
2025-11-24 08:54:58.435879 | controller | [WARNING]: unknown field
2025-11-24 08:54:58.445536 | controller | "spec.containers[0].startupProbe.httpGet.failureThreshold"
2025-11-24 08:54:58.445555 | controller | [WARNING]: unknown field
2025-11-24 08:54:58.445562 | controller | "spec.containers[0].startupProbe.httpGet.initialDelaySeconds"
2025-11-24 08:54:58.445572 | controller | changed: [instance]
2025-11-24 08:54:58.474019 | controller |
2025-11-24 08:54:58.474037 | controller | TASK [podman : Ensure podman is installed] *************************************
2025-11-24 08:54:58.474045 | controller | Monday 24 November 2025  08:54:58 +0000 (0:00:30.676)       0:01:57.154 *******
2025-11-24 08:54:58.474054 | controller | skipping: [instance]
2025-11-24 08:54:58.502330 | controller |
2025-11-24 08:54:58.502352 | controller | TASK [podman : Enable loginctl linger for ansible_user_id] *********************
2025-11-24 08:54:58.502360 | controller | Monday 24 November 2025  08:54:58 +0000 (0:00:00.028)       0:01:57.183 *******
2025-11-24 08:54:58.502383 | controller | skipping: [instance]
2025-11-24 08:54:58.529678 | controller |
2025-11-24 08:54:58.529700 | controller | TASK [podman : Ensure subordinate UID entry exists for zuul] *******************
2025-11-24 08:54:58.529710 | controller | Monday 24 November 2025  08:54:58 +0000 (0:00:00.028)       0:01:57.211 *******
2025-11-24 08:54:58.529720 | controller | skipping: [instance]
2025-11-24 08:54:58.552719 | controller |
2025-11-24 08:54:58.552743 | controller | TASK [podman : Ensure subordinate GID entry exists for zuul] *******************
2025-11-24 08:54:58.552752 | controller | Monday 24 November 2025  08:54:58 +0000 (0:00:00.027)       0:01:57.239 *******
2025-11-24 08:54:58.552763 | controller | skipping: [instance]
2025-11-24 08:54:58.552929 | controller |
2025-11-24 08:54:58.552948 | controller | TASK [podman : Run podman system migrate if subuid/subgid files were changed] ***
2025-11-24 08:54:58.579714 | controller | Monday 24 November 2025  08:54:58 +0000 (0:00:00.023)       0:01:57.262 *******
2025-11-24 08:54:58.579777 | controller | skipping: [instance]
2025-11-24 08:54:58.599992 | controller |
2025-11-24 08:54:58.600020 | controller | TASK [sushy_emulator : Pull Sushy Emulator container image] ********************
2025-11-24 08:54:58.600028 | controller | Monday 24 November 2025  08:54:58 +0000 (0:00:00.026)       0:01:57.288 *******
2025-11-24 08:54:58.600038 | controller | skipping: [instance]
2025-11-24 08:54:58.600178 | controller |
2025-11-24 08:54:58.600206 | controller | TASK [sushy_emulator : Create and start Sushy Emulator container] **************
2025-11-24 08:54:58.625703 | controller | Monday 24 November 2025  08:54:58 +0000 (0:00:00.020)       0:01:57.309 *******
2025-11-24 08:54:58.625779 | controller | skipping: [instance]
2025-11-24 08:54:58.625886 | controller |
2025-11-24 08:54:58.625906 | controller | TASK [Verify connection to baremetal VMs via Sushy Emulator] *******************
2025-11-24 08:54:58.687236 | controller | Monday 24 November 2025  08:54:58 +0000 (0:00:00.025)       0:01:57.335 *******
2025-11-24 08:54:58.687264 | controller |
2025-11-24 08:54:58.719051 | controller | TASK [sushy_emulator : Load baremetal hosts from libvirt_manager_bm_info_data fact] ***
2025-11-24 08:54:58.719152 | controller | Monday 24 November 2025  08:54:58 +0000 (0:00:00.061)       0:01:57.396 *******
2025-11-24 08:54:58.719174 | controller | ok: [instance]
2025-11-24 08:54:58.719226 | controller |
2025-11-24 08:54:58.719254 | controller | TASK [sushy_emulator : Slurp content of: /home/zuul/ci-framework-data/parameters/baremetal-info.yml] ***
2025-11-24 08:54:58.753333 | controller | Monday 24 November 2025  08:54:58 +0000 (0:00:00.031)       0:01:57.428 *******
2025-11-24 08:54:58.753417 | controller | skipping: [instance]
2025-11-24 08:54:58.781184 | controller |
2025-11-24 08:54:58.781210 | controller | TASK [sushy_emulator : Set cifmw_baremetal_hosts fact from /home/zuul/ci-framework-data/parameters/baremetal-info.yml] ***
2025-11-24 08:54:58.781219 | controller | Monday 24 November 2025  08:54:58 +0000 (0:00:00.034)       0:01:57.462 *******
2025-11-24 08:54:58.781229 | controller | skipping: [instance]
2025-11-24 08:54:59.907697 | controller |
2025-11-24 08:54:59.907752 | controller | TASK [sushy_emulator : Test Sushy Emulator and connection to hypervisor libvirt socket] ***
2025-11-24 08:54:59.907767 | controller | Monday 24 November 2025  08:54:58 +0000 (0:00:00.027)       0:01:57.490 *******
2025-11-24 08:54:59.907781 | controller | ok: [instance]
2025-11-24 08:55:02.558583 | controller |
2025-11-24 08:55:02.558635 | controller | TASK [sushy_emulator : Verify connection to baremetal VMs via Sushy Emulator] ***
2025-11-24 08:55:02.558643 | controller | Monday 24 November 2025  08:54:59 +0000 (0:00:01.126)       0:01:58.616 *******
2025-11-24 08:55:02.558653 | controller | ok: [instance] => (item=6ba068ec-ffb7-445c-a563-2e6434f9aa53)
2025-11-24 08:55:02.559018 | controller | ok: [instance] => (item=bbbfb155-4553-4120-b0a8-a179c7fb525f)
2025-11-24 08:55:02.559072 | controller |
2025-11-24 08:55:02.610729 | controller | TASK [sushy_emulator : Verify baremetal VM power status] ***********************
2025-11-24 08:55:02.610761 | controller | Monday 24 November 2025  08:55:02 +0000 (0:00:02.650)       0:02:01.267 *******
2025-11-24 08:55:02.610775 | controller | ok: [instance] => (item=cifmw-compute-0)
2025-11-24 08:55:02.610814 | controller | ok: [instance] => (item=cifmw-compute-1)
2025-11-24 08:55:02.610824 | controller |
2025-11-24 08:55:02.611062 | controller | TASK [Run Sushy Emulator role against podman] **********************************
2025-11-24 08:55:02.707632 | controller | Monday 24 November 2025  08:55:02 +0000 (0:00:00.052)       0:02:01.319 *******
2025-11-24 08:55:02.707708 | controller |
2025-11-24 08:55:02.929297 | controller | TASK [sushy_emulator : Create Sushy Emulator resource directory] ***************
2025-11-24 08:55:02.929473 | controller | Monday 24 November 2025  08:55:02 +0000 (0:00:00.095)       0:02:01.415 *******
2025-11-24 08:55:02.929494 | controller | ok: [instance]
2025-11-24 08:55:04.227109 | controller |
2025-11-24 08:55:04.227154 | controller | TASK [sushy_emulator : Install required packages] ******************************
2025-11-24 08:55:04.227163 | controller | Monday 24 November 2025  08:55:02 +0000 (0:00:00.222)       0:02:01.637 *******
2025-11-24 08:55:04.227176 | controller | ok: [instance]
2025-11-24 08:55:04.248774 | controller |
2025-11-24 08:55:04.248840 | controller | TASK [sushy_emulator : Get ingresses domain] ***********************************
2025-11-24 08:55:04.248850 | controller | Monday 24 November 2025  08:55:04 +0000 (0:00:01.298)       0:02:02.936 *******
2025-11-24 08:55:04.248864 | controller | skipping: [instance]
2025-11-24 08:55:04.248886 | controller |
2025-11-24 08:55:04.248900 | controller | TASK [sushy_emulator : Set sushy url for ocp installation] *********************
2025-11-24 08:55:04.248925 | controller | Monday 24 November 2025  08:55:04 +0000 (0:00:00.022)       0:02:02.958 *******
2025-11-24 08:55:04.271530 | controller | skipping: [instance]
2025-11-24 08:55:04.271627 | controller |
2025-11-24 08:55:04.271738 | controller | TASK [sushy_emulator : Create ssh key for Sushy Emulator] **********************
2025-11-24 08:55:04.271851 | controller | Monday 24 November 2025  08:55:04 +0000 (0:00:00.022)       0:02:02.981 *******
2025-11-24 08:55:04.561169 | controller | ok: [instance]
2025-11-24 08:55:04.561228 | controller |
2025-11-24 08:55:04.561310 | controller | TASK [sushy_emulator : Slurp private ssh key for later use] ********************
2025-11-24 08:55:04.561412 | controller | Monday 24 November 2025  08:55:04 +0000 (0:00:00.273)       0:02:03.255 *******
2025-11-24 08:55:04.762699 | controller | ok: [instance]
2025-11-24 08:55:04.762786 | controller |
2025-11-24 08:55:04.762903 | controller | TASK [sushy_emulator : Allow Sushy Emulator key] *******************************
2025-11-24 08:55:04.763014 | controller | Monday 24 November 2025  08:55:04 +0000 (0:00:00.217)       0:02:03.472 *******
2025-11-24 08:55:05.828530 | controller | ok: [instance -> controller-0(192.168.26.172)]
2025-11-24 08:55:05.828575 | controller |
2025-11-24 08:55:05.828586 | controller | TASK [sushy_emulator : Run ssh-keyscan] ****************************************
2025-11-24 08:55:05.828778 | controller | Monday 24 November 2025  08:55:05 +0000 (0:00:01.065)       0:02:04.537 *******
2025-11-24 08:55:06.085502 | controller | changed: [instance]
2025-11-24 08:55:06.085556 | controller |
2025-11-24 08:55:06.085703 | controller | TASK [sushy_emulator : Write known hosts for later use] ************************
2025-11-24 08:55:06.085788 | controller | Monday 24 November 2025  08:55:06 +0000 (0:00:00.257)       0:02:04.795 *******
2025-11-24 08:55:06.455647 | controller | changed: [instance]
2025-11-24 08:55:06.455708 | controller |
2025-11-24 08:55:06.455798 | controller | TASK [sushy_emulator : Ensure file exists: /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
2025-11-24 08:55:06.455897 | controller | Monday 24 November 2025  08:55:06 +0000 (0:00:00.369)       0:02:05.165 *******
2025-11-24 08:55:06.481297 | controller | skipping: [instance]
2025-11-24 08:55:06.481421 | controller |
2025-11-24 08:55:06.481585 | controller | TASK [sushy_emulator : Slurp content of: /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
2025-11-24 08:55:06.481774 | controller | Monday 24 November 2025  08:55:06 +0000 (0:00:00.025)       0:02:05.190 *******
2025-11-24 08:55:06.506727 | controller | skipping: [instance]
2025-11-24 08:55:06.506808 | controller |
2025-11-24 08:55:06.506889 | controller | TASK [sushy_emulator : Set cifmw_libvirt_manager_uuids fact from /home/zuul/ci-framework-data/artifacts/libvirt-uuids.yml] ***
2025-11-24 08:55:06.506995 | controller | Monday 24 November 2025  08:55:06 +0000 (0:00:00.025)       0:02:05.216 *******
2025-11-24 08:55:06.530376 | controller | skipping: [instance]
2025-11-24 08:55:06.530466 | controller |
2025-11-24 08:55:06.530626 | controller | TASK [sushy_emulator : Generate list of filtered VMs] **************************
2025-11-24 08:55:06.530751 | controller | Monday 24 November 2025  08:55:06 +0000 (0:00:00.023)       0:02:05.240 *******
2025-11-24 08:55:06.567067 | controller | ok: [instance]
2025-11-24 08:55:06.567134 | controller |
2025-11-24 08:55:06.567240 | controller | TASK [sushy_emulator : Get Openstack instance UUIDs] ***************************
2025-11-24 08:55:06.567350 | controller | Monday 24 November 2025  08:55:06 +0000 (0:00:00.036)       0:02:05.276 *******
2025-11-24 08:55:06.586258 | controller | skipping: [instance]
2025-11-24 08:55:06.586366 | controller |
2025-11-24 08:55:06.586530 | controller | TASK [sushy_emulator : Set instance_uuid variable for openstack driver] ********
2025-11-24 08:55:06.586681 | controller | Monday 24 November 2025  08:55:06 +0000 (0:00:00.019)       0:02:05.295 *******
2025-11-24 08:55:06.604501 | controller | skipping: [instance]
2025-11-24 08:55:06.604621 | controller |
2025-11-24 08:55:06.604779 | controller | TASK [sushy_emulator : Base64 encode openstack clouds.yaml file] ***************
2025-11-24 08:55:06.604911 | controller | Monday 24 November 2025  08:55:06 +0000 (0:00:00.018)       0:02:05.314 *******
2025-11-24 08:55:06.622911 | controller | skipping: [instance]
2025-11-24 08:55:06.623032 | controller |
2025-11-24 08:55:06.623146 | controller | TASK [sushy_emulator : Generate htpasswd string] *******************************
2025-11-24 08:55:06.623243 | controller | Monday 24 November 2025  08:55:06 +0000 (0:00:00.018)       0:02:05.332 *******
2025-11-24 08:55:06.834740 | controller | changed: [instance]
2025-11-24 08:55:06.834801 | controller |
2025-11-24 08:55:06.834922 | controller | TASK [sushy_emulator : Write sushy emulator resource loop] *********************
2025-11-24 08:55:06.835033 | controller | Monday 24 November 2025  08:55:06 +0000 (0:00:00.211)       0:02:05.544 *******
2025-11-24 08:55:06.935022 | controller | skipping: [instance] => (item=secret)
2025-11-24 08:55:06.935179 | controller | skipping: [instance] => (item=configmap)
2025-11-24 08:55:06.935309 | controller | skipping: [instance] => (item=pod)
2025-11-24 08:55:06.935325 | controller | skipping: [instance] => (item=service)
2025-11-24 08:55:06.935443 | controller | skipping: [instance] => (item=route)
2025-11-24 08:55:06.935597 | controller | skipping: [instance]
2025-11-24 08:55:06.935717 | controller |
2025-11-24 08:55:06.935823 | controller | TASK [sushy_emulator : Write sushy emulator config] ****************************
2025-11-24 08:55:06.935907 | controller | Monday 24 November 2025  08:55:06 +0000 (0:00:00.100)       0:02:05.644 *******
2025-11-24 08:55:07.336087 | controller | changed: [instance]
2025-11-24 08:55:07.336437 | controller |
2025-11-24 08:55:07.695310 | controller | TASK [sushy_emulator : Write htpasswd string to file] **************************
2025-11-24 08:55:07.695419 | controller | Monday 24 November 2025  08:55:07 +0000 (0:00:00.400)       0:02:06.045 *******
2025-11-24 08:55:07.695436 | controller | changed: [instance]
2025-11-24 08:55:07.695467 | controller |
2025-11-24 08:55:07.695479 | controller | TASK [sushy_emulator : Create the sushy-emulator namespace] ********************
2025-11-24 08:55:07.695581 | controller | Monday 24 November 2025  08:55:07 +0000 (0:00:00.359)       0:02:06.404 *******
2025-11-24 08:55:07.716241 | controller | skipping: [instance]
2025-11-24 08:55:07.716356 | controller |
2025-11-24 08:55:07.716490 | controller | TASK [sushy_emulator : Check if router pod is running in openshift-ingress namespace] ***
2025-11-24 08:55:07.716633 | controller | Monday 24 November 2025  08:55:07 +0000 (0:00:00.021)       0:02:06.425 *******
2025-11-24 08:55:07.738819 | controller | skipping: [instance]
2025-11-24 08:55:07.738929 | controller |
2025-11-24 08:55:07.739054 | controller | TASK [sushy_emulator : Apply Sushy Emulator resources] *************************
2025-11-24 08:55:07.739157 | controller | Monday 24 November 2025  08:55:07 +0000 (0:00:00.022)       0:02:06.448 *******
2025-11-24 08:55:07.772874 | controller | skipping: [instance] => (item=secret)
2025-11-24 08:55:07.773088 | controller | skipping: [instance] => (item=configmap)
2025-11-24 08:55:07.773202 | controller | skipping: [instance] => (item=service)
2025-11-24 08:55:07.773220 | controller | skipping: [instance] => (item=route)
2025-11-24 08:55:07.773335 | controller | skipping: [instance]
2025-11-24 08:55:07.773365 | controller |
2025-11-24 08:55:07.773473 | controller | TASK [sushy_emulator : Apply Sushy Emulator pod resource] **********************
2025-11-24 08:55:07.773591 | controller | Monday 24 November 2025  08:55:07 +0000 (0:00:00.033)       0:02:06.482 *******
2025-11-24 08:55:07.794852 | controller | skipping: [instance]
2025-11-24 08:55:07.794930 | controller |
2025-11-24 08:55:07.795031 | controller | TASK [podman : Ensure podman is installed] *************************************
2025-11-24 08:55:07.795131 | controller | Monday 24 November 2025  08:55:07 +0000 (0:00:00.022)       0:02:06.504 *******
2025-11-24 08:55:09.073810 | controller | ok: [instance]
2025-11-24 08:55:09.073864 | controller |
2025-11-24 08:55:09.073966 | controller | TASK [podman : Enable loginctl linger for ansible_user_id] *********************
2025-11-24 08:55:09.074065 | controller | Monday 24 November 2025  08:55:09 +0000 (0:00:01.278)       0:02:07.782 *******
2025-11-24 08:55:09.307139 | controller | changed: [instance]
2025-11-24 08:55:09.307297 | controller |
2025-11-24 08:55:09.307503 | controller | TASK [podman : Ensure subordinate UID entry exists for zuul] *******************
2025-11-24 08:55:09.307519 | controller | Monday 24 November 2025  08:55:09 +0000 (0:00:00.233)       0:02:08.016 *******
2025-11-24 08:55:09.343493 | controller | skipping: [instance]
2025-11-24 08:55:09.343579 | controller |
2025-11-24 08:55:09.343705 | controller | TASK [podman : Ensure subordinate GID entry exists for zuul] *******************
2025-11-24 08:55:09.343802 | controller | Monday 24 November 2025  08:55:09 +0000 (0:00:00.036)       0:02:08.052 *******
2025-11-24 08:55:09.372202 | controller | skipping: [instance]
2025-11-24 08:55:09.372305 | controller |
2025-11-24 08:55:09.372447 | controller | TASK [podman : Run podman system migrate if subuid/subgid files were changed] ***
2025-11-24 08:55:09.372630 | controller | Monday 24 November 2025  08:55:09 +0000 (0:00:00.029)       0:02:08.081 *******
2025-11-24 08:55:09.405925 | controller | skipping: [instance]
2025-11-24 08:55:09.406023 | controller |
2025-11-24 08:55:09.406152 | controller | TASK [sushy_emulator : Pull Sushy Emulator container image] ********************
2025-11-24 08:55:09.406295 | controller | Monday 24 November 2025  08:55:09 +0000 (0:00:00.033)       0:02:08.115 *******
2025-11-24 08:55:15.706484 | controller | changed: [instance]
2025-11-24 08:55:15.706548 | controller |
2025-11-24 08:55:15.706726 | controller | TASK [sushy_emulator : Create and start Sushy Emulator container] **************
2025-11-24 08:55:15.706814 | controller | Monday 24 November 2025  08:55:15 +0000 (0:00:06.300)       0:02:14.415 *******
2025-11-24 08:55:16.574007 | controller | changed: [instance]
2025-11-24 08:55:16.674404 | controller |
2025-11-24 08:55:16.674436 | controller | TASK [Verify connection to baremetal VMs via Sushy Emulator] *******************
2025-11-24 08:55:16.674444 | controller | Monday 24 November 2025  08:55:16 +0000 (0:00:00.866)       0:02:15.282 *******
2025-11-24 08:55:16.674454 | controller |
2025-11-24 08:55:16.703996 | controller | TASK [sushy_emulator : Load baremetal hosts from libvirt_manager_bm_info_data fact] ***
2025-11-24 08:55:16.704019 | controller | Monday 24 November 2025  08:55:16 +0000 (0:00:00.101)       0:02:15.383 *******
2025-11-24 08:55:16.704030 | controller | ok: [instance]
2025-11-24 08:55:16.729024 | controller |
2025-11-24 08:55:16.729044 | controller | TASK [sushy_emulator : Slurp content of: /home/zuul/ci-framework-data/parameters/baremetal-info.yml] ***
2025-11-24 08:55:16.729052 | controller | Monday 24 November 2025  08:55:16 +0000 (0:00:00.029)       0:02:15.413 *******
2025-11-24 08:55:16.729061 | controller | skipping: [instance]
2025-11-24 08:55:16.754573 | controller |
2025-11-24 08:55:16.754591 | controller | TASK [sushy_emulator : Set cifmw_baremetal_hosts fact from /home/zuul/ci-framework-data/parameters/baremetal-info.yml] ***
2025-11-24 08:55:16.754622 | controller | Monday 24 November 2025  08:55:16 +0000 (0:00:00.025)       0:02:15.438 *******
2025-11-24 08:55:16.754635 | controller | skipping: [instance]
2025-11-24 08:55:17.739682 | controller |
2025-11-24 08:55:17.739713 | controller | TASK [sushy_emulator : Test Sushy Emulator and connection to hypervisor libvirt socket] ***
2025-11-24 08:55:17.739721 | controller | Monday 24 November 2025  08:55:16 +0000 (0:00:00.025)       0:02:15.464 *******
2025-11-24 08:55:17.739732 | controller | ok: [instance]
2025-11-24 08:55:17.739887 | controller |
2025-11-24 08:55:17.740062 | controller | TASK [sushy_emulator : Verify connection to baremetal VMs via Sushy Emulator] ***
2025-11-24 08:55:18.438350 | controller | Monday 24 November 2025  08:55:17 +0000 (0:00:00.984)       0:02:16.448 *******
2025-11-24 08:55:18.438394 | controller | ok: [instance] => (item=6ba068ec-ffb7-445c-a563-2e6434f9aa53)
2025-11-24 08:55:18.501319 | controller | ok: [instance] => (item=bbbfb155-4553-4120-b0a8-a179c7fb525f)
2025-11-24 08:55:18.501354 | controller |
2025-11-24 08:55:18.501362 | controller | TASK [sushy_emulator : Verify baremetal VM power status] ***********************
2025-11-24 08:55:18.501368 | controller | Monday 24 November 2025  08:55:18 +0000 (0:00:00.698)       0:02:17.147 *******
2025-11-24 08:55:18.501390 | controller | ok: [instance] => (item=cifmw-compute-0)
2025-11-24 08:55:18.501409 | controller | ok: [instance] => (item=cifmw-compute-1)
2025-11-24 08:55:18.501415 | controller |
2025-11-24 08:55:18.501420 | controller | PLAY RECAP *********************************************************************
2025-11-24 08:55:18.501426 | controller | instance                   : ok=229  changed=86   unreachable=0    failed=0    skipped=110  rescued=0    ignored=0
2025-11-24 08:55:18.501431 | controller |
2025-11-24 08:55:18.501439 | controller | Monday 24 November 2025  08:55:18 +0000 (0:00:00.062)       0:02:17.209 *******
2025-11-24 08:55:18.501691 | controller | ===============================================================================
2025-11-24 08:55:18.501726 | controller | sushy_emulator : Apply Sushy Emulator pod resource --------------------- 30.68s
2025-11-24 08:55:18.501736 | controller | libvirt_manager : Install packages required for using KVM --------------- 9.60s
2025-11-24 08:55:18.502097 | controller | sushy_emulator : Pull Sushy Emulator container image -------------------- 6.30s
2025-11-24 08:55:18.502460 | controller | ci_nmstate : Install required packages on instance ---------------------- 4.89s
2025-11-24 08:55:18.502486 | controller | dnsmasq : Ensure SELinux knows about the new files and directories ------ 3.82s
2025-11-24 08:55:18.502493 | controller | sushy_emulator : Install required packages ------------------------------ 3.73s
2025-11-24 08:55:18.502501 | controller | sushy_emulator : Verify connection to baremetal VMs via Sushy Emulator --- 2.65s
2025-11-24 08:55:18.503368 | controller | sushy_emulator : Apply Sushy Emulator resources ------------------------- 2.45s
2025-11-24 08:55:18.503385 | controller | ci_nmstate : Apply the desidered state on instance ---------------------- 1.90s
2025-11-24 08:55:18.503391 | controller | sushy_emulator : Write sushy emulator resource loop --------------------- 1.67s
2025-11-24 08:55:18.503400 | controller | libvirt_manager : Restart firewalld ------------------------------------- 1.64s
2025-11-24 08:55:18.503406 | controller | dnsmasq : Restart dnsmasq ----------------------------------------------- 1.36s
2025-11-24 08:55:18.503417 | controller | dnsmasq : Add/Remove address -------------------------------------------- 1.34s
2025-11-24 08:55:18.503422 | controller | libvirt_manager : Ensure read-write socket is enabled for proxy. -------- 1.33s
2025-11-24 08:55:18.503427 | controller | libvirt_manager : Ensure read-only socket is enabled for interface. ----- 1.33s
2025-11-24 08:55:18.503433 | controller | sushy_emulator : Install required packages ------------------------------ 1.30s
2025-11-24 08:55:18.503438 | controller | libvirt_manager : Attach interface public on cifmw-compute-1 ------------ 1.30s
2025-11-24 08:55:18.503443 | controller | podman : Ensure podman is installed ------------------------------------- 1.28s
2025-11-24 08:55:18.503448 | controller | dnsmasq : Install needed packages --------------------------------------- 1.25s
2025-11-24 08:55:18.503455 | controller | sushy_emulator : Allow Sushy Emulator key ------------------------------- 1.23s
2025-11-24 08:55:18.585893 | controller | INFO     Running default > cleanup
2025-11-24 08:55:18.586332 | controller | WARNING  Skipping, cleanup playbook not configured.
2025-11-24 08:55:18.586933 | controller | INFO     Writing /tmp/report.html report.
2025-11-24 08:55:19.121328 | [controller] Waiting on logger
2025-11-24 08:55:24.274440 | [controller] Waiting on logger
2025-11-24 08:55:34.706406 | [controller] Waiting on logger
2025-11-24 08:55:45.138449 | [controller] Waiting on logger
2025-11-24 08:55:48.674616 | [Zuul] Log Stream did not terminate
2025-11-24 08:55:48.674814 | controller | changed
2025-11-24 08:55:48.702318 | 
2025-11-24 08:55:48.702380 | PLAY RECAP
2025-11-24 08:55:48.702423 | controller | ok: 4 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-11-24 08:55:48.702446 | 
2025-11-24 08:55:48.768120 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-11-24 08:55:48.768852 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-11-24 08:55:49.293497 | 
2025-11-24 08:55:49.293598 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-11-24 08:55:49.313759 | 
2025-11-24 08:55:49.313833 | TASK [Filter out host if needed]
2025-11-24 08:55:49.322426 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-11-24 08:55:49.326823 | 
2025-11-24 08:55:49.326890 | TASK [Ensure file is present]
2025-11-24 08:55:49.690488 | controller | ok
2025-11-24 08:55:49.696000 | 
2025-11-24 08:55:49.696065 | TASK [Manage molecule report file]
2025-11-24 08:55:49.716171 | [controller] Waiting on logger
2025-11-24 08:56:00.114476 | [controller] Waiting on logger
2025-11-24 08:56:09.458391 | [controller] Waiting on logger
2025-11-24 08:56:19.890420 | [controller] Waiting on logger
2025-11-24 08:56:20.078696 | [Zuul] Log Stream did not terminate
2025-11-24 08:56:20.078845 | controller | changed
2025-11-24 08:56:20.084116 | 
2025-11-24 08:56:20.084179 | TASK [Check if we get ci-framework-data basedir]
2025-11-24 08:56:20.335378 | controller | ok
2025-11-24 08:56:20.340425 | 
2025-11-24 08:56:20.340490 | TASK [Create ci-framework-data log directory for zuul]
2025-11-24 08:56:20.712703 | controller | changed
2025-11-24 08:56:20.718304 | 
2025-11-24 08:56:20.718368 | TASK [Copy ci-framework interesting files]
2025-11-24 08:56:20.739236 | [controller] Waiting on logger
2025-11-24 08:56:31.154451 | [controller] Waiting on logger
2025-11-24 08:56:40.562422 | [controller] Waiting on logger
2025-11-24 08:56:50.994507 | [controller] Waiting on logger
2025-11-24 08:56:51.000817 | [Zuul] Log Stream did not terminate
2025-11-24 08:56:51.001056 | controller | changed
2025-11-24 08:56:51.006375 | 
2025-11-24 08:56:51.006442 | TASK [Get SELinux listing]
2025-11-24 08:56:52.082429 | [controller] Waiting on logger
2025-11-24 08:57:06.610513 | [controller] Waiting on logger
2025-11-24 08:57:17.042560 | [controller] Waiting on logger
2025-11-24 08:57:21.306978 | [Zuul] Log Stream did not terminate
2025-11-24 08:57:21.307944 | controller | changed
2025-11-24 08:57:21.313698 | 
2025-11-24 08:57:21.313769 | TASK [Generate log index]
2025-11-24 08:57:22.488821 | controller | changed
2025-11-24 08:57:22.493585 | 
2025-11-24 08:57:22.493649 | TASK [Get some env related data]
2025-11-24 08:57:22.514250 | [controller] Waiting on logger
2025-11-24 08:57:32.914888 | [controller] Waiting on logger
2025-11-24 08:57:42.258326 | [controller] Waiting on logger
2025-11-24 08:57:52.690575 | [controller] Waiting on logger
2025-11-24 08:57:53.842066 | [Zuul] Log Stream did not terminate
2025-11-24 08:57:53.842274 | controller | changed
2025-11-24 08:57:53.847603 | 
2025-11-24 08:57:53.847669 | TASK [Generate list of logs to collect in home directory]
2025-11-24 08:57:54.219630 | controller | ok: All paths examined
2025-11-24 08:57:54.224710 | 
2025-11-24 08:57:54.224782 | LOOP [Copy logs from home directory]
2025-11-24 08:57:54.765402 | controller | changed:
2025-11-24 08:57:54.765645 | controller | {
2025-11-24 08:57:54.765677 | controller |   "atime": 1743544925.4788878,
2025-11-24 08:57:54.765698 | controller |   "ctime": 1743545329.1409318,
2025-11-24 08:57:54.765718 | controller |   "dev": 64513,
2025-11-24 08:57:54.765737 | controller |   "gid": 1000,
2025-11-24 08:57:54.765754 | controller |   "gr_name": "zuul",
2025-11-24 08:57:54.765770 | controller |   "inode": 4518807,
2025-11-24 08:57:54.765785 | controller |   "isblk": false,
2025-11-24 08:57:54.765799 | controller |   "ischr": false,
2025-11-24 08:57:54.765820 | controller |   "isdir": false,
2025-11-24 08:57:54.765836 | controller |   "isfifo": false,
2025-11-24 08:57:54.765853 | controller |   "isgid": false,
2025-11-24 08:57:54.765868 | controller |   "islnk": false,
2025-11-24 08:57:54.765882 | controller |   "isreg": true,
2025-11-24 08:57:54.765895 | controller |   "issock": false,
2025-11-24 08:57:54.765928 | controller |   "isuid": false,
2025-11-24 08:57:54.765949 | controller |   "mode": "0644",
2025-11-24 08:57:54.765966 | controller |   "mtime": 1743545329.1409318,
2025-11-24 08:57:54.765982 | controller |   "nlink": 1,
2025-11-24 08:57:54.765998 | controller |   "path": "/home/zuul/crc-setup.log",
2025-11-24 08:57:54.766013 | controller |   "pw_name": "zuul",
2025-11-24 08:57:54.766027 | controller |   "rgrp": true,
2025-11-24 08:57:54.766040 | controller |   "roth": true,
2025-11-24 08:57:54.766055 | controller |   "rusr": true,
2025-11-24 08:57:54.766069 | controller |   "size": 4108,
2025-11-24 08:57:54.766082 | controller |   "uid": 1000,
2025-11-24 08:57:54.766096 | controller |   "wgrp": false,
2025-11-24 08:57:54.766120 | controller |   "woth": false,
2025-11-24 08:57:54.766136 | controller |   "wusr": true,
2025-11-24 08:57:54.766150 | controller |   "xgrp": false,
2025-11-24 08:57:54.766164 | controller |   "xoth": false,
2025-11-24 08:57:54.766178 | controller |   "xusr": false
2025-11-24 08:57:54.766192 | controller | }
2025-11-24 08:57:55.274039 | controller | changed:
2025-11-24 08:57:55.274124 | controller | {
2025-11-24 08:57:55.274150 | controller |   "atime": 1743545331.0429637,
2025-11-24 08:57:55.274171 | controller |   "ctime": 1743545842.0111232,
2025-11-24 08:57:55.274189 | controller |   "dev": 64513,
2025-11-24 08:57:55.274221 | controller |   "gid": 1000,
2025-11-24 08:57:55.274240 | controller |   "gr_name": "zuul",
2025-11-24 08:57:55.274256 | controller |   "inode": 4194437,
2025-11-24 08:57:55.274271 | controller |   "isblk": false,
2025-11-24 08:57:55.274286 | controller |   "ischr": false,
2025-11-24 08:57:55.274308 | controller |   "isdir": false,
2025-11-24 08:57:55.274329 | controller |   "isfifo": false,
2025-11-24 08:57:55.274349 | controller |   "isgid": false,
2025-11-24 08:57:55.274367 | controller |   "islnk": false,
2025-11-24 08:57:55.274386 | controller |   "isreg": true,
2025-11-24 08:57:55.274404 | controller |   "issock": false,
2025-11-24 08:57:55.274422 | controller |   "isuid": false,
2025-11-24 08:57:55.274440 | controller |   "mode": "0644",
2025-11-24 08:57:55.274458 | controller |   "mtime": 1743545842.0111232,
2025-11-24 08:57:55.274477 | controller |   "nlink": 1,
2025-11-24 08:57:55.274493 | controller |   "path": "/home/zuul/crc-start.log",
2025-11-24 08:57:55.274507 | controller |   "pw_name": "zuul",
2025-11-24 08:57:55.274521 | controller |   "rgrp": true,
2025-11-24 08:57:55.274538 | controller |   "roth": true,
2025-11-24 08:57:55.274557 | controller |   "rusr": true,
2025-11-24 08:57:55.274576 | controller |   "size": 4023,
2025-11-24 08:57:55.274595 | controller |   "uid": 1000,
2025-11-24 08:57:55.274686 | controller |   "wgrp": false,
2025-11-24 08:57:55.274714 | controller |   "woth": false,
2025-11-24 08:57:55.274733 | controller |   "wusr": true,
2025-11-24 08:57:55.274748 | controller |   "xgrp": false,
2025-11-24 08:57:55.274762 | controller |   "xoth": false,
2025-11-24 08:57:55.274776 | controller |   "xusr": false
2025-11-24 08:57:55.274791 | controller | }
2025-11-24 08:57:55.804176 | controller | changed:
2025-11-24 08:57:55.804274 | controller | {
2025-11-24 08:57:55.804302 | controller |   "atime": 1763973712.8343468,
2025-11-24 08:57:55.804321 | controller |   "ctime": 1763973728.088532,
2025-11-24 08:57:55.804339 | controller |   "dev": 64513,
2025-11-24 08:57:55.804355 | controller |   "gid": 1000,
2025-11-24 08:57:55.804371 | controller |   "gr_name": "zuul",
2025-11-24 08:57:55.804389 | controller |   "inode": 4233449,
2025-11-24 08:57:55.804405 | controller |   "isblk": false,
2025-11-24 08:57:55.804421 | controller |   "ischr": false,
2025-11-24 08:57:55.804435 | controller |   "isdir": false,
2025-11-24 08:57:55.804448 | controller |   "isfifo": false,
2025-11-24 08:57:55.804462 | controller |   "isgid": false,
2025-11-24 08:57:55.804476 | controller |   "islnk": false,
2025-11-24 08:57:55.804489 | controller |   "isreg": true,
2025-11-24 08:57:55.804502 | controller |   "issock": false,
2025-11-24 08:57:55.804515 | controller |   "isuid": false,
2025-11-24 08:57:55.804529 | controller |   "mode": "0644",
2025-11-24 08:57:55.804543 | controller |   "mtime": 1763973728.088532,
2025-11-24 08:57:55.804557 | controller |   "nlink": 1,
2025-11-24 08:57:55.804571 | controller |   "path": "/home/zuul/ansible.log",
2025-11-24 08:57:55.804585 | controller |   "pw_name": "zuul",
2025-11-24 08:57:55.804599 | controller |   "rgrp": true,
2025-11-24 08:57:55.804613 | controller |   "roth": true,
2025-11-24 08:57:55.804627 | controller |   "rusr": true,
2025-11-24 08:57:55.804641 | controller |   "size": 6749,
2025-11-24 08:57:55.804655 | controller |   "uid": 1000,
2025-11-24 08:57:55.804669 | controller |   "wgrp": false,
2025-11-24 08:57:55.804683 | controller |   "woth": false,
2025-11-24 08:57:55.804702 | controller |   "wusr": true,
2025-11-24 08:57:55.804717 | controller |   "xgrp": false,
2025-11-24 08:57:55.804731 | controller |   "xoth": false,
2025-11-24 08:57:55.804745 | controller |   "xusr": false
2025-11-24 08:57:55.804758 | controller | }
2025-11-24 08:57:55.819120 | 
2025-11-24 08:57:55.819190 | TASK [Copy crio stats log file]
2025-11-24 08:57:55.832668 | controller | skipping: Conditional result was False
2025-11-24 08:57:55.838058 | 
2025-11-24 08:57:55.838124 | TASK [Get SELinux related data]
2025-11-24 08:57:55.858761 | [controller] Waiting on logger
2025-11-24 08:58:00.961621 | controller | ERROR
2025-11-24 08:58:00.961985 | controller | {
2025-11-24 08:58:00.962025 | controller |   "delta": "0:00:00.009629",
2025-11-24 08:58:00.962049 | controller |   "end": "2025-11-24 08:57:56.108446",
2025-11-24 08:58:00.962067 | controller |   "msg": "non-zero return code",
2025-11-24 08:58:00.962083 | controller |   "rc": 1,
2025-11-24 08:58:00.962099 | controller |   "start": "2025-11-24 08:57:56.098817"
2025-11-24 08:58:00.962114 | controller | }
2025-11-24 08:58:00.962135 | controller | ERROR: Ignoring Errors
2025-11-24 08:58:00.967304 | 
2025-11-24 08:58:00.967370 | TASK [Create system configuration directory]
2025-11-24 08:58:01.239575 | controller | changed
2025-11-24 08:58:01.245033 | 
2025-11-24 08:58:01.245127 | TASK [Get some of the system configurations]
2025-11-24 08:58:01.265954 | [controller] Waiting on logger
2025-11-24 08:58:11.698646 | [controller] Waiting on logger
2025-11-24 08:58:22.130413 | [controller] Waiting on logger
2025-11-24 08:58:31.474764 | [controller] Waiting on logger
2025-11-24 08:58:31.567730 | [Zuul] Log Stream did not terminate
2025-11-24 08:58:31.567969 | controller | changed
2025-11-24 08:58:31.573319 | 
2025-11-24 08:58:31.573385 | TASK [Copy generated documentation if available]
2025-11-24 08:58:31.586746 | controller | skipping: Conditional result was False
2025-11-24 08:58:31.592104 | 
2025-11-24 08:58:31.592169 | TASK [Copy generated AsciiDoc documentation if available]
2025-11-24 08:58:31.605430 | controller | skipping: Conditional result was False
2025-11-24 08:58:31.610535 | 
2025-11-24 08:58:31.610599 | TASK [Compress logs bigger than 2MB]
2025-11-24 08:58:34.738397 | [controller] Waiting on logger
2025-11-24 08:58:40.997590 | controller | changed
2025-11-24 08:58:41.002866 | 
2025-11-24 08:58:41.002947 | TASK [Copy files from workspace on node]
2025-11-24 08:58:41.020844 | controller | ok
2025-11-24 08:58:41.042235 | 
2025-11-24 08:58:41.042313 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-24 08:58:41.055165 | controller | skipping: Conditional result was False
2025-11-24 08:58:41.061005 | 
2025-11-24 08:58:41.061074 | TASK [fetch-output : Set log path for single node]
2025-11-24 08:58:41.089053 | controller | ok
2025-11-24 08:58:41.093779 | 
2025-11-24 08:58:41.093843 | LOOP [fetch-output : Ensure local output dirs]
2025-11-24 08:58:41.282660 | controller -> localhost | ok: "/var/lib/zuul/builds/8398fbba5c154ca589b23f07df8183ff/work/logs"
2025-11-24 08:58:41.282860 | controller -> localhost | changed: All items complete
2025-11-24 08:58:41.282889 | 
2025-11-24 08:58:41.459613 | controller -> localhost | changed: "/var/lib/zuul/builds/8398fbba5c154ca589b23f07df8183ff/work/artifacts"
2025-11-24 08:58:41.639625 | controller -> localhost | changed: "/var/lib/zuul/builds/8398fbba5c154ca589b23f07df8183ff/work/docs"
2025-11-24 08:58:41.650441 | 
2025-11-24 08:58:41.650574 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-24 08:58:42.290144 | controller | changed:
2025-11-24 08:58:42.290328 | controller | .d..t...... ./
2025-11-24 08:58:42.290357 | controller | >f+++++++++ README.html
2025-11-24 08:58:42.290378 | controller | >f+++++++++ ansible-execution.log
2025-11-24 08:58:42.290397 | controller | >f+++++++++ ansible.log
2025-11-24 08:58:42.290414 | controller | >f+++++++++ crc-setup.log
2025-11-24 08:58:42.290432 | controller | >f+++++++++ crc-start.log
2025-11-24 08:58:42.290449 | controller | >f+++++++++ dmesg.log
2025-11-24 08:58:42.290471 | controller | >f+++++++++ installed-pkgs.log
2025-11-24 08:58:42.290488 | controller | >f+++++++++ python.log
2025-11-24 08:58:42.290504 | controller | >f+++++++++ registries.conf
2025-11-24 08:58:42.290519 | controller | >f+++++++++ report.html
2025-11-24 08:58:42.290535 | controller | >f+++++++++ selinux-denials.log
2025-11-24 08:58:42.290550 | controller | >f+++++++++ selinux-listing.log
2025-11-24 08:58:42.290565 | controller | cd+++++++++ ci-framework-data/
2025-11-24 08:58:42.290579 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-11-24 08:58:42.290594 | controller | >f+++++++++ ci-framework-data/artifacts/debug_cifmw_libvirt_manager_layout.yml
2025-11-24 08:58:42.290608 | controller | >f+++++++++ ci-framework-data/artifacts/debug_network_data.yml
2025-11-24 08:58:42.290624 | controller | >f+++++++++ ci-framework-data/artifacts/debug_pub_net_value.txt
2025-11-24 08:58:42.290640 | controller | >f+++++++++ ci-framework-data/artifacts/interfaces-info.yml
2025-11-24 08:58:42.290655 | controller | >f+++++++++ ci-framework-data/artifacts/libvirt-uuids.yml
2025-11-24 08:58:42.290669 | controller | >f+++++++++ ci-framework-data/artifacts/net-map-def-patch.yml
2025-11-24 08:58:42.290683 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-11-24 08:58:42.290697 | controller | cd+++++++++ ci-framework-data/artifacts/nmstate/
2025-11-24 08:58:42.290712 | controller | >f+++++++++ ci-framework-data/artifacts/nmstate/instance-final-state.yaml
2025-11-24 08:58:42.290726 | controller | >f+++++++++ ci-framework-data/artifacts/nmstate/instance-state.yaml
2025-11-24 08:58:42.290740 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-11-24 08:58:42.290754 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-11-24 08:58:42.290767 | controller | cd+++++++++ ci-framework-data/artifacts/repositories/
2025-11-24 08:58:42.290781 | controller | >f+++++++++ ci-framework-data/artifacts/repositories/delorean.repo.md5
2025-11-24 08:58:42.290794 | controller | cd+++++++++ ci-framework-data/artifacts/sushy_emulator/
2025-11-24 08:58:42.290808 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/.htpasswd
2025-11-24 08:58:42.290822 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/config.conf
2025-11-24 08:58:42.290836 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/configmap.yaml
2025-11-24 08:58:42.290849 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/known_hosts
2025-11-24 08:58:42.290863 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/pod.yaml
2025-11-24 08:58:42.290877 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/route.yaml
2025-11-24 08:58:42.290892 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/secret.yaml
2025-11-24 08:58:42.290905 | controller | >f+++++++++ ci-framework-data/artifacts/sushy_emulator/service.yaml
2025-11-24 08:58:42.290944 | controller | cd+++++++++ ci-framework-data/logs/
2025-11-24 08:58:42.290961 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-11-24 08:58:42.290977 | controller | cd+++++++++ registries.conf.d/
2025-11-24 08:58:42.290992 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-11-24 08:58:42.291007 | controller | cd+++++++++ system-config/
2025-11-24 08:58:42.291021 | controller | cd+++++++++ system-config/libvirt/
2025-11-24 08:58:42.291035 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-11-24 08:58:42.291052 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-11-24 08:58:42.291067 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf
2025-11-24 08:58:42.291081 | controller | >f+++++++++ system-config/libvirt/network.conf
2025-11-24 08:58:42.291096 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf
2025-11-24 08:58:42.291109 | controller | >f+++++++++ system-config/libvirt/qemu.conf
2025-11-24 08:58:42.291124 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf
2025-11-24 08:58:42.291141 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf
2025-11-24 08:58:42.291157 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf
2025-11-24 08:58:42.291171 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf
2025-11-24 08:58:42.291185 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf
2025-11-24 08:58:42.291210 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf
2025-11-24 08:58:42.291226 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf
2025-11-24 08:58:42.291240 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf
2025-11-24 08:58:42.291254 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf
2025-11-24 08:58:42.291267 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf
2025-11-24 08:58:42.754097 | controller | changed: .d..t...... ./
2025-11-24 08:58:43.211636 | controller | changed: .d..t...... ./
2025-11-24 08:58:43.225439 | 
2025-11-24 08:58:43.225510 | TASK [Return artifact to Zuul]
2025-11-24 08:58:43.253950 | controller | ok
2025-11-24 08:58:43.272252 | 
2025-11-24 08:58:43.272307 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-11-24 08:58:43.272397 | 
2025-11-24 08:58:43.272423 | PLAY RECAP
2025-11-24 08:58:43.272460 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-11-24 08:58:43.272481 | 
2025-11-24 08:58:43.346881 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-11-24 08:58:43.347599 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-11-24 08:58:43.850737 | 
2025-11-24 08:58:43.850833 | PLAY [all]
2025-11-24 08:58:43.869011 | 
2025-11-24 08:58:43.869083 | TASK [include_role : fetch-output]
2025-11-24 08:58:43.897017 | controller | ok
2025-11-24 08:58:43.913158 | 
2025-11-24 08:58:43.913249 | TASK [fetch-output : Set log path for multiple nodes]
2025-11-24 08:58:43.956438 | controller | skipping: Conditional result was False
2025-11-24 08:58:43.961750 | 
2025-11-24 08:58:43.961831 | TASK [fetch-output : Set log path for single node]
2025-11-24 08:58:43.989699 | controller | ok
2025-11-24 08:58:43.994480 | 
2025-11-24 08:58:43.994546 | LOOP [fetch-output : Ensure local output dirs]
2025-11-24 08:58:44.304101 | controller -> localhost | ok: "/var/lib/zuul/builds/8398fbba5c154ca589b23f07df8183ff/work/logs"
2025-11-24 08:58:44.483295 | controller -> localhost | ok: "/var/lib/zuul/builds/8398fbba5c154ca589b23f07df8183ff/work/artifacts"
2025-11-24 08:58:44.660554 | controller -> localhost | ok: "/var/lib/zuul/builds/8398fbba5c154ca589b23f07df8183ff/work/docs"
2025-11-24 08:58:44.672244 | 
2025-11-24 08:58:44.672312 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-11-24 08:58:45.284228 | controller | ok
2025-11-24 08:58:45.284536 | controller | ok: All items complete
2025-11-24 08:58:45.284574 | 
2025-11-24 08:58:45.739325 | controller | ok
2025-11-24 08:58:46.196130 | controller | ok
2025-11-24 08:58:46.215168 | 
2025-11-24 08:58:46.215250 | TASK [include_role : fetch-output-openshift]
2025-11-24 08:58:46.228772 | controller | skipping: Conditional result was False
2025-11-24 08:58:46.234120 | 
2025-11-24 08:58:46.234198 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-11-24 08:58:46.560540 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006095
2025-11-24 08:58:46.746001 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006337
2025-11-24 08:58:46.777437 | 
2025-11-24 08:58:46.777495 | PLAY [all]
2025-11-24 08:58:46.791105 | 
2025-11-24 08:58:46.791171 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-11-24 08:58:47.286750 | controller | changed
2025-11-24 08:58:47.307981 | 
2025-11-24 08:58:47.308033 | PLAY RECAP
2025-11-24 08:58:47.308076 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-11-24 08:58:47.308104 | 
2025-11-24 08:58:47.378650 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-11-24 08:58:47.379370 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-11-24 08:58:47.919433 | 
2025-11-24 08:58:47.919543 | PLAY [localhost]
2025-11-24 08:58:47.937133 | 
2025-11-24 08:58:47.937223 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-11-24 08:58:48.238279 | localhost | changed
2025-11-24 08:58:48.242875 | 
2025-11-24 08:58:48.242982 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-11-24 08:58:48.260630 | localhost | ok
2025-11-24 08:58:48.268296 | 
2025-11-24 08:58:48.268362 | TASK [add-fileserver : Create SSH private key tempfile]
2025-11-24 08:58:48.551306 | localhost | changed
2025-11-24 08:58:48.557459 | 
2025-11-24 08:58:48.557528 | TASK [add-fileserver : Create SSH private key from secret]
2025-11-24 08:58:49.081166 | localhost | changed
2025-11-24 08:58:49.086034 | 
2025-11-24 08:58:49.086101 | TASK [add-fileserver : Add fileserver ssh key]
2025-11-24 08:58:49.407085 | localhost | Identity added: /var/lib/zuul/builds/8398fbba5c154ca589b23f07df8183ff/work/tmp/ansible.ns_dd4db (/var/lib/zuul/builds/8398fbba5c154ca589b23f07df8183ff/work/tmp/ansible.ns_dd4db)
2025-11-24 08:58:49.407260 | localhost | ok: Runtime: 0:00:00.006165
2025-11-24 08:58:49.411420 | 
2025-11-24 08:58:49.411487 | TASK [add-fileserver : Remove SSH private key from disk]
2025-11-24 08:58:49.621360 | localhost | ok: Runtime: 0:00:00.004198
2025-11-24 08:58:49.625974 | 
2025-11-24 08:58:49.626040 | TASK [add-fileserver : Add fileserver to inventory]
2025-11-24 08:58:49.674482 | localhost | changed
2025-11-24 08:58:49.679267 | 
2025-11-24 08:58:49.679332 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-11-24 08:58:49.979897 | localhost | changed
2025-11-24 08:58:49.998588 | 
2025-11-24 08:58:49.998646 | PLAY [localhost]
2025-11-24 08:58:50.009599 | 
2025-11-24 08:58:50.009660 | TASK [Generate bulk log download script]
2025-11-24 08:58:50.028018 | localhost | ok
2025-11-24 08:58:50.038952 | 
2025-11-24 08:58:50.039019 | TASK [local-log-download : Check API endpoint is defined]
2025-11-24 08:58:50.066355 | localhost | ok: All assertions passed
2025-11-24 08:58:50.070719 | 
2025-11-24 08:58:50.070781 | TASK [local-log-download : Create download script]
2025-11-24 08:58:50.418479 | localhost -> localhost | changed
2025-11-24 08:58:50.427102 | 
2025-11-24 08:58:50.427169 | TASK [Register quick-download link]
2025-11-24 08:58:50.444502 | localhost | ok
2025-11-24 08:58:50.478423 | 
2025-11-24 08:58:50.478514 | PLAY [logserver.rdoproject.org]
2025-11-24 08:58:50.487853 | 
2025-11-24 08:58:50.487930 | TASK [Set zuul-log-path fact]
2025-11-24 08:58:50.503746 | logserver.rdoproject.org | ok
2025-11-24 08:58:50.512389 | 
2025-11-24 08:58:50.512455 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-11-24 08:58:50.538499 | logserver.rdoproject.org | ok
2025-11-24 08:58:50.543649 | 
2025-11-24 08:58:50.543715 | TASK [upload-logs : Create log directories]
2025-11-24 08:58:52.393452 | logserver.rdoproject.org | changed
2025-11-24 08:58:52.396552 | 
2025-11-24 08:58:52.396616 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-11-24 08:58:52.623062 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004770
2025-11-24 08:58:52.627449 | 
2025-11-24 08:58:52.627513 | TASK [upload-logs : Upload logs to log server]
2025-11-24 08:58:54.131066 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-11-24 08:58:54.133864 | 
2025-11-24 08:58:54.133944 | LOOP [upload-logs : Compress console log and json output]
2025-11-24 08:58:54.170467 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 08:58:54.178616 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 08:58:54.191361 | 
2025-11-24 08:58:54.191446 | LOOP [upload-logs : Upload compressed console log and json output]
2025-11-24 08:58:54.224572 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 08:58:54.224750 | 
2025-11-24 08:58:54.228270 | logserver.rdoproject.org | skipping: Conditional result was False
2025-11-24 08:58:54.238989 | 
2025-11-24 08:58:54.239073 | LOOP [upload-logs : Upload console log and json output]