2025-10-01 10:49:46.079955 | Job console starting...
2025-10-01 10:49:46.308666 | Updating repositories
2025-10-01 10:49:47.062801 | Preparing job workspace
2025-10-01 10:49:55.865974 | Running Ansible setup...
2025-10-01 10:50:00.031251 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-01 10:50:00.660744 | 
2025-10-01 10:50:00.660841 | PLAY [localhost]
2025-10-01 10:50:00.677560 | 
2025-10-01 10:50:00.677647 | TASK [Gathering Facts]
2025-10-01 10:50:02.017768 | localhost | ok
2025-10-01 10:50:02.042466 | 
2025-10-01 10:50:02.042594 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-01 10:50:02.565954 | localhost -> localhost | changed
2025-10-01 10:50:02.572496 | 
2025-10-01 10:50:02.572588 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-01 10:50:03.684725 | localhost -> localhost | changed
2025-10-01 10:50:03.692921 | 
2025-10-01 10:50:03.693001 | TASK [Setup log path fact]
2025-10-01 10:50:03.712731 | localhost | ok
2025-10-01 10:50:03.726750 | 
2025-10-01 10:50:03.726824 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-01 10:50:03.758230 | localhost | ok
2025-10-01 10:50:03.776850 | 
2025-10-01 10:50:03.776941 | TASK [emit-job-header : Print job information]
2025-10-01 10:50:03.834065 | # Job Information
2025-10-01 10:50:03.834224 | Ansible Version: 2.15.12
2025-10-01 10:50:03.834255 | Job: cifmw-molecule-virtualbmc
2025-10-01 10:50:03.834278 | Pipeline: github-check
2025-10-01 10:50:03.834298 | Executor: ibm-bm3-ze.softwarefactory-project.io
2025-10-01 10:50:03.834336 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3237
2025-10-01 10:50:03.834357 | Log URL (when completed): https://logserver.rdoproject.org/8d5/rdoproject.org/8d5c77bb7ae4469297059e6cc9454a62/
2025-10-01 10:50:03.834376 | Event ID: 2c962f60-9eb3-11f0-844e-f06c90bcb25f
2025-10-01 10:50:03.837887 | 
2025-10-01 10:50:03.837954 | LOOP [emit-job-header : Print node information]
2025-10-01 10:50:03.931643 | localhost | ok:
2025-10-01 10:50:03.931883 | localhost | # Node Information
2025-10-01 10:50:03.931916 | localhost | Inventory Hostname: controller
2025-10-01 10:50:03.931946 | localhost | Hostname: np0005464427
2025-10-01 10:50:03.931978 | localhost | Username: zuul
2025-10-01 10:50:03.932002 | localhost | Distro: CentOS 9
2025-10-01 10:50:03.932022 | localhost | Provider: ibm-bm3-nodepool
2025-10-01 10:50:03.932041 | localhost | Region: regionOne
2025-10-01 10:50:03.932059 | localhost | Label: cloud-centos-9-stream-tripleo-ibm
2025-10-01 10:50:03.932077 | localhost | Product Name: OpenStack Compute
2025-10-01 10:50:03.932099 | localhost | Interface IP: 192.168.25.188
2025-10-01 10:50:03.951355 | 
2025-10-01 10:50:03.951497 | PLAY [all]
2025-10-01 10:50:03.958163 | 
2025-10-01 10:50:03.958233 | TASK [Gather network facts]
2025-10-01 10:50:04.312426 | controller | ok
2025-10-01 10:50:04.329281 | 
2025-10-01 10:50:04.329394 | TASK [include_role : start-zuul-console]
2025-10-01 10:50:04.347039 | controller | ok
2025-10-01 10:50:04.361060 | 
2025-10-01 10:50:04.361183 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-01 10:50:04.673158 | controller | ok
2025-10-01 10:50:04.682168 | 
2025-10-01 10:50:04.682239 | TASK [include_role : add-build-sshkey]
2025-10-01 10:50:04.700293 | controller | ok
2025-10-01 10:50:04.713493 | 
2025-10-01 10:50:04.713566 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-01 10:50:04.913134 | controller -> localhost | ok
2025-10-01 10:50:04.918582 | 
2025-10-01 10:50:04.918655 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-01 10:50:04.960678 | controller | ok
2025-10-01 10:50:04.973234 | controller | included: /var/lib/zuul/builds/8d5c77bb7ae4469297059e6cc9454a62/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-01 10:50:04.978842 | 
2025-10-01 10:50:04.978914 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-01 10:50:05.410060 | controller -> localhost | Generating public/private rsa key pair.
2025-10-01 10:50:05.410242 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/8d5c77bb7ae4469297059e6cc9454a62/work/8d5c77bb7ae4469297059e6cc9454a62_id_rsa.
2025-10-01 10:50:05.410278 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/8d5c77bb7ae4469297059e6cc9454a62/work/8d5c77bb7ae4469297059e6cc9454a62_id_rsa.pub.
2025-10-01 10:50:05.410320 | controller -> localhost | The key fingerprint is:
2025-10-01 10:50:05.410345 | controller -> localhost | SHA256:HO8OQ9PV161F6IrdC/NE2giMkahGSfI0Z44Uh4tQzaU zuul-build-sshkey
2025-10-01 10:50:05.410369 | controller -> localhost | The key's randomart image is:
2025-10-01 10:50:05.410521 | controller -> localhost | +---[RSA 3072]----+
2025-10-01 10:50:05.410557 | controller -> localhost | | .o+*==. .     ..|
2025-10-01 10:50:05.410582 | controller -> localhost | |.  =*O. o    ...o|
2025-10-01 10:50:05.410603 | controller -> localhost | | . oEo. .+  ... =|
2025-10-01 10:50:05.410623 | controller -> localhost | |  . +  ..+o.  o+ |
2025-10-01 10:50:05.410643 | controller -> localhost | |   .    S o+ B.  |
2025-10-01 10:50:05.410662 | controller -> localhost | |       . o. B +  |
2025-10-01 10:50:05.410680 | controller -> localhost | |        o .  = . |
2025-10-01 10:50:05.410700 | controller -> localhost | |         +    o  |
2025-10-01 10:50:05.410718 | controller -> localhost | |          .      |
2025-10-01 10:50:05.410736 | controller -> localhost | +----[SHA256]-----+
2025-10-01 10:50:05.410784 | controller -> localhost | ok: Runtime: 0:00:00.071107
2025-10-01 10:50:05.416805 | 
2025-10-01 10:50:05.416874 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-01 10:50:05.436244 | controller | ok
2025-10-01 10:50:05.445781 | controller | included: /var/lib/zuul/builds/8d5c77bb7ae4469297059e6cc9454a62/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-01 10:50:05.454811 | 
2025-10-01 10:50:05.454895 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-01 10:50:05.468927 | controller | skipping: Conditional result was False
2025-10-01 10:50:05.474726 | 
2025-10-01 10:50:05.474799 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-01 10:50:05.860148 | controller | changed
2025-10-01 10:50:05.865349 | 
2025-10-01 10:50:05.865442 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-01 10:50:06.058372 | controller | ok
2025-10-01 10:50:06.064867 | 
2025-10-01 10:50:06.064983 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-01 10:50:06.637254 | controller | changed
2025-10-01 10:50:06.642051 | 
2025-10-01 10:50:06.642129 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-01 10:50:07.210703 | controller | changed
2025-10-01 10:50:07.215413 | 
2025-10-01 10:50:07.215493 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-01 10:50:07.239423 | controller | skipping: Conditional result was False
2025-10-01 10:50:07.244524 | 
2025-10-01 10:50:07.244595 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-01 10:50:07.629293 | controller -> localhost | changed
2025-10-01 10:50:07.669060 | 
2025-10-01 10:50:07.669151 | TASK [add-build-sshkey : Add back temp key]
2025-10-01 10:50:07.937525 | controller -> localhost | Identity added: /var/lib/zuul/builds/8d5c77bb7ae4469297059e6cc9454a62/work/8d5c77bb7ae4469297059e6cc9454a62_id_rsa (zuul-build-sshkey)
2025-10-01 10:50:07.937736 | controller -> localhost | ok: Runtime: 0:00:00.007253
2025-10-01 10:50:07.943741 | 
2025-10-01 10:50:07.943932 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-01 10:50:08.227296 | controller | ok
2025-10-01 10:50:08.234237 | 
2025-10-01 10:50:08.234375 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-01 10:50:08.260110 | controller | skipping: Conditional result was False
2025-10-01 10:50:08.269570 | 
2025-10-01 10:50:08.269639 | TASK [include_role : validate-host]
2025-10-01 10:50:08.287418 | controller | ok
2025-10-01 10:50:08.309902 | 
2025-10-01 10:50:08.310025 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-01 10:50:08.338972 | controller | ok
2025-10-01 10:50:08.343560 | 
2025-10-01 10:50:08.343623 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-01 10:50:08.603209 | controller -> localhost | ok
2025-10-01 10:50:08.612191 | 
2025-10-01 10:50:08.612503 | TASK [validate-host : Collect information about the host]
2025-10-01 10:50:09.248686 | controller | ok
2025-10-01 10:50:09.256411 | 
2025-10-01 10:50:09.256497 | TASK [validate-host : Sanitize hostname]
2025-10-01 10:50:09.305059 | controller | ok
2025-10-01 10:50:09.310895 | 
2025-10-01 10:50:09.310960 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-01 10:50:09.744405 | controller -> localhost | changed
2025-10-01 10:50:09.750030 | 
2025-10-01 10:50:09.750101 | TASK [validate-host : Collect information about zuul worker]
2025-10-01 10:50:10.090488 | controller | ok
2025-10-01 10:50:10.099371 | 
2025-10-01 10:50:10.099515 | TASK [validate-host : Write out all zuul information for each host]
2025-10-01 10:50:10.541691 | controller -> localhost | changed
2025-10-01 10:50:10.551013 | 
2025-10-01 10:50:10.551092 | TASK [include_role : prepare-workspace-openshift]
2025-10-01 10:50:10.581016 | controller | skipping: Conditional result was False
2025-10-01 10:50:10.586485 | 
2025-10-01 10:50:10.586560 | TASK [include_role : remove-zuul-sshkey]
2025-10-01 10:50:10.609896 | controller | skipping: Conditional result was False
2025-10-01 10:50:10.615279 | 
2025-10-01 10:50:10.615373 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-01 10:50:10.832785 | controller | ok: "logs"
2025-10-01 10:50:10.833015 | controller | ok: All items complete
2025-10-01 10:50:10.833054 | 
2025-10-01 10:50:11.000692 | controller | ok: "artifacts"
2025-10-01 10:50:11.165275 | controller | ok: "docs"
2025-10-01 10:50:11.182054 | 
2025-10-01 10:50:11.182156 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-01 10:50:11.396485 | controller | changed: "logs"
2025-10-01 10:50:11.588219 | controller | changed: "artifacts"
2025-10-01 10:50:11.757887 | controller | changed: "docs"
2025-10-01 10:50:11.787059 | 
2025-10-01 10:50:11.787153 | PLAY RECAP
2025-10-01 10:50:11.787199 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-01 10:50:11.787229 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-01 10:50:11.787249 | 
2025-10-01 10:50:11.879887 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-01 10:50:11.880680 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-01 10:50:12.450806 | 
2025-10-01 10:50:12.450926 | PLAY [all]
2025-10-01 10:50:12.470914 | 
2025-10-01 10:50:12.470992 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-01 10:50:12.529791 | controller | ok
2025-10-01 10:50:12.535019 | 
2025-10-01 10:50:12.535103 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-01 10:50:12.898406 | controller | changed
2025-10-01 10:50:12.904104 | 
2025-10-01 10:50:12.904187 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-01 10:50:13.738623 | controller | changed
2025-10-01 10:50:13.751366 | 
2025-10-01 10:50:13.751496 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-10-01 10:50:14.158027 | controller | changed:
2025-10-01 10:50:14.158198 | controller | {
2025-10-01 10:50:14.158227 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-10-01 10:50:14.158256 | controller | }
2025-10-01 10:50:14.385218 | controller | changed:
2025-10-01 10:50:14.385320 | controller | {
2025-10-01 10:50:14.385351 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-10-01 10:50:14.385375 | controller | }
2025-10-01 10:50:14.618776 | controller | changed:
2025-10-01 10:50:14.618863 | controller | {
2025-10-01 10:50:14.619012 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-10-01 10:50:14.619044 | controller | }
2025-10-01 10:50:14.845647 | controller | changed:
2025-10-01 10:50:14.845788 | controller | {
2025-10-01 10:50:14.845817 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-10-01 10:50:14.845840 | controller | }
2025-10-01 10:50:15.083946 | controller | changed:
2025-10-01 10:50:15.084040 | controller | {
2025-10-01 10:50:15.084066 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-10-01 10:50:15.084086 | controller | }
2025-10-01 10:50:15.304448 | controller | changed:
2025-10-01 10:50:15.305154 | controller | {
2025-10-01 10:50:15.305196 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-10-01 10:50:15.305223 | controller | }
2025-10-01 10:50:15.518492 | controller | changed:
2025-10-01 10:50:15.518583 | controller | {
2025-10-01 10:50:15.518611 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDLOQd4ZLtkZXQGY6UwAr/06ppWQK4fDO3HaqxPk98csyOCBXsliSKK39Bso828+5srIXiW7aI6aC9P5mwi4mUZlGPfJlQbfrcGvY+b/SocuvaGK+1RrHLoJCT52LBhwgrzlXio2jeksZeein8iaTrhsPrOAs7KggIL/rB9hEiB3NaOPWhhoCP4vlW6MEMExGcqB/1FVxXFBPnLkEyW0Lk7ycVflZl2ocRxbfjZi0+tI1Wlinp8PvSQSc/WVrAcDgKjc/mB4ODPOyYy3G8FHgfMsrXSDEyjBKgLKMsdCrAUcqJQWjkqXleXSYOV4q3pzL+9umK+q/e3P/bIoSFQzmJKTU1eDfuvPXmow9F5H54fii/Da7ezlMJ+wPGHJrRAkmzvMbALy7xwswLhZMkOGNtRcPqaKYRmIBKpw3o6bCTtcNUHOtOQnzwY8JzrM2eBWJBXAANYw+9/ho80JIiwhg29CFNpVBuHbql2YxJQNrnl90guN65rYNpDxdIluweyUf8= anbanerj@kaermorhen"
2025-10-01 10:50:15.518635 | controller | }
2025-10-01 10:50:15.738460 | controller | changed:
2025-10-01 10:50:15.738778 | controller | {
2025-10-01 10:50:15.738818 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC3VwV8Im9kRm49lt3tM36hj4Zv27FxGo4C1Q/0jqhzFmHY7RHbmeRr8ObhwWoHjXSozKWg8FL5ER0z3hTwL0W6lez3sL7hUaCmSuZmG5Hnl3x4vTSxDI9JZ/Y65rtYiiWQo2fC5xJhU/4+0e5e/pseCm8cKRSu+SaxhO+sd6FDojA2x1BzOzKiQRDy/1zWGp/cZkxcEuB1wHI5LMzN03c67vmbu+fhZRAUO4dQkvcnj2LrhQtpa+ytvnSjr8icMDosf1OsbSffwZFyHB/hfWGAfe0eIeSA2XPraxiPknXxiPKx2MJsaUTYbsZcm3EjFdHBBMumw5rBI74zLrMRvCO9GwBEmGT4rFng1nP+yw5DB8sn2zqpOsPg1LYRwCPOUveC13P6pgsZZPh812e8v5EKnETct+5XI3dVpdw6CnNiLwAyVAF15DJvBGT/u1k0Myg/bQn+Gv9k2MSj6LvQmf6WbZu2Wgjm30z3FyCneBqTL7mLF19YXzeC0ufHz5pnO1E= dasm@fedora"
2025-10-01 10:50:15.738844 | controller | }
2025-10-01 10:50:15.951481 | controller | changed:
2025-10-01 10:50:15.951626 | controller | {
2025-10-01 10:50:15.951658 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-10-01 10:50:15.951682 | controller | }
2025-10-01 10:50:16.160997 | controller | changed:
2025-10-01 10:50:16.161081 | controller | {
2025-10-01 10:50:16.161109 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-10-01 10:50:16.161131 | controller | }
2025-10-01 10:50:16.383239 | controller | changed:
2025-10-01 10:50:16.383433 | controller | {
2025-10-01 10:50:16.383476 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-10-01 10:50:16.383503 | controller | }
2025-10-01 10:50:16.606145 | controller | changed:
2025-10-01 10:50:16.606237 | controller | {
2025-10-01 10:50:16.606277 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-10-01 10:50:16.606308 | controller | }
2025-10-01 10:50:16.856505 | controller | changed:
2025-10-01 10:50:16.856586 | controller | {
2025-10-01 10:50:16.856615 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-10-01 10:50:16.856638 | controller | }
2025-10-01 10:50:17.066769 | controller | changed:
2025-10-01 10:50:17.066861 | controller | {
2025-10-01 10:50:17.066888 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-10-01 10:50:17.066910 | controller | }
2025-10-01 10:50:17.273488 | controller | changed:
2025-10-01 10:50:17.273601 | controller | {
2025-10-01 10:50:17.273630 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-10-01 10:50:17.273652 | controller | }
2025-10-01 10:50:17.489932 | controller | changed:
2025-10-01 10:50:17.490022 | controller | {
2025-10-01 10:50:17.490050 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-10-01 10:50:17.490072 | controller | }
2025-10-01 10:50:17.726715 | controller | changed:
2025-10-01 10:50:17.726807 | controller | {
2025-10-01 10:50:17.726835 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQCfNtF7NvKl915TGsGGoseUb06Hj8L/S4toWf0hExeY+F00woL6NvBlJD0nDct+P5a22I4EhvoQCRQ8reaPCm1lybR3uiRIJsj+8zkVvLwby9LXzfZorlNG9ofjd00FEmB09uW/YvTl6Q9XwwwX6tInzIOv3TMqTHHGOL74ibbj8J/FJR0cFEyj0z4WQRvtkh32xAHl83gbuINryMt0sqRI+clj2381NKL55DRLQrVw0gsfqqxiHAnXg21qWmc4J+b9e9kiuAFQjcjwTVkwJCcg3xbPwC/qokYRby/Y5S40UUd7/jEARGXT7RZgpzTuDd1oZiCVrnrqJNPaMNdVv5MLeFdf1B7iIe5aa/fGouX7AO4SdKhZUdnJmCFAGvjC6S3JMZ2wAcUl+OHnssfmdj7XL50cLo27vjuzMtLAgSqi6N99m92WCF2s8J9aVzszX7Xz9OKZCeGsiVJp3/NdABKzSEAyM9xBD/5Vho894Sav+otpySHe3p6RUTgbB5Zu8VyZRZ/UtB3ueXxyo764yrc6qWIDqrehm84Xm9g+/jpIBzGPl07NUNJpdt/6Sgf9RIKXw/7XypO5yZfUcuFNGTxLfqjTNrtgLZNcjfav6sSdVXVcMPL//XNuRdKmVFaO76eV/oGMQGr1fGcCD+N+CpI7+Q+fCNB6VFWG4nZFuI/Iuw== averdagu@redhat.com"
2025-10-01 10:50:17.726857 | controller | }
2025-10-01 10:50:17.934925 | controller | changed:
2025-10-01 10:50:17.935027 | controller | {
2025-10-01 10:50:17.935058 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDq8l27xI+QlQVdS4djp9ogSoyrNE2+Ox6vKPdhSNL1J3PE5w+WCSvMz9A5gnNuH810zwbekEApbxTze/gLQJwBHA52CChfURpXrFaxY7ePXRElwKAL3mJfzBWY/c5jnNL9TCVmFJTGZkFZP3Nh+BMgZvL6xBkt3WKm6Uq18qzd9XeKcZusrA+O+uLv1fVeQnadY9RIqOCyeFYCzLWrUfTyE8x/XG0hAWIM7qpnF2cALQS2h9n4hW5ybiUN790H08wf9hFwEf5nxY9Z9dVkPFQiTSGKNBzmnCXU9skxS/xhpFjJ5duGSZdtAHe9O+nGZm9c67hxgtf8e5PDuqAdXEv2cf6e3VBAt+Bz8EKI3yosTj0oZHfwr42Yzb1l/SKy14Rggsrc9KAQlrGXan6+u2jcQqqx7l+SWmnpFiWTV9u5cWj2IgOhApOitmRBPYqk9rE2usfO0hLn/Pj/R/Nau4803e1/EikdLE7Ps95s9mX5jRDjAoUa2JwFF5RsVFyL910= ashigupt@ashigupt.remote.csb"
2025-10-01 10:50:17.935090 | controller | }
2025-10-01 10:50:18.146710 | controller | changed:
2025-10-01 10:50:18.146801 | controller | {
2025-10-01 10:50:18.146829 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-10-01 10:50:18.146851 | controller | }
2025-10-01 10:50:18.349094 | controller | changed:
2025-10-01 10:50:18.349260 | controller | {
2025-10-01 10:50:18.349290 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-10-01 10:50:18.349326 | controller | }
2025-10-01 10:50:18.574014 | controller | changed:
2025-10-01 10:50:18.574089 | controller | {
2025-10-01 10:50:18.574116 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-10-01 10:50:18.574137 | controller | }
2025-10-01 10:50:18.789449 | controller | changed:
2025-10-01 10:50:18.789530 | controller | {
2025-10-01 10:50:18.789556 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-10-01 10:50:18.789576 | controller | }
2025-10-01 10:50:19.008671 | controller | changed:
2025-10-01 10:50:19.008767 | controller | {
2025-10-01 10:50:19.008794 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQDZdI7t1cxYx65heVI24HTV4F7oQLW1zyfxHreL2TIJKxjyrUUKIFEUmTutcBlJRLNT2Eoix6x1sOw9YrchloCLcn//SGfTElr9mSc5jbjb7QXEU+zJMhtxyEJ1Po3CUGnj7ckiIXw7wcawZtrEOAQ9pH3ExYCJcEMiyNjRQZCxT3tPK+S4B95EWh5Fsrz9CkwpjNRPPH7LigCeQTM3Wc7r97utAslBUUvYceDSLA7rMgkitJE38b7rZBeYzsGQ8YYUBjTCtehqQXxCRjizbHWaaZkBU+N3zkKB6n/iCNGIO690NK7A/qb6msTijiz1PeuM8ThOsi9qXnbX5v0PoTpcFSojV7NHAQ71f0XXuS43FhZctT+Dcx44dT8Fb5vJu2cJGrk+qF8ZgJYNpRS7gPg0EG2EqjK7JMf9ULdjSu0r+KlqIAyLvtzT4eOnQipoKlb/WG5D/0ohKv7OMQ352ggfkBFIQsRXyyTCT98Ft9juqPuahi3CAQmP4H9dyE+7+Kz437PEtsxLmfm6naNmWi7Ee1DqWPwS8rEajsm4sNM4wW9gdBboJQtc0uZw0DfLj1I9r3Mc8Ol0jYtz0yNQDSzVLrGCaJlC311trU70tZ+ZkAVV6Mn8lOhSbj1cK0lvSr6ZK4dgqGl3I1eTZJJhbLNdg7UOVaiRx9543+C/p/As7w== brjackma@redhat.com"
2025-10-01 10:50:19.008815 | controller | }
2025-10-01 10:50:19.222427 | controller | changed:
2025-10-01 10:50:19.222510 | controller | {
2025-10-01 10:50:19.222537 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-10-01 10:50:19.222558 | controller | }
2025-10-01 10:50:19.440738 | controller | changed:
2025-10-01 10:50:19.440810 | controller | {
2025-10-01 10:50:19.440836 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-10-01 10:50:19.440858 | controller | }
2025-10-01 10:50:19.652621 | controller | changed:
2025-10-01 10:50:19.652710 | controller | {
2025-10-01 10:50:19.652737 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-10-01 10:50:19.652756 | controller | }
2025-10-01 10:50:19.670799 | 
2025-10-01 10:50:19.670863 | TASK [Set timezone to UTC]
2025-10-01 10:50:20.070468 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-10-01 10:50:20.076160 | 
2025-10-01 10:50:20.076228 | TASK [Create nodepool directory]
2025-10-01 10:50:20.287040 | controller | changed
2025-10-01 10:50:20.292509 | 
2025-10-01 10:50:20.292576 | TASK [Create nodepool sub_nodes file]
2025-10-01 10:50:20.854296 | controller | changed
2025-10-01 10:50:20.860440 | 
2025-10-01 10:50:20.860529 | TASK [Create nodepool sub_nodes_private file]
2025-10-01 10:50:21.428353 | controller | changed
2025-10-01 10:50:21.433417 | 
2025-10-01 10:50:21.433485 | LOOP [Populate nodepool sub_nodes file]
2025-10-01 10:50:21.462008 | 
2025-10-01 10:50:21.462145 | LOOP [Populate nodepool sub_nodes_private file]
2025-10-01 10:50:21.490369 | 
2025-10-01 10:50:21.490534 | TASK [Create nodepool primary file]
2025-10-01 10:50:21.513985 | controller | skipping: Conditional result was False
2025-10-01 10:50:21.519329 | 
2025-10-01 10:50:21.519424 | TASK [Create nodepool node_private for this node]
2025-10-01 10:50:22.104591 | controller | changed
2025-10-01 10:50:22.113205 | 
2025-10-01 10:50:22.113422 | LOOP [Copy ssh keys to nodepool directory]
2025-10-01 10:50:22.492764 | controller | ok: Item: id_rsa Runtime: 0:00:00.006450
2025-10-01 10:50:22.492949 | 
2025-10-01 10:50:22.679821 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.005454
2025-10-01 10:50:22.686181 | 
2025-10-01 10:50:22.686296 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-10-01 10:50:23.263160 | controller | changed
2025-10-01 10:50:23.268200 | 
2025-10-01 10:50:23.268264 | TASK [Validate sudoers config after edits]
2025-10-01 10:50:23.522474 | controller | /etc/sudoers: parsed OK
2025-10-01 10:50:23.522557 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-10-01 10:50:23.522572 | controller | /etc/sudoers.d/zuul: parsed OK
2025-10-01 10:50:23.522578 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-10-01 10:50:23.820821 | controller | ok: Runtime: 0:00:00.005873
2025-10-01 10:50:23.826741 | 
2025-10-01 10:50:23.826809 | TASK [Show the environment passed in to job shell scripts]
2025-10-01 10:50:24.041357 | controller | SHELL=/bin/bash
2025-10-01 10:50:24.041414 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-10-01 10:50:24.041425 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-10-01 10:50:24.041432 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/37/3237/9f82bbc44cf7fa37a2cf6305277fe598af8c6e39
2025-10-01 10:50:24.041439 | controller | PWD=/home/zuul
2025-10-01 10:50:24.041445 | controller | ZUUL_PIPELINE=github-check
2025-10-01 10:50:24.041450 | controller | LOGNAME=zuul
2025-10-01 10:50:24.041456 | controller | XDG_SESSION_TYPE=tty
2025-10-01 10:50:24.041510 | controller | _=/usr/bin/env
2025-10-01 10:50:24.041532 | controller | MOTD_SHOWN=pam
2025-10-01 10:50:24.041541 | controller | HOME=/home/zuul
2025-10-01 10:50:24.041546 | controller | LANG=en_US.UTF-8
2025-10-01 10:50:24.041552 | controller | SSH_CONNECTION=192.168.25.12 59090 192.168.25.188 22
2025-10-01 10:50:24.041558 | controller | TOX_TESTENV_PASSENV=ZUUL_UUID ZUUL_PROJECT ZUUL_SHORT_PROJECT_NAME ZUUL_PIPELINE ZUUL_VOTING WORKSPACE BUILD_TIMEOUT ZUUL_BRANCH ZUUL_CHANGES ZUUL_CHANGE_IDS ZUUL_CHANGE ZUUL_PATCHSET
2025-10-01 10:50:24.041567 | controller | ZUUL_CHANGE_IDS=3237,9f82bbc44cf7fa37a2cf6305277fe598af8c6e39
2025-10-01 10:50:24.041573 | controller | WORKSPACE=/home/zuul/workspace
2025-10-01 10:50:24.041579 | controller | XDG_SESSION_CLASS=user
2025-10-01 10:50:24.041584 | controller | SELINUX_ROLE_REQUESTED=
2025-10-01 10:50:24.041590 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-10-01 10:50:24.041595 | controller | USER=zuul
2025-10-01 10:50:24.041601 | controller | ZUUL_VOTING=True
2025-10-01 10:50:24.041606 | controller | BUILD_TIMEOUT=1800000
2025-10-01 10:50:24.041611 | controller | SELINUX_USE_CURRENT_RANGE=
2025-10-01 10:50:24.041616 | controller | SHLVL=1
2025-10-01 10:50:24.041622 | controller | ZUUL_PATCHSET=9f82bbc44cf7fa37a2cf6305277fe598af8c6e39
2025-10-01 10:50:24.041627 | controller | XDG_SESSION_ID=1
2025-10-01 10:50:24.041633 | controller | ZUUL_BRANCH=main
2025-10-01 10:50:24.041638 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-10-01 10:50:24.041644 | controller | SSH_CLIENT=192.168.25.12 59090 22
2025-10-01 10:50:24.041651 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-10-01 10:50:24.041657 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-10-01 10:50:24.041662 | controller | which_declare=declare -f
2025-10-01 10:50:24.041668 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-10-01 10:50:24.041674 | controller | SELINUX_LEVEL_REQUESTED=
2025-10-01 10:50:24.041680 | controller | ZUUL_CHANGE=3237
2025-10-01 10:50:24.041685 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-10-01 10:50:24.041690 | controller | ZUUL_UUID=8d5c77bb7ae4469297059e6cc9454a62
2025-10-01 10:50:24.041696 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-10-01 10:50:24.041702 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-10-01 10:50:24.041708 | controller | }
2025-10-01 10:50:24.355093 | controller | ok: Runtime: 0:00:00.006659
2025-10-01 10:50:24.361040 | 
2025-10-01 10:50:24.361133 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-10-01 10:50:24.379023 | controller | skipping: Conditional result was False
2025-10-01 10:50:24.385745 | 
2025-10-01 10:50:24.385830 | TASK [Symlink /home/zuul-worker/workspace]
2025-10-01 10:50:24.913054 | controller | skipping: Conditional result was False
2025-10-01 10:50:24.919400 | 
2025-10-01 10:50:24.919468 | TASK [Ensure legacy workspace directory]
2025-10-01 10:50:25.119861 | controller | changed
2025-10-01 10:50:25.142562 | 
2025-10-01 10:50:25.142662 | PLAY RECAP
2025-10-01 10:50:25.142710 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-01 10:50:25.142733 | 
2025-10-01 10:50:25.263051 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-01 10:50:25.263849 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-01 10:50:25.860524 | 
2025-10-01 10:50:25.860626 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-10-01 10:50:25.880857 | 
2025-10-01 10:50:25.880964 | TASK [Create zuul-output directory]
2025-10-01 10:50:26.235139 | controller | changed
2025-10-01 10:50:26.241366 | 
2025-10-01 10:50:26.241474 | TASK [Slurp Zuul inventory test]
2025-10-01 10:50:26.541547 | controller -> localhost | ok
2025-10-01 10:50:26.548533 | 
2025-10-01 10:50:26.548614 | TASK [Save zuul inventory]
2025-10-01 10:50:27.429648 | controller | changed
2025-10-01 10:50:27.434678 | 
2025-10-01 10:50:27.434766 | TASK [Save zuul vars without the change_message]
2025-10-01 10:50:28.051098 | controller | changed
2025-10-01 10:50:28.069968 | 
2025-10-01 10:50:28.070056 | PLAY RECAP
2025-10-01 10:50:28.070103 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-01 10:50:28.070146 | 
2025-10-01 10:50:28.143681 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-01 10:50:28.144550 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-01 10:50:28.694588 | 
2025-10-01 10:50:28.694694 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-10-01 10:50:28.715255 | 
2025-10-01 10:50:28.715344 | TASK [Read group_vars]
2025-10-01 10:50:28.735243 | controller | ok
2025-10-01 10:50:28.753092 | 
2025-10-01 10:50:28.753178 | TASK [cifmw_helpers : Check directory is available]
2025-10-01 10:50:29.087041 | controller | ok
2025-10-01 10:50:29.094852 | 
2025-10-01 10:50:29.094947 | TASK [cifmw_helpers : List dir in ansible user home]
2025-10-01 10:50:29.403094 | controller | var one
2025-10-01 10:50:29.404625 | controller | ls: cannot access '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/group_vars'$'\n': No such file or directory
2025-10-01 10:50:29.406001 | controller | ls: cannot access '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/group_vars': No such file or directory
2025-10-01 10:50:29.407360 | controller | ls: cannot access '/root/src/github.com/openstack-k8s-operators/ci-framework/group_vars': Permission denied
2025-10-01 10:50:29.409219 | controller | ls: cannot access '/workspace/src/github.com/openstack-k8s-operators/ci-framework/group_vars': No such file or directory
2025-10-01 10:50:29.619413 | controller | ERROR
2025-10-01 10:50:29.619552 | controller | {
2025-10-01 10:50:29.619583 | controller |   "delta": "0:00:00.010786",
2025-10-01 10:50:29.619605 | controller |   "end": "2025-10-01 10:50:29.409666",
2025-10-01 10:50:29.619626 | controller |   "msg": "non-zero return code",
2025-10-01 10:50:29.619650 | controller |   "rc": 2,
2025-10-01 10:50:29.619671 | controller |   "start": "2025-10-01 10:50:29.398880"
2025-10-01 10:50:29.619689 | controller | }
2025-10-01 10:50:29.619718 | controller | ERROR: Ignoring Errors
2025-10-01 10:50:29.625698 | 
2025-10-01 10:50:29.625765 | TASK [cifmw_helpers : List available files]
2025-10-01 10:50:30.148792 | controller | skipping: Conditional result was False
2025-10-01 10:50:30.154970 | 
2025-10-01 10:50:30.155222 | LOOP [cifmw_helpers : Read vars]
2025-10-01 10:50:30.174426 | 
2025-10-01 10:50:30.174760 | LOOP [cifmw_helpers : Call task to parse all files as fact]
2025-10-01 10:50:30.198578 | 
2025-10-01 10:50:30.198726 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-10-01 10:50:30.217836 | controller | ok
2025-10-01 10:50:30.265080 | 
2025-10-01 10:50:30.265321 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-01 10:50:30.289786 | controller | skipping: Conditional result was False
2025-10-01 10:50:30.295181 | 
2025-10-01 10:50:30.295255 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-01 10:50:30.627973 | controller | ok
2025-10-01 10:50:30.634340 | 
2025-10-01 10:50:30.634424 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-01 10:50:31.170703 | controller | ok
2025-10-01 10:50:31.182632 | 
2025-10-01 10:50:31.182713 | TASK [Prepare workspace]
2025-10-01 10:50:31.201492 | controller | ok
2025-10-01 10:50:31.223717 | 
2025-10-01 10:50:31.223811 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-01 10:50:31.506357 | controller | ok
2025-10-01 10:50:31.513893 | 
2025-10-01 10:50:31.514092 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-01 10:50:33.506358 | controller | Output suppressed because no_log was given
2025-10-01 10:50:33.515687 | 
2025-10-01 10:50:33.515760 | LOOP [Create zuul-output directory]
2025-10-01 10:50:33.709825 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-10-01 10:50:33.710024 | 
2025-10-01 10:50:33.885775 | controller | ok: "/home/zuul/zuul-output/logs"
2025-10-01 10:50:33.892617 | 
2025-10-01 10:50:33.892769 | TASK [Install required packages]
2025-10-01 10:51:59.366654 | controller | changed
2025-10-01 10:51:59.377097 | 
2025-10-01 10:51:59.377210 | TASK [Install venv]
2025-10-01 10:53:16.559584 | controller | changed
2025-10-01 10:53:16.583154 | 
2025-10-01 10:53:16.583218 | PLAY RECAP
2025-10-01 10:53:16.583262 | controller | ok: 9 changed: 5 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-10-01 10:53:16.583312 | 
2025-10-01 10:53:16.650920 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-01 10:53:16.651755 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-01 10:53:17.181574 | 
2025-10-01 10:53:17.181683 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-10-01 10:53:17.202973 | 
2025-10-01 10:53:17.203144 | TASK [Gather required facts]
2025-10-01 10:53:17.709318 | controller | ok
2025-10-01 10:53:17.714988 | 
2025-10-01 10:53:17.715071 | TASK [Load environment var if instructed to]
2025-10-01 10:53:17.738869 | controller | skipping: Conditional result was False
2025-10-01 10:53:17.744746 | 
2025-10-01 10:53:17.744824 | TASK [Run molecule]
2025-10-01 10:53:18.723826 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-10-01 10:53:18.793319 | controller | INFO     Performing prerun with role_name_check=0...
2025-10-01 10:53:35.515832 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/f9b5a8/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-01 10:53:35.516307 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/f9b5a8/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-01 10:53:35.516787 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/f9b5a8/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-01 10:53:35.517255 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/f9b5a8/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-01 10:53:35.517746 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+9f82bbc4 was found installed in /home/zuul/.cache/ansible-compat/f9b5a8/collections/ansible_collections, only the first one will be used, 1.0.0+9f82bbc4 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-01 10:53:35.518203 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/f9b5a8/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-01 10:53:35.518643 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/f9b5a8/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-01 10:53:35.519098 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/f9b5a8/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-01 10:53:35.519544 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/f9b5a8/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-01 10:53:35.520002 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/f9b5a8/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-01 10:53:35.520440 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/f9b5a8/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-01 10:53:35.520886 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/f9b5a8/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-01 10:53:35.521338 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/f9b5a8/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-01 10:53:35.521777 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/f9b5a8/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-01 10:53:35.522232 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/f9b5a8/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-01 10:53:35.531793 | controller | INFO     Running default > prepare
2025-10-01 10:53:36.257063 | controller |
2025-10-01 10:53:36.257144 | controller | PLAY [Prepare] *****************************************************************
2025-10-01 10:53:36.257248 | controller |
2025-10-01 10:53:36.257353 | controller | TASK [Gathering Facts] *********************************************************
2025-10-01 10:53:36.257455 | controller | Wednesday 01 October 2025  10:53:36 +0000 (0:00:00.022)       0:00:00.022 *****
2025-10-01 10:53:37.089174 | controller | ok: [instance]
2025-10-01 10:53:37.089236 | controller |
2025-10-01 10:53:37.089339 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-10-01 10:53:37.089450 | controller | Wednesday 01 October 2025  10:53:37 +0000 (0:00:00.832)       0:00:00.855 *****
2025-10-01 10:53:37.106999 | controller | skipping: [instance]
2025-10-01 10:53:37.107082 | controller |
2025-10-01 10:53:37.107191 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-10-01 10:53:37.107296 | controller | Wednesday 01 October 2025  10:53:37 +0000 (0:00:00.018)       0:00:00.873 *****
2025-10-01 10:53:37.150008 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-10-01 10:53:37.150077 | controller |
2025-10-01 10:53:37.150183 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-10-01 10:53:37.150296 | controller | Wednesday 01 October 2025  10:53:37 +0000 (0:00:00.042)       0:00:00.916 *****
2025-10-01 10:53:37.444106 | controller | ok: [instance]
2025-10-01 10:53:37.444170 | controller |
2025-10-01 10:53:37.444284 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-10-01 10:53:37.444379 | controller | Wednesday 01 October 2025  10:53:37 +0000 (0:00:00.293)       0:00:01.209 *****
2025-10-01 10:53:37.759258 | controller | ok: [instance]
2025-10-01 10:53:37.759327 | controller |
2025-10-01 10:53:37.759436 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-10-01 10:53:37.759571 | controller | Wednesday 01 October 2025  10:53:37 +0000 (0:00:00.315)       0:00:01.525 *****
2025-10-01 10:53:38.440150 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-10-01 10:53:38.440211 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-10-01 10:53:38.440328 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-10-01 10:53:38.440420 | controller |
2025-10-01 10:53:38.440541 | controller | TASK [Deploy repo-setup] *******************************************************
2025-10-01 10:53:38.440655 | controller | Wednesday 01 October 2025  10:53:38 +0000 (0:00:00.680)       0:00:02.206 *****
2025-10-01 10:53:38.501064 | controller |
2025-10-01 10:53:38.501154 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-10-01 10:53:38.501281 | controller | Wednesday 01 October 2025  10:53:38 +0000 (0:00:00.061)       0:00:02.267 *****
2025-10-01 10:53:39.055173 | controller | changed: [instance] => (item=tmp)
2025-10-01 10:53:39.055262 | controller | changed: [instance] => (item=artifacts/repositories)
2025-10-01 10:53:39.055381 | controller | changed: [instance] => (item=venv/repo_setup)
2025-10-01 10:53:39.055483 | controller |
2025-10-01 10:53:39.055619 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-10-01 10:53:39.055728 | controller | Wednesday 01 October 2025  10:53:39 +0000 (0:00:00.553)       0:00:02.821 *****
2025-10-01 10:53:39.872693 | controller | ok: [instance]
2025-10-01 10:53:39.872751 | controller |
2025-10-01 10:53:39.873076 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-10-01 10:53:41.065262 | controller | Wednesday 01 October 2025  10:53:39 +0000 (0:00:00.817)       0:00:03.638 *****
2025-10-01 10:53:41.065300 | controller | changed: [instance]
2025-10-01 10:53:49.017565 | controller |
2025-10-01 10:53:49.017606 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-10-01 10:53:49.017617 | controller | Wednesday 01 October 2025  10:53:41 +0000 (0:00:01.192)       0:00:04.830 *****
2025-10-01 10:53:49.017628 | controller | changed: [instance]
2025-10-01 10:53:49.789253 | controller |
2025-10-01 10:53:49.789303 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-10-01 10:53:49.789312 | controller | Wednesday 01 October 2025  10:53:49 +0000 (0:00:07.952)       0:00:12.783 *****
2025-10-01 10:53:49.789323 | controller | changed: [instance]
2025-10-01 10:53:49.815306 | controller |
2025-10-01 10:53:49.815350 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-10-01 10:53:49.815358 | controller | Wednesday 01 October 2025  10:53:49 +0000 (0:00:00.771)       0:00:13.554 *****
2025-10-01 10:53:49.815370 | controller | skipping: [instance]
2025-10-01 10:53:50.689916 | controller |
2025-10-01 10:53:50.689972 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-10-01 10:53:50.689982 | controller | Wednesday 01 October 2025  10:53:49 +0000 (0:00:00.026)       0:00:13.580 *****
2025-10-01 10:53:50.689994 | controller | changed: [instance]
2025-10-01 10:53:50.729735 | controller |
2025-10-01 10:53:50.729766 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-10-01 10:53:50.729775 | controller | Wednesday 01 October 2025  10:53:50 +0000 (0:00:00.874)       0:00:14.455 *****
2025-10-01 10:53:50.729788 | controller | skipping: [instance]
2025-10-01 10:53:50.768624 | controller |
2025-10-01 10:53:50.768659 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-10-01 10:53:50.768668 | controller | Wednesday 01 October 2025  10:53:50 +0000 (0:00:00.039)       0:00:14.494 *****
2025-10-01 10:53:50.768682 | controller | skipping: [instance]
2025-10-01 10:53:50.768708 | controller |
2025-10-01 10:53:50.768718 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-10-01 10:53:50.769439 | controller | Wednesday 01 October 2025  10:53:50 +0000 (0:00:00.039)       0:00:14.534 *****
2025-10-01 10:53:50.808606 | controller | skipping: [instance]
2025-10-01 10:53:50.808808 | controller |
2025-10-01 10:53:50.809009 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-10-01 10:53:50.809187 | controller | Wednesday 01 October 2025  10:53:50 +0000 (0:00:00.039)       0:00:14.574 *****
2025-10-01 10:53:51.428095 | controller | changed: [instance]
2025-10-01 10:53:51.909631 | controller |
2025-10-01 10:53:51.909665 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-10-01 10:53:51.909674 | controller | Wednesday 01 October 2025  10:53:51 +0000 (0:00:00.618)       0:00:15.192 *****
2025-10-01 10:53:51.909685 | controller | changed: [instance]
2025-10-01 10:53:51.909712 | controller |
2025-10-01 10:53:51.910002 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-10-01 10:53:51.941350 | controller | Wednesday 01 October 2025  10:53:51 +0000 (0:00:00.482)       0:00:15.675 *****
2025-10-01 10:53:51.941386 | controller | skipping: [instance]
2025-10-01 10:53:51.972499 | controller |
2025-10-01 10:53:51.972531 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-10-01 10:53:51.972541 | controller | Wednesday 01 October 2025  10:53:51 +0000 (0:00:00.031)       0:00:15.707 *****
2025-10-01 10:53:51.972551 | controller | skipping: [instance]
2025-10-01 10:53:52.005165 | controller |
2025-10-01 10:53:52.005191 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-10-01 10:53:52.005200 | controller | Wednesday 01 October 2025  10:53:51 +0000 (0:00:00.031)       0:00:15.738 *****
2025-10-01 10:53:52.005217 | controller | skipping: [instance]
2025-10-01 10:53:52.050034 | controller |
2025-10-01 10:53:52.050050 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-10-01 10:53:52.050057 | controller | Wednesday 01 October 2025  10:53:52 +0000 (0:00:00.032)       0:00:15.770 *****
2025-10-01 10:53:52.050066 | controller | ok: [instance]
2025-10-01 10:53:52.083284 | controller |
2025-10-01 10:53:52.083303 | controller | TASK [repo_setup : Create download directory] **********************************
2025-10-01 10:53:52.083310 | controller | Wednesday 01 October 2025  10:53:52 +0000 (0:00:00.044)       0:00:15.815 *****
2025-10-01 10:53:52.083319 | controller | skipping: [instance]
2025-10-01 10:53:52.112647 | controller |
2025-10-01 10:53:52.112666 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-10-01 10:53:52.112674 | controller | Wednesday 01 October 2025  10:53:52 +0000 (0:00:00.033)       0:00:15.849 *****
2025-10-01 10:53:52.112691 | controller | skipping: [instance]
2025-10-01 10:53:52.139748 | controller |
2025-10-01 10:53:52.139766 | controller | TASK [Download the RPM] ********************************************************
2025-10-01 10:53:52.139773 | controller | Wednesday 01 October 2025  10:53:52 +0000 (0:00:00.029)       0:00:15.878 *****
2025-10-01 10:53:52.139781 | controller | skipping: [instance]
2025-10-01 10:53:52.169219 | controller |
2025-10-01 10:53:52.169238 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-10-01 10:53:52.169246 | controller | Wednesday 01 October 2025  10:53:52 +0000 (0:00:00.027)       0:00:15.905 *****
2025-10-01 10:53:52.169255 | controller | skipping: [instance]
2025-10-01 10:53:52.202569 | controller |
2025-10-01 10:53:52.202594 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-10-01 10:53:52.202603 | controller | Wednesday 01 October 2025  10:53:52 +0000 (0:00:00.029)       0:00:15.935 *****
2025-10-01 10:53:52.202615 | controller | skipping: [instance]
2025-10-01 10:53:52.234586 | controller |
2025-10-01 10:53:52.234611 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-10-01 10:53:52.234619 | controller | Wednesday 01 October 2025  10:53:52 +0000 (0:00:00.033)       0:00:15.968 *****
2025-10-01 10:53:52.234629 | controller | skipping: [instance]
2025-10-01 10:53:52.234691 | controller |
2025-10-01 10:53:52.234705 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-10-01 10:53:52.234715 | controller | Wednesday 01 October 2025  10:53:52 +0000 (0:00:00.032)       0:00:16.000 *****
2025-10-01 10:53:52.269044 | controller | skipping: [instance]
2025-10-01 10:53:52.269485 | controller |
2025-10-01 10:53:52.269886 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-10-01 10:53:52.270213 | controller | Wednesday 01 October 2025  10:53:52 +0000 (0:00:00.030)       0:00:16.031 *****
2025-10-01 10:53:52.495349 | controller | ok: [instance]
2025-10-01 10:53:52.729750 | controller |
2025-10-01 10:53:52.729784 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-10-01 10:53:52.729792 | controller | Wednesday 01 October 2025  10:53:52 +0000 (0:00:00.229)       0:00:16.260 *****
2025-10-01 10:53:52.729803 | controller | changed: [instance]
2025-10-01 10:53:52.964258 | controller |
2025-10-01 10:53:52.964292 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-10-01 10:53:52.964301 | controller | Wednesday 01 October 2025  10:53:52 +0000 (0:00:00.234)       0:00:16.495 *****
2025-10-01 10:53:52.964311 | controller | changed: [instance]
2025-10-01 10:53:52.986529 | controller |
2025-10-01 10:53:52.986562 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-10-01 10:53:52.986570 | controller | Wednesday 01 October 2025  10:53:52 +0000 (0:00:00.234)       0:00:16.729 *****
2025-10-01 10:53:52.986580 | controller | skipping: [instance]
2025-10-01 10:53:53.009811 | controller |
2025-10-01 10:53:53.009834 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-10-01 10:53:53.009842 | controller | Wednesday 01 October 2025  10:53:52 +0000 (0:00:00.022)       0:00:16.752 *****
2025-10-01 10:53:53.009852 | controller | skipping: [instance]
2025-10-01 10:53:53.033993 | controller |
2025-10-01 10:53:53.034012 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-10-01 10:53:53.034020 | controller | Wednesday 01 October 2025  10:53:53 +0000 (0:00:00.023)       0:00:16.775 *****
2025-10-01 10:53:53.034029 | controller | skipping: [instance]
2025-10-01 10:53:53.059473 | controller |
2025-10-01 10:53:53.059492 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-10-01 10:53:53.059502 | controller | Wednesday 01 October 2025  10:53:53 +0000 (0:00:00.024)       0:00:16.800 *****
2025-10-01 10:53:53.059512 | controller | skipping: [instance]
2025-10-01 10:53:53.083632 | controller |
2025-10-01 10:53:53.083700 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-10-01 10:53:53.083716 | controller | Wednesday 01 October 2025  10:53:53 +0000 (0:00:00.025)       0:00:16.825 *****
2025-10-01 10:53:53.083730 | controller | skipping: [instance]
2025-10-01 10:53:53.106934 | controller |
2025-10-01 10:53:53.106962 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-10-01 10:53:53.106996 | controller | Wednesday 01 October 2025  10:53:53 +0000 (0:00:00.024)       0:00:16.849 *****
2025-10-01 10:53:53.107006 | controller | skipping: [instance]
2025-10-01 10:53:53.124453 | controller |
2025-10-01 10:53:53.124471 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-10-01 10:53:53.124478 | controller | Wednesday 01 October 2025  10:53:53 +0000 (0:00:00.023)       0:00:16.872 *****
2025-10-01 10:53:53.124486 | controller | skipping: [instance]
2025-10-01 10:53:53.154674 | controller |
2025-10-01 10:53:53.154715 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-10-01 10:53:53.154723 | controller | Wednesday 01 October 2025  10:53:53 +0000 (0:00:00.017)       0:00:16.890 *****
2025-10-01 10:53:53.154735 | controller | skipping: [instance]
2025-10-01 10:53:53.154760 | controller |
2025-10-01 10:53:53.154768 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-10-01 10:53:53.154864 | controller | Wednesday 01 October 2025  10:53:53 +0000 (0:00:00.030)       0:00:16.920 *****
2025-10-01 10:53:53.172852 | controller | skipping: [instance]
2025-10-01 10:53:53.194696 | controller |
2025-10-01 10:53:53.194745 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-10-01 10:53:53.194755 | controller | Wednesday 01 October 2025  10:53:53 +0000 (0:00:00.018)       0:00:16.938 *****
2025-10-01 10:53:53.194769 | controller | skipping: [instance]
2025-10-01 10:53:53.226118 | controller |
2025-10-01 10:53:53.226160 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-10-01 10:53:53.226168 | controller | Wednesday 01 October 2025  10:53:53 +0000 (0:00:00.021)       0:00:16.960 *****
2025-10-01 10:53:53.226179 | controller | skipping: [instance]
2025-10-01 10:53:53.257544 | controller |
2025-10-01 10:53:53.257587 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-10-01 10:53:53.257596 | controller | Wednesday 01 October 2025  10:53:53 +0000 (0:00:00.031)       0:00:16.991 *****
2025-10-01 10:53:53.257607 | controller | skipping: [instance]
2025-10-01 10:53:53.288551 | controller |
2025-10-01 10:53:53.288590 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-10-01 10:53:53.288599 | controller | Wednesday 01 October 2025  10:53:53 +0000 (0:00:00.031)       0:00:17.023 *****
2025-10-01 10:53:53.288610 | controller | skipping: [instance]
2025-10-01 10:53:53.323488 | controller |
2025-10-01 10:53:53.323543 | controller | TASK [test_deps : Install additional packages] *********************************
2025-10-01 10:53:53.323554 | controller | Wednesday 01 October 2025  10:53:53 +0000 (0:00:00.030)       0:00:17.054 *****
2025-10-01 10:53:53.323565 | controller | skipping: [instance]
2025-10-01 10:54:47.671784 | controller |
2025-10-01 10:54:47.671856 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-10-01 10:54:47.671865 | controller | Wednesday 01 October 2025  10:53:53 +0000 (0:00:00.035)       0:00:17.089 *****
2025-10-01 10:54:47.671880 | controller | ok: [instance]
2025-10-01 10:54:49.008462 | controller |
2025-10-01 10:54:49.008541 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-10-01 10:54:49.008553 | controller | Wednesday 01 October 2025  10:54:47 +0000 (0:00:54.347)       0:01:11.436 *****
2025-10-01 10:54:49.008567 | controller | ok: [instance]
2025-10-01 10:54:52.428235 | controller |
2025-10-01 10:54:52.428286 | controller | TASK [test_deps : Install extra packages] **************************************
2025-10-01 10:54:52.428295 | controller | Wednesday 01 October 2025  10:54:49 +0000 (0:00:01.336)       0:01:12.773 *****
2025-10-01 10:54:52.428307 | controller | changed: [instance]
2025-10-01 10:54:52.642438 | controller |
2025-10-01 10:54:52.642480 | controller | TASK [libvirt_manager : Ensure output directory exists] ************************
2025-10-01 10:54:52.642489 | controller | Wednesday 01 October 2025  10:54:52 +0000 (0:00:03.420)       0:01:16.193 *****
2025-10-01 10:54:52.642500 | controller | ok: [instance]
2025-10-01 10:54:52.846299 | controller |
2025-10-01 10:54:52.846335 | controller | TASK [libvirt_manager : Get vmx/svm extensions from /proc/cpuinfo] *************
2025-10-01 10:54:52.846343 | controller | Wednesday 01 October 2025  10:54:52 +0000 (0:00:00.214)       0:01:16.407 *****
2025-10-01 10:54:52.846354 | controller | changed: [instance]
2025-10-01 10:54:53.046674 | controller |
2025-10-01 10:54:53.046707 | controller | TASK [libvirt_manager : Check if KVM is enabled] *******************************
2025-10-01 10:54:53.046716 | controller | Wednesday 01 October 2025  10:54:52 +0000 (0:00:00.203)       0:01:16.611 *****
2025-10-01 10:54:53.046726 | controller | ok: [instance]
2025-10-01 10:54:53.081686 | controller |
2025-10-01 10:54:53.081746 | controller | TASK [libvirt_manager : Fail if KVM not enabled] *******************************
2025-10-01 10:54:53.081766 | controller | Wednesday 01 October 2025  10:54:53 +0000 (0:00:00.200)       0:01:16.812 *****
2025-10-01 10:54:53.081780 | controller | skipping: [instance]
2025-10-01 10:54:53.081805 | controller |
2025-10-01 10:54:53.081957 | controller | TASK [libvirt_manager : Check if VMX virtualization] ***************************
2025-10-01 10:54:53.082000 | controller | Wednesday 01 October 2025  10:54:53 +0000 (0:00:00.035)       0:01:16.847 *****
2025-10-01 10:54:53.104056 | controller | skipping: [instance]
2025-10-01 10:54:53.127592 | controller |
2025-10-01 10:54:53.127615 | controller | TASK [libvirt_manager : Check if SVM virtualization] ***************************
2025-10-01 10:54:53.127623 | controller | Wednesday 01 October 2025  10:54:53 +0000 (0:00:00.022)       0:01:16.869 *****
2025-10-01 10:54:53.127633 | controller | ok: [instance]
2025-10-01 10:54:53.158742 | controller |
2025-10-01 10:54:53.158762 | controller | TASK [libvirt_manager : Enable VMX virtualization] *****************************
2025-10-01 10:54:53.158770 | controller | Wednesday 01 October 2025  10:54:53 +0000 (0:00:00.023)       0:01:16.893 *****
2025-10-01 10:54:53.158780 | controller | skipping: [instance]
2025-10-01 10:56:21.330773 | controller |
2025-10-01 10:56:21.330823 | controller | TASK [libvirt_manager : Install packages required for using KVM] ***************
2025-10-01 10:56:21.330832 | controller | Wednesday 01 October 2025  10:54:53 +0000 (0:00:00.031)       0:01:16.924 *****
2025-10-01 10:56:21.330844 | controller | changed: [instance]
2025-10-01 10:56:21.560101 | controller |
2025-10-01 10:56:21.560144 | controller | TASK [libvirt_manager : Create rules.d polkit folder] **************************
2025-10-01 10:56:21.560152 | controller | Wednesday 01 October 2025  10:56:21 +0000 (0:01:28.170)       0:02:45.094 *****
2025-10-01 10:56:21.560164 | controller | changed: [instance]
2025-10-01 10:56:21.964531 | controller |
2025-10-01 10:56:21.964569 | controller | TASK [libvirt_manager : Enable UNIX socket PolicyKit auth] *********************
2025-10-01 10:56:21.964578 | controller | Wednesday 01 October 2025  10:56:21 +0000 (0:00:00.230)       0:02:45.325 *****
2025-10-01 10:56:21.964589 | controller | changed: [instance]
2025-10-01 10:56:21.964602 | controller |
2025-10-01 10:56:21.964608 | controller | TASK [libvirt_manager : Restart service polkit service] ************************
2025-10-01 10:56:21.964616 | controller | Wednesday 01 October 2025  10:56:21 +0000 (0:00:00.404)       0:02:45.730 *****
2025-10-01 10:56:22.631620 | controller | changed: [instance]
2025-10-01 10:56:22.854437 | controller |
2025-10-01 10:56:22.854478 | controller | TASK [libvirt_manager : Remove directory for service override] *****************
2025-10-01 10:56:22.854499 | controller | Wednesday 01 October 2025  10:56:22 +0000 (0:00:00.666)       0:02:46.397 *****
2025-10-01 10:56:22.854551 | controller | ok: [instance]
2025-10-01 10:56:22.854604 | controller |
2025-10-01 10:56:22.854631 | controller | TASK [libvirt_manager : Reload systemctl and start/enable virtproxyd.service] ***
2025-10-01 10:56:22.854758 | controller | Wednesday 01 October 2025  10:56:22 +0000 (0:00:00.223)       0:02:46.620 *****
2025-10-01 10:56:23.591332 | controller | ok: [instance]
2025-10-01 10:56:24.509756 | controller |
2025-10-01 10:56:24.509799 | controller | TASK [libvirt_manager : Ensure firewalld service is up] ************************
2025-10-01 10:56:24.509808 | controller | Wednesday 01 October 2025  10:56:23 +0000 (0:00:00.736)       0:02:47.356 *****
2025-10-01 10:56:24.509820 | controller | changed: [instance]
2025-10-01 10:56:24.591184 | controller |
2025-10-01 10:56:24.591215 | controller | TASK [libvirt_manager : Ensure libvirt modular driver daemons are started.] ****
2025-10-01 10:56:24.591223 | controller | Wednesday 01 October 2025  10:56:24 +0000 (0:00:00.917)       0:02:48.274 *****
2025-10-01 10:56:24.591235 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=qemu)
2025-10-01 10:56:24.959147 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=interface)
2025-10-01 10:56:24.959189 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=network)
2025-10-01 10:56:24.959197 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nodedev)
2025-10-01 10:56:24.959203 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nwfilter)
2025-10-01 10:56:24.959209 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=secret)
2025-10-01 10:56:24.959215 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=storage)
2025-10-01 10:56:24.959220 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=proxy)
2025-10-01 10:56:24.959226 | controller |
2025-10-01 10:56:24.959232 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for qemu.] *********
2025-10-01 10:56:24.959238 | controller | Wednesday 01 October 2025  10:56:24 +0000 (0:00:00.081)       0:02:48.356 *****
2025-10-01 10:56:24.959249 | controller | changed: [instance]
2025-10-01 10:56:25.316433 | controller |
2025-10-01 10:56:25.316468 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for qemu.] **********
2025-10-01 10:56:25.316477 | controller | Wednesday 01 October 2025  10:56:24 +0000 (0:00:00.368)       0:02:48.724 *****
2025-10-01 10:56:25.316498 | controller | changed: [instance]
2025-10-01 10:56:25.666705 | controller |
2025-10-01 10:56:25.666747 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for qemu.] **************
2025-10-01 10:56:25.666756 | controller | Wednesday 01 October 2025  10:56:25 +0000 (0:00:00.357)       0:02:49.082 *****
2025-10-01 10:56:25.666768 | controller | changed: [instance]
2025-10-01 10:56:26.020875 | controller |
2025-10-01 10:56:26.020908 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for interface.] ****
2025-10-01 10:56:26.020917 | controller | Wednesday 01 October 2025  10:56:25 +0000 (0:00:00.350)       0:02:49.432 *****
2025-10-01 10:56:26.020940 | controller | changed: [instance]
2025-10-01 10:56:26.020960 | controller |
2025-10-01 10:56:26.021192 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for interface.] *****
2025-10-01 10:56:26.377066 | controller | Wednesday 01 October 2025  10:56:26 +0000 (0:00:00.354)       0:02:49.786 *****
2025-10-01 10:56:26.377104 | controller | changed: [instance]
2025-10-01 10:56:26.714783 | controller |
2025-10-01 10:56:26.714817 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for interface.] *********
2025-10-01 10:56:26.714825 | controller | Wednesday 01 October 2025  10:56:26 +0000 (0:00:00.355)       0:02:50.142 *****
2025-10-01 10:56:26.714835 | controller | changed: [instance]
2025-10-01 10:56:26.714859 | controller |
2025-10-01 10:56:26.714865 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for network.] ******
2025-10-01 10:56:26.714873 | controller | Wednesday 01 October 2025  10:56:26 +0000 (0:00:00.337)       0:02:50.480 *****
2025-10-01 10:56:27.057892 | controller | changed: [instance]
2025-10-01 10:56:27.438898 | controller |
2025-10-01 10:56:27.438931 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for network.] *******
2025-10-01 10:56:27.438939 | controller | Wednesday 01 October 2025  10:56:27 +0000 (0:00:00.342)       0:02:50.823 *****
2025-10-01 10:56:27.438951 | controller | changed: [instance]
2025-10-01 10:56:27.792145 | controller |
2025-10-01 10:56:27.792181 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for network.] ***********
2025-10-01 10:56:27.792189 | controller | Wednesday 01 October 2025  10:56:27 +0000 (0:00:00.380)       0:02:51.204 *****
2025-10-01 10:56:27.792200 | controller | changed: [instance]
2025-10-01 10:56:28.145750 | controller |
2025-10-01 10:56:28.145783 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nodedev.] ******
2025-10-01 10:56:28.145791 | controller | Wednesday 01 October 2025  10:56:27 +0000 (0:00:00.353)       0:02:51.557 *****
2025-10-01 10:56:28.145802 | controller | changed: [instance]
2025-10-01 10:56:28.496057 | controller |
2025-10-01 10:56:28.496098 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nodedev.] *******
2025-10-01 10:56:28.496106 | controller | Wednesday 01 October 2025  10:56:28 +0000 (0:00:00.353)       0:02:51.911 *****
2025-10-01 10:56:28.496117 | controller | changed: [instance]
2025-10-01 10:56:28.869133 | controller |
2025-10-01 10:56:28.869167 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nodedev.] ***********
2025-10-01 10:56:28.869176 | controller | Wednesday 01 October 2025  10:56:28 +0000 (0:00:00.350)       0:02:52.261 *****
2025-10-01 10:56:28.869187 | controller | changed: [instance]
2025-10-01 10:56:29.213914 | controller |
2025-10-01 10:56:29.213947 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nwfilter.] *****
2025-10-01 10:56:29.213956 | controller | Wednesday 01 October 2025  10:56:28 +0000 (0:00:00.372)       0:02:52.634 *****
2025-10-01 10:56:29.213967 | controller | changed: [instance]
2025-10-01 10:56:29.555004 | controller |
2025-10-01 10:56:29.555037 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nwfilter.] ******
2025-10-01 10:56:29.555046 | controller | Wednesday 01 October 2025  10:56:29 +0000 (0:00:00.344)       0:02:52.979 *****
2025-10-01 10:56:29.555056 | controller | changed: [instance]
2025-10-01 10:56:29.905100 | controller |
2025-10-01 10:56:29.905131 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nwfilter.] **********
2025-10-01 10:56:29.905140 | controller | Wednesday 01 October 2025  10:56:29 +0000 (0:00:00.341)       0:02:53.320 *****
2025-10-01 10:56:29.905150 | controller | changed: [instance]
2025-10-01 10:56:30.241197 | controller |
2025-10-01 10:56:30.241229 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for secret.] *******
2025-10-01 10:56:30.241239 | controller | Wednesday 01 October 2025  10:56:29 +0000 (0:00:00.350)       0:02:53.670 *****
2025-10-01 10:56:30.241250 | controller | changed: [instance]
2025-10-01 10:56:30.583990 | controller |
2025-10-01 10:56:30.584022 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for secret.] ********
2025-10-01 10:56:30.584031 | controller | Wednesday 01 October 2025  10:56:30 +0000 (0:00:00.336)       0:02:54.006 *****
2025-10-01 10:56:30.584042 | controller | changed: [instance]
2025-10-01 10:56:30.933622 | controller |
2025-10-01 10:56:30.933666 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for secret.] ************
2025-10-01 10:56:30.933677 | controller | Wednesday 01 October 2025  10:56:30 +0000 (0:00:00.342)       0:02:54.349 *****
2025-10-01 10:56:30.933689 | controller | changed: [instance]
2025-10-01 10:56:30.933713 | controller |
2025-10-01 10:56:30.933932 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for storage.] ******
2025-10-01 10:56:31.287481 | controller | Wednesday 01 October 2025  10:56:30 +0000 (0:00:00.349)       0:02:54.699 *****
2025-10-01 10:56:31.287540 | controller | changed: [instance]
2025-10-01 10:56:31.641297 | controller |
2025-10-01 10:56:31.641334 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for storage.] *******
2025-10-01 10:56:31.641349 | controller | Wednesday 01 October 2025  10:56:31 +0000 (0:00:00.353)       0:02:55.053 *****
2025-10-01 10:56:31.641360 | controller | changed: [instance]
2025-10-01 10:56:31.985011 | controller |
2025-10-01 10:56:31.985046 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for storage.] ***********
2025-10-01 10:56:31.985054 | controller | Wednesday 01 October 2025  10:56:31 +0000 (0:00:00.353)       0:02:55.406 *****
2025-10-01 10:56:31.985066 | controller | changed: [instance]
2025-10-01 10:56:32.332739 | controller |
2025-10-01 10:56:32.332772 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for proxy.] ********
2025-10-01 10:56:32.332781 | controller | Wednesday 01 October 2025  10:56:31 +0000 (0:00:00.343)       0:02:55.750 *****
2025-10-01 10:56:32.332791 | controller | changed: [instance]
2025-10-01 10:56:32.667887 | controller |
2025-10-01 10:56:32.667923 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for proxy.] *********
2025-10-01 10:56:32.667932 | controller | Wednesday 01 October 2025  10:56:32 +0000 (0:00:00.347)       0:02:56.098 *****
2025-10-01 10:56:32.667944 | controller | changed: [instance]
2025-10-01 10:56:32.999694 | controller |
2025-10-01 10:56:32.999724 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for proxy.] *************
2025-10-01 10:56:32.999733 | controller | Wednesday 01 October 2025  10:56:32 +0000 (0:00:00.335)       0:02:56.433 *****
2025-10-01 10:56:32.999750 | controller | changed: [instance]
2025-10-01 10:56:33.017492 | controller |
2025-10-01 10:56:33.017558 | controller | TASK [libvirt_manager : Manage service for older releases] *********************
2025-10-01 10:56:33.017567 | controller | Wednesday 01 October 2025  10:56:32 +0000 (0:00:00.331)       0:02:56.765 *****
2025-10-01 10:56:33.017578 | controller | skipping: [instance]
2025-10-01 10:56:33.303703 | controller |
2025-10-01 10:56:33.303735 | controller | TASK [libvirt_manager : Get libvirt group users] *******************************
2025-10-01 10:56:33.303743 | controller | Wednesday 01 October 2025  10:56:33 +0000 (0:00:00.017)       0:02:56.783 *****
2025-10-01 10:56:33.303754 | controller | ok: [instance]
2025-10-01 10:56:33.739641 | controller |
2025-10-01 10:56:33.739677 | controller | TASK [libvirt_manager : Add user if not exists in libvirt group] ***************
2025-10-01 10:56:33.739686 | controller | Wednesday 01 October 2025  10:56:33 +0000 (0:00:00.285)       0:02:57.069 *****
2025-10-01 10:56:33.739696 | controller | changed: [instance]
2025-10-01 10:56:33.739722 | controller |
2025-10-01 10:56:33.739985 | controller | TASK [libvirt_manager : Allow QEMU on home directory for the storage access] ***
2025-10-01 10:56:34.050321 | controller | Wednesday 01 October 2025  10:56:33 +0000 (0:00:00.435)       0:02:57.504 *****
2025-10-01 10:56:34.050357 | controller | changed: [instance]
2025-10-01 10:56:34.332163 | controller |
2025-10-01 10:56:34.332199 | controller | TASK [libvirt_manager : Inject system connection parameters in bashrc] *********
2025-10-01 10:56:34.332209 | controller | Wednesday 01 October 2025  10:56:34 +0000 (0:00:00.311)       0:02:57.815 *****
2025-10-01 10:56:34.332222 | controller | [WARNING]: Reset is not implemented for this connection
2025-10-01 10:56:34.343621 | controller | changed: [instance]
2025-10-01 10:56:35.959630 | controller |
2025-10-01 10:56:35.959691 | controller | TASK [libvirt_manager : Ensure we reload user env] *****************************
2025-10-01 10:56:35.959700 | controller | Wednesday 01 October 2025  10:56:34 +0000 (0:00:00.277)       0:02:58.092 *****
2025-10-01 10:56:35.959706 | controller |
2025-10-01 10:56:35.959712 | controller | TASK [discover_latest_image : Get latest image] ********************************
2025-10-01 10:56:35.959718 | controller | Wednesday 01 October 2025  10:56:34 +0000 (0:00:00.016)       0:02:58.109 *****
2025-10-01 10:56:35.959731 | controller | changed: [instance]
2025-10-01 10:56:35.986445 | controller |
2025-10-01 10:56:35.986471 | controller | TASK [discover_latest_image : Export facts accordingly] ************************
2025-10-01 10:56:35.986479 | controller | Wednesday 01 October 2025  10:56:35 +0000 (0:00:01.615)       0:02:59.724 *****
2025-10-01 10:56:35.986489 | controller | ok: [instance]
2025-10-01 10:56:36.007423 | controller |
2025-10-01 10:56:36.007441 | controller | TASK [Load networking definition] **********************************************
2025-10-01 10:56:36.007449 | controller | Wednesday 01 October 2025  10:56:35 +0000 (0:00:00.027)       0:02:59.752 *****
2025-10-01 10:56:36.007459 | controller | ok: [instance]
2025-10-01 10:56:36.039064 | controller |
2025-10-01 10:56:36.039087 | controller | TASK [libvirt_manager : Import layout generator if needed] *********************
2025-10-01 10:56:36.039094 | controller | Wednesday 01 October 2025  10:56:36 +0000 (0:00:00.020)       0:02:59.773 *****
2025-10-01 10:56:36.039105 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/generate_layout.yml for instance
2025-10-01 10:56:36.073976 | controller |
2025-10-01 10:56:36.073997 | controller | TASK [libvirt_manager : Chose right parameter for layout definition] ***********
2025-10-01 10:56:36.074005 | controller | Wednesday 01 October 2025  10:56:36 +0000 (0:00:00.031)       0:02:59.804 *****
2025-10-01 10:56:36.074023 | controller | ok: [instance]
2025-10-01 10:56:36.135581 | controller |
2025-10-01 10:56:36.135609 | controller | TASK [libvirt_manager : Patch the layout if needed] ****************************
2025-10-01 10:56:36.135617 | controller | Wednesday 01 October 2025  10:56:36 +0000 (0:00:00.034)       0:02:59.839 *****
2025-10-01 10:56:36.135628 | controller | skipping: [instance]
2025-10-01 10:56:36.586576 | controller |
2025-10-01 10:56:36.586609 | controller | TASK [libvirt_manager : Enable forwarding in the libvirt zone] *****************
2025-10-01 10:56:36.586617 | controller | Wednesday 01 October 2025  10:56:36 +0000 (0:00:00.061)       0:02:59.901 *****
2025-10-01 10:56:36.586628 | controller | changed: [instance]
2025-10-01 10:56:37.089634 | controller |
2025-10-01 10:56:37.089670 | controller | TASK [libvirt_manager : Enable masquerading for public traffic] ****************
2025-10-01 10:56:37.089685 | controller | Wednesday 01 October 2025  10:56:36 +0000 (0:00:00.451)       0:03:00.352 *****
2025-10-01 10:56:37.089698 | controller | changed: [instance]
2025-10-01 10:56:37.089725 | controller |
2025-10-01 10:56:37.089733 | controller | TASK [libvirt_manager : Ensure firewalld is restarts] **************************
2025-10-01 10:56:37.089742 | controller | Wednesday 01 October 2025  10:56:37 +0000 (0:00:00.495)       0:03:00.847 *****
2025-10-01 10:56:37.090046 | controller |
2025-10-01 10:56:37.846220 | controller | RUNNING HANDLER [libvirt_manager : Restart firewalld] **************************
2025-10-01 10:56:37.846250 | controller | Wednesday 01 October 2025  10:56:37 +0000 (0:00:00.007)       0:03:00.855 *****
2025-10-01 10:56:37.846262 | controller | changed: [instance]
2025-10-01 10:56:37.874665 | controller |
2025-10-01 10:56:37.874711 | controller | TASK [Deploy virtualbmc] *******************************************************
2025-10-01 10:56:37.874722 | controller | Wednesday 01 October 2025  10:56:37 +0000 (0:00:00.756)       0:03:01.612 *****
2025-10-01 10:56:37.874735 | controller | skipping: [instance]
2025-10-01 10:56:37.874759 | controller |
2025-10-01 10:56:37.874839 | controller | TASK [libvirt_manager : Let the project know we have vbmc available] ***********
2025-10-01 10:56:37.874965 | controller | Wednesday 01 October 2025  10:56:37 +0000 (0:00:00.028)       0:03:01.640 *****
2025-10-01 10:56:37.903584 | controller | skipping: [instance]
2025-10-01 10:56:38.455063 | controller |
2025-10-01 10:56:38.455094 | controller | TASK [libvirt_manager : Create needed workload directory] **********************
2025-10-01 10:56:38.455103 | controller | Wednesday 01 October 2025  10:56:37 +0000 (0:00:00.028)       0:03:01.669 *****
2025-10-01 10:56:38.455120 | controller | changed: [instance] => (item=workload)
2025-10-01 10:56:38.872431 | controller | changed: [instance] => (item=reproducer-inventory)
2025-10-01 10:56:38.872462 | controller | changed: [instance] => (item=volumes)
2025-10-01 10:56:38.872471 | controller |
2025-10-01 10:56:38.872478 | controller | TASK [libvirt_manager : Allow QEMU on workload directory] **********************
2025-10-01 10:56:38.872484 | controller | Wednesday 01 October 2025  10:56:38 +0000 (0:00:00.551)       0:03:02.220 *****
2025-10-01 10:56:38.872494 | controller | changed: [instance] => (item=workload)
2025-10-01 10:56:38.944003 | controller | changed: [instance] => (item=volumes)
2025-10-01 10:56:38.944032 | controller |
2025-10-01 10:56:38.944040 | controller | TASK [libvirt_manager : Generate networking data] ******************************
2025-10-01 10:56:38.944046 | controller | Wednesday 01 October 2025  10:56:38 +0000 (0:00:00.417)       0:03:02.638 *****
2025-10-01 10:56:38.944056 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/generate_networking_data.yml for instance
2025-10-01 10:56:38.961681 | controller |
2025-10-01 10:56:38.961721 | controller | TASK [libvirt_manager : Ensure fact is existing, and empty] ********************
2025-10-01 10:56:38.961732 | controller | Wednesday 01 October 2025  10:56:38 +0000 (0:00:00.071)       0:03:02.709 *****
2025-10-01 10:56:38.961745 | controller | ok: [instance]
2025-10-01 10:56:39.173027 | controller |
2025-10-01 10:56:39.173060 | controller | TASK [libvirt_manager : Check if we get an existing interfaces-info.yml] *******
2025-10-01 10:56:39.173068 | controller | Wednesday 01 October 2025  10:56:38 +0000 (0:00:00.017)       0:03:02.727 *****
2025-10-01 10:56:39.173078 | controller | ok: [instance]
2025-10-01 10:56:39.201588 | controller |
2025-10-01 10:56:39.201618 | controller | TASK [libvirt_manager : Load file if exists] ***********************************
2025-10-01 10:56:39.201628 | controller | Wednesday 01 October 2025  10:56:39 +0000 (0:00:00.211)       0:03:02.938 *****
2025-10-01 10:56:39.201641 | controller | skipping: [instance]
2025-10-01 10:56:39.201817 | controller |
2025-10-01 10:56:39.201830 | controller | TASK [libvirt_manager : Update fact with existing content] *********************
2025-10-01 10:56:39.201841 | controller | Wednesday 01 October 2025  10:56:39 +0000 (0:00:00.028)       0:03:02.967 *****
2025-10-01 10:56:39.229560 | controller | skipping: [instance]
2025-10-01 10:56:39.280280 | controller |
2025-10-01 10:56:39.280311 | controller | TASK [libvirt_manager : Generate VM list] **************************************
2025-10-01 10:56:39.280320 | controller | Wednesday 01 October 2025  10:56:39 +0000 (0:00:00.027)       0:03:02.995 *****
2025-10-01 10:56:39.280337 | controller | ok: [instance]
2025-10-01 10:56:39.354055 | controller |
2025-10-01 10:56:39.354090 | controller | TASK [libvirt_manager : Generate/update mapping all nodes] *********************
2025-10-01 10:56:39.354107 | controller | Wednesday 01 October 2025  10:56:39 +0000 (0:00:00.050)       0:03:03.045 *****
2025-10-01 10:56:39.354120 | controller | ok: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
2025-10-01 10:56:39.387542 | controller |
2025-10-01 10:56:39.387576 | controller | TASK [libvirt_manager : Append baremetal nodes if needed] **********************
2025-10-01 10:56:39.387585 | controller | Wednesday 01 October 2025  10:56:39 +0000 (0:00:00.073)       0:03:03.119 *****
2025-10-01 10:56:39.387595 | controller | skipping: [instance]
2025-10-01 10:56:39.740393 | controller |
2025-10-01 10:56:39.740428 | controller | TASK [libvirt_manager : Dump MAC mapping] **************************************
2025-10-01 10:56:39.740437 | controller | Wednesday 01 October 2025  10:56:39 +0000 (0:00:00.033)       0:03:03.153 *****
2025-10-01 10:56:39.740448 | controller | changed: [instance]
2025-10-01 10:56:39.805083 | controller |
2025-10-01 10:56:39.805113 | controller | TASK [libvirt_manager : Inject all VMs in the inventory] ***********************
2025-10-01 10:56:39.805123 | controller | Wednesday 01 October 2025  10:56:39 +0000 (0:00:00.352)       0:03:03.505 *****
2025-10-01 10:56:39.805135 | controller | changed: [instance] => (item=Adding compute-0 to computes)
2025-10-01 10:56:39.827989 | controller |
2025-10-01 10:56:39.828016 | controller | TASK [networking_mapper : Check for Networking Definition file existence] ******
2025-10-01 10:56:39.828025 | controller | Wednesday 01 October 2025  10:56:39 +0000 (0:00:00.064)       0:03:03.570 *****
2025-10-01 10:56:39.828037 | controller | skipping: [instance]
2025-10-01 10:56:39.850461 | controller |
2025-10-01 10:56:39.850488 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2025-10-01 10:56:39.850496 | controller | Wednesday 01 October 2025  10:56:39 +0000 (0:00:00.022)       0:03:03.593 *****
2025-10-01 10:56:39.850533 | controller | skipping: [instance]
2025-10-01 10:56:39.873150 | controller |
2025-10-01 10:56:39.873172 | controller | TASK [networking_mapper : Check for interfaces info file existence] ************
2025-10-01 10:56:39.873179 | controller | Wednesday 01 October 2025  10:56:39 +0000 (0:00:00.022)       0:03:03.616 *****
2025-10-01 10:56:39.873189 | controller | skipping: [instance]
2025-10-01 10:56:39.896258 | controller |
2025-10-01 10:56:39.896282 | controller | TASK [networking_mapper : Load the interfaces info from file] ******************
2025-10-01 10:56:39.896292 | controller | Wednesday 01 October 2025  10:56:39 +0000 (0:00:00.022)       0:03:03.639 *****
2025-10-01 10:56:39.896303 | controller | skipping: [instance]
2025-10-01 10:56:39.914279 | controller |
2025-10-01 10:56:39.914313 | controller | TASK [networking_mapper : Ensure local fact is empty] **************************
2025-10-01 10:56:39.914322 | controller | Wednesday 01 October 2025  10:56:39 +0000 (0:00:00.022)       0:03:03.662 *****
2025-10-01 10:56:39.914332 | controller | ok: [instance]
2025-10-01 10:56:39.987099 | controller |
2025-10-01 10:56:39.987135 | controller | TASK [networking_mapper : Set the input Networking Definition and patch it if needed] ***
2025-10-01 10:56:39.987143 | controller | Wednesday 01 October 2025  10:56:39 +0000 (0:00:00.017)       0:03:03.679 *****
2025-10-01 10:56:39.987157 | 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, 'tools': {'multus': {'ranges': [{'start': 30, 'end': 39}]}, 'netconfig': {'ranges': [{'start': '192.168.122.40', 'end': '192.168.122.49'}]}, 'metallb': {'ranges': [{'start': '192.168.122.80', 'end': '192.168.122.90'}]}}}, 'internalapi': {'network': '172.17.0.0/24', 'gateway': '172.17.0.1', 'vlan': 20, 'mtu': 1496, 'tools': {'metallb': {'ranges': [{'start': '172.17.0.90', 'end': '172.17.0.100'}]}, 'netconfig': {'ranges': [{'start': '172.17.0.40', 'end': '172.17.0.49'}]}, 'multus': {'ranges': [{'start': 50, 'end': 59}]}}}, 'storage': {'network': '172.18.0.0/24', 'vlan': 21, 'mtu': 1496, 'tools': {'netconfig': {'ranges': [{'start': '172.18.0.40', 'end': '172.18.0.49'}]}}}, 'tenant': {'network': '172.19.0.0/24', 'gateway-v4': '172.19.0.1', 'search-domain': 'tenant.example.local', 'dns-v4': ['8.8.8.8', '172.19.0.1'], 'tools': {'netconfig': {'ranges': [{'start': '172.19.0.40', 'end': '172.19.0.49'}]}}, 'vlan': 22, 'mtu': 1496}}, 'group-templates': {'computes': {'network-template': {'range': {'start': 10, 'end': 15}}, 'networks': {'ctlplane': {}, 'internalapi': {}, 'tenant': {}, 'storage': {}}}, 'sl-computes': {'network-template': {'range': {'start': 16, 'length': 2}}, 'networks': {'ctlplane': {}, 'internalapi': {}, 'tenant': {}, 'storage': {}}}, 'baremetals': {'networks': {'ctlplane': {'range': '192.168.122.20-192.168.122.24'}, 'internalapi': {'range': '20-24'}, 'tenant': {'range': {'start': 20, 'length': 5}}, 'storage': {'range': {'start': 20, 'length': 5}}}}}})
2025-10-01 10:56:40.003870 | controller |
2025-10-01 10:56:40.003901 | controller | TASK [networking_mapper : Gather facts if requested] ***************************
2025-10-01 10:56:40.003910 | controller | Wednesday 01 October 2025  10:56:39 +0000 (0:00:00.072)       0:03:03.752 *****
2025-10-01 10:56:40.003921 | controller | skipping: [instance]
2025-10-01 10:56:40.209234 | controller |
2025-10-01 10:56:40.209264 | controller | TASK [networking_mapper : Ensure CI infrastructure dir exists] *****************
2025-10-01 10:56:40.209273 | controller | Wednesday 01 October 2025  10:56:40 +0000 (0:00:00.017)       0:03:03.769 *****
2025-10-01 10:56:40.209283 | controller | changed: [instance]
2025-10-01 10:56:40.614836 | controller |
2025-10-01 10:56:40.614867 | controller | TASK [networking_mapper : Write the Networking Definition to file] *************
2025-10-01 10:56:40.614876 | controller | Wednesday 01 October 2025  10:56:40 +0000 (0:00:00.205)       0:03:03.974 *****
2025-10-01 10:56:40.614886 | controller | changed: [instance]
2025-10-01 10:56:40.664588 | controller |
2025-10-01 10:56:40.664626 | controller | TASK [networking_mapper : Call the networking mapper] **************************
2025-10-01 10:56:40.664635 | controller | Wednesday 01 October 2025  10:56:40 +0000 (0:00:00.405)       0:03:04.380 *****
2025-10-01 10:56:40.664648 | controller | ok: [instance]
2025-10-01 10:56:40.690413 | controller |
2025-10-01 10:56:40.690438 | controller | TASK [networking_mapper : Set networking mapper facts] *************************
2025-10-01 10:56:40.690447 | controller | Wednesday 01 October 2025  10:56:40 +0000 (0:00:00.049)       0:03:04.430 *****
2025-10-01 10:56:40.690458 | controller | ok: [instance]
2025-10-01 10:56:41.067005 | controller |
2025-10-01 10:56:41.067041 | controller | TASK [networking_mapper : Write the Networking Environment Definition to file] ***
2025-10-01 10:56:41.067050 | controller | Wednesday 01 October 2025  10:56:40 +0000 (0:00:00.026)       0:03:04.456 *****
2025-10-01 10:56:41.067067 | controller | changed: [instance]
2025-10-01 10:56:41.133489 | controller |
2025-10-01 10:56:41.133563 | controller | TASK [libvirt_manager : Manage networks if needed] *****************************
2025-10-01 10:56:41.133577 | controller | Wednesday 01 October 2025  10:56:41 +0000 (0:00:00.376)       0:03:04.832 *****
2025-10-01 10:56:41.133591 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_networks.yml for instance
2025-10-01 10:56:41.172928 | controller |
2025-10-01 10:56:41.172961 | controller | TASK [libvirt_manager : Define the localized variables for performing the tasks here.] ***
2025-10-01 10:56:41.172969 | controller | Wednesday 01 October 2025  10:56:41 +0000 (0:00:00.066)       0:03:04.899 *****
2025-10-01 10:56:41.172980 | controller | ok: [instance] => (item=public)
2025-10-01 10:56:41.917598 | controller |
2025-10-01 10:56:41.917630 | controller | TASK [libvirt_manager : Ensure networks are defined] ***************************
2025-10-01 10:56:41.917639 | controller | Wednesday 01 October 2025  10:56:41 +0000 (0:00:00.039)       0:03:04.938 *****
2025-10-01 10:56:41.917649 | controller | changed: [instance] => (item=cifmw-public)
2025-10-01 10:56:41.917949 | controller |
2025-10-01 10:56:42.263550 | controller | TASK [libvirt_manager : Ensure networks are created/started] *******************
2025-10-01 10:56:42.263583 | controller | Wednesday 01 October 2025  10:56:41 +0000 (0:00:00.745)       0:03:05.683 *****
2025-10-01 10:56:42.263596 | controller | ok: [instance] => (item=cifmw-public)
2025-10-01 10:56:42.491277 | controller |
2025-10-01 10:56:42.491309 | controller | TASK [libvirt_manager : Ensure networks are active] ****************************
2025-10-01 10:56:42.491317 | controller | Wednesday 01 October 2025  10:56:42 +0000 (0:00:00.345)       0:03:06.029 *****
2025-10-01 10:56:42.491332 | controller | ok: [instance] => (item=cifmw-public)
2025-10-01 10:56:42.713967 | controller |
2025-10-01 10:56:42.714002 | controller | TASK [libvirt_manager : Ensure networks enabled to autostart] ******************
2025-10-01 10:56:42.714011 | controller | Wednesday 01 October 2025  10:56:42 +0000 (0:00:00.227)       0:03:06.257 *****
2025-10-01 10:56:42.714022 | controller | changed: [instance] => (item=cifmw-public)
2025-10-01 10:56:42.765744 | controller |
2025-10-01 10:56:42.765778 | controller | TASK [libvirt_manager : Add a dummy interface to bridges if required] **********
2025-10-01 10:56:42.765788 | controller | Wednesday 01 October 2025  10:56:42 +0000 (0:00:00.222)       0:03:06.479 *****
2025-10-01 10:56:42.765801 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_networks_dummy_interfaces.yml for instance
2025-10-01 10:56:42.948823 | controller |
2025-10-01 10:56:42.948857 | controller | TASK [libvirt_manager : Fetch present bridge interfaces] ***********************
2025-10-01 10:56:42.948867 | controller | Wednesday 01 October 2025  10:56:42 +0000 (0:00:00.051)       0:03:06.531 *****
2025-10-01 10:56:42.948877 | controller | ok: [instance]
2025-10-01 10:56:43.156207 | controller |
2025-10-01 10:56:43.156241 | controller | TASK [libvirt_manager : Fetch bridges ports link info] *************************
2025-10-01 10:56:43.156249 | controller | Wednesday 01 October 2025  10:56:42 +0000 (0:00:00.183)       0:03:06.714 *****
2025-10-01 10:56:43.156260 | controller | ok: [instance] => (item=cifmw-public)
2025-10-01 10:56:43.221293 | controller |
2025-10-01 10:56:43.221329 | controller | TASK [Create dummy interfaces to ensure bridges are UP] ************************
2025-10-01 10:56:43.221339 | controller | Wednesday 01 October 2025  10:56:43 +0000 (0:00:00.207)       0:03:06.921 *****
2025-10-01 10:56:43.221352 | controller |
2025-10-01 10:56:43.253790 | controller | TASK [ci_nmstate : Ensure we have needed facts] ********************************
2025-10-01 10:56:43.253818 | controller | Wednesday 01 October 2025  10:56:43 +0000 (0:00:00.065)       0:03:06.987 *****
2025-10-01 10:56:43.253830 | controller | skipping: [instance]
2025-10-01 10:56:52.419403 | controller |
2025-10-01 10:56:52.419438 | controller | TASK [ci_nmstate : Install required packages on instance] **********************
2025-10-01 10:56:52.419448 | controller | Wednesday 01 October 2025  10:56:43 +0000 (0:00:00.032)       0:03:07.019 *****
2025-10-01 10:56:52.419459 | controller | changed: [instance]
2025-10-01 10:56:52.629294 | controller |
2025-10-01 10:56:52.629325 | controller | TASK [ci_nmstate : Create the target NMstate dump directory] *******************
2025-10-01 10:56:52.629333 | controller | Wednesday 01 October 2025  10:56:52 +0000 (0:00:09.165)       0:03:16.184 *****
2025-10-01 10:56:52.629344 | controller | changed: [instance]
2025-10-01 10:56:53.021747 | controller |
2025-10-01 10:56:53.021777 | controller | TASK [ci_nmstate : Save nmstate state for instance] ****************************
2025-10-01 10:56:53.021786 | controller | Wednesday 01 October 2025  10:56:52 +0000 (0:00:00.210)       0:03:16.395 *****
2025-10-01 10:56:53.021796 | controller | changed: [instance]
2025-10-01 10:56:54.740118 | controller |
2025-10-01 10:56:54.740153 | controller | TASK [ci_nmstate : Apply the desidered state on instance] **********************
2025-10-01 10:56:54.740163 | controller | Wednesday 01 October 2025  10:56:53 +0000 (0:00:00.392)       0:03:16.787 *****
2025-10-01 10:56:54.740176 | controller | changed: [instance]
2025-10-01 10:56:55.076924 | controller |
2025-10-01 10:56:55.076955 | controller | TASK [ci_nmstate : Save nmstate debugging data for instance] *******************
2025-10-01 10:56:55.076969 | controller | Wednesday 01 October 2025  10:56:54 +0000 (0:00:01.718)       0:03:18.505 *****
2025-10-01 10:56:55.076980 | controller | changed: [instance]
2025-10-01 10:56:55.105628 | controller |
2025-10-01 10:56:55.105657 | controller | TASK [Create extra network configuration] **************************************
2025-10-01 10:56:55.105667 | controller | Wednesday 01 October 2025  10:56:55 +0000 (0:00:00.337)       0:03:18.842 *****
2025-10-01 10:56:55.105679 | controller | skipping: [instance]
2025-10-01 10:56:55.105687 | controller |
2025-10-01 10:56:55.105694 | controller | TASK [libvirt_manager : Ensure extra networks is in correct zone] **************
2025-10-01 10:56:55.105702 | controller | Wednesday 01 October 2025  10:56:55 +0000 (0:00:00.028)       0:03:18.871 *****
2025-10-01 10:56:55.131347 | controller | skipping: [instance]
2025-10-01 10:56:55.510709 | controller |
2025-10-01 10:56:55.510746 | controller | TASK [libvirt_manager : Refresh networking facts on host] **********************
2025-10-01 10:56:55.510755 | controller | Wednesday 01 October 2025  10:56:55 +0000 (0:00:00.025)       0:03:18.897 *****
2025-10-01 10:56:55.510765 | controller | ok: [instance]
2025-10-01 10:56:55.626249 | controller |
2025-10-01 10:56:55.626280 | controller | TASK [libvirt_manager : Build needed network/dnsmasq related content] **********
2025-10-01 10:56:55.626288 | controller | Wednesday 01 October 2025  10:56:55 +0000 (0:00:00.379)       0:03:19.276 *****
2025-10-01 10:56:55.626299 | controller | ok: [instance] => (item=cifmw-public)
2025-10-01 10:56:56.844614 | controller |
2025-10-01 10:56:56.844648 | controller | TASK [dnsmasq : Install needed packages] ***************************************
2025-10-01 10:56:56.844656 | controller | Wednesday 01 October 2025  10:56:55 +0000 (0:00:00.115)       0:03:19.391 *****
2025-10-01 10:56:56.844668 | controller | ok: [instance]
2025-10-01 10:57:00.358149 | controller |
2025-10-01 10:57:00.358181 | controller | TASK [dnsmasq : Ensure SELinux knows about the new files and directories] ******
2025-10-01 10:57:00.358190 | controller | Wednesday 01 October 2025  10:56:56 +0000 (0:00:01.218)       0:03:20.610 *****
2025-10-01 10:57:00.358200 | controller | changed: [instance] => (item={'target': '/etc/cifmw-dnsmasq.conf', 'setype': 'dnsmasq_etc_t'})
2025-10-01 10:57:00.572493 | controller | changed: [instance] => (item={'target': '/etc/cifmw-dnsmasq.d(/.*)?', 'setype': 'dnsmasq_etc_t'})
2025-10-01 10:57:00.572552 | controller | changed: [instance] => (item={'target': '/var/run/cifmw-dnsmasq.pid', 'setype': 'dnsmasq_var_run_t'})
2025-10-01 10:57:00.572564 | controller |
2025-10-01 10:57:00.572570 | controller | TASK [dnsmasq : Manage configuration directory] ********************************
2025-10-01 10:57:00.572576 | controller | Wednesday 01 October 2025  10:57:00 +0000 (0:00:03.513)       0:03:24.123 *****
2025-10-01 10:57:00.572586 | controller | changed: [instance]
2025-10-01 10:57:00.961976 | controller |
2025-10-01 10:57:00.962003 | controller | TASK [dnsmasq : Manage systemd unit file] **************************************
2025-10-01 10:57:00.962011 | controller | Wednesday 01 October 2025  10:57:00 +0000 (0:00:00.214)       0:03:24.338 *****
2025-10-01 10:57:00.962021 | controller | changed: [instance]
2025-10-01 10:57:01.411368 | controller |
2025-10-01 10:57:01.411401 | controller | TASK [dnsmasq : Manage base configuration file] ********************************
2025-10-01 10:57:01.411409 | controller | Wednesday 01 October 2025  10:57:00 +0000 (0:00:00.389)       0:03:24.727 *****
2025-10-01 10:57:01.411419 | controller | changed: [instance]
2025-10-01 10:57:01.446435 | controller |
2025-10-01 10:57:01.446456 | controller | TASK [dnsmasq : Render listener configuration] *********************************
2025-10-01 10:57:01.446464 | controller | Wednesday 01 October 2025  10:57:01 +0000 (0:00:00.449)       0:03:25.177 *****
2025-10-01 10:57:01.446473 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/listener.yml for instance
2025-10-01 10:57:01.910001 | controller |
2025-10-01 10:57:01.910033 | controller | TASK [dnsmasq : Create listener configuration file] ****************************
2025-10-01 10:57:01.910041 | controller | Wednesday 01 October 2025  10:57:01 +0000 (0:00:00.035)       0:03:25.212 *****
2025-10-01 10:57:01.910052 | controller | changed: [instance]
2025-10-01 10:57:01.939534 | controller |
2025-10-01 10:57:01.939573 | controller | TASK [dnsmasq : Remove listener configuration file] ****************************
2025-10-01 10:57:01.939582 | controller | Wednesday 01 October 2025  10:57:01 +0000 (0:00:00.463)       0:03:25.675 *****
2025-10-01 10:57:01.939591 | controller | skipping: [instance]
2025-10-01 10:57:01.977742 | controller |
2025-10-01 10:57:01.977767 | controller | TASK [dnsmasq : Render dns configuration] **************************************
2025-10-01 10:57:01.977774 | controller | Wednesday 01 October 2025  10:57:01 +0000 (0:00:00.029)       0:03:25.705 *****
2025-10-01 10:57:01.977786 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/dns.yml for instance
2025-10-01 10:57:02.423100 | controller |
2025-10-01 10:57:02.423139 | controller | TASK [dnsmasq : Create dns configuration file] *********************************
2025-10-01 10:57:02.423147 | controller | Wednesday 01 October 2025  10:57:01 +0000 (0:00:00.038)       0:03:25.743 *****
2025-10-01 10:57:02.423157 | controller | changed: [instance]
2025-10-01 10:57:02.450943 | controller |
2025-10-01 10:57:02.450982 | controller | TASK [dnsmasq : Remove dns configuration file] *********************************
2025-10-01 10:57:02.450998 | controller | Wednesday 01 October 2025  10:57:02 +0000 (0:00:00.445)       0:03:26.188 *****
2025-10-01 10:57:02.451010 | controller | skipping: [instance]
2025-10-01 10:57:02.701604 | controller |
2025-10-01 10:57:02.701636 | controller | TASK [dnsmasq : Add localhost addresses from defined dnsmasq listen addresses to loopback interface] ***
2025-10-01 10:57:02.701644 | controller | Wednesday 01 October 2025  10:57:02 +0000 (0:00:00.027)       0:03:26.216 *****
2025-10-01 10:57:02.701654 | controller | ok: [instance] => (item=127.0.0.2)
2025-10-01 10:57:03.471079 | controller |
2025-10-01 10:57:03.471109 | controller | TASK [dnsmasq : Enable and start service] **************************************
2025-10-01 10:57:03.471117 | controller | Wednesday 01 October 2025  10:57:02 +0000 (0:00:00.250)       0:03:26.467 *****
2025-10-01 10:57:03.471127 | controller | changed: [instance]
2025-10-01 10:57:03.488258 | controller |
2025-10-01 10:57:03.488285 | controller | TASK [dnsmasq : Stop service] **************************************************
2025-10-01 10:57:03.488293 | controller | Wednesday 01 October 2025  10:57:03 +0000 (0:00:00.769)       0:03:27.236 *****
2025-10-01 10:57:03.488303 | controller | skipping: [instance]
2025-10-01 10:57:03.505136 | controller |
2025-10-01 10:57:03.505159 | controller | TASK [dnsmasq : Remove unit file] **********************************************
2025-10-01 10:57:03.505167 | controller | Wednesday 01 October 2025  10:57:03 +0000 (0:00:00.017)       0:03:27.254 *****
2025-10-01 10:57:03.505177 | controller | skipping: [instance]
2025-10-01 10:57:03.530663 | controller |
2025-10-01 10:57:03.530691 | controller | TASK [dnsmasq : Remove main configuration files] *******************************
2025-10-01 10:57:03.530701 | controller | Wednesday 01 October 2025  10:57:03 +0000 (0:00:00.016)       0:03:27.271 *****
2025-10-01 10:57:03.530713 | controller | skipping: [instance] => (item=/etc/cifmw-dnsmasq.conf)
2025-10-01 10:57:03.530743 | controller | skipping: [instance] => (item=/etc/cifmw-dnsmasq.d)
2025-10-01 10:57:03.530751 | controller | skipping: [instance]
2025-10-01 10:57:03.530760 | controller |
2025-10-01 10:57:03.530952 | controller | TASK [Create dnsmasq networks] *************************************************
2025-10-01 10:57:03.598658 | controller | Wednesday 01 October 2025  10:57:03 +0000 (0:00:00.025)       0:03:27.296 *****
2025-10-01 10:57:03.598690 | controller |
2025-10-01 10:57:03.598797 | controller | TASK [dnsmasq : Assert mandatory parameter] ************************************
2025-10-01 10:57:03.598820 | controller | Wednesday 01 October 2025  10:57:03 +0000 (0:00:00.068)       0:03:27.364 *****
2025-10-01 10:57:03.628250 | controller | ok: [instance] => changed=false
2025-10-01 10:57:03.668632 | controller |   msg: All assertions passed
2025-10-01 10:57:03.668667 | controller |
2025-10-01 10:57:03.668675 | controller | TASK [dnsmasq : Assert mandatory parameters for new network] *******************
2025-10-01 10:57:03.668681 | controller | Wednesday 01 October 2025  10:57:03 +0000 (0:00:00.029)       0:03:27.393 *****
2025-10-01 10:57:03.668691 | controller | ok: [instance] => changed=false
2025-10-01 10:57:03.668711 | controller |   msg: All assertions passed
2025-10-01 10:57:03.668733 | controller |
2025-10-01 10:57:03.668979 | controller | TASK [dnsmasq : Create network] ************************************************
2025-10-01 10:57:04.106761 | controller | Wednesday 01 October 2025  10:57:03 +0000 (0:00:00.040)       0:03:27.434 *****
2025-10-01 10:57:04.106796 | controller | changed: [instance]
2025-10-01 10:57:04.124146 | controller |
2025-10-01 10:57:04.124169 | controller | TASK [dnsmasq : Remove network] ************************************************
2025-10-01 10:57:04.124178 | controller | Wednesday 01 October 2025  10:57:04 +0000 (0:00:00.437)       0:03:27.872 *****
2025-10-01 10:57:04.124187 | controller | skipping: [instance]
2025-10-01 10:57:04.146171 | controller |
2025-10-01 10:57:04.146194 | controller | TASK [dnsmasq : Remove dhcp host files] ****************************************
2025-10-01 10:57:04.146203 | controller | Wednesday 01 October 2025  10:57:04 +0000 (0:00:00.017)       0:03:27.890 *****
2025-10-01 10:57:04.146213 | controller | skipping: [instance]
2025-10-01 10:57:04.463977 | controller |
2025-10-01 10:57:04.464006 | controller | TASK [libvirt_manager : Ensure network is in correct zone] *********************
2025-10-01 10:57:04.464014 | controller | Wednesday 01 October 2025  10:57:04 +0000 (0:00:00.021)       0:03:27.912 *****
2025-10-01 10:57:04.464032 | controller | changed: [instance] => (item=cifmw-public)
2025-10-01 10:57:04.492130 | controller |
2025-10-01 10:57:04.492161 | controller | TASK [libvirt_manager : Extract IP address from network bridges] ***************
2025-10-01 10:57:04.492168 | controller | Wednesday 01 October 2025  10:57:04 +0000 (0:00:00.317)       0:03:28.229 *****
2025-10-01 10:57:04.492178 | 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-10-01 10:57:04.807430 | controller |
2025-10-01 10:57:04.807459 | controller | TASK [libvirt_manager : Extract IP address from network bridges] ***************
2025-10-01 10:57:04.807467 | controller | Wednesday 01 October 2025  10:57:04 +0000 (0:00:00.028)       0:03:28.257 *****
2025-10-01 10:57:04.807477 | controller | ok: [instance]
2025-10-01 10:57:04.843306 | controller |
2025-10-01 10:57:04.843326 | controller | TASK [libvirt_manager : Set network_bridge_info fact with network and address] ***
2025-10-01 10:57:04.843333 | controller | Wednesday 01 October 2025  10:57:04 +0000 (0:00:00.315)       0:03:28.573 *****
2025-10-01 10:57:04.843343 | controller | ok: [instance]
2025-10-01 10:57:05.203643 | controller |
2025-10-01 10:57:05.203673 | controller | TASK [libvirt_manager : Output _network_data] **********************************
2025-10-01 10:57:05.203686 | controller | Wednesday 01 October 2025  10:57:04 +0000 (0:00:00.036)       0:03:28.609 *****
2025-10-01 10:57:05.203697 | controller | changed: [instance]
2025-10-01 10:57:05.557007 | controller |
2025-10-01 10:57:05.557038 | controller | TASK [libvirt_manager : Output pub_net] ****************************************
2025-10-01 10:57:05.557047 | controller | Wednesday 01 October 2025  10:57:05 +0000 (0:00:00.360)       0:03:28.969 *****
2025-10-01 10:57:05.557056 | controller | changed: [instance]
2025-10-01 10:57:05.902067 | controller |
2025-10-01 10:57:05.902098 | controller | TASK [libvirt_manager : Output _cifmw_libvirt_manager_layout] ******************
2025-10-01 10:57:05.902107 | controller | Wednesday 01 October 2025  10:57:05 +0000 (0:00:00.353)       0:03:29.322 *****
2025-10-01 10:57:05.902117 | controller | changed: [instance]
2025-10-01 10:57:05.999341 | controller |
2025-10-01 10:57:05.999359 | controller | TASK [libvirt_manager : Expose patch for networking_mapper] ********************
2025-10-01 10:57:05.999367 | controller | Wednesday 01 October 2025  10:57:05 +0000 (0:00:00.344)       0:03:29.667 *****
2025-10-01 10:57:05.999376 | controller | ok: [instance]
2025-10-01 10:57:06.345454 | controller |
2025-10-01 10:57:06.345484 | controller | TASK [libvirt_manager : Save networking_mapper patch] **************************
2025-10-01 10:57:06.345492 | controller | Wednesday 01 October 2025  10:57:05 +0000 (0:00:00.097)       0:03:29.765 *****
2025-10-01 10:57:06.345502 | controller | changed: [instance]
2025-10-01 10:57:06.369643 | controller |
2025-10-01 10:57:06.369688 | controller | TASK [networking_mapper : Check for Networking Definition file existence] ******
2025-10-01 10:57:06.369699 | controller | Wednesday 01 October 2025  10:57:06 +0000 (0:00:00.345)       0:03:30.111 *****
2025-10-01 10:57:06.369711 | controller | skipping: [instance]
2025-10-01 10:57:06.369733 | controller |
2025-10-01 10:57:06.369740 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2025-10-01 10:57:06.369749 | controller | Wednesday 01 October 2025  10:57:06 +0000 (0:00:00.024)       0:03:30.135 *****
2025-10-01 10:57:06.392668 | controller | skipping: [instance]
2025-10-01 10:57:06.392759 | controller |
2025-10-01 10:57:06.392869 | controller | TASK [networking_mapper : Check for interfaces info file existence] ************
2025-10-01 10:57:06.393000 | controller | Wednesday 01 October 2025  10:57:06 +0000 (0:00:00.023)       0:03:30.159 *****
2025-10-01 10:57:06.417200 | controller | skipping: [instance]
2025-10-01 10:57:06.440117 | controller |
2025-10-01 10:57:06.440134 | controller | TASK [networking_mapper : Load the interfaces info from file] ******************
2025-10-01 10:57:06.440142 | controller | Wednesday 01 October 2025  10:57:06 +0000 (0:00:00.024)       0:03:30.183 *****
2025-10-01 10:57:06.440151 | controller | skipping: [instance]
2025-10-01 10:57:06.458312 | controller |
2025-10-01 10:57:06.458328 | controller | TASK [networking_mapper : Ensure local fact is empty] **************************
2025-10-01 10:57:06.458335 | controller | Wednesday 01 October 2025  10:57:06 +0000 (0:00:00.022)       0:03:30.206 *****
2025-10-01 10:57:06.458344 | controller | ok: [instance]
2025-10-01 10:57:06.539051 | controller |
2025-10-01 10:57:06.539071 | controller | TASK [networking_mapper : Set the input Networking Definition and patch it if needed] ***
2025-10-01 10:57:06.539078 | controller | Wednesday 01 October 2025  10:57:06 +0000 (0:00:00.018)       0:03:30.224 *****
2025-10-01 10:57:06.539089 | 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, 'tools': {'multus': {'ranges': [{'start': 30, 'end': 39}]}, 'netconfig': {'ranges': [{'start': '192.168.122.40', 'end': '192.168.122.49'}]}, 'metallb': {'ranges': [{'start': '192.168.122.80', 'end': '192.168.122.90'}]}}}, 'internalapi': {'network': '172.17.0.0/24', 'gateway': '172.17.0.1', 'vlan': 20, 'mtu': 1496, 'tools': {'metallb': {'ranges': [{'start': '172.17.0.90', 'end': '172.17.0.100'}]}, 'netconfig': {'ranges': [{'start': '172.17.0.40', 'end': '172.17.0.49'}]}, 'multus': {'ranges': [{'start': 50, 'end': 59}]}}}, 'storage': {'network': '172.18.0.0/24', 'vlan': 21, 'mtu': 1496, 'tools': {'netconfig': {'ranges': [{'start': '172.18.0.40', 'end': '172.18.0.49'}]}}}, 'tenant': {'network': '172.19.0.0/24', 'gateway-v4': '172.19.0.1', 'search-domain': 'tenant.example.local', 'dns-v4': ['8.8.8.8', '172.19.0.1'], 'tools': {'netconfig': {'ranges': [{'start': '172.19.0.40', 'end': '172.19.0.49'}]}}, 'vlan': 22, 'mtu': 1496}}, 'group-templates': {'computes': {'network-template': {'range': {'start': 10, 'end': 15}}, 'networks': {'ctlplane': {}, 'internalapi': {}, 'tenant': {}, 'storage': {}}}, 'sl-computes': {'network-template': {'range': {'start': 16, 'length': 2}}, 'networks': {'ctlplane': {}, 'internalapi': {}, 'tenant': {}, 'storage': {}}}, 'baremetals': {'networks': {'ctlplane': {'range': '192.168.122.20-192.168.122.24'}, 'internalapi': {'range': '20-24'}, 'tenant': {'range': {'start': 20, 'length': 5}}, 'storage': {'range': {'start': 20, 'length': 5}}}}}})
2025-10-01 10:57:06.556233 | controller | ok: [instance] => (item={'networks': {'public': {'network-v4': '192.168.110.0/24'}}, 'group-templates': {'computes': {'networks': {'public': None}}}})
2025-10-01 10:57:06.556252 | controller |
2025-10-01 10:57:06.556259 | controller | TASK [networking_mapper : Gather facts if requested] ***************************
2025-10-01 10:57:06.556265 | controller | Wednesday 01 October 2025  10:57:06 +0000 (0:00:00.080)       0:03:30.304 *****
2025-10-01 10:57:06.556274 | controller | skipping: [instance]
2025-10-01 10:57:06.763211 | controller |
2025-10-01 10:57:06.763241 | controller | TASK [networking_mapper : Ensure CI infrastructure dir exists] *****************
2025-10-01 10:57:06.763249 | controller | Wednesday 01 October 2025  10:57:06 +0000 (0:00:00.017)       0:03:30.322 *****
2025-10-01 10:57:06.763259 | controller | ok: [instance]
2025-10-01 10:57:07.177023 | controller |
2025-10-01 10:57:07.177054 | controller | TASK [networking_mapper : Write the Networking Definition to file] *************
2025-10-01 10:57:07.177062 | controller | Wednesday 01 October 2025  10:57:06 +0000 (0:00:00.206)       0:03:30.529 *****
2025-10-01 10:57:07.177072 | controller | changed: [instance]
2025-10-01 10:57:07.228287 | controller |
2025-10-01 10:57:07.228315 | controller | TASK [networking_mapper : Call the networking mapper] **************************
2025-10-01 10:57:07.228323 | controller | Wednesday 01 October 2025  10:57:07 +0000 (0:00:00.413)       0:03:30.942 *****
2025-10-01 10:57:07.228332 | controller | ok: [instance]
2025-10-01 10:57:07.256664 | controller |
2025-10-01 10:57:07.256706 | controller | TASK [networking_mapper : Set networking mapper facts] *************************
2025-10-01 10:57:07.256717 | controller | Wednesday 01 October 2025  10:57:07 +0000 (0:00:00.051)       0:03:30.994 *****
2025-10-01 10:57:07.256752 | controller | ok: [instance]
2025-10-01 10:57:07.256783 | controller |
2025-10-01 10:57:07.256911 | controller | TASK [networking_mapper : Write the Networking Environment Definition to file] ***
2025-10-01 10:57:07.256938 | controller | Wednesday 01 October 2025  10:57:07 +0000 (0:00:00.028)       0:03:31.022 *****
2025-10-01 10:57:07.674630 | controller | changed: [instance]
2025-10-01 10:57:07.674687 | controller |
2025-10-01 10:57:07.674819 | controller | TASK [libvirt_manager : Be sure to save current state of networking_mapper environment] ***
2025-10-01 10:57:07.674950 | controller | Wednesday 01 October 2025  10:57:07 +0000 (0:00:00.417)       0:03:31.440 *****
2025-10-01 10:57:07.699339 | controller | ok: [instance]
2025-10-01 10:57:07.716988 | controller |
2025-10-01 10:57:07.717010 | controller | TASK [libvirt_manager : Unset patch] *******************************************
2025-10-01 10:57:07.717019 | controller | Wednesday 01 October 2025  10:57:07 +0000 (0:00:00.024)       0:03:31.465 *****
2025-10-01 10:57:07.717030 | controller | ok: [instance]
2025-10-01 10:57:07.734628 | controller |
2025-10-01 10:57:07.734663 | controller | TASK [libvirt_manager : Initialize empty _lm_dhcp_entries fact] ****************
2025-10-01 10:57:07.734673 | controller | Wednesday 01 October 2025  10:57:07 +0000 (0:00:00.017)       0:03:31.482 *****
2025-10-01 10:57:07.734686 | controller | ok: [instance]
2025-10-01 10:57:07.734716 | controller |
2025-10-01 10:57:07.734938 | controller | TASK [libvirt_manager : Reserve IPs on networks] *******************************
2025-10-01 10:57:07.786632 | controller | Wednesday 01 October 2025  10:57:07 +0000 (0:00:00.017)       0:03:31.500 *****
2025-10-01 10:57:07.786662 | 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-10-01 10:57:07.786699 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/reserve_dnsmasq_ips.yml for instance => (item=internalapi)
2025-10-01 10:57:07.786708 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/reserve_dnsmasq_ips.yml for instance => (item=storage)
2025-10-01 10:57:07.786717 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/reserve_dnsmasq_ips.yml for instance => (item=tenant)
2025-10-01 10:57:07.787076 | 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-10-01 10:57:07.839255 | controller |
2025-10-01 10:57:07.839278 | controller | TASK [libvirt_manager : Loop on host IPs] **************************************
2025-10-01 10:57:07.839285 | controller | Wednesday 01 October 2025  10:57:07 +0000 (0:00:00.051)       0:03:31.552 *****
2025-10-01 10:57:07.839295 | controller | skipping: [instance] => (item=compute-0 - ctlplane)
2025-10-01 10:57:07.890640 | controller | skipping: [instance]
2025-10-01 10:57:07.890676 | controller |
2025-10-01 10:57:07.890686 | controller | TASK [libvirt_manager : Loop on host IPs] **************************************
2025-10-01 10:57:07.890695 | controller | Wednesday 01 October 2025  10:57:07 +0000 (0:00:00.052)       0:03:31.605 *****
2025-10-01 10:57:07.890707 | controller | skipping: [instance] => (item=compute-0 - internalapi)
2025-10-01 10:57:07.890735 | controller | skipping: [instance]
2025-10-01 10:57:07.890744 | controller |
2025-10-01 10:57:07.891002 | controller | TASK [libvirt_manager : Loop on host IPs] **************************************
2025-10-01 10:57:07.943109 | controller | Wednesday 01 October 2025  10:57:07 +0000 (0:00:00.051)       0:03:31.656 *****
2025-10-01 10:57:07.943135 | controller | skipping: [instance] => (item=compute-0 - storage)
2025-10-01 10:57:07.995580 | controller | skipping: [instance]
2025-10-01 10:57:07.995603 | controller |
2025-10-01 10:57:07.995611 | controller | TASK [libvirt_manager : Loop on host IPs] **************************************
2025-10-01 10:57:07.995618 | controller | Wednesday 01 October 2025  10:57:07 +0000 (0:00:00.052)       0:03:31.708 *****
2025-10-01 10:57:07.995627 | controller | skipping: [instance] => (item=compute-0 - tenant)
2025-10-01 10:57:08.066655 | controller | skipping: [instance]
2025-10-01 10:57:08.066691 | controller |
2025-10-01 10:57:08.066701 | controller | TASK [libvirt_manager : Loop on host IPs] **************************************
2025-10-01 10:57:08.066710 | controller | Wednesday 01 October 2025  10:57:07 +0000 (0:00:00.052)       0:03:31.761 *****
2025-10-01 10:57:08.066721 | controller | ok: [instance] => (item=compute-0 - public)
2025-10-01 10:57:08.066750 | controller |
2025-10-01 10:57:08.066760 | controller | TASK [Inject DHCP entries for net {{ net_name }}] ******************************
2025-10-01 10:57:08.066863 | controller | Wednesday 01 October 2025  10:57:08 +0000 (0:00:00.071)       0:03:31.832 *****
2025-10-01 10:57:08.143664 | controller |
2025-10-01 10:57:08.143871 | controller | TASK [dnsmasq : Ensure we have the right data and type] ************************
2025-10-01 10:57:08.180622 | controller | Wednesday 01 October 2025  10:57:08 +0000 (0:00:00.076)       0:03:31.909 *****
2025-10-01 10:57:08.180660 | controller | ok: [instance]
2025-10-01 10:57:08.180706 | controller |
2025-10-01 10:57:08.180729 | controller | TASK [dnsmasq : Assert we have needed host data] *******************************
2025-10-01 10:57:08.180742 | controller | Wednesday 01 October 2025  10:57:08 +0000 (0:00:00.036)       0:03:31.946 *****
2025-10-01 10:57:08.224062 | controller | ok: [instance] => (item={'network': 'public', 'name': 'compute-0', 'state': 'present', 'mac': '52:54:00:d6:57:e8', 'ips': ['192.168.110.10', '']})
2025-10-01 10:57:08.266069 | controller |
2025-10-01 10:57:08.266091 | controller | TASK [dnsmasq : Ensure networks exists] ****************************************
2025-10-01 10:57:08.266100 | controller | Wednesday 01 October 2025  10:57:08 +0000 (0:00:00.043)       0:03:31.989 *****
2025-10-01 10:57:08.266109 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/_check_net_status.yml for instance => (item=public)
2025-10-01 10:57:08.439171 | controller |
2025-10-01 10:57:08.439194 | controller | TASK [dnsmasq : Check network file status] *************************************
2025-10-01 10:57:08.439202 | controller | Wednesday 01 October 2025  10:57:08 +0000 (0:00:00.042)       0:03:32.032 *****
2025-10-01 10:57:08.439212 | controller | ok: [instance]
2025-10-01 10:57:08.460993 | controller |
2025-10-01 10:57:08.461013 | controller | TASK [dnsmasq : Assert network exists] *****************************************
2025-10-01 10:57:08.461026 | controller | Wednesday 01 October 2025  10:57:08 +0000 (0:00:00.172)       0:03:32.205 *****
2025-10-01 10:57:08.461035 | controller | ok: [instance]
2025-10-01 10:57:08.479046 | controller |
2025-10-01 10:57:08.479064 | controller | TASK [dnsmasq : Initialize empty dhcp_host_entries] ****************************
2025-10-01 10:57:08.479072 | controller | Wednesday 01 October 2025  10:57:08 +0000 (0:00:00.021)       0:03:32.227 *****
2025-10-01 10:57:08.479081 | controller | ok: [instance]
2025-10-01 10:57:08.558200 | controller |
2025-10-01 10:57:08.558227 | controller | TASK [dnsmasq : Compute entry] *************************************************
2025-10-01 10:57:08.558235 | controller | Wednesday 01 October 2025  10:57:08 +0000 (0:00:00.018)       0:03:32.245 *****
2025-10-01 10:57:08.558245 | controller | ok: [instance] => (item={'network': 'public', 'name': 'compute-0', 'state': 'present', 'mac': '52:54:00:d6:57:e8', 'ips': ['192.168.110.10', '']})
2025-10-01 10:57:08.594600 | controller |
2025-10-01 10:57:08.594627 | controller | TASK [dnsmasq : Create add/remove sets] ****************************************
2025-10-01 10:57:08.594636 | controller | Wednesday 01 October 2025  10:57:08 +0000 (0:00:00.078)       0:03:32.324 *****
2025-10-01 10:57:08.594648 | controller | ok: [instance]
2025-10-01 10:57:08.594896 | controller |
2025-10-01 10:57:08.594911 | controller | TASK [dnsmasq : Add DHCP entries] **********************************************
2025-10-01 10:57:08.961598 | controller | Wednesday 01 October 2025  10:57:08 +0000 (0:00:00.036)       0:03:32.360 *****
2025-10-01 10:57:08.961640 | controller | changed: [instance] => (item={'file': 'public_compute-0_52:54:00:d6:57:e8', 'entry': '52:54:00:d6:57:e8,192.168.110.10,compute-0', 'state': 'present'})
2025-10-01 10:57:08.961661 | controller |
2025-10-01 10:57:08.961900 | controller | TASK [dnsmasq : Remove DHCP entries] *******************************************
2025-10-01 10:57:08.983609 | controller | Wednesday 01 October 2025  10:57:08 +0000 (0:00:00.367)       0:03:32.727 *****
2025-10-01 10:57:08.983639 | controller | skipping: [instance]
2025-10-01 10:57:09.082267 | controller |
2025-10-01 10:57:09.082290 | controller | TASK [libvirt_manager : Create per-network and .utility DNS entries] ***********
2025-10-01 10:57:09.082299 | controller | Wednesday 01 October 2025  10:57:08 +0000 (0:00:00.021)       0:03:32.749 *****
2025-10-01 10:57:09.082310 | controller | ok: [instance] => (item=compute-0)
2025-10-01 10:57:09.163659 | controller |
2025-10-01 10:57:09.163683 | controller | TASK [Inject VMs in the .utility zone] *****************************************
2025-10-01 10:57:09.163692 | controller | Wednesday 01 October 2025  10:57:09 +0000 (0:00:00.098)       0:03:32.848 *****
2025-10-01 10:57:09.163703 | controller |
2025-10-01 10:57:09.202280 | controller | TASK [dnsmasq : Assert we have needed host record data] ************************
2025-10-01 10:57:09.202299 | controller | Wednesday 01 October 2025  10:57:09 +0000 (0:00:00.081)       0:03:32.929 *****
2025-10-01 10:57:09.202313 | controller | ok: [instance]
2025-10-01 10:57:09.298652 | controller |
2025-10-01 10:57:09.298675 | controller | TASK [dnsmasq : Assert each address element have needed data] ******************
2025-10-01 10:57:09.298684 | controller | Wednesday 01 October 2025  10:57:09 +0000 (0:00:00.038)       0:03:32.968 *****
2025-10-01 10:57:09.298695 | 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-10-01 10:57:09.298894 | controller | ok: [instance] => (item={'names': ['compute-0.ctlplane.local', 'compute-0.ctlplane.local'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
2025-10-01 10:57:09.299070 | controller | ok: [instance] => (item={'names': ['compute-0.internalapi.local', 'compute-0.internalapi.local'], 'ips': ['172.17.0.10', ''], 'state': 'present'})
2025-10-01 10:57:09.299221 | controller | ok: [instance] => (item={'names': ['compute-0.public.local', 'compute-0.public.local'], 'ips': ['192.168.110.10', ''], 'state': 'present'})
2025-10-01 10:57:09.299365 | controller | ok: [instance] => (item={'names': ['compute-0.storage.local', 'compute-0.storage.local'], 'ips': ['172.18.0.10', ''], 'state': 'present'})
2025-10-01 10:57:09.299504 | controller | ok: [instance] => (item={'names': ['compute-0.tenant.local', 'compute-0.tenant.local'], 'ips': ['172.19.0.10', ''], 'state': 'present'})
2025-10-01 10:57:09.299690 | controller |
2025-10-01 10:57:09.299847 | controller | TASK [dnsmasq : Add/Remove address] ********************************************
2025-10-01 10:57:09.299987 | controller | Wednesday 01 October 2025  10:57:09 +0000 (0:00:00.096)       0:03:33.064 *****
2025-10-01 10:57:10.613606 | 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-10-01 10:57:10.613872 | controller | changed: [instance] => (item={'names': ['compute-0.ctlplane.local', 'compute-0.ctlplane.local'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
2025-10-01 10:57:10.613885 | controller | changed: [instance] => (item={'names': ['compute-0.internalapi.local', 'compute-0.internalapi.local'], 'ips': ['172.17.0.10', ''], 'state': 'present'})
2025-10-01 10:57:10.613892 | controller | changed: [instance] => (item={'names': ['compute-0.public.local', 'compute-0.public.local'], 'ips': ['192.168.110.10', ''], 'state': 'present'})
2025-10-01 10:57:10.613898 | controller | changed: [instance] => (item={'names': ['compute-0.storage.local', 'compute-0.storage.local'], 'ips': ['172.18.0.10', ''], 'state': 'present'})
2025-10-01 10:57:10.613904 | controller | changed: [instance] => (item={'names': ['compute-0.tenant.local', 'compute-0.tenant.local'], 'ips': ['172.19.0.10', ''], 'state': 'present'})
2025-10-01 10:57:10.613909 | controller |
2025-10-01 10:57:10.613917 | controller | TASK [libvirt_manager : Ensure some domains are local] *************************
2025-10-01 10:57:10.990843 | controller | Wednesday 01 October 2025  10:57:10 +0000 (0:00:01.314)       0:03:34.379 *****
2025-10-01 10:57:10.990878 | controller | changed: [instance]
2025-10-01 10:57:11.801104 | controller |
2025-10-01 10:57:11.801133 | controller | TASK [libvirt_manager : Ensure dnsmasq is reloaded now] ************************
2025-10-01 10:57:11.801142 | controller | Wednesday 01 October 2025  10:57:10 +0000 (0:00:00.367)       0:03:34.746 *****
2025-10-01 10:57:11.801148 | controller |
2025-10-01 10:57:11.801153 | controller | RUNNING HANDLER [libvirt_manager : Restart firewalld] **************************
2025-10-01 10:57:11.801159 | controller | Wednesday 01 October 2025  10:57:10 +0000 (0:00:00.009)       0:03:34.756 *****
2025-10-01 10:57:11.801168 | controller | changed: [instance]
2025-10-01 10:57:12.142739 | controller |
2025-10-01 10:57:12.142767 | controller | RUNNING HANDLER [dnsmasq : Restart dnsmasq] ************************************
2025-10-01 10:57:12.142776 | controller | Wednesday 01 October 2025  10:57:11 +0000 (0:00:00.810)       0:03:35.566 *****
2025-10-01 10:57:12.142786 | controller | changed: [instance]
2025-10-01 10:57:12.478352 | controller |
2025-10-01 10:57:12.478386 | controller | RUNNING HANDLER [dnsmasq : Reload dnsmasq] *************************************
2025-10-01 10:57:12.478394 | controller | Wednesday 01 October 2025  10:57:12 +0000 (0:00:00.341)       0:03:35.908 *****
2025-10-01 10:57:12.478414 | controller | changed: [instance]
2025-10-01 10:57:12.876074 | controller |
2025-10-01 10:57:12.876106 | controller | TASK [libvirt_manager : Create group inventories] ******************************
2025-10-01 10:57:12.876114 | controller | Wednesday 01 October 2025  10:57:12 +0000 (0:00:00.335)       0:03:36.244 *****
2025-10-01 10:57:12.876124 | controller | changed: [instance] => (item=compute)
2025-10-01 10:57:13.267349 | controller |
2025-10-01 10:57:13.267381 | controller | TASK [libvirt_manager : Create "all" group inventory file] *********************
2025-10-01 10:57:13.267389 | controller | Wednesday 01 October 2025  10:57:12 +0000 (0:00:00.397)       0:03:36.641 *****
2025-10-01 10:57:13.267400 | controller | changed: [instance]
2025-10-01 10:57:13.304669 | controller |
2025-10-01 10:57:13.304705 | controller | TASK [libvirt_manager : Ensure storage pool is present.] ***********************
2025-10-01 10:57:13.304723 | controller | Wednesday 01 October 2025  10:57:13 +0000 (0:00:00.391)       0:03:37.033 *****
2025-10-01 10:57:13.304735 | controller | skipping: [instance]
2025-10-01 10:57:13.304756 | controller |
2025-10-01 10:57:13.304766 | controller | TASK [libvirt_manager : Ensure images are present] *****************************
2025-10-01 10:57:13.304883 | controller | Wednesday 01 October 2025  10:57:13 +0000 (0:00:00.037)       0:03:37.070 *****
2025-10-01 10:57:13.377670 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/get_image.yml for instance => (item=compute)
2025-10-01 10:57:13.394591 | controller |
2025-10-01 10:57:13.394612 | controller | TASK [libvirt_manager : Ensure directory exists] *******************************
2025-10-01 10:57:13.394620 | controller | Wednesday 01 October 2025  10:57:13 +0000 (0:00:00.072)       0:03:37.143 *****
2025-10-01 10:57:13.394629 | controller | skipping: [instance]
2025-10-01 10:57:13.411603 | controller |
2025-10-01 10:57:13.411630 | controller | TASK [libvirt_manager : Check if base image exists] ****************************
2025-10-01 10:57:13.411639 | controller | Wednesday 01 October 2025  10:57:13 +0000 (0:00:00.017)       0:03:37.160 *****
2025-10-01 10:57:13.411651 | controller | skipping: [instance]
2025-10-01 10:57:13.411929 | controller |
2025-10-01 10:57:13.429777 | controller | TASK [libvirt_manager : Download base image] ***********************************
2025-10-01 10:57:13.429800 | controller | Wednesday 01 October 2025  10:57:13 +0000 (0:00:00.017)       0:03:37.177 *****
2025-10-01 10:57:13.429813 | controller | skipping: [instance]
2025-10-01 10:57:13.446301 | controller |
2025-10-01 10:57:13.446319 | controller | TASK [libvirt_manager : Check image] *******************************************
2025-10-01 10:57:13.446326 | controller | Wednesday 01 October 2025  10:57:13 +0000 (0:00:00.018)       0:03:37.195 *****
2025-10-01 10:57:13.446335 | controller | skipping: [instance]
2025-10-01 10:57:13.446478 | controller |
2025-10-01 10:57:13.446672 | controller | TASK [libvirt_manager : Assert image status] ***********************************
2025-10-01 10:57:13.446829 | controller | Wednesday 01 October 2025  10:57:13 +0000 (0:00:00.016)       0:03:37.212 *****
2025-10-01 10:57:13.463110 | controller | skipping: [instance]
2025-10-01 10:57:13.463261 | controller |
2025-10-01 10:57:13.463419 | controller | TASK [libvirt_manager : Ensure image access rights] ****************************
2025-10-01 10:57:13.463613 | controller | Wednesday 01 October 2025  10:57:13 +0000 (0:00:00.016)       0:03:37.229 *****
2025-10-01 10:57:13.480079 | controller | skipping: [instance]
2025-10-01 10:57:13.480223 | controller |
2025-10-01 10:57:13.480365 | controller | TASK [libvirt_manager : Get ssh key state] *************************************
2025-10-01 10:57:13.480505 | controller | Wednesday 01 October 2025  10:57:13 +0000 (0:00:00.016)       0:03:37.246 *****
2025-10-01 10:57:13.648263 | controller | ok: [instance]
2025-10-01 10:57:14.027945 | controller |
2025-10-01 10:57:14.027975 | controller | TASK [libvirt_manager : Create temporary ssh keypair] **************************
2025-10-01 10:57:14.027983 | controller | Wednesday 01 October 2025  10:57:13 +0000 (0:00:00.167)       0:03:37.414 *****
2025-10-01 10:57:14.027993 | controller | changed: [instance]
2025-10-01 10:57:14.310969 | controller |
2025-10-01 10:57:14.310998 | controller | TASK [libvirt_manager : Slurp public key for later use] ************************
2025-10-01 10:57:14.311007 | controller | Wednesday 01 October 2025  10:57:14 +0000 (0:00:00.379)       0:03:37.793 *****
2025-10-01 10:57:14.311016 | controller | ok: [instance]
2025-10-01 10:57:14.482830 | controller |
2025-10-01 10:57:14.482861 | controller | TASK [libvirt_manager : Slurp private key for later use] ***********************
2025-10-01 10:57:14.482870 | controller | Wednesday 01 October 2025  10:57:14 +0000 (0:00:00.282)       0:03:38.076 *****
2025-10-01 10:57:14.482880 | controller | ok: [instance]
2025-10-01 10:57:14.863627 | controller |
2025-10-01 10:57:14.863662 | controller | TASK [libvirt_manager : Inject cifmw_reproducer_key.pub in hypervisor authorized_keys] ***
2025-10-01 10:57:14.863671 | controller | Wednesday 01 October 2025  10:57:14 +0000 (0:00:00.171)       0:03:38.248 *****
2025-10-01 10:57:14.863684 | controller | changed: [instance]
2025-10-01 10:57:14.881590 | controller |
2025-10-01 10:57:14.881613 | controller | TASK [libvirt_manager : Create fact holding network data for VMs] **************
2025-10-01 10:57:14.881621 | controller | Wednesday 01 October 2025  10:57:14 +0000 (0:00:00.380)       0:03:38.629 *****
2025-10-01 10:57:14.881630 | controller | ok: [instance]
2025-10-01 10:57:14.881978 | controller |
2025-10-01 10:57:15.103111 | controller | TASK [libvirt_manager : List existing networks] ********************************
2025-10-01 10:57:15.103144 | controller | Wednesday 01 October 2025  10:57:14 +0000 (0:00:00.018)       0:03:38.647 *****
2025-10-01 10:57:15.103156 | controller | ok: [instance]
2025-10-01 10:57:15.490138 | controller |
2025-10-01 10:57:15.490171 | controller | TASK [libvirt_manager : Gather pool fact] **************************************
2025-10-01 10:57:15.490179 | controller | Wednesday 01 October 2025  10:57:15 +0000 (0:00:00.220)       0:03:38.868 *****
2025-10-01 10:57:15.490189 | controller | ok: [instance]
2025-10-01 10:57:15.549232 | controller |
2025-10-01 10:57:15.549261 | controller | TASK [libvirt_manager : Create and run VMs] ************************************
2025-10-01 10:57:15.549269 | controller | Wednesday 01 October 2025  10:57:15 +0000 (0:00:00.387)       0:03:39.255 *****
2025-10-01 10:57:15.549279 | 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-10-01 10:57:15.801104 | controller |
2025-10-01 10:57:15.801133 | controller | TASK [libvirt_manager : Create VM image for compute-0] *************************
2025-10-01 10:57:15.801142 | controller | Wednesday 01 October 2025  10:57:15 +0000 (0:00:00.059)       0:03:39.315 *****
2025-10-01 10:57:15.801152 | controller | changed: [instance]
2025-10-01 10:57:16.024885 | controller |
2025-10-01 10:57:16.024914 | controller | TASK [libvirt_manager : Ensure file ownership and rights for compute-0] ********
2025-10-01 10:57:16.024922 | controller | Wednesday 01 October 2025  10:57:15 +0000 (0:00:00.251)       0:03:39.566 *****
2025-10-01 10:57:16.024932 | controller | changed: [instance]
2025-10-01 10:57:17.062408 | controller |
2025-10-01 10:57:17.062437 | controller | TASK [libvirt_manager : Define VMs for type compute-0] *************************
2025-10-01 10:57:17.062446 | controller | Wednesday 01 October 2025  10:57:16 +0000 (0:00:00.223)       0:03:39.790 *****
2025-10-01 10:57:17.062456 | controller | changed: [instance]
2025-10-01 10:57:17.087433 | controller |
2025-10-01 10:57:17.087453 | controller | TASK [libvirt_manager : Attach listed networks to the VMs compute-0] ***********
2025-10-01 10:57:17.087460 | controller | Wednesday 01 October 2025  10:57:17 +0000 (0:00:01.037)       0:03:40.828 *****
2025-10-01 10:57:17.087469 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/net_to_vms.yml for instance
2025-10-01 10:57:17.120361 | controller |
2025-10-01 10:57:17.120383 | controller | TASK [libvirt_manager : Attach {{ vm_item }} to {{ net_item }}] ****************
2025-10-01 10:57:17.120391 | controller | Wednesday 01 October 2025  10:57:17 +0000 (0:00:00.025)       0:03:40.853 *****
2025-10-01 10:57:17.120403 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/attach_interface.yml for instance => (item=public)
2025-10-01 10:57:17.345228 | controller |
2025-10-01 10:57:17.345256 | controller | TASK [libvirt_manager : Get virtual network information] ***********************
2025-10-01 10:57:17.345265 | controller | Wednesday 01 October 2025  10:57:17 +0000 (0:00:00.032)       0:03:40.886 *****
2025-10-01 10:57:17.345275 | controller | ok: [instance]
2025-10-01 10:57:17.385468 | controller |
2025-10-01 10:57:17.385492 | controller | TASK [libvirt_manager : Create network to bridge mapping] **********************
2025-10-01 10:57:17.385504 | controller | Wednesday 01 October 2025  10:57:17 +0000 (0:00:00.224)       0:03:41.110 *****
2025-10-01 10:57:17.385533 | controller | ok: [instance] => (item=default)
2025-10-01 10:57:17.613468 | controller | ok: [instance] => (item=cifmw-public)
2025-10-01 10:57:17.613499 | controller |
2025-10-01 10:57:17.613508 | controller | TASK [libvirt_manager : Dump domain xml] ***************************************
2025-10-01 10:57:17.613514 | controller | Wednesday 01 October 2025  10:57:17 +0000 (0:00:00.040)       0:03:41.151 *****
2025-10-01 10:57:17.613575 | controller | ok: [instance]
2025-10-01 10:57:17.811614 | controller |
2025-10-01 10:57:17.811653 | controller | TASK [libvirt_manager : Extract networks from XML] *****************************
2025-10-01 10:57:17.811662 | controller | Wednesday 01 October 2025  10:57:17 +0000 (0:00:00.228)       0:03:41.379 *****
2025-10-01 10:57:17.811673 | controller | ok: [instance]
2025-10-01 10:57:17.811691 | controller |
2025-10-01 10:57:17.811937 | controller | TASK [libvirt_manager : Attach interface public on cifmw-compute-0] ************
2025-10-01 10:57:18.102313 | controller | Wednesday 01 October 2025  10:57:17 +0000 (0:00:00.198)       0:03:41.577 *****
2025-10-01 10:57:18.102348 | controller | changed: [instance]
2025-10-01 10:57:18.122160 | controller |
2025-10-01 10:57:18.122183 | controller | TASK [libvirt_manager : Attach spines/leafs networks to the VMs compute-0] *****
2025-10-01 10:57:18.122193 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.290)       0:03:41.868 *****
2025-10-01 10:57:18.122204 | controller | skipping: [instance]
2025-10-01 10:57:18.147988 | controller |
2025-10-01 10:57:18.148004 | controller | TASK [libvirt_manager : Create the requested extra disks for compute-0] ********
2025-10-01 10:57:18.148011 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.019)       0:03:41.888 *****
2025-10-01 10:57:18.148025 | controller | skipping: [instance]
2025-10-01 10:57:18.175642 | controller |
2025-10-01 10:57:18.175664 | controller | TASK [libvirt_manager : Find volume attachments for VM compute-0] **************
2025-10-01 10:57:18.175674 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.025)       0:03:41.913 *****
2025-10-01 10:57:18.175684 | controller | skipping: [instance]
2025-10-01 10:57:18.201094 | controller |
2025-10-01 10:57:18.201112 | controller | TASK [libvirt_manager : Attach volumes for VM compute-0] ***********************
2025-10-01 10:57:18.201119 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.027)       0:03:41.941 *****
2025-10-01 10:57:18.201127 | controller | skipping: [instance]
2025-10-01 10:57:18.423382 | controller |
2025-10-01 10:57:18.423412 | controller | TASK [libvirt_manager : Get VM UUID] *******************************************
2025-10-01 10:57:18.423420 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.025)       0:03:41.967 *****
2025-10-01 10:57:18.423431 | controller | changed: [instance]
2025-10-01 10:57:18.460154 | controller |
2025-10-01 10:57:18.460176 | controller | TASK [libvirt_manager : Inject UUID in dataset] ********************************
2025-10-01 10:57:18.460184 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.222)       0:03:42.189 *****
2025-10-01 10:57:18.460193 | controller | ok: [instance]
2025-10-01 10:57:18.480121 | controller |
2025-10-01 10:57:18.480140 | controller | TASK [libvirt_manager : Create cloud-init ISO] *********************************
2025-10-01 10:57:18.480148 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.037)       0:03:42.226 *****
2025-10-01 10:57:18.480156 | controller | skipping: [instance]
2025-10-01 10:57:18.499599 | controller |
2025-10-01 10:57:18.499671 | controller | TASK [libvirt_manager : Attach cloud-init ISO if exists] ***********************
2025-10-01 10:57:18.499680 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.020)       0:03:42.246 *****
2025-10-01 10:57:18.499692 | controller | skipping: [instance]
2025-10-01 10:57:18.542586 | controller |
2025-10-01 10:57:18.542609 | controller | TASK [libvirt_manager : Attach additional devices if specified] ****************
2025-10-01 10:57:18.542617 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.019)       0:03:42.265 *****
2025-10-01 10:57:18.542626 | controller | skipping: [instance]
2025-10-01 10:57:18.574690 | controller |
2025-10-01 10:57:18.574725 | controller | TASK [libvirt_manager : Start (power-on) VMs] **********************************
2025-10-01 10:57:18.574735 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.042)       0:03:42.308 *****
2025-10-01 10:57:18.574753 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/start_vms.yml for instance
2025-10-01 10:57:18.574789 | controller |
2025-10-01 10:57:18.574807 | controller | TASK [libvirt_manager : Refresh oooq_pool before starting VMs] *****************
2025-10-01 10:57:18.574818 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.032)       0:03:42.340 *****
2025-10-01 10:57:18.601634 | controller | skipping: [instance]
2025-10-01 10:57:18.601689 | controller |
2025-10-01 10:57:18.601700 | controller | TASK [libvirt_manager : Start VMs for type {{ vm_type }}] **********************
2025-10-01 10:57:18.601711 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.026)       0:03:42.367 *****
2025-10-01 10:57:18.636619 | controller | skipping: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
2025-10-01 10:57:18.636835 | controller | skipping: [instance]
2025-10-01 10:57:18.636853 | controller |
2025-10-01 10:57:18.636864 | controller | TASK [libvirt_manager : Wait for SSH on started VMs] ***************************
2025-10-01 10:57:18.680390 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.034)       0:03:42.402 *****
2025-10-01 10:57:18.680419 | controller | skipping: [instance] => (item=compute-0.utility)
2025-10-01 10:57:18.705569 | controller | skipping: [instance]
2025-10-01 10:57:18.705592 | controller |
2025-10-01 10:57:18.705601 | controller | TASK [libvirt_manager : Ensure we get SSH on nodes] ****************************
2025-10-01 10:57:18.705609 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.043)       0:03:42.446 *****
2025-10-01 10:57:18.705626 | 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-10-01 10:57:18.743062 | controller | skipping: [instance]
2025-10-01 10:57:18.743080 | controller |
2025-10-01 10:57:18.743088 | controller | TASK [libvirt_manager : Configure managed VMs] *********************************
2025-10-01 10:57:18.743094 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.025)       0:03:42.471 *****
2025-10-01 10:57:18.743102 | controller | skipping: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
2025-10-01 10:57:18.778372 | controller | skipping: [instance]
2025-10-01 10:57:18.778390 | controller |
2025-10-01 10:57:18.778398 | controller | TASK [Create VBMC entity] ******************************************************
2025-10-01 10:57:18.778404 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.037)       0:03:42.508 *****
2025-10-01 10:57:18.778412 | controller | skipping: [instance] => (item=compute-0)
2025-10-01 10:57:19.002664 | controller | skipping: [instance]
2025-10-01 10:57:19.002698 | controller |
2025-10-01 10:57:19.002706 | controller | TASK [libvirt_manager : List running virtual machines.] ************************
2025-10-01 10:57:19.002713 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.035)       0:03:42.544 *****
2025-10-01 10:57:19.002724 | controller | ok: [instance]
2025-10-01 10:57:19.002748 | controller |
2025-10-01 10:57:19.002757 | controller | TASK [libvirt_manager : Dump UUIDs] ********************************************
2025-10-01 10:57:19.002880 | controller | Wednesday 01 October 2025  10:57:18 +0000 (0:00:00.224)       0:03:42.768 *****
2025-10-01 10:57:19.386788 | controller | changed: [instance]
2025-10-01 10:57:19.416990 | controller |
2025-10-01 10:57:19.417017 | controller | TASK [Ensure fresh vbmc listing] ***********************************************
2025-10-01 10:57:19.417027 | controller | Wednesday 01 October 2025  10:57:19 +0000 (0:00:00.383)       0:03:43.152 *****
2025-10-01 10:57:19.417037 | controller | skipping: [instance]
2025-10-01 10:57:19.468955 | controller |
2025-10-01 10:57:19.468983 | controller | TASK [libvirt_manager : Update vbmc related fact] ******************************
2025-10-01 10:57:19.468991 | controller | Wednesday 01 October 2025  10:57:19 +0000 (0:00:00.030)       0:03:43.182 *****
2025-10-01 10:57:19.469001 | controller | skipping: [instance]
2025-10-01 10:57:19.498650 | controller |
2025-10-01 10:57:19.498677 | controller | TASK [libvirt_manager : Dump vbmc known hosts] *********************************
2025-10-01 10:57:19.498686 | controller | Wednesday 01 October 2025  10:57:19 +0000 (0:00:00.052)       0:03:43.234 *****
2025-10-01 10:57:19.498696 | controller | skipping: [instance]
2025-10-01 10:57:19.521655 | controller |
2025-10-01 10:57:19.521678 | controller | TASK [libvirt_manager : Copy authorized_keys] **********************************
2025-10-01 10:57:19.521685 | controller | Wednesday 01 October 2025  10:57:19 +0000 (0:00:00.029)       0:03:43.264 *****
2025-10-01 10:57:19.521694 | controller | skipping: [instance]
2025-10-01 10:57:19.565217 | controller |
2025-10-01 10:57:19.565243 | controller | TASK [libvirt_manager : Enable root access on CRC] *****************************
2025-10-01 10:57:19.565252 | controller | Wednesday 01 October 2025  10:57:19 +0000 (0:00:00.022)       0:03:43.287 *****
2025-10-01 10:57:19.565262 | controller | skipping: [instance]
2025-10-01 10:57:19.565298 | controller |
2025-10-01 10:57:19.638162 | controller | PLAY RECAP *********************************************************************
2025-10-01 10:57:19.638185 | controller | instance                   : ok=190  changed=92   unreachable=0    failed=0    skipped=89   rescued=0    ignored=0
2025-10-01 10:57:19.638192 | controller |
2025-10-01 10:57:19.638198 | controller | Wednesday 01 October 2025  10:57:19 +0000 (0:00:00.040)       0:03:43.328 *****
2025-10-01 10:57:19.638204 | controller | ===============================================================================
2025-10-01 10:57:19.638209 | controller | libvirt_manager : Install packages required for using KVM -------------- 88.17s
2025-10-01 10:57:19.638214 | controller | test_deps : Install selinux python libs -------------------------------- 54.35s
2025-10-01 10:57:19.638220 | controller | ci_nmstate : Install required packages on instance ---------------------- 9.17s
2025-10-01 10:57:19.638225 | controller | repo_setup : Initialize python venv and install requirements ------------ 7.95s
2025-10-01 10:57:19.638231 | controller | dnsmasq : Ensure SELinux knows about the new files and directories ------ 3.51s
2025-10-01 10:57:19.638236 | controller | test_deps : Install extra packages -------------------------------------- 3.42s
2025-10-01 10:57:19.638241 | controller | ci_nmstate : Apply the desidered state on instance ---------------------- 1.72s
2025-10-01 10:57:19.638247 | controller | discover_latest_image : Get latest image -------------------------------- 1.62s
2025-10-01 10:57:19.638252 | controller | libvirt_manager : Restart firewalld ------------------------------------- 1.57s
2025-10-01 10:57:19.638257 | controller | test_deps : Install python yaml libs ------------------------------------ 1.34s
2025-10-01 10:57:19.638262 | controller | dnsmasq : Add/Remove address -------------------------------------------- 1.31s
2025-10-01 10:57:19.638267 | controller | dnsmasq : Install needed packages --------------------------------------- 1.22s
2025-10-01 10:57:19.638273 | controller | repo_setup : Get repo-setup repository ---------------------------------- 1.19s
2025-10-01 10:57:19.638278 | controller | libvirt_manager : Define VMs for type compute-0 ------------------------- 1.04s
2025-10-01 10:57:19.638283 | controller | libvirt_manager : Ensure firewalld service is up ------------------------ 0.92s
2025-10-01 10:57:19.638288 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.87s
2025-10-01 10:57:19.638293 | controller | Gathering Facts --------------------------------------------------------- 0.83s
2025-10-01 10:57:19.638303 | controller | repo_setup : Make sure git-core package is installed -------------------- 0.82s
2025-10-01 10:57:19.638309 | controller | repo_setup : Install repo-setup package --------------------------------- 0.77s
2025-10-01 10:57:19.638314 | controller | dnsmasq : Enable and start service -------------------------------------- 0.77s
2025-10-01 10:57:19.638323 | controller | INFO     Running default > converge
2025-10-01 10:57:20.089931 | controller |
2025-10-01 10:57:20.090158 | controller | PLAY [Converge] ****************************************************************
2025-10-01 10:57:20.090330 | controller |
2025-10-01 10:57:20.090492 | controller | TASK [Gathering Facts] *********************************************************
2025-10-01 10:57:20.090702 | controller | Wednesday 01 October 2025  10:57:20 +0000 (0:00:00.018)       0:00:00.018 *****
2025-10-01 10:57:20.919683 | controller | ok: [instance]
2025-10-01 10:57:20.919743 | controller |
2025-10-01 10:57:20.919950 | controller | TASK [virtualbmc : Ensure needed directories exist] ****************************
2025-10-01 10:57:21.214737 | controller | Wednesday 01 October 2025  10:57:20 +0000 (0:00:00.829)       0:00:00.848 *****
2025-10-01 10:57:21.214772 | controller | ok: [instance] => (item={'key': '/home/zuul/.ssh', 'mode': '0700'})
2025-10-01 10:57:22.548257 | controller |
2025-10-01 10:57:22.548288 | controller | TASK [podman : Ensure podman is installed] *************************************
2025-10-01 10:57:22.548296 | controller | Wednesday 01 October 2025  10:57:21 +0000 (0:00:00.294)       0:00:01.143 *****
2025-10-01 10:57:22.548306 | controller | ok: [instance]
2025-10-01 10:57:22.871634 | controller |
2025-10-01 10:57:22.871675 | controller | TASK [podman : Enable loginctl linger for ansible_user_id] *********************
2025-10-01 10:57:22.871686 | controller | Wednesday 01 October 2025  10:57:22 +0000 (0:00:01.333)       0:00:02.476 *****
2025-10-01 10:57:22.871699 | controller | changed: [instance]
2025-10-01 10:57:22.895252 | controller |
2025-10-01 10:57:22.895270 | controller | TASK [podman : Ensure subordinate UID entry exists for zuul] *******************
2025-10-01 10:57:22.895277 | controller | Wednesday 01 October 2025  10:57:22 +0000 (0:00:00.323)       0:00:02.800 *****
2025-10-01 10:57:22.895285 | controller | skipping: [instance]
2025-10-01 10:57:22.917284 | controller |
2025-10-01 10:57:22.917301 | controller | TASK [podman : Ensure subordinate GID entry exists for zuul] *******************
2025-10-01 10:57:22.917308 | controller | Wednesday 01 October 2025  10:57:22 +0000 (0:00:00.023)       0:00:02.824 *****
2025-10-01 10:57:22.917317 | controller | skipping: [instance]
2025-10-01 10:57:22.943088 | controller |
2025-10-01 10:57:22.943105 | controller | TASK [podman : Run podman system migrate if subuid/subgid files were changed] ***
2025-10-01 10:57:22.943111 | controller | Wednesday 01 October 2025  10:57:22 +0000 (0:00:00.022)       0:00:02.846 *****
2025-10-01 10:57:22.943120 | controller | skipping: [instance]
2025-10-01 10:57:23.362732 | controller |
2025-10-01 10:57:23.362762 | controller | TASK [virtualbmc : Check if container already exists] **************************
2025-10-01 10:57:23.362770 | controller | Wednesday 01 October 2025  10:57:22 +0000 (0:00:00.025)       0:00:02.872 *****
2025-10-01 10:57:23.362780 | controller | ok: [instance]
2025-10-01 10:57:23.705600 | controller |
2025-10-01 10:57:23.705630 | controller | TASK [virtualbmc : Create ssh key for VBMC] ************************************
2025-10-01 10:57:23.705639 | controller | Wednesday 01 October 2025  10:57:23 +0000 (0:00:00.419)       0:00:03.291 *****
2025-10-01 10:57:23.705649 | controller | changed: [instance]
2025-10-01 10:57:23.705814 | controller |
2025-10-01 10:57:23.705825 | controller | TASK [virtualbmc : Pull vbmc container image] **********************************
2025-10-01 10:57:23.705833 | controller | Wednesday 01 October 2025  10:57:23 +0000 (0:00:00.342)       0:00:03.634 *****
2025-10-01 10:57:29.933592 | controller | changed: [instance]
2025-10-01 10:57:30.309024 | controller |
2025-10-01 10:57:30.309057 | controller | TASK [virtualbmc : Allow VBMC temporary key] ***********************************
2025-10-01 10:57:30.309065 | controller | Wednesday 01 October 2025  10:57:29 +0000 (0:00:06.227)       0:00:09.862 *****
2025-10-01 10:57:30.309075 | controller | changed: [instance]
2025-10-01 10:57:30.850054 | controller |
2025-10-01 10:57:30.850086 | controller | TASK [virtualbmc : Create ssh_config snippet for VBMC] *************************
2025-10-01 10:57:30.850094 | controller | Wednesday 01 October 2025  10:57:30 +0000 (0:00:00.375)       0:00:10.237 *****
2025-10-01 10:57:30.850104 | controller | changed: [instance]
2025-10-01 10:57:31.187129 | controller |
2025-10-01 10:57:31.187161 | controller | TASK [virtualbmc : Create vbmc server configuration file] **********************
2025-10-01 10:57:31.187170 | controller | Wednesday 01 October 2025  10:57:30 +0000 (0:00:00.541)       0:00:10.778 *****
2025-10-01 10:57:31.187180 | controller | changed: [instance]
2025-10-01 10:57:31.526642 | controller |
2025-10-01 10:57:31.526681 | controller | TASK [virtualbmc : Create undying vbmcd service script] ************************
2025-10-01 10:57:31.526693 | controller | Wednesday 01 October 2025  10:57:31 +0000 (0:00:00.337)       0:00:11.115 *****
2025-10-01 10:57:31.526704 | controller | changed: [instance]
2025-10-01 10:57:32.215584 | controller |
2025-10-01 10:57:32.215616 | controller | TASK [virtualbmc : Create and start vbmc container] ****************************
2025-10-01 10:57:32.215625 | controller | Wednesday 01 October 2025  10:57:31 +0000 (0:00:00.339)       0:00:11.455 *****
2025-10-01 10:57:32.215635 | controller | changed: [instance]
2025-10-01 10:57:32.242226 | controller |
2025-10-01 10:57:32.242255 | controller | TASK [virtualbmc : Assert we have required data] *******************************
2025-10-01 10:57:32.242263 | controller | Wednesday 01 October 2025  10:57:32 +0000 (0:00:00.688)       0:00:12.144 *****
2025-10-01 10:57:32.242278 | controller | ok: [instance] => changed=false
2025-10-01 10:57:32.717601 | controller |   msg: All assertions passed
2025-10-01 10:57:32.717631 | controller |
2025-10-01 10:57:32.717639 | controller | TASK [virtualbmc : Get existing known VBMC nodes] ******************************
2025-10-01 10:57:32.717646 | controller | Wednesday 01 October 2025  10:57:32 +0000 (0:00:00.026)       0:00:12.170 *****
2025-10-01 10:57:32.717656 | controller | changed: [instance]
2025-10-01 10:57:32.737496 | controller |
2025-10-01 10:57:32.737533 | controller | TASK [virtualbmc : Expose known hosts] *****************************************
2025-10-01 10:57:32.737544 | controller | Wednesday 01 October 2025  10:57:32 +0000 (0:00:00.475)       0:00:12.646 *****
2025-10-01 10:57:32.737566 | controller | ok: [instance]
2025-10-01 10:57:32.760333 | controller |
2025-10-01 10:57:32.760354 | controller | TASK [virtualbmc : Stop host in VBMC] ******************************************
2025-10-01 10:57:32.760362 | controller | Wednesday 01 October 2025  10:57:32 +0000 (0:00:00.020)       0:00:12.666 *****
2025-10-01 10:57:32.760373 | controller | skipping: [instance]
2025-10-01 10:57:33.423184 | controller |
2025-10-01 10:57:33.423213 | controller | TASK [virtualbmc : Add new host to VBMC] ***************************************
2025-10-01 10:57:33.423221 | controller | Wednesday 01 October 2025  10:57:32 +0000 (0:00:00.022)       0:00:12.689 *****
2025-10-01 10:57:33.423231 | controller | changed: [instance]
2025-10-01 10:57:33.888914 | controller |
2025-10-01 10:57:33.888946 | controller | TASK [virtualbmc : Start new host in VBMC] *************************************
2025-10-01 10:57:33.888954 | controller | Wednesday 01 October 2025  10:57:33 +0000 (0:00:00.662)       0:00:13.352 *****
2025-10-01 10:57:33.888964 | controller | changed: [instance]
2025-10-01 10:57:34.246157 | controller |
2025-10-01 10:57:34.246186 | controller | TASK [Stop VM using IPMI] ******************************************************
2025-10-01 10:57:34.246194 | controller | Wednesday 01 October 2025  10:57:33 +0000 (0:00:00.465)       0:00:13.817 *****
2025-10-01 10:57:34.246204 | controller | changed: [instance]
2025-10-01 10:57:34.567857 | controller |
2025-10-01 10:57:34.567886 | controller | TASK [List VMs from the hypervisor] ********************************************
2025-10-01 10:57:34.567894 | controller | Wednesday 01 October 2025  10:57:34 +0000 (0:00:00.357)       0:00:14.174 *****
2025-10-01 10:57:34.567904 | controller | ok: [instance]
2025-10-01 10:57:34.588406 | controller |
2025-10-01 10:57:34.588427 | controller | TASK [Ensure VM is stopped] ****************************************************
2025-10-01 10:57:34.588437 | controller | Wednesday 01 October 2025  10:57:34 +0000 (0:00:00.321)       0:00:14.496 *****
2025-10-01 10:57:34.588448 | controller | ok: [instance] => changed=false
2025-10-01 10:57:35.088345 | controller |   msg: All assertions passed
2025-10-01 10:57:35.088374 | controller |
2025-10-01 10:57:35.088382 | controller | TASK [virtualbmc : Get existing known VBMC nodes] ******************************
2025-10-01 10:57:35.088388 | controller | Wednesday 01 October 2025  10:57:34 +0000 (0:00:00.020)       0:00:14.517 *****
2025-10-01 10:57:35.088398 | controller | changed: [instance]
2025-10-01 10:57:35.113025 | controller |
2025-10-01 10:57:35.113046 | controller | TASK [virtualbmc : Expose known hosts] *****************************************
2025-10-01 10:57:35.113054 | controller | Wednesday 01 October 2025  10:57:35 +0000 (0:00:00.499)       0:00:15.017 *****
2025-10-01 10:57:35.113063 | controller | ok: [instance]
2025-10-01 10:57:35.139411 | controller |
2025-10-01 10:57:35.139430 | controller | TASK [Ensure we have the needed fact] ******************************************
2025-10-01 10:57:35.139438 | controller | Wednesday 01 October 2025  10:57:35 +0000 (0:00:00.024)       0:00:15.042 *****
2025-10-01 10:57:35.139447 | controller | ok: [instance] => changed=false
2025-10-01 10:57:35.159403 | controller |   msg: All assertions passed
2025-10-01 10:57:35.159421 | controller |
2025-10-01 10:57:35.159428 | controller | TASK [Expose known hosts] ******************************************************
2025-10-01 10:57:35.159434 | controller | Wednesday 01 October 2025  10:57:35 +0000 (0:00:00.026)       0:00:15.068 *****
2025-10-01 10:57:35.159443 | controller | ok: [instance] =>
2025-10-01 10:57:35.184154 | controller |   cifmw_virtualbmc_known_hosts:
2025-10-01 10:57:35.184171 | controller |   - Address: 127.0.0.1
2025-10-01 10:57:35.184178 | controller |     Domain name: cifmw-compute-0
2025-10-01 10:57:35.184184 | controller |     Port: 6241
2025-10-01 10:57:35.184190 | controller |     Status: running
2025-10-01 10:57:35.184200 | controller |
2025-10-01 10:57:35.184206 | controller | TASK [virtualbmc : Assert we have required data] *******************************
2025-10-01 10:57:35.184211 | controller | Wednesday 01 October 2025  10:57:35 +0000 (0:00:00.019)       0:00:15.087 *****
2025-10-01 10:57:35.184223 | controller | ok: [instance] => changed=false
2025-10-01 10:57:35.626802 | controller |   msg: All assertions passed
2025-10-01 10:57:35.626836 | controller |
2025-10-01 10:57:35.626844 | controller | TASK [virtualbmc : Get existing known VBMC nodes] ******************************
2025-10-01 10:57:35.626851 | controller | Wednesday 01 October 2025  10:57:35 +0000 (0:00:00.025)       0:00:15.113 *****
2025-10-01 10:57:35.626860 | controller | changed: [instance]
2025-10-01 10:57:35.646371 | controller |
2025-10-01 10:57:35.646395 | controller | TASK [virtualbmc : Expose known hosts] *****************************************
2025-10-01 10:57:35.646405 | controller | Wednesday 01 October 2025  10:57:35 +0000 (0:00:00.442)       0:00:15.555 *****
2025-10-01 10:57:35.646416 | controller | ok: [instance]
2025-10-01 10:57:36.130174 | controller |
2025-10-01 10:57:36.130203 | controller | TASK [virtualbmc : Stop host in VBMC] ******************************************
2025-10-01 10:57:36.130211 | controller | Wednesday 01 October 2025  10:57:35 +0000 (0:00:00.019)       0:00:15.575 *****
2025-10-01 10:57:36.130222 | controller | changed: [instance]
2025-10-01 10:57:36.617615 | controller |
2025-10-01 10:57:36.617644 | controller | TASK [virtualbmc : Add new host to VBMC] ***************************************
2025-10-01 10:57:36.617653 | controller | Wednesday 01 October 2025  10:57:36 +0000 (0:00:00.483)       0:00:16.058 *****
2025-10-01 10:57:36.617663 | controller | changed: [instance]
2025-10-01 10:57:36.649076 | controller |
2025-10-01 10:57:36.649106 | controller | TASK [virtualbmc : Start new host in VBMC] *************************************
2025-10-01 10:57:36.649114 | controller | Wednesday 01 October 2025  10:57:36 +0000 (0:00:00.487)       0:00:16.546 *****
2025-10-01 10:57:36.649124 | controller | skipping: [instance]
2025-10-01 10:57:37.080079 | controller |
2025-10-01 10:57:37.080109 | controller | TASK [virtualbmc : Get existing known VBMC nodes] ******************************
2025-10-01 10:57:37.080118 | controller | Wednesday 01 October 2025  10:57:36 +0000 (0:00:00.031)       0:00:16.578 *****
2025-10-01 10:57:37.080128 | controller | changed: [instance]
2025-10-01 10:57:37.104233 | controller |
2025-10-01 10:57:37.104261 | controller | TASK [virtualbmc : Expose known hosts] *****************************************
2025-10-01 10:57:37.104271 | controller | Wednesday 01 October 2025  10:57:37 +0000 (0:00:00.430)       0:00:17.008 *****
2025-10-01 10:57:37.104282 | controller | ok: [instance]
2025-10-01 10:57:37.145397 | controller |
2025-10-01 10:57:37.145419 | controller | TASK [Ensure we have the needed fact] ******************************************
2025-10-01 10:57:37.145426 | controller | Wednesday 01 October 2025  10:57:37 +0000 (0:00:00.024)       0:00:17.033 *****
2025-10-01 10:57:37.145436 | controller | ok: [instance] => changed=false
2025-10-01 10:57:37.202981 | controller |   msg: All assertions passed
2025-10-01 10:57:37.203011 | controller |
2025-10-01 10:57:37.203019 | controller | PLAY RECAP *********************************************************************
2025-10-01 10:57:37.203026 | controller | instance                   : ok=32   changed=17   unreachable=0    failed=0    skipped=5    rescued=0    ignored=0
2025-10-01 10:57:37.203032 | controller |
2025-10-01 10:57:37.203038 | controller | Wednesday 01 October 2025  10:57:37 +0000 (0:00:00.038)       0:00:17.071 *****
2025-10-01 10:57:37.203043 | controller | ===============================================================================
2025-10-01 10:57:37.203048 | controller | virtualbmc : Pull vbmc container image ---------------------------------- 6.23s
2025-10-01 10:57:37.203054 | controller | podman : Ensure podman is installed ------------------------------------- 1.33s
2025-10-01 10:57:37.203059 | controller | Gathering Facts --------------------------------------------------------- 0.83s
2025-10-01 10:57:37.203064 | controller | virtualbmc : Create and start vbmc container ---------------------------- 0.69s
2025-10-01 10:57:37.203070 | controller | virtualbmc : Add new host to VBMC --------------------------------------- 0.66s
2025-10-01 10:57:37.203075 | controller | virtualbmc : Create ssh_config snippet for VBMC ------------------------- 0.54s
2025-10-01 10:57:37.203080 | controller | virtualbmc : Get existing known VBMC nodes ------------------------------ 0.50s
2025-10-01 10:57:37.203090 | controller | virtualbmc : Add new host to VBMC --------------------------------------- 0.49s
2025-10-01 10:57:37.203095 | controller | virtualbmc : Stop host in VBMC ------------------------------------------ 0.48s
2025-10-01 10:57:37.203100 | controller | virtualbmc : Get existing known VBMC nodes ------------------------------ 0.48s
2025-10-01 10:57:37.203106 | controller | virtualbmc : Start new host in VBMC ------------------------------------- 0.47s
2025-10-01 10:57:37.203111 | controller | virtualbmc : Get existing known VBMC nodes ------------------------------ 0.44s
2025-10-01 10:57:37.203119 | controller | virtualbmc : Get existing known VBMC nodes ------------------------------ 0.43s
2025-10-01 10:57:37.203124 | controller | virtualbmc : Check if container already exists -------------------------- 0.42s
2025-10-01 10:57:37.203129 | controller | virtualbmc : Allow VBMC temporary key ----------------------------------- 0.38s
2025-10-01 10:57:37.203135 | controller | Stop VM using IPMI ------------------------------------------------------ 0.36s
2025-10-01 10:57:37.203140 | controller | virtualbmc : Create ssh key for VBMC ------------------------------------ 0.34s
2025-10-01 10:57:37.203145 | controller | virtualbmc : Create undying vbmcd service script ------------------------ 0.34s
2025-10-01 10:57:37.203151 | controller | virtualbmc : Create vbmc server configuration file ---------------------- 0.34s
2025-10-01 10:57:37.203156 | controller | podman : Enable loginctl linger for ansible_user_id --------------------- 0.32s
2025-10-01 10:57:37.203166 | controller | INFO     Running default > cleanup
2025-10-01 10:57:37.687549 | controller |
2025-10-01 10:57:37.687789 | controller | PLAY [Cleanup] *****************************************************************
2025-10-01 10:57:37.687930 | controller |
2025-10-01 10:57:37.688076 | controller | TASK [Gathering Facts] *********************************************************
2025-10-01 10:57:37.688218 | controller | Wednesday 01 October 2025  10:57:37 +0000 (0:00:00.016)       0:00:00.016 *****
2025-10-01 10:57:38.516652 | controller | ok: [instance]
2025-10-01 10:57:38.516703 | controller |
2025-10-01 10:57:38.516973 | controller | TASK [libvirt_manager : Get installed packages list] ***************************
2025-10-01 10:57:39.287640 | controller | Wednesday 01 October 2025  10:57:38 +0000 (0:00:00.829)       0:00:00.845 *****
2025-10-01 10:57:39.287679 | controller | ok: [instance]
2025-10-01 10:57:39.287710 | controller |
2025-10-01 10:57:39.287721 | controller | TASK [libvirt_manager : Populate service facts] ********************************
2025-10-01 10:57:39.287828 | controller | Wednesday 01 October 2025  10:57:39 +0000 (0:00:00.771)       0:00:01.616 *****
2025-10-01 10:57:41.469653 | controller | ok: [instance]
2025-10-01 10:57:41.469786 | controller |
2025-10-01 10:57:41.469807 | controller | TASK [libvirt_manager : Start virtqemud socket service] ************************
2025-10-01 10:57:41.469822 | controller | Wednesday 01 October 2025  10:57:41 +0000 (0:00:02.181)       0:00:03.798 *****
2025-10-01 10:57:42.383683 | controller | ok: [instance] => (item=virtqemud.service)
2025-10-01 10:57:42.383770 | controller | ok: [instance] => (item=virtqemud.socket)
2025-10-01 10:57:42.383787 | controller |
2025-10-01 10:57:42.383794 | controller | TASK [libvirt_manager : Set _is_deepscrub internal fact] ***********************
2025-10-01 10:57:42.383803 | controller | Wednesday 01 October 2025  10:57:42 +0000 (0:00:00.914)       0:00:04.712 *****
2025-10-01 10:57:42.436069 | controller | ok: [instance]
2025-10-01 10:57:42.835414 | controller |
2025-10-01 10:57:42.835449 | controller | TASK [libvirt_manager : List all of the existing virtual machines] *************
2025-10-01 10:57:42.835457 | controller | Wednesday 01 October 2025  10:57:42 +0000 (0:00:00.052)       0:00:04.765 *****
2025-10-01 10:57:42.835467 | controller | ok: [instance]
2025-10-01 10:57:43.229590 | controller |
2025-10-01 10:57:43.229623 | controller | TASK [libvirt_manager : Get pool configuration] ********************************
2025-10-01 10:57:43.229632 | controller | Wednesday 01 October 2025  10:57:42 +0000 (0:00:00.399)       0:00:05.164 *****
2025-10-01 10:57:43.229642 | controller | ok: [instance]
2025-10-01 10:57:43.314652 | controller |
2025-10-01 10:57:43.314684 | controller | TASK [libvirt_manager : Filter out target environment] *************************
2025-10-01 10:57:43.314692 | controller | Wednesday 01 October 2025  10:57:43 +0000 (0:00:00.394)       0:00:05.558 *****
2025-10-01 10:57:43.314702 | controller | ok: [instance]
2025-10-01 10:57:43.314733 | controller |
2025-10-01 10:57:43.314741 | controller | TASK [libvirt_manager : Expose cleanup list] ***********************************
2025-10-01 10:57:43.314886 | controller | Wednesday 01 October 2025  10:57:43 +0000 (0:00:00.085)       0:00:05.643 *****
2025-10-01 10:57:43.441649 | controller | ok: [instance] =>
2025-10-01 10:57:43.441699 | controller |   cleanup_vms:
2025-10-01 10:57:43.441709 | controller |   - cifmw-compute-0
2025-10-01 10:57:43.442000 | controller |
2025-10-01 10:57:43.780281 | controller | TASK [libvirt_manager : Clean ssh known_hosts] *********************************
2025-10-01 10:57:43.780310 | controller | Wednesday 01 October 2025  10:57:43 +0000 (0:00:00.127)       0:00:05.770 *****
2025-10-01 10:57:43.780322 | controller | ok: [instance] => (item=cifmw-compute-0)
2025-10-01 10:57:44.092629 | controller |
2025-10-01 10:57:44.092663 | controller | TASK [libvirt_manager : Destroy machine] ***************************************
2025-10-01 10:57:44.092673 | controller | Wednesday 01 October 2025  10:57:43 +0000 (0:00:00.338)       0:00:06.109 *****
2025-10-01 10:57:44.092689 | controller | ok: [instance] => (item=cifmw-compute-0)
2025-10-01 10:57:44.411848 | controller |
2025-10-01 10:57:44.411891 | controller | TASK [libvirt_manager : Undefine machine] **************************************
2025-10-01 10:57:44.411901 | controller | Wednesday 01 October 2025  10:57:44 +0000 (0:00:00.312)       0:00:06.421 *****
2025-10-01 10:57:44.411915 | controller | ok: [instance] => (item=cifmw-compute-0)
2025-10-01 10:57:44.411939 | controller |
2025-10-01 10:57:44.411947 | controller | TASK [libvirt_manager : (localhost) Clean ssh jumpers] *************************
2025-10-01 10:57:44.411956 | controller | Wednesday 01 October 2025  10:57:44 +0000 (0:00:00.318)       0:00:06.740 *****
2025-10-01 10:57:44.829644 | controller | ok: [instance -> localhost] => (item=cifmw-compute-0)
2025-10-01 10:57:44.829902 | controller |
2025-10-01 10:57:44.829942 | controller | TASK [libvirt_manager : (instance) Clean ssh jumpers] **************************
2025-10-01 10:57:45.110682 | controller | Wednesday 01 October 2025  10:57:44 +0000 (0:00:00.418)       0:00:07.158 *****
2025-10-01 10:57:45.110725 | controller | ok: [instance] => (item=cifmw-compute-0)
2025-10-01 10:57:45.530113 | controller |
2025-10-01 10:57:45.530148 | controller | TASK [libvirt_manager : Get network list] **************************************
2025-10-01 10:57:45.530158 | controller | Wednesday 01 October 2025  10:57:45 +0000 (0:00:00.280)       0:00:07.439 *****
2025-10-01 10:57:45.530170 | controller | ok: [instance]
2025-10-01 10:57:45.625238 | controller |
2025-10-01 10:57:45.625263 | controller | TASK [libvirt_manager : Filter out target nets] ********************************
2025-10-01 10:57:45.625272 | controller | Wednesday 01 October 2025  10:57:45 +0000 (0:00:00.419)       0:00:07.858 *****
2025-10-01 10:57:45.625283 | controller | ok: [instance]
2025-10-01 10:57:45.706635 | controller |
2025-10-01 10:57:45.706672 | controller | TASK [libvirt_manager : Expose cleanup list] ***********************************
2025-10-01 10:57:45.706681 | controller | Wednesday 01 October 2025  10:57:45 +0000 (0:00:00.095)       0:00:07.954 *****
2025-10-01 10:57:45.706692 | controller | ok: [instance] =>
2025-10-01 10:57:45.706718 | controller |   cleanup_nets:
2025-10-01 10:57:45.707128 | controller |   - cifmw-public
2025-10-01 10:57:45.853057 | controller |
2025-10-01 10:57:45.853097 | controller | TASK [Remove dnsmasq network bits] *********************************************
2025-10-01 10:57:45.853107 | controller | Wednesday 01 October 2025  10:57:45 +0000 (0:00:00.081)       0:00:08.035 *****
2025-10-01 10:57:45.853119 | controller |
2025-10-01 10:57:45.940067 | controller | TASK [dnsmasq : Assert mandatory parameter] ************************************
2025-10-01 10:57:45.940104 | controller | Wednesday 01 October 2025  10:57:45 +0000 (0:00:00.145)       0:00:08.181 *****
2025-10-01 10:57:45.940118 | controller | ok: [instance] => changed=false
2025-10-01 10:57:45.940318 | controller |   msg: All assertions passed
2025-10-01 10:57:45.940454 | controller |
2025-10-01 10:57:45.940638 | controller | TASK [dnsmasq : Assert mandatory parameters for new network] *******************
2025-10-01 10:57:45.940783 | controller | Wednesday 01 October 2025  10:57:45 +0000 (0:00:00.087)       0:00:08.269 *****
2025-10-01 10:57:46.020576 | controller | skipping: [instance]
2025-10-01 10:57:46.020757 | controller |
2025-10-01 10:57:46.020908 | controller | TASK [dnsmasq : Create network] ************************************************
2025-10-01 10:57:46.021050 | controller | Wednesday 01 October 2025  10:57:46 +0000 (0:00:00.080)       0:00:08.349 *****
2025-10-01 10:57:46.100371 | controller | skipping: [instance]
2025-10-01 10:57:46.100581 | controller |
2025-10-01 10:57:46.100745 | controller | TASK [dnsmasq : Remove network] ************************************************
2025-10-01 10:57:46.100887 | controller | Wednesday 01 October 2025  10:57:46 +0000 (0:00:00.079)       0:00:08.429 *****
2025-10-01 10:57:46.473470 | controller | ok: [instance]
2025-10-01 10:57:46.786587 | controller |
2025-10-01 10:57:46.786623 | controller | TASK [dnsmasq : Remove dhcp host files] ****************************************
2025-10-01 10:57:46.786633 | controller | Wednesday 01 October 2025  10:57:46 +0000 (0:00:00.372)       0:00:08.802 *****
2025-10-01 10:57:46.786645 | controller | ok: [instance]
2025-10-01 10:57:47.392261 | controller |
2025-10-01 10:57:47.392293 | controller | TASK [libvirt_manager : Destroy networks] **************************************
2025-10-01 10:57:47.392301 | controller | Wednesday 01 October 2025  10:57:46 +0000 (0:00:00.313)       0:00:09.115 *****
2025-10-01 10:57:47.392311 | controller | ok: [instance] => (item=cifmw-public)
2025-10-01 10:57:47.709119 | controller |
2025-10-01 10:57:47.709150 | controller | TASK [libvirt_manager : Undefine networks] *************************************
2025-10-01 10:57:47.709159 | controller | Wednesday 01 October 2025  10:57:47 +0000 (0:00:00.605)       0:00:09.721 *****
2025-10-01 10:57:47.709168 | controller | ok: [instance] => (item=cifmw-public)
2025-10-01 10:57:48.136639 | controller |
2025-10-01 10:57:48.136672 | controller | TASK [libvirt_manager : Ensure no trace of networks lays in nmcli] *************
2025-10-01 10:57:48.136683 | controller | Wednesday 01 October 2025  10:57:47 +0000 (0:00:00.316)       0:00:10.037 *****
2025-10-01 10:57:48.136695 | controller | ok: [instance] => (item=cifmw-public)
2025-10-01 10:57:48.136728 | controller |
2025-10-01 10:57:48.136738 | controller | TASK [libvirt_manager : Find dummy interface connection files] *****************
2025-10-01 10:57:48.136804 | controller | Wednesday 01 October 2025  10:57:48 +0000 (0:00:00.427)       0:00:10.465 *****
2025-10-01 10:57:48.482663 | controller | ok: [instance]
2025-10-01 10:57:48.482920 | controller |
2025-10-01 10:57:48.482960 | controller | TASK [libvirt_manager : Remove dummy interface connections] ********************
2025-10-01 10:57:48.820226 | controller | Wednesday 01 October 2025  10:57:48 +0000 (0:00:00.346)       0:00:10.811 *****
2025-10-01 10:57:48.820264 | controller | changed: [instance] => (item={'path': '/etc/NetworkManager/system-connections/dummy-zoorn5o4.nmconnection', 'mode': '0600', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 0, 'gid': 0, 'size': 308, 'inode': 311129, 'dev': 64513, 'nlink': 1, 'atime': 1759316213.529814, 'mtime': 1759316213.529814, 'ctime': 1759316213.529814, 'gr_name': 'root', 'pw_name': 'root', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': False, 'xgrp': False, 'woth': False, 'roth': False, 'xoth': False, 'isuid': False, 'isgid': False})
2025-10-01 10:57:49.331690 | controller |
2025-10-01 10:57:49.331725 | controller | TASK [libvirt_manager : Clean firewalld libvirt zone] **************************
2025-10-01 10:57:49.331734 | controller | Wednesday 01 October 2025  10:57:48 +0000 (0:00:00.337)       0:00:11.149 *****
2025-10-01 10:57:49.331746 | controller | changed: [instance] => (item=cifmw-public)
2025-10-01 10:57:49.331774 | controller |
2025-10-01 10:57:49.331784 | controller | TASK [libvirt_manager : Disable masquerade in firewalld default zone] **********
2025-10-01 10:57:49.331890 | controller | Wednesday 01 October 2025  10:57:49 +0000 (0:00:00.511)       0:00:11.660 *****
2025-10-01 10:57:49.729995 | controller | changed: [instance]
2025-10-01 10:57:50.298652 | controller |
2025-10-01 10:57:50.298686 | controller | TASK [libvirt_manager : Disable forward in firewalld libvirt zone] *************
2025-10-01 10:57:50.298696 | controller | Wednesday 01 October 2025  10:57:49 +0000 (0:00:00.398)       0:00:12.058 *****
2025-10-01 10:57:50.298708 | controller | changed: [instance]
2025-10-01 10:57:50.298739 | controller |
2025-10-01 10:57:50.298747 | controller | TASK [libvirt_manager : Remove cifmw storage pool] *****************************
2025-10-01 10:57:50.298756 | controller | Wednesday 01 October 2025  10:57:50 +0000 (0:00:00.568)       0:00:12.627 *****
2025-10-01 10:57:50.415080 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/storage_pool.yml for instance
2025-10-01 10:57:50.529331 | controller |
2025-10-01 10:57:50.529367 | controller | TASK [libvirt_manager : Ensure we have a known action] *************************
2025-10-01 10:57:50.529375 | controller | Wednesday 01 October 2025  10:57:50 +0000 (0:00:00.116)       0:00:12.744 *****
2025-10-01 10:57:50.529385 | controller | ok: [instance] => changed=false
2025-10-01 10:57:50.809587 | controller |   msg: All assertions passed
2025-10-01 10:57:50.809620 | controller |
2025-10-01 10:57:50.809628 | controller | TASK [libvirt_manager : Gather the status of cifmw-pool storage pool.] *********
2025-10-01 10:57:50.809635 | controller | Wednesday 01 October 2025  10:57:50 +0000 (0:00:00.113)       0:00:12.858 *****
2025-10-01 10:57:50.809645 | controller | changed: [instance]
2025-10-01 10:57:50.891008 | controller |
2025-10-01 10:57:50.891036 | controller | TASK [libvirt_manager : Create the storage pool] *******************************
2025-10-01 10:57:50.891044 | controller | Wednesday 01 October 2025  10:57:50 +0000 (0:00:00.280)       0:00:13.138 *****
2025-10-01 10:57:50.891054 | controller | skipping: [instance]
2025-10-01 10:57:51.005256 | controller |
2025-10-01 10:57:51.005288 | controller | TASK [libvirt_manager : Ensure the storage pool is started] ********************
2025-10-01 10:57:51.005296 | controller | Wednesday 01 October 2025  10:57:50 +0000 (0:00:00.081)       0:00:13.219 *****
2025-10-01 10:57:51.005306 | controller | skipping: [instance] => (item=pool-start)
2025-10-01 10:57:51.085393 | controller | skipping: [instance] => (item=pool-autostart)
2025-10-01 10:57:51.085420 | controller | skipping: [instance]
2025-10-01 10:57:51.085428 | controller |
2025-10-01 10:57:51.085435 | controller | TASK [libvirt_manager : Gather all the volumes in the pool to delete] **********
2025-10-01 10:57:51.085441 | controller | Wednesday 01 October 2025  10:57:51 +0000 (0:00:00.113)       0:00:13.333 *****
2025-10-01 10:57:51.085450 | controller | skipping: [instance]
2025-10-01 10:57:51.166503 | controller |
2025-10-01 10:57:51.166548 | controller | TASK [libvirt_manager : Remove the volumes from pool to delete] ****************
2025-10-01 10:57:51.166569 | controller | Wednesday 01 October 2025  10:57:51 +0000 (0:00:00.080)       0:00:13.414 *****
2025-10-01 10:57:51.166579 | controller | skipping: [instance]
2025-10-01 10:57:51.278353 | controller |
2025-10-01 10:57:51.278381 | controller | TASK [libvirt_manager : Delete storage pool] ***********************************
2025-10-01 10:57:51.278390 | controller | Wednesday 01 October 2025  10:57:51 +0000 (0:00:00.081)       0:00:13.495 *****
2025-10-01 10:57:51.278400 | controller | skipping: [instance] => (item=pool-destroy)
2025-10-01 10:57:51.575576 | controller | skipping: [instance] => (item=pool-undefine)
2025-10-01 10:57:51.575609 | controller | skipping: [instance]
2025-10-01 10:57:51.575617 | controller |
2025-10-01 10:57:51.575624 | controller | TASK [libvirt_manager : Refresh pools facts] ***********************************
2025-10-01 10:57:51.575630 | controller | Wednesday 01 October 2025  10:57:51 +0000 (0:00:00.111)       0:00:13.607 *****
2025-10-01 10:57:51.575640 | controller | ok: [instance]
2025-10-01 10:57:51.621644 | controller |
2025-10-01 10:57:51.621680 | controller | TASK [libvirt_manager : Remove overlay images from ocp_volume pools if exists] ***
2025-10-01 10:57:51.621689 | controller | Wednesday 01 October 2025  10:57:51 +0000 (0:00:00.297)       0:00:13.904 *****
2025-10-01 10:57:51.621702 | controller | skipping: [instance]
2025-10-01 10:57:51.621734 | controller |
2025-10-01 10:57:51.621762 | controller | TASK [libvirt_manager : Remove ocp_volumes storage pool] ***********************
2025-10-01 10:57:51.621895 | controller | Wednesday 01 October 2025  10:57:51 +0000 (0:00:00.046)       0:00:13.951 *****
2025-10-01 10:57:51.726401 | controller | skipping: [instance]
2025-10-01 10:57:51.772601 | controller |
2025-10-01 10:57:51.772641 | controller | TASK [libvirt_manager : Refresh all pools after actions] ***********************
2025-10-01 10:57:51.772652 | controller | Wednesday 01 October 2025  10:57:51 +0000 (0:00:00.104)       0:00:14.055 *****
2025-10-01 10:57:51.772666 | controller | skipping: [instance]
2025-10-01 10:57:52.065641 | controller |
2025-10-01 10:57:52.065678 | controller | TASK [libvirt_manager : Get temporary key status] ******************************
2025-10-01 10:57:52.065688 | controller | Wednesday 01 October 2025  10:57:51 +0000 (0:00:00.046)       0:00:14.101 *****
2025-10-01 10:57:52.065700 | controller | ok: [instance]
2025-10-01 10:57:52.065736 | controller |
2025-10-01 10:57:52.065883 | controller | TASK [libvirt_manager : Get public key] ****************************************
2025-10-01 10:57:52.065926 | controller | Wednesday 01 October 2025  10:57:52 +0000 (0:00:00.293)       0:00:14.394 *****
2025-10-01 10:57:52.115622 | controller | skipping: [instance]
2025-10-01 10:57:52.165622 | controller |
2025-10-01 10:57:52.165651 | controller | TASK [libvirt_manager : Remove public key] *************************************
2025-10-01 10:57:52.165658 | controller | Wednesday 01 October 2025  10:57:52 +0000 (0:00:00.049)       0:00:14.444 *****
2025-10-01 10:57:52.165668 | controller | skipping: [instance]
2025-10-01 10:57:52.165693 | controller |
2025-10-01 10:57:52.165701 | controller | TASK [libvirt_manager : Remove keypair] ****************************************
2025-10-01 10:57:52.165834 | controller | Wednesday 01 October 2025  10:57:52 +0000 (0:00:00.050)       0:00:14.494 *****
2025-10-01 10:57:52.221639 | controller | skipping: [instance] => (item=cifmw_reproducer_key.pub)
2025-10-01 10:57:52.221685 | controller | skipping: [instance] => (item=cifmw_reproducer_key)
2025-10-01 10:57:52.221693 | controller | skipping: [instance]
2025-10-01 10:57:52.221699 | controller |
2025-10-01 10:57:52.221707 | controller | TASK [libvirt_manager : List libvirt logs] *************************************
2025-10-01 10:57:52.221834 | controller | Wednesday 01 October 2025  10:57:52 +0000 (0:00:00.055)       0:00:14.550 *****
2025-10-01 10:57:52.437187 | controller | ok: [instance]
2025-10-01 10:57:52.474456 | controller |
2025-10-01 10:57:52.474482 | controller | TASK [libvirt_manager : Remove detected logs] **********************************
2025-10-01 10:57:52.474492 | controller | Wednesday 01 October 2025  10:57:52 +0000 (0:00:00.215)       0:00:14.765 *****
2025-10-01 10:57:52.474503 | controller | skipping: [instance]
2025-10-01 10:57:53.864399 | controller |
2025-10-01 10:57:53.864429 | controller | TASK [libvirt_manager : Remove workload and volumes] ***************************
2025-10-01 10:57:53.864438 | controller | Wednesday 01 October 2025  10:57:52 +0000 (0:00:00.037)       0:00:14.803 *****
2025-10-01 10:57:53.864448 | controller | changed: [instance] => (item=workload)
2025-10-01 10:57:53.916657 | controller | changed: [instance] => (item=volumes)
2025-10-01 10:57:53.916689 | controller | changed: [instance] => (item=artifacts/debug_network_data.yml)
2025-10-01 10:57:53.916699 | controller | changed: [instance] => (item=artifacts/debug_pub_net_value.txt)
2025-10-01 10:57:53.916706 | controller | changed: [instance] => (item=artifacts/debug_cifmw_libvirt_manager_layout.yml)
2025-10-01 10:57:53.916713 | controller | changed: [instance] => (item=artifacts/interfaces-info.yml)
2025-10-01 10:57:53.916720 | controller | changed: [instance] => (item=artifacts/libvirt-uuids.yml)
2025-10-01 10:57:53.916727 | controller | changed: [instance] => (item=artifacts/net-map-def-patch.yml)
2025-10-01 10:57:53.916734 | controller |
2025-10-01 10:57:53.916740 | controller | TASK [libvirt_manager : Deepscrub data] ****************************************
2025-10-01 10:57:53.916747 | controller | Wednesday 01 October 2025  10:57:53 +0000 (0:00:01.388)       0:00:16.192 *****
2025-10-01 10:57:53.916759 | controller | skipping: [instance] => (item=images)
2025-10-01 10:57:55.256485 | controller | skipping: [instance] => (item=artifacts/virtual-nodes.yml)
2025-10-01 10:57:55.256533 | controller | skipping: [instance]
2025-10-01 10:57:55.256545 | controller |
2025-10-01 10:57:55.256552 | controller | TASK [podman : Ensure podman is installed] *************************************
2025-10-01 10:57:55.256568 | controller | Wednesday 01 October 2025  10:57:53 +0000 (0:00:00.053)       0:00:16.245 *****
2025-10-01 10:57:55.256578 | controller | ok: [instance]
2025-10-01 10:57:55.507135 | controller |
2025-10-01 10:57:55.507169 | controller | TASK [podman : Enable loginctl linger for ansible_user_id] *********************
2025-10-01 10:57:55.507179 | controller | Wednesday 01 October 2025  10:57:55 +0000 (0:00:01.339)       0:00:17.585 *****
2025-10-01 10:57:55.507191 | controller | changed: [instance]
2025-10-01 10:57:55.552623 | controller |
2025-10-01 10:57:55.552652 | controller | TASK [podman : Ensure subordinate UID entry exists for zuul] *******************
2025-10-01 10:57:55.552662 | controller | Wednesday 01 October 2025  10:57:55 +0000 (0:00:00.250)       0:00:17.836 *****
2025-10-01 10:57:55.552674 | controller | skipping: [instance]
2025-10-01 10:57:55.552708 | controller |
2025-10-01 10:57:55.552719 | controller | TASK [podman : Ensure subordinate GID entry exists for zuul] *******************
2025-10-01 10:57:55.552833 | controller | Wednesday 01 October 2025  10:57:55 +0000 (0:00:00.045)       0:00:17.881 *****
2025-10-01 10:57:55.616348 | controller | skipping: [instance]
2025-10-01 10:57:55.681791 | controller |
2025-10-01 10:57:55.681811 | controller | TASK [podman : Run podman system migrate if subuid/subgid files were changed] ***
2025-10-01 10:57:55.681819 | controller | Wednesday 01 October 2025  10:57:55 +0000 (0:00:00.063)       0:00:17.945 *****
2025-10-01 10:57:55.681827 | controller | skipping: [instance]
2025-10-01 10:58:06.268463 | controller |
2025-10-01 10:58:06.268496 | controller | TASK [virtualbmc : Stop and remove vbmc container] *****************************
2025-10-01 10:58:06.268504 | controller | Wednesday 01 October 2025  10:57:55 +0000 (0:00:00.065)       0:00:18.010 *****
2025-10-01 10:58:06.268535 | controller | changed: [instance]
2025-10-01 10:58:07.428707 | controller |
2025-10-01 10:58:07.428752 | controller | TASK [virtualbmc : Remove vbmc container image] ********************************
2025-10-01 10:58:07.428767 | controller | Wednesday 01 October 2025  10:58:06 +0000 (0:00:10.586)       0:00:28.597 *****
2025-10-01 10:58:07.428781 | controller | changed: [instance]
2025-10-01 10:58:07.679051 | controller |
2025-10-01 10:58:07.679088 | controller | TASK [virtualbmc : Check if VBMC key exists] ***********************************
2025-10-01 10:58:07.679106 | controller | Wednesday 01 October 2025  10:58:07 +0000 (0:00:01.160)       0:00:29.757 *****
2025-10-01 10:58:07.679118 | controller | ok: [instance]
2025-10-01 10:58:07.679142 | controller |
2025-10-01 10:58:07.679395 | controller | TASK [virtualbmc : Slurp key] **************************************************
2025-10-01 10:58:07.981643 | controller | Wednesday 01 October 2025  10:58:07 +0000 (0:00:00.250)       0:00:30.008 *****
2025-10-01 10:58:07.981684 | controller | ok: [instance]
2025-10-01 10:58:08.404440 | controller |
2025-10-01 10:58:08.404476 | controller | TASK [virtualbmc : Revoke VBMC SSH access] *************************************
2025-10-01 10:58:08.404486 | controller | Wednesday 01 October 2025  10:58:07 +0000 (0:00:00.302)       0:00:30.310 *****
2025-10-01 10:58:08.404498 | controller | changed: [instance]
2025-10-01 10:58:09.155678 | controller |
2025-10-01 10:58:09.155713 | controller | TASK [virtualbmc : Remove vbmc files] ******************************************
2025-10-01 10:58:09.155723 | controller | Wednesday 01 October 2025  10:58:08 +0000 (0:00:00.422)       0:00:30.733 *****
2025-10-01 10:58:09.155736 | controller | changed: [instance] => (item=/home/zuul/.ssh/vbmc-key)
2025-10-01 10:58:09.155797 | controller | changed: [instance] => (item=/home/zuul/.ssh/vbmc-key.pub)
2025-10-01 10:58:09.155828 | controller | changed: [instance] => (item=/home/zuul/.ssh/virtualbmc.conf)
2025-10-01 10:58:09.155836 | controller | changed: [instance] => (item=/home/zuul/.ssh/vbmcd.sh)
2025-10-01 10:58:09.155841 | controller |
2025-10-01 10:58:09.155847 | controller | TASK [Clean remote ssh config] *************************************************
2025-10-01 10:58:09.155857 | controller | Wednesday 01 October 2025  10:58:09 +0000 (0:00:00.751)       0:00:31.484 *****
2025-10-01 10:58:09.238413 | controller |
2025-10-01 10:58:09.568193 | controller | TASK [ssh_jumper : Remove Include cifmw_ssh_config.d] **************************
2025-10-01 10:58:09.568224 | controller | Wednesday 01 October 2025  10:58:09 +0000 (0:00:00.083)       0:00:31.567 *****
2025-10-01 10:58:09.568236 | controller | ok: [instance]
2025-10-01 10:58:09.799202 | controller |
2025-10-01 10:58:09.799236 | controller | TASK [ssh_jumper : Remove cifmw_ssh_config.d directory] ************************
2025-10-01 10:58:09.799246 | controller | Wednesday 01 October 2025  10:58:09 +0000 (0:00:00.329)       0:00:31.897 *****
2025-10-01 10:58:09.799258 | controller | ok: [instance]
2025-10-01 10:58:09.883033 | controller |
2025-10-01 10:58:09.883055 | controller | TASK [Clean local ssh config] **************************************************
2025-10-01 10:58:09.883064 | controller | Wednesday 01 October 2025  10:58:09 +0000 (0:00:00.230)       0:00:32.128 *****
2025-10-01 10:58:09.883075 | controller |
2025-10-01 10:58:10.085631 | controller | TASK [ssh_jumper : Remove Include cifmw_ssh_config.d] **************************
2025-10-01 10:58:10.085665 | controller | Wednesday 01 October 2025  10:58:09 +0000 (0:00:00.084)       0:00:32.212 *****
2025-10-01 10:58:10.085678 | controller | ok: [instance -> localhost]
2025-10-01 10:58:10.085704 | controller |
2025-10-01 10:58:10.085973 | controller | TASK [ssh_jumper : Remove cifmw_ssh_config.d directory] ************************
2025-10-01 10:58:10.315336 | controller | Wednesday 01 October 2025  10:58:10 +0000 (0:00:00.202)       0:00:32.414 *****
2025-10-01 10:58:10.315374 | controller | ok: [instance -> localhost]
2025-10-01 10:58:10.386107 | controller |
2025-10-01 10:58:10.386131 | controller | TASK [dnsmasq : Cleaning dnsmasq] **********************************************
2025-10-01 10:58:10.386139 | controller | Wednesday 01 October 2025  10:58:10 +0000 (0:00:00.229)       0:00:32.644 *****
2025-10-01 10:58:10.386149 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/configure.yml for instance
2025-10-01 10:58:11.614651 | controller |
2025-10-01 10:58:11.614686 | controller | TASK [dnsmasq : Install needed packages] ***************************************
2025-10-01 10:58:11.614696 | controller | Wednesday 01 October 2025  10:58:10 +0000 (0:00:00.070)       0:00:32.715 *****
2025-10-01 10:58:11.614709 | controller | ok: [instance]
2025-10-01 10:58:15.026680 | controller |
2025-10-01 10:58:15.026717 | controller | TASK [dnsmasq : Ensure SELinux knows about the new files and directories] ******
2025-10-01 10:58:15.026727 | controller | Wednesday 01 October 2025  10:58:11 +0000 (0:00:01.228)       0:00:33.943 *****
2025-10-01 10:58:15.026739 | controller | changed: [instance] => (item={'target': '/etc/cifmw-dnsmasq.conf', 'setype': 'dnsmasq_etc_t'})
2025-10-01 10:58:15.026769 | controller | changed: [instance] => (item={'target': '/etc/cifmw-dnsmasq.d(/.*)?', 'setype': 'dnsmasq_etc_t'})
2025-10-01 10:58:15.026779 | controller | changed: [instance] => (item={'target': '/var/run/cifmw-dnsmasq.pid', 'setype': 'dnsmasq_var_run_t'})
2025-10-01 10:58:15.027060 | controller |
2025-10-01 10:58:15.266406 | controller | TASK [dnsmasq : Manage configuration directory] ********************************
2025-10-01 10:58:15.266435 | controller | Wednesday 01 October 2025  10:58:15 +0000 (0:00:03.412)       0:00:37.355 *****
2025-10-01 10:58:15.266447 | controller | changed: [instance]
2025-10-01 10:58:15.326597 | controller |
2025-10-01 10:58:15.326621 | controller | TASK [dnsmasq : Manage systemd unit file] **************************************
2025-10-01 10:58:15.326635 | controller | Wednesday 01 October 2025  10:58:15 +0000 (0:00:00.239)       0:00:37.595 *****
2025-10-01 10:58:15.326646 | controller | skipping: [instance]
2025-10-01 10:58:15.327054 | controller |
2025-10-01 10:58:15.367022 | controller | TASK [dnsmasq : Manage base configuration file] ********************************
2025-10-01 10:58:15.367041 | controller | Wednesday 01 October 2025  10:58:15 +0000 (0:00:00.060)       0:00:37.656 *****
2025-10-01 10:58:15.367051 | controller | skipping: [instance]
2025-10-01 10:58:15.432040 | controller |
2025-10-01 10:58:15.432059 | controller | TASK [dnsmasq : Render listener configuration] *********************************
2025-10-01 10:58:15.432066 | controller | Wednesday 01 October 2025  10:58:15 +0000 (0:00:00.039)       0:00:37.696 *****
2025-10-01 10:58:15.432075 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/listener.yml for instance
2025-10-01 10:58:15.470312 | controller |
2025-10-01 10:58:15.470333 | controller | TASK [dnsmasq : Create listener configuration file] ****************************
2025-10-01 10:58:15.470340 | controller | Wednesday 01 October 2025  10:58:15 +0000 (0:00:00.064)       0:00:37.761 *****
2025-10-01 10:58:15.470349 | controller | skipping: [instance]
2025-10-01 10:58:15.692670 | controller |
2025-10-01 10:58:15.692711 | controller | TASK [dnsmasq : Remove listener configuration file] ****************************
2025-10-01 10:58:15.692721 | controller | Wednesday 01 October 2025  10:58:15 +0000 (0:00:00.038)       0:00:37.799 *****
2025-10-01 10:58:15.692733 | controller | changed: [instance]
2025-10-01 10:58:15.757405 | controller |
2025-10-01 10:58:15.757440 | controller | TASK [dnsmasq : Render dns configuration] **************************************
2025-10-01 10:58:15.757449 | controller | Wednesday 01 October 2025  10:58:15 +0000 (0:00:00.222)       0:00:38.021 *****
2025-10-01 10:58:15.757461 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/dns.yml for instance
2025-10-01 10:58:15.794976 | controller |
2025-10-01 10:58:15.794995 | controller | TASK [dnsmasq : Create dns configuration file] *********************************
2025-10-01 10:58:15.795003 | controller | Wednesday 01 October 2025  10:58:15 +0000 (0:00:00.064)       0:00:38.086 *****
2025-10-01 10:58:15.795011 | controller | skipping: [instance]
2025-10-01 10:58:16.015690 | controller |
2025-10-01 10:58:16.015725 | controller | TASK [dnsmasq : Remove dns configuration file] *********************************
2025-10-01 10:58:16.015736 | controller | Wednesday 01 October 2025  10:58:15 +0000 (0:00:00.037)       0:00:38.124 *****
2025-10-01 10:58:16.015754 | controller | changed: [instance]
2025-10-01 10:58:16.078072 | controller |
2025-10-01 10:58:16.078107 | controller | TASK [dnsmasq : Add localhost addresses from defined dnsmasq listen addresses to loopback interface] ***
2025-10-01 10:58:16.078117 | controller | Wednesday 01 October 2025  10:58:16 +0000 (0:00:00.220)       0:00:38.344 *****
2025-10-01 10:58:16.078129 | controller | skipping: [instance]
2025-10-01 10:58:16.116508 | controller |
2025-10-01 10:58:16.116549 | controller | TASK [dnsmasq : Enable and start service] **************************************
2025-10-01 10:58:16.116566 | controller | Wednesday 01 October 2025  10:58:16 +0000 (0:00:00.062)       0:00:38.407 *****
2025-10-01 10:58:16.116576 | controller | skipping: [instance]
2025-10-01 10:58:16.871197 | controller |
2025-10-01 10:58:16.871226 | controller | TASK [dnsmasq : Stop service] **************************************************
2025-10-01 10:58:16.871234 | controller | Wednesday 01 October 2025  10:58:16 +0000 (0:00:00.038)       0:00:38.445 *****
2025-10-01 10:58:16.871244 | controller | changed: [instance]
2025-10-01 10:58:17.094285 | controller |
2025-10-01 10:58:17.094315 | controller | TASK [dnsmasq : Remove unit file] **********************************************
2025-10-01 10:58:17.094324 | controller | Wednesday 01 October 2025  10:58:16 +0000 (0:00:00.754)       0:00:39.200 *****
2025-10-01 10:58:17.094334 | controller | changed: [instance]
2025-10-01 10:58:17.495654 | controller |
2025-10-01 10:58:17.495691 | controller | TASK [dnsmasq : Remove main configuration files] *******************************
2025-10-01 10:58:17.495701 | controller | Wednesday 01 October 2025  10:58:17 +0000 (0:00:00.222)       0:00:39.423 *****
2025-10-01 10:58:17.495713 | controller | changed: [instance] => (item=/etc/cifmw-dnsmasq.conf)
2025-10-01 10:58:17.495745 | controller | changed: [instance] => (item=/etc/cifmw-dnsmasq.d)
2025-10-01 10:58:17.496157 | controller |
2025-10-01 10:58:17.791416 | controller | TASK [dnsmasq : Remove lease file] *********************************************
2025-10-01 10:58:17.791451 | controller | Wednesday 01 October 2025  10:58:17 +0000 (0:00:00.401)       0:00:39.824 *****
2025-10-01 10:58:17.791464 | controller | changed: [instance]
2025-10-01 10:58:19.006144 | controller |
2025-10-01 10:58:19.006173 | controller | TASK [podman : Ensure podman is installed] *************************************
2025-10-01 10:58:19.006181 | controller | Wednesday 01 October 2025  10:58:17 +0000 (0:00:00.295)       0:00:40.119 *****
2025-10-01 10:58:19.006191 | controller | ok: [instance]
2025-10-01 10:58:19.250439 | controller |
2025-10-01 10:58:19.250467 | controller | TASK [podman : Enable loginctl linger for ansible_user_id] *********************
2025-10-01 10:58:19.250475 | controller | Wednesday 01 October 2025  10:58:19 +0000 (0:00:01.215)       0:00:41.335 *****
2025-10-01 10:58:19.250485 | controller | changed: [instance]
2025-10-01 10:58:19.296694 | controller |
2025-10-01 10:58:19.296730 | controller | TASK [podman : Ensure subordinate UID entry exists for zuul] *******************
2025-10-01 10:58:19.296744 | controller | Wednesday 01 October 2025  10:58:19 +0000 (0:00:00.244)       0:00:41.579 *****
2025-10-01 10:58:19.296757 | controller | skipping: [instance]
2025-10-01 10:58:19.296780 | controller |
2025-10-01 10:58:19.296826 | controller | TASK [podman : Ensure subordinate GID entry exists for zuul] *******************
2025-10-01 10:58:19.296953 | controller | Wednesday 01 October 2025  10:58:19 +0000 (0:00:00.046)       0:00:41.626 *****
2025-10-01 10:58:19.340058 | controller | skipping: [instance]
2025-10-01 10:58:19.404761 | controller |
2025-10-01 10:58:19.404786 | controller | TASK [podman : Run podman system migrate if subuid/subgid files were changed] ***
2025-10-01 10:58:19.404794 | controller | Wednesday 01 October 2025  10:58:19 +0000 (0:00:00.043)       0:00:41.669 *****
2025-10-01 10:58:19.404803 | controller | skipping: [instance]
2025-10-01 10:58:19.749233 | controller |
2025-10-01 10:58:19.749266 | controller | TASK [virtualbmc : Stop and remove vbmc container] *****************************
2025-10-01 10:58:19.749274 | controller | Wednesday 01 October 2025  10:58:19 +0000 (0:00:00.064)       0:00:41.733 *****
2025-10-01 10:58:19.749284 | controller | ok: [instance]
2025-10-01 10:58:20.065634 | controller |
2025-10-01 10:58:20.065672 | controller | TASK [virtualbmc : Remove vbmc container image] ********************************
2025-10-01 10:58:20.065681 | controller | Wednesday 01 October 2025  10:58:19 +0000 (0:00:00.344)       0:00:42.078 *****
2025-10-01 10:58:20.065692 | controller | ok: [instance]
2025-10-01 10:58:20.267654 | controller |
2025-10-01 10:58:20.267693 | controller | TASK [virtualbmc : Check if VBMC key exists] ***********************************
2025-10-01 10:58:20.267703 | controller | Wednesday 01 October 2025  10:58:20 +0000 (0:00:00.316)       0:00:42.394 *****
2025-10-01 10:58:20.267716 | controller | ok: [instance]
2025-10-01 10:58:20.267744 | controller |
2025-10-01 10:58:20.267754 | controller | TASK [virtualbmc : Slurp key] **************************************************
2025-10-01 10:58:20.267883 | controller | Wednesday 01 October 2025  10:58:20 +0000 (0:00:00.202)       0:00:42.596 *****
2025-10-01 10:58:20.306186 | controller | skipping: [instance]
2025-10-01 10:58:20.343543 | controller |
2025-10-01 10:58:20.343583 | controller | TASK [virtualbmc : Revoke VBMC SSH access] *************************************
2025-10-01 10:58:20.343591 | controller | Wednesday 01 October 2025  10:58:20 +0000 (0:00:00.038)       0:00:42.635 *****
2025-10-01 10:58:20.343601 | controller | skipping: [instance]
2025-10-01 10:58:21.144388 | controller |
2025-10-01 10:58:21.144426 | controller | TASK [virtualbmc : Remove vbmc files] ******************************************
2025-10-01 10:58:21.144435 | controller | Wednesday 01 October 2025  10:58:20 +0000 (0:00:00.037)       0:00:42.672 *****
2025-10-01 10:58:21.144445 | controller | ok: [instance] => (item=/home/zuul/.ssh/vbmc-key)
2025-10-01 10:58:21.974569 | controller | ok: [instance] => (item=/home/zuul/.ssh/vbmc-key.pub)
2025-10-01 10:58:21.974601 | controller | ok: [instance] => (item=/home/zuul/.ssh/virtualbmc.conf)
2025-10-01 10:58:21.974609 | controller | ok: [instance] => (item=/home/zuul/.ssh/vbmcd.sh)
2025-10-01 10:58:21.974615 | controller |
2025-10-01 10:58:21.974621 | controller | RUNNING HANDLER [libvirt_manager : Restart firewalld] **************************
2025-10-01 10:58:21.974627 | controller | Wednesday 01 October 2025  10:58:21 +0000 (0:00:00.800)       0:00:43.472 *****
2025-10-01 10:58:21.974636 | controller | changed: [instance]
2025-10-01 10:58:22.042574 | controller |
2025-10-01 10:58:22.042620 | controller | PLAY RECAP *********************************************************************
2025-10-01 10:58:22.042629 | controller | instance                   : ok=66   changed=21   unreachable=0    failed=0    skipped=29   rescued=0    ignored=0
2025-10-01 10:58:22.042635 | controller |
2025-10-01 10:58:22.042641 | controller | Wednesday 01 October 2025  10:58:21 +0000 (0:00:00.828)       0:00:44.301 *****
2025-10-01 10:58:22.042646 | controller | ===============================================================================
2025-10-01 10:58:22.042651 | controller | virtualbmc : Stop and remove vbmc container ---------------------------- 10.59s
2025-10-01 10:58:22.042657 | controller | dnsmasq : Ensure SELinux knows about the new files and directories ------ 3.41s
2025-10-01 10:58:22.042662 | controller | libvirt_manager : Populate service facts -------------------------------- 2.18s
2025-10-01 10:58:22.042667 | controller | libvirt_manager : Remove workload and volumes --------------------------- 1.39s
2025-10-01 10:58:22.042673 | controller | podman : Ensure podman is installed ------------------------------------- 1.34s
2025-10-01 10:58:22.042678 | controller | dnsmasq : Install needed packages --------------------------------------- 1.23s
2025-10-01 10:58:22.042683 | controller | podman : Ensure podman is installed ------------------------------------- 1.22s
2025-10-01 10:58:22.042688 | controller | virtualbmc : Remove vbmc container image -------------------------------- 1.16s
2025-10-01 10:58:22.042694 | controller | libvirt_manager : Start virtqemud socket service ------------------------ 0.91s
2025-10-01 10:58:22.042703 | controller | Gathering Facts --------------------------------------------------------- 0.83s
2025-10-01 10:58:22.042709 | controller | libvirt_manager : Restart firewalld ------------------------------------- 0.83s
2025-10-01 10:58:22.042714 | controller | virtualbmc : Remove vbmc files ------------------------------------------ 0.80s
2025-10-01 10:58:22.042719 | controller | libvirt_manager : Get installed packages list --------------------------- 0.77s
2025-10-01 10:58:22.042725 | controller | dnsmasq : Stop service -------------------------------------------------- 0.75s
2025-10-01 10:58:22.042730 | controller | virtualbmc : Remove vbmc files ------------------------------------------ 0.75s
2025-10-01 10:58:22.042735 | controller | libvirt_manager : Destroy networks -------------------------------------- 0.61s
2025-10-01 10:58:22.042741 | controller | libvirt_manager : Disable forward in firewalld libvirt zone ------------- 0.57s
2025-10-01 10:58:22.042751 | controller | libvirt_manager : Clean firewalld libvirt zone -------------------------- 0.51s
2025-10-01 10:58:22.042756 | controller | libvirt_manager : Ensure no trace of networks lays in nmcli ------------- 0.43s
2025-10-01 10:58:22.042761 | controller | virtualbmc : Revoke VBMC SSH access ------------------------------------- 0.42s
2025-10-01 10:58:22.042771 | controller | INFO     Writing /tmp/report.html report.
2025-10-01 10:58:22.143507 | [controller] Waiting on logger
2025-10-01 10:58:27.296804 | [controller] Waiting on logger
2025-10-01 10:58:37.728884 | [controller] Waiting on logger
2025-10-01 10:58:48.160867 | [controller] Waiting on logger
2025-10-01 10:58:52.121939 | [Zuul] Log Stream did not terminate
2025-10-01 10:58:52.122122 | controller | changed
2025-10-01 10:58:52.149955 | 
2025-10-01 10:58:52.150008 | PLAY RECAP
2025-10-01 10:58:52.150047 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-01 10:58:52.150070 | 
2025-10-01 10:58:52.217508 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-01 10:58:52.218309 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-01 10:58:52.747319 | 
2025-10-01 10:58:52.747514 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-10-01 10:58:52.767578 | 
2025-10-01 10:58:52.767649 | TASK [Filter out host if needed]
2025-10-01 10:58:52.776295 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-10-01 10:58:52.780876 | 
2025-10-01 10:58:52.780942 | TASK [Ensure file is present]
2025-10-01 10:58:53.082621 | controller | ok
2025-10-01 10:58:53.089129 | 
2025-10-01 10:58:53.089241 | TASK [Manage molecule report file]
2025-10-01 10:58:53.112486 | [controller] Waiting on logger
2025-10-01 10:59:02.496986 | [controller] Waiting on logger
2025-10-01 10:59:12.929028 | [controller] Waiting on logger
2025-10-01 10:59:22.272979 | [controller] Waiting on logger
2025-10-01 10:59:23.420632 | [Zuul] Log Stream did not terminate
2025-10-01 10:59:23.420811 | controller | changed
2025-10-01 10:59:23.426072 | 
2025-10-01 10:59:23.426136 | TASK [Check if we get ci-framework-data basedir]
2025-10-01 10:59:23.616109 | controller | ok
2025-10-01 10:59:23.621072 | 
2025-10-01 10:59:23.621134 | TASK [Create ci-framework-data log directory for zuul]
2025-10-01 10:59:23.932884 | controller | changed
2025-10-01 10:59:23.937874 | 
2025-10-01 10:59:23.937944 | TASK [Copy ci-framework interesting files]
2025-10-01 10:59:28.964080 | controller | changed
2025-10-01 10:59:28.969998 | 
2025-10-01 10:59:28.970088 | TASK [Get SELinux listing]
2025-10-01 10:59:28.990151 | [controller] Waiting on logger
2025-10-01 10:59:37.888841 | [controller] Waiting on logger
2025-10-01 10:59:48.704794 | [controller] Waiting on logger
2025-10-01 10:59:54.464861 | [controller] Waiting on logger
2025-10-01 10:59:54.963305 | controller | changed
2025-10-01 10:59:54.968863 | 
2025-10-01 10:59:54.968931 | TASK [Generate log index]
2025-10-01 10:59:55.594695 | controller | changed
2025-10-01 10:59:55.599434 | 
2025-10-01 10:59:55.599500 | TASK [Get some env related data]
2025-10-01 10:59:56.640879 | [controller] Waiting on logger
2025-10-01 11:00:14.176695 | [controller] Waiting on logger
2025-10-01 11:00:15.264814 | [controller] Waiting on logger
2025-10-01 11:00:26.761321 | [Zuul] Log Stream did not terminate
2025-10-01 11:00:26.761518 | controller | changed
2025-10-01 11:00:26.766439 | 
2025-10-01 11:00:26.766502 | TASK [Generate list of logs to collect in home directory]
2025-10-01 11:00:27.068726 | controller | ok: All paths examined
2025-10-01 11:00:27.073760 | 
2025-10-01 11:00:27.073828 | LOOP [Copy logs from home directory]
2025-10-01 11:00:27.382061 | controller | changed:
2025-10-01 11:00:27.382175 | controller | {
2025-10-01 11:00:27.382203 | controller |   "atime": 1759315980.0850236,
2025-10-01 11:00:27.382224 | controller |   "ctime": 1759315996.143126,
2025-10-01 11:00:27.382253 | controller |   "dev": 64513,
2025-10-01 11:00:27.382274 | controller |   "gid": 1000,
2025-10-01 11:00:27.382292 | controller |   "gr_name": "zuul",
2025-10-01 11:00:27.382310 | controller |   "inode": 4340699,
2025-10-01 11:00:27.382327 | controller |   "isblk": false,
2025-10-01 11:00:27.382343 | controller |   "ischr": false,
2025-10-01 11:00:27.382360 | controller |   "isdir": false,
2025-10-01 11:00:27.382375 | controller |   "isfifo": false,
2025-10-01 11:00:27.382412 | controller |   "isgid": false,
2025-10-01 11:00:27.382431 | controller |   "islnk": false,
2025-10-01 11:00:27.382447 | controller |   "isreg": true,
2025-10-01 11:00:27.382463 | controller |   "issock": false,
2025-10-01 11:00:27.382478 | controller |   "isuid": false,
2025-10-01 11:00:27.382492 | controller |   "mode": "0644",
2025-10-01 11:00:27.382509 | controller |   "mtime": 1759315996.143126,
2025-10-01 11:00:27.382525 | controller |   "nlink": 1,
2025-10-01 11:00:27.382542 | controller |   "path": "/home/zuul/ansible.log",
2025-10-01 11:00:27.382557 | controller |   "pw_name": "zuul",
2025-10-01 11:00:27.382572 | controller |   "rgrp": true,
2025-10-01 11:00:27.382587 | controller |   "roth": true,
2025-10-01 11:00:27.382602 | controller |   "rusr": true,
2025-10-01 11:00:27.382616 | controller |   "size": 6749,
2025-10-01 11:00:27.382631 | controller |   "uid": 1000,
2025-10-01 11:00:27.382647 | controller |   "wgrp": false,
2025-10-01 11:00:27.382662 | controller |   "woth": false,
2025-10-01 11:00:27.382677 | controller |   "wusr": true,
2025-10-01 11:00:27.382691 | controller |   "xgrp": false,
2025-10-01 11:00:27.382706 | controller |   "xoth": false,
2025-10-01 11:00:27.382720 | controller |   "xusr": false
2025-10-01 11:00:27.382734 | controller | }
2025-10-01 11:00:27.396076 | 
2025-10-01 11:00:27.396178 | TASK [Copy crio stats log file]
2025-10-01 11:00:27.410213 | controller | skipping: Conditional result was False
2025-10-01 11:00:27.415775 | 
2025-10-01 11:00:27.415841 | TASK [Get SELinux related data]
2025-10-01 11:00:27.436444 | [controller] Waiting on logger
2025-10-01 11:00:33.888992 | [controller] Waiting on logger
2025-10-01 11:00:47.136908 | [controller] Waiting on logger
2025-10-01 11:00:56.480846 | [controller] Waiting on logger
2025-10-01 11:00:57.647083 | [Zuul] Log Stream did not terminate
2025-10-01 11:00:57.647297 | controller | ERROR
2025-10-01 11:00:57.647428 | controller | {
2025-10-01 11:00:57.647472 | controller |   "delta": "0:00:00.009130",
2025-10-01 11:00:57.647497 | controller |   "end": "2025-10-01 11:00:27.623203",
2025-10-01 11:00:57.647518 | controller |   "msg": "non-zero return code",
2025-10-01 11:00:57.647537 | controller |   "rc": 1,
2025-10-01 11:00:57.647556 | controller |   "start": "2025-10-01 11:00:27.614073"
2025-10-01 11:00:57.647575 | controller | }
2025-10-01 11:00:57.647599 | controller | ERROR: Ignoring Errors
2025-10-01 11:00:57.652662 | 
2025-10-01 11:00:57.652723 | TASK [Create system configuration directory]
2025-10-01 11:00:57.840909 | controller | changed
2025-10-01 11:00:57.845910 | 
2025-10-01 11:00:57.845991 | TASK [Get some of the system configurations]
2025-10-01 11:01:00.960824 | [controller] Waiting on logger
2025-10-01 11:01:10.304836 | [controller] Waiting on logger
2025-10-01 11:01:20.737025 | [controller] Waiting on logger
2025-10-01 11:01:28.077191 | [Zuul] Log Stream did not terminate
2025-10-01 11:01:28.077366 | controller | changed
2025-10-01 11:01:28.082534 | 
2025-10-01 11:01:28.082598 | TASK [Copy generated documentation if available]
2025-10-01 11:01:28.095952 | controller | skipping: Conditional result was False
2025-10-01 11:01:28.101212 | 
2025-10-01 11:01:28.101298 | TASK [Copy generated AsciiDoc documentation if available]
2025-10-01 11:01:28.114454 | controller | skipping: Conditional result was False
2025-10-01 11:01:28.119821 | 
2025-10-01 11:01:28.119886 | TASK [Compress logs bigger than 2MB]
2025-10-01 11:01:29.184886 | [controller] Waiting on logger
2025-10-01 11:01:39.617047 | [controller] Waiting on logger
2025-10-01 11:01:50.048895 | [controller] Waiting on logger
2025-10-01 11:01:58.349975 | [Zuul] Log Stream did not terminate
2025-10-01 11:01:58.350171 | controller | changed
2025-10-01 11:01:58.355561 | 
2025-10-01 11:01:58.355622 | TASK [Copy files from workspace on node]
2025-10-01 11:01:58.373363 | controller | ok
2025-10-01 11:01:58.394860 | 
2025-10-01 11:01:58.394931 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-01 11:01:58.408260 | controller | skipping: Conditional result was False
2025-10-01 11:01:58.413461 | 
2025-10-01 11:01:58.413527 | TASK [fetch-output : Set log path for single node]
2025-10-01 11:01:58.441162 | controller | ok
2025-10-01 11:01:58.446790 | 
2025-10-01 11:01:58.446850 | LOOP [fetch-output : Ensure local output dirs]
2025-10-01 11:01:58.636645 | controller -> localhost | ok: "/var/lib/zuul/builds/8d5c77bb7ae4469297059e6cc9454a62/work/logs"
2025-10-01 11:01:58.636867 | controller -> localhost | changed: All items complete
2025-10-01 11:01:58.636900 | 
2025-10-01 11:01:58.818447 | controller -> localhost | changed: "/var/lib/zuul/builds/8d5c77bb7ae4469297059e6cc9454a62/work/artifacts"
2025-10-01 11:01:58.994449 | controller -> localhost | changed: "/var/lib/zuul/builds/8d5c77bb7ae4469297059e6cc9454a62/work/docs"
2025-10-01 11:01:59.002864 | 
2025-10-01 11:01:59.002934 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-01 11:01:59.392770 | [controller] Waiting on logger
2025-10-01 11:01:59.560848 | controller | changed:
2025-10-01 11:01:59.560943 | controller | .d..t...... ./
2025-10-01 11:01:59.560971 | controller | >f+++++++++ README.html
2025-10-01 11:01:59.560992 | controller | >f+++++++++ ansible-execution.log
2025-10-01 11:01:59.561011 | controller | >f+++++++++ ansible.log
2025-10-01 11:01:59.561028 | controller | >f+++++++++ dmesg.log
2025-10-01 11:01:59.561045 | controller | >f+++++++++ installed-pkgs.log
2025-10-01 11:01:59.561060 | controller | >f+++++++++ python.log
2025-10-01 11:01:59.561084 | controller | >f+++++++++ registries.conf
2025-10-01 11:01:59.561101 | controller | >f+++++++++ report.html
2025-10-01 11:01:59.561116 | controller | >f+++++++++ selinux-denials.log
2025-10-01 11:01:59.561131 | controller | >f+++++++++ selinux-listing.log
2025-10-01 11:01:59.561145 | controller | cd+++++++++ ci-framework-data/
2025-10-01 11:01:59.561160 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-10-01 11:01:59.561175 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-10-01 11:01:59.561189 | controller | cd+++++++++ ci-framework-data/artifacts/nmstate/
2025-10-01 11:01:59.561203 | controller | >f+++++++++ ci-framework-data/artifacts/nmstate/instance-final-state.yaml
2025-10-01 11:01:59.561218 | controller | >f+++++++++ ci-framework-data/artifacts/nmstate/instance-state.yaml
2025-10-01 11:01:59.561246 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-10-01 11:01:59.561263 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-10-01 11:01:59.561277 | controller | cd+++++++++ ci-framework-data/artifacts/repositories/
2025-10-01 11:01:59.561291 | controller | >f+++++++++ ci-framework-data/artifacts/repositories/delorean.repo.md5
2025-10-01 11:01:59.561305 | controller | cd+++++++++ ci-framework-data/logs/
2025-10-01 11:01:59.561319 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-10-01 11:01:59.561333 | controller | cd+++++++++ registries.conf.d/
2025-10-01 11:01:59.561347 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-10-01 11:01:59.561361 | controller | cd+++++++++ system-config/
2025-10-01 11:01:59.561375 | controller | cd+++++++++ system-config/libvirt/
2025-10-01 11:01:59.561416 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-10-01 11:01:59.561436 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-10-01 11:01:59.561452 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf
2025-10-01 11:01:59.561468 | controller | >f+++++++++ system-config/libvirt/network.conf
2025-10-01 11:01:59.561483 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf
2025-10-01 11:01:59.561498 | controller | >f+++++++++ system-config/libvirt/qemu.conf
2025-10-01 11:01:59.561513 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf
2025-10-01 11:01:59.561528 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf
2025-10-01 11:01:59.561542 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf
2025-10-01 11:01:59.561557 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf
2025-10-01 11:01:59.561572 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf
2025-10-01 11:01:59.561586 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf
2025-10-01 11:01:59.561601 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf
2025-10-01 11:01:59.561615 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf
2025-10-01 11:01:59.561629 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf
2025-10-01 11:01:59.561643 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf
2025-10-01 11:01:59.920093 | controller | changed: .d..t...... ./
2025-10-01 11:02:00.286641 | controller | changed: .d..t...... ./
2025-10-01 11:02:00.303178 | 
2025-10-01 11:02:00.303259 | TASK [Return artifact to Zuul]
2025-10-01 11:02:00.331620 | controller | ok
2025-10-01 11:02:00.349632 | 
2025-10-01 11:02:00.349692 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-10-01 11:02:00.349868 | 
2025-10-01 11:02:00.349905 | PLAY RECAP
2025-10-01 11:02:00.349945 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-10-01 11:02:00.349968 | 
2025-10-01 11:02:00.431671 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-01 11:02:00.432430 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-01 11:02:00.928871 | 
2025-10-01 11:02:00.928968 | PLAY [all]
2025-10-01 11:02:00.946803 | 
2025-10-01 11:02:00.946873 | TASK [include_role : fetch-output]
2025-10-01 11:02:00.974975 | controller | ok
2025-10-01 11:02:00.990892 | 
2025-10-01 11:02:00.990973 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-01 11:02:01.034479 | controller | skipping: Conditional result was False
2025-10-01 11:02:01.039873 | 
2025-10-01 11:02:01.039945 | TASK [fetch-output : Set log path for single node]
2025-10-01 11:02:01.068106 | controller | ok
2025-10-01 11:02:01.072862 | 
2025-10-01 11:02:01.072931 | LOOP [fetch-output : Ensure local output dirs]
2025-10-01 11:02:01.383904 | controller -> localhost | ok: "/var/lib/zuul/builds/8d5c77bb7ae4469297059e6cc9454a62/work/logs"
2025-10-01 11:02:01.564099 | controller -> localhost | ok: "/var/lib/zuul/builds/8d5c77bb7ae4469297059e6cc9454a62/work/artifacts"
2025-10-01 11:02:01.742142 | controller -> localhost | ok: "/var/lib/zuul/builds/8d5c77bb7ae4469297059e6cc9454a62/work/docs"
2025-10-01 11:02:01.750605 | 
2025-10-01 11:02:01.750674 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-01 11:02:02.254031 | controller | ok
2025-10-01 11:02:02.254221 | controller | ok: All items complete
2025-10-01 11:02:02.254267 | 
2025-10-01 11:02:02.625643 | controller | ok
2025-10-01 11:02:02.985089 | controller | ok
2025-10-01 11:02:03.000678 | 
2025-10-01 11:02:03.000785 | TASK [include_role : fetch-output-openshift]
2025-10-01 11:02:03.014554 | controller | skipping: Conditional result was False
2025-10-01 11:02:03.020090 | 
2025-10-01 11:02:03.020161 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-01 11:02:03.355843 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006268
2025-10-01 11:02:03.554688 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006218
2025-10-01 11:02:03.583579 | 
2025-10-01 11:02:03.583674 | PLAY [all]
2025-10-01 11:02:03.596956 | 
2025-10-01 11:02:03.597029 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-01 11:02:03.991826 | controller | changed
2025-10-01 11:02:04.012719 | 
2025-10-01 11:02:04.012797 | PLAY RECAP
2025-10-01 11:02:04.012838 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-01 11:02:04.012860 | 
2025-10-01 11:02:04.087665 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-01 11:02:04.088468 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-01 11:02:04.631548 | 
2025-10-01 11:02:04.631751 | PLAY [localhost]
2025-10-01 11:02:04.649179 | 
2025-10-01 11:02:04.649288 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-01 11:02:04.949863 | localhost | changed
2025-10-01 11:02:04.954198 | 
2025-10-01 11:02:04.954284 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-01 11:02:04.970858 | localhost | ok
2025-10-01 11:02:04.978521 | 
2025-10-01 11:02:04.978591 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-01 11:02:05.268871 | localhost | changed
2025-10-01 11:02:05.274246 | 
2025-10-01 11:02:05.274318 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-01 11:02:05.817531 | localhost | changed
2025-10-01 11:02:05.822327 | 
2025-10-01 11:02:05.822410 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-01 11:02:06.143025 | localhost | Identity added: /var/lib/zuul/builds/8d5c77bb7ae4469297059e6cc9454a62/work/tmp/ansible.j2sbjk4t (/var/lib/zuul/builds/8d5c77bb7ae4469297059e6cc9454a62/work/tmp/ansible.j2sbjk4t)
2025-10-01 11:02:06.143187 | localhost | ok: Runtime: 0:00:00.005708
2025-10-01 11:02:06.147356 | 
2025-10-01 11:02:06.147441 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-01 11:02:06.366915 | localhost | ok: Runtime: 0:00:00.004426
2025-10-01 11:02:06.371447 | 
2025-10-01 11:02:06.371528 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-01 11:02:06.419189 | localhost | changed
2025-10-01 11:02:06.424286 | 
2025-10-01 11:02:06.424350 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-01 11:02:06.745579 | localhost | changed
2025-10-01 11:02:06.765857 | 
2025-10-01 11:02:06.765956 | PLAY [localhost]
2025-10-01 11:02:06.777971 | 
2025-10-01 11:02:06.778032 | TASK [Generate bulk log download script]
2025-10-01 11:02:06.796363 | localhost | ok
2025-10-01 11:02:06.807616 | 
2025-10-01 11:02:06.807683 | TASK [local-log-download : Check API endpoint is defined]
2025-10-01 11:02:06.844802 | localhost | ok: All assertions passed
2025-10-01 11:02:06.849020 | 
2025-10-01 11:02:06.849084 | TASK [local-log-download : Create download script]
2025-10-01 11:02:07.196561 | localhost -> localhost | changed
2025-10-01 11:02:07.206212 | 
2025-10-01 11:02:07.206329 | TASK [Register quick-download link]
2025-10-01 11:02:07.224921 | localhost | ok
2025-10-01 11:02:07.260882 | 
2025-10-01 11:02:07.261023 | PLAY [logserver.rdoproject.org]
2025-10-01 11:02:07.272440 | 
2025-10-01 11:02:07.272501 | TASK [Set zuul-log-path fact]
2025-10-01 11:02:07.288616 | logserver.rdoproject.org | ok
2025-10-01 11:02:07.297936 | 
2025-10-01 11:02:07.298025 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-01 11:02:07.323942 | logserver.rdoproject.org | ok
2025-10-01 11:02:07.330142 | 
2025-10-01 11:02:07.330216 | TASK [upload-logs : Create log directories]
2025-10-01 11:02:09.191035 | logserver.rdoproject.org | changed
2025-10-01 11:02:09.194159 | 
2025-10-01 11:02:09.194223 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-01 11:02:09.411560 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004560
2025-10-01 11:02:09.415994 | 
2025-10-01 11:02:09.416058 | TASK [upload-logs : Upload logs to log server]
2025-10-01 11:02:10.973566 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-01 11:02:10.976405 | 
2025-10-01 11:02:10.976470 | LOOP [upload-logs : Compress console log and json output]
2025-10-01 11:02:11.014846 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-01 11:02:11.024186 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-01 11:02:11.034354 | 
2025-10-01 11:02:11.034521 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-01 11:02:11.068168 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-01 11:02:11.068623 | 
2025-10-01 11:02:11.072173 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-01 11:02:11.082550 | 
2025-10-01 11:02:11.082649 | LOOP [upload-logs : Upload console log and json output]