2025-10-08 12:38:53.573688 | Job console starting...
2025-10-08 12:38:53.818705 | Updating repositories
2025-10-08 12:38:54.536395 | Preparing job workspace
2025-10-08 12:39:02.862888 | Running Ansible setup...
2025-10-08 12:39:05.882809 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-08 12:39:06.500548 | 
2025-10-08 12:39:06.500672 | PLAY [localhost]
2025-10-08 12:39:06.511301 | 
2025-10-08 12:39:06.511396 | TASK [Gathering Facts]
2025-10-08 12:39:07.399803 | localhost | ok
2025-10-08 12:39:07.413167 | 
2025-10-08 12:39:07.413271 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-08 12:39:07.755856 | localhost -> localhost | changed
2025-10-08 12:39:07.761750 | 
2025-10-08 12:39:07.761839 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-08 12:39:08.518865 | localhost -> localhost | changed
2025-10-08 12:39:08.529471 | 
2025-10-08 12:39:08.529571 | TASK [Setup log path fact]
2025-10-08 12:39:08.558345 | localhost | ok
2025-10-08 12:39:08.569663 | 
2025-10-08 12:39:08.569748 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-08 12:39:08.597013 | localhost | ok
2025-10-08 12:39:08.604515 | 
2025-10-08 12:39:08.604601 | TASK [emit-job-header : Print job information]
2025-10-08 12:39:08.631923 | # Job Information
2025-10-08 12:39:08.632081 | Ansible Version: 2.15.12
2025-10-08 12:39:08.632117 | Job: cifmw-molecule-virtualbmc
2025-10-08 12:39:08.632140 | Pipeline: github-check
2025-10-08 12:39:08.632161 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-10-08 12:39:08.632181 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3368
2025-10-08 12:39:08.632202 | Log URL (when completed): https://logserver.rdoproject.org/849/rdoproject.org/849a4dc819e84bd080920a22c783739b/
2025-10-08 12:39:08.632222 | Event ID: e452cdb0-a431-11f0-8caa-4725382b7326
2025-10-08 12:39:08.636018 | 
2025-10-08 12:39:08.636091 | LOOP [emit-job-header : Print node information]
2025-10-08 12:39:08.728043 | localhost | ok:
2025-10-08 12:39:08.728189 | localhost | # Node Information
2025-10-08 12:39:08.728220 | localhost | Inventory Hostname: controller
2025-10-08 12:39:08.728249 | localhost | Hostname: np0005476259
2025-10-08 12:39:08.728270 | localhost | Username: zuul
2025-10-08 12:39:08.728292 | localhost | Distro: CentOS 9
2025-10-08 12:39:08.728312 | localhost | Provider: ibm-bm4-nodepool
2025-10-08 12:39:08.728331 | localhost | Region: regionOne
2025-10-08 12:39:08.728350 | localhost | Label: cloud-centos-9-stream-tripleo-ibm
2025-10-08 12:39:08.728368 | localhost | Product Name: OpenStack Compute
2025-10-08 12:39:08.728386 | localhost | Interface IP: 192.168.26.82
2025-10-08 12:39:08.752729 | 
2025-10-08 12:39:08.752978 | PLAY [all]
2025-10-08 12:39:08.759746 | 
2025-10-08 12:39:08.759815 | TASK [Gather network facts]
2025-10-08 12:39:09.145124 | controller | ok
2025-10-08 12:39:09.162009 | 
2025-10-08 12:39:09.162087 | TASK [include_role : start-zuul-console]
2025-10-08 12:39:09.183682 | controller | ok
2025-10-08 12:39:09.196747 | 
2025-10-08 12:39:09.196864 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-08 12:39:09.531571 | controller | ok
2025-10-08 12:39:09.540706 | 
2025-10-08 12:39:09.540778 | TASK [include_role : add-build-sshkey]
2025-10-08 12:39:09.568543 | controller | ok
2025-10-08 12:39:09.581326 | 
2025-10-08 12:39:09.581401 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-08 12:39:09.799217 | controller -> localhost | ok
2025-10-08 12:39:09.805299 | 
2025-10-08 12:39:09.805377 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-08 12:39:09.834274 | controller | ok
2025-10-08 12:39:09.846742 | controller | included: /var/lib/zuul/builds/849a4dc819e84bd080920a22c783739b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-08 12:39:09.852392 | 
2025-10-08 12:39:09.852463 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-08 12:39:10.375142 | controller -> localhost | Generating public/private rsa key pair.
2025-10-08 12:39:10.375351 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/849a4dc819e84bd080920a22c783739b/work/849a4dc819e84bd080920a22c783739b_id_rsa.
2025-10-08 12:39:10.375388 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/849a4dc819e84bd080920a22c783739b/work/849a4dc819e84bd080920a22c783739b_id_rsa.pub.
2025-10-08 12:39:10.375415 | controller -> localhost | The key fingerprint is:
2025-10-08 12:39:10.375437 | controller -> localhost | SHA256:Hl7doIIdlrL04sgCO94nwGDNFAH1kuFTHXoSgxzc3UI zuul-build-sshkey
2025-10-08 12:39:10.375457 | controller -> localhost | The key's randomart image is:
2025-10-08 12:39:10.375476 | controller -> localhost | +---[RSA 3072]----+
2025-10-08 12:39:10.375495 | controller -> localhost | | .=**++Eo        |
2025-10-08 12:39:10.375514 | controller -> localhost | |  .==.++ o       |
2025-10-08 12:39:10.375533 | controller -> localhost | |  += +o.=   .    |
2025-10-08 12:39:10.375552 | controller -> localhost | |.. oo.oB . o o   |
2025-10-08 12:39:10.375570 | controller -> localhost | |=     + S o . .  |
2025-10-08 12:39:10.375587 | controller -> localhost | | = . o + +       |
2025-10-08 12:39:10.375604 | controller -> localhost | |o o o . o        |
2025-10-08 12:39:10.375624 | controller -> localhost | |...o .           |
2025-10-08 12:39:10.375643 | controller -> localhost | | . .o            |
2025-10-08 12:39:10.375661 | controller -> localhost | +----[SHA256]-----+
2025-10-08 12:39:10.375707 | controller -> localhost | ok: Runtime: 0:00:00.149770
2025-10-08 12:39:10.381262 | 
2025-10-08 12:39:10.381329 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-08 12:39:10.399857 | controller | ok
2025-10-08 12:39:10.410302 | controller | included: /var/lib/zuul/builds/849a4dc819e84bd080920a22c783739b/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-08 12:39:10.419536 | 
2025-10-08 12:39:10.419608 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-08 12:39:10.443732 | controller | skipping: Conditional result was False
2025-10-08 12:39:10.449254 | 
2025-10-08 12:39:10.449336 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-08 12:39:10.833006 | controller | changed
2025-10-08 12:39:10.838866 | 
2025-10-08 12:39:10.839021 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-08 12:39:11.040737 | controller | ok
2025-10-08 12:39:11.045680 | 
2025-10-08 12:39:11.045750 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-08 12:39:11.657255 | controller | changed
2025-10-08 12:39:11.662194 | 
2025-10-08 12:39:11.662264 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-08 12:39:12.249255 | controller | changed
2025-10-08 12:39:12.255330 | 
2025-10-08 12:39:12.255404 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-08 12:39:12.279183 | controller | skipping: Conditional result was False
2025-10-08 12:39:12.284922 | 
2025-10-08 12:39:12.284994 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-08 12:39:12.602251 | controller -> localhost | changed
2025-10-08 12:39:12.612110 | 
2025-10-08 12:39:12.612194 | TASK [add-build-sshkey : Add back temp key]
2025-10-08 12:39:12.860152 | controller -> localhost | Identity added: /var/lib/zuul/builds/849a4dc819e84bd080920a22c783739b/work/849a4dc819e84bd080920a22c783739b_id_rsa (zuul-build-sshkey)
2025-10-08 12:39:12.860355 | controller -> localhost | ok: Runtime: 0:00:00.007326
2025-10-08 12:39:12.867293 | 
2025-10-08 12:39:12.867360 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-08 12:39:13.179799 | controller | ok
2025-10-08 12:39:13.184310 | 
2025-10-08 12:39:13.184372 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-08 12:39:13.208001 | controller | skipping: Conditional result was False
2025-10-08 12:39:13.217043 | 
2025-10-08 12:39:13.217109 | TASK [include_role : validate-host]
2025-10-08 12:39:13.234532 | controller | ok
2025-10-08 12:39:13.254679 | 
2025-10-08 12:39:13.254768 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-08 12:39:13.293231 | controller | ok
2025-10-08 12:39:13.297718 | 
2025-10-08 12:39:13.297783 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-08 12:39:13.513410 | controller -> localhost | ok
2025-10-08 12:39:13.519395 | 
2025-10-08 12:39:13.519485 | TASK [validate-host : Collect information about the host]
2025-10-08 12:39:14.137659 | controller | ok
2025-10-08 12:39:14.147114 | 
2025-10-08 12:39:14.147194 | TASK [validate-host : Sanitize hostname]
2025-10-08 12:39:14.241086 | controller | ok
2025-10-08 12:39:14.246311 | 
2025-10-08 12:39:14.246381 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-08 12:39:14.615023 | controller -> localhost | changed
2025-10-08 12:39:14.621565 | 
2025-10-08 12:39:14.621635 | TASK [validate-host : Collect information about zuul worker]
2025-10-08 12:39:14.933109 | controller | ok
2025-10-08 12:39:14.939074 | 
2025-10-08 12:39:14.939156 | TASK [validate-host : Write out all zuul information for each host]
2025-10-08 12:39:15.321441 | controller -> localhost | changed
2025-10-08 12:39:15.330699 | 
2025-10-08 12:39:15.330770 | TASK [include_role : prepare-workspace-openshift]
2025-10-08 12:39:15.343663 | controller | skipping: Conditional result was False
2025-10-08 12:39:15.348927 | 
2025-10-08 12:39:15.348997 | TASK [include_role : remove-zuul-sshkey]
2025-10-08 12:39:15.362132 | controller | skipping: Conditional result was False
2025-10-08 12:39:15.368253 | 
2025-10-08 12:39:15.368344 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-08 12:39:15.587496 | controller | ok: "logs"
2025-10-08 12:39:15.587723 | controller | ok: All items complete
2025-10-08 12:39:15.587757 | 
2025-10-08 12:39:15.766606 | controller | ok: "artifacts"
2025-10-08 12:39:15.945033 | controller | ok: "docs"
2025-10-08 12:39:15.962374 | 
2025-10-08 12:39:15.962509 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-08 12:39:16.192425 | controller | changed: "logs"
2025-10-08 12:39:16.367317 | controller | changed: "artifacts"
2025-10-08 12:39:16.536253 | controller | changed: "docs"
2025-10-08 12:39:16.561525 | 
2025-10-08 12:39:16.561608 | PLAY RECAP
2025-10-08 12:39:16.561658 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-08 12:39:16.561689 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-08 12:39:16.561710 | 
2025-10-08 12:39:16.641117 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-08 12:39:16.641865 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-08 12:39:17.204804 | 
2025-10-08 12:39:17.204932 | PLAY [all]
2025-10-08 12:39:17.224937 | 
2025-10-08 12:39:17.225024 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-08 12:39:17.273804 | controller | ok
2025-10-08 12:39:17.279100 | 
2025-10-08 12:39:17.279179 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-08 12:39:17.633624 | controller | changed
2025-10-08 12:39:17.639126 | 
2025-10-08 12:39:17.639202 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-08 12:39:18.432722 | controller | changed
2025-10-08 12:39:18.442704 | 
2025-10-08 12:39:18.442795 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-10-08 12:39:18.824053 | controller | changed:
2025-10-08 12:39:18.824211 | controller | {
2025-10-08 12:39:18.824244 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-10-08 12:39:18.824277 | controller | }
2025-10-08 12:39:19.046607 | controller | changed:
2025-10-08 12:39:19.046689 | controller | {
2025-10-08 12:39:19.046722 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-10-08 12:39:19.046746 | controller | }
2025-10-08 12:39:19.260086 | controller | changed:
2025-10-08 12:39:19.260170 | controller | {
2025-10-08 12:39:19.260200 | 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-08 12:39:19.260223 | controller | }
2025-10-08 12:39:19.468300 | controller | changed:
2025-10-08 12:39:19.468403 | controller | {
2025-10-08 12:39:19.468439 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-10-08 12:39:19.468464 | controller | }
2025-10-08 12:39:19.678232 | controller | changed:
2025-10-08 12:39:19.678327 | controller | {
2025-10-08 12:39:19.678355 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-10-08 12:39:19.678376 | controller | }
2025-10-08 12:39:19.890073 | controller | changed:
2025-10-08 12:39:19.890168 | controller | {
2025-10-08 12:39:19.890196 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-10-08 12:39:19.890217 | controller | }
2025-10-08 12:39:20.099990 | controller | changed:
2025-10-08 12:39:20.100078 | controller | {
2025-10-08 12:39:20.100106 | 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-08 12:39:20.100127 | controller | }
2025-10-08 12:39:20.318407 | controller | changed:
2025-10-08 12:39:20.318499 | controller | {
2025-10-08 12:39:20.318529 | 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-08 12:39:20.318552 | controller | }
2025-10-08 12:39:20.535987 | controller | changed:
2025-10-08 12:39:20.536129 | controller | {
2025-10-08 12:39:20.536168 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-10-08 12:39:20.536190 | controller | }
2025-10-08 12:39:20.746833 | controller | changed:
2025-10-08 12:39:20.746972 | controller | {
2025-10-08 12:39:20.747005 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-10-08 12:39:20.747027 | controller | }
2025-10-08 12:39:20.965517 | controller | changed:
2025-10-08 12:39:20.965595 | controller | {
2025-10-08 12:39:20.965623 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-10-08 12:39:20.965645 | controller | }
2025-10-08 12:39:21.201365 | controller | changed:
2025-10-08 12:39:21.201449 | controller | {
2025-10-08 12:39:21.201478 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-10-08 12:39:21.201602 | controller | }
2025-10-08 12:39:21.384475 | controller | changed:
2025-10-08 12:39:21.384567 | controller | {
2025-10-08 12:39:21.384597 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-10-08 12:39:21.384618 | controller | }
2025-10-08 12:39:21.591021 | controller | changed:
2025-10-08 12:39:21.591108 | controller | {
2025-10-08 12:39:21.591136 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-10-08 12:39:21.591156 | controller | }
2025-10-08 12:39:21.796756 | controller | changed:
2025-10-08 12:39:21.796841 | controller | {
2025-10-08 12:39:21.796869 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-10-08 12:39:21.796904 | controller | }
2025-10-08 12:39:22.000697 | controller | changed:
2025-10-08 12:39:22.000778 | controller | {
2025-10-08 12:39:22.000805 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-10-08 12:39:22.000827 | controller | }
2025-10-08 12:39:22.200356 | controller | changed:
2025-10-08 12:39:22.200441 | controller | {
2025-10-08 12:39:22.200469 | 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-08 12:39:22.200492 | controller | }
2025-10-08 12:39:22.407020 | controller | changed:
2025-10-08 12:39:22.407113 | controller | {
2025-10-08 12:39:22.407141 | 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-08 12:39:22.407170 | controller | }
2025-10-08 12:39:22.615100 | controller | changed:
2025-10-08 12:39:22.615323 | controller | {
2025-10-08 12:39:22.615362 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-10-08 12:39:22.615386 | controller | }
2025-10-08 12:39:22.823530 | controller | changed:
2025-10-08 12:39:22.823627 | controller | {
2025-10-08 12:39:22.823656 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-10-08 12:39:22.823678 | controller | }
2025-10-08 12:39:23.029721 | controller | changed:
2025-10-08 12:39:23.029844 | controller | {
2025-10-08 12:39:23.029872 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-10-08 12:39:23.029921 | controller | }
2025-10-08 12:39:23.234394 | controller | changed:
2025-10-08 12:39:23.234478 | controller | {
2025-10-08 12:39:23.234506 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-10-08 12:39:23.234527 | controller | }
2025-10-08 12:39:23.464711 | controller | changed:
2025-10-08 12:39:23.464803 | controller | {
2025-10-08 12:39:23.464829 | 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-08 12:39:23.464850 | controller | }
2025-10-08 12:39:23.686620 | controller | changed:
2025-10-08 12:39:23.686698 | controller | {
2025-10-08 12:39:23.686725 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-10-08 12:39:23.686746 | controller | }
2025-10-08 12:39:23.913136 | controller | changed:
2025-10-08 12:39:23.913223 | controller | {
2025-10-08 12:39:23.913253 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-10-08 12:39:23.913275 | controller | }
2025-10-08 12:39:24.154102 | controller | changed:
2025-10-08 12:39:24.154234 | controller | {
2025-10-08 12:39:24.154265 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-10-08 12:39:24.154288 | controller | }
2025-10-08 12:39:24.192645 | 
2025-10-08 12:39:24.192966 | TASK [Set timezone to UTC]
2025-10-08 12:39:24.641630 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-10-08 12:39:24.647742 | 
2025-10-08 12:39:24.647813 | TASK [Create nodepool directory]
2025-10-08 12:39:24.859513 | controller | changed
2025-10-08 12:39:24.867314 | 
2025-10-08 12:39:24.867435 | TASK [Create nodepool sub_nodes file]
2025-10-08 12:39:25.428153 | controller | changed
2025-10-08 12:39:25.434110 | 
2025-10-08 12:39:25.434212 | TASK [Create nodepool sub_nodes_private file]
2025-10-08 12:39:25.973579 | controller | changed
2025-10-08 12:39:25.981585 | 
2025-10-08 12:39:25.981723 | LOOP [Populate nodepool sub_nodes file]
2025-10-08 12:39:26.028009 | 
2025-10-08 12:39:26.028337 | LOOP [Populate nodepool sub_nodes_private file]
2025-10-08 12:39:26.061521 | 
2025-10-08 12:39:26.061749 | TASK [Create nodepool primary file]
2025-10-08 12:39:26.088254 | controller | skipping: Conditional result was False
2025-10-08 12:39:26.095761 | 
2025-10-08 12:39:26.095940 | TASK [Create nodepool node_private for this node]
2025-10-08 12:39:26.656288 | controller | changed
2025-10-08 12:39:26.663714 | 
2025-10-08 12:39:26.663880 | LOOP [Copy ssh keys to nodepool directory]
2025-10-08 12:39:27.003693 | controller | ok: Item: id_rsa Runtime: 0:00:00.005909
2025-10-08 12:39:27.004061 | 
2025-10-08 12:39:27.169881 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.004044
2025-10-08 12:39:27.180057 | 
2025-10-08 12:39:27.180218 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-10-08 12:39:27.786806 | controller | changed
2025-10-08 12:39:27.795118 | 
2025-10-08 12:39:27.795220 | TASK [Validate sudoers config after edits]
2025-10-08 12:39:28.053378 | controller | /etc/sudoers: parsed OK
2025-10-08 12:39:28.053465 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-10-08 12:39:28.053477 | controller | /etc/sudoers.d/zuul: parsed OK
2025-10-08 12:39:28.053486 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-10-08 12:39:28.340658 | controller | ok: Runtime: 0:00:00.006081
2025-10-08 12:39:28.346492 | 
2025-10-08 12:39:28.346561 | TASK [Show the environment passed in to job shell scripts]
2025-10-08 12:39:28.569747 | controller | SHELL=/bin/bash
2025-10-08 12:39:28.569807 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-10-08 12:39:28.569817 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-10-08 12:39:28.569823 | controller | ZUUL_CHANGES=openstack-k8s-operators/edpm-ansible:main:refs/changes/42/1042/4d1575d1c5aa317d07bf95973aac6faacde3d75b^openstack-k8s-operators/ci-framework:main:refs/changes/68/3368/a7a306bfcc713c1569b93e3182b828584aee713d
2025-10-08 12:39:28.569832 | controller | PWD=/home/zuul
2025-10-08 12:39:28.569837 | controller | ZUUL_PIPELINE=github-check
2025-10-08 12:39:28.569843 | controller | LOGNAME=zuul
2025-10-08 12:39:28.569848 | controller | XDG_SESSION_TYPE=tty
2025-10-08 12:39:28.569854 | controller | _=/usr/bin/env
2025-10-08 12:39:28.569897 | controller | MOTD_SHOWN=pam
2025-10-08 12:39:28.569906 | controller | HOME=/home/zuul
2025-10-08 12:39:28.569911 | controller | LANG=en_US.UTF-8
2025-10-08 12:39:28.569916 | controller | SSH_CONNECTION=192.168.26.12 50094 192.168.26.82 22
2025-10-08 12:39:28.569922 | 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-08 12:39:28.569928 | controller | ZUUL_CHANGE_IDS=1042,4d1575d1c5aa317d07bf95973aac6faacde3d75b 3368,a7a306bfcc713c1569b93e3182b828584aee713d
2025-10-08 12:39:28.569933 | controller | WORKSPACE=/home/zuul/workspace
2025-10-08 12:39:28.569939 | controller | XDG_SESSION_CLASS=user
2025-10-08 12:39:28.569944 | controller | SELINUX_ROLE_REQUESTED=
2025-10-08 12:39:28.569965 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-10-08 12:39:28.569975 | controller | USER=zuul
2025-10-08 12:39:28.569980 | controller | ZUUL_VOTING=True
2025-10-08 12:39:28.569986 | controller | BUILD_TIMEOUT=1800000
2025-10-08 12:39:28.569991 | controller | SELINUX_USE_CURRENT_RANGE=
2025-10-08 12:39:28.569996 | controller | SHLVL=1
2025-10-08 12:39:28.570002 | controller | ZUUL_PATCHSET=a7a306bfcc713c1569b93e3182b828584aee713d
2025-10-08 12:39:28.570007 | controller | XDG_SESSION_ID=1
2025-10-08 12:39:28.570012 | controller | ZUUL_BRANCH=main
2025-10-08 12:39:28.570017 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-10-08 12:39:28.570023 | controller | SSH_CLIENT=192.168.26.12 50094 22
2025-10-08 12:39:28.570028 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-10-08 12:39:28.570033 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-10-08 12:39:28.570039 | controller | which_declare=declare -f
2025-10-08 12:39:28.570044 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-10-08 12:39:28.570050 | controller | SELINUX_LEVEL_REQUESTED=
2025-10-08 12:39:28.570055 | controller | ZUUL_CHANGE=3368
2025-10-08 12:39:28.570061 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-10-08 12:39:28.570066 | controller | ZUUL_UUID=849a4dc819e84bd080920a22c783739b
2025-10-08 12:39:28.570071 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-10-08 12:39:28.570077 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-10-08 12:39:28.570082 | controller | }
2025-10-08 12:39:28.875679 | controller | ok: Runtime: 0:00:00.006925
2025-10-08 12:39:28.881871 | 
2025-10-08 12:39:28.881976 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-10-08 12:39:28.936286 | controller | skipping: Conditional result was False
2025-10-08 12:39:28.943038 | 
2025-10-08 12:39:28.943129 | TASK [Symlink /home/zuul-worker/workspace]
2025-10-08 12:39:29.483640 | controller | skipping: Conditional result was False
2025-10-08 12:39:29.490187 | 
2025-10-08 12:39:29.490256 | TASK [Ensure legacy workspace directory]
2025-10-08 12:39:29.681167 | controller | changed
2025-10-08 12:39:29.704797 | 
2025-10-08 12:39:29.704880 | PLAY RECAP
2025-10-08 12:39:29.704991 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-08 12:39:29.705020 | 
2025-10-08 12:39:29.795771 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-08 12:39:29.796569 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-08 12:39:30.380420 | 
2025-10-08 12:39:30.380582 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-10-08 12:39:30.402165 | 
2025-10-08 12:39:30.402280 | TASK [Create zuul-output directory]
2025-10-08 12:39:30.735997 | controller | changed
2025-10-08 12:39:30.740985 | 
2025-10-08 12:39:30.741059 | TASK [Slurp Zuul inventory test]
2025-10-08 12:39:31.042138 | controller -> localhost | ok
2025-10-08 12:39:31.048787 | 
2025-10-08 12:39:31.048860 | TASK [Save zuul inventory]
2025-10-08 12:39:31.789735 | controller | changed
2025-10-08 12:39:31.795125 | 
2025-10-08 12:39:31.795195 | TASK [Save zuul vars without the change_message]
2025-10-08 12:39:32.371503 | controller | changed
2025-10-08 12:39:32.389410 | 
2025-10-08 12:39:32.389488 | PLAY RECAP
2025-10-08 12:39:32.389534 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-08 12:39:32.389559 | 
2025-10-08 12:39:32.482642 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-08 12:39:32.483472 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-08 12:39:33.072527 | 
2025-10-08 12:39:33.072638 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-10-08 12:39:33.094146 | 
2025-10-08 12:39:33.094240 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-10-08 12:39:33.123064 | controller | ok
2025-10-08 12:39:33.140240 | 
2025-10-08 12:39:33.140349 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-08 12:39:33.163976 | controller | skipping: Conditional result was False
2025-10-08 12:39:33.169808 | 
2025-10-08 12:39:33.169922 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-08 12:39:33.512569 | controller | ok
2025-10-08 12:39:33.518870 | 
2025-10-08 12:39:33.519037 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-08 12:39:34.195614 | controller | ok
2025-10-08 12:39:34.205904 | 
2025-10-08 12:39:34.206030 | TASK [Prepare workspace]
2025-10-08 12:39:34.224011 | controller | ok
2025-10-08 12:39:34.240099 | 
2025-10-08 12:39:34.240177 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-08 12:39:34.579633 | controller | ok
2025-10-08 12:39:34.586283 | 
2025-10-08 12:39:34.586352 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-08 12:39:37.054332 | controller | Output suppressed because no_log was given
2025-10-08 12:39:37.064109 | 
2025-10-08 12:39:37.064196 | LOOP [Create zuul-output directory]
2025-10-08 12:39:37.261648 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-10-08 12:39:37.422241 | controller | ok: "/home/zuul/zuul-output/logs"
2025-10-08 12:39:37.434928 | 
2025-10-08 12:39:37.435036 | TASK [Install required packages]
2025-10-08 12:40:41.364656 | controller | changed
2025-10-08 12:40:41.370240 | 
2025-10-08 12:40:41.370325 | TASK [Install venv]
2025-10-08 12:41:42.121230 | controller | changed
2025-10-08 12:41:42.150753 | 
2025-10-08 12:41:42.150857 | PLAY RECAP
2025-10-08 12:41:42.150957 | controller | ok: 7 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-08 12:41:42.150987 | 
2025-10-08 12:41:42.252400 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-08 12:41:42.253264 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-08 12:41:42.871734 | 
2025-10-08 12:41:42.871852 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-10-08 12:41:42.893164 | 
2025-10-08 12:41:42.893272 | TASK [Gather required facts]
2025-10-08 12:41:43.452984 | controller | ok
2025-10-08 12:41:43.462458 | 
2025-10-08 12:41:43.462594 | TASK [Load environment var if instructed to]
2025-10-08 12:41:43.497446 | controller | skipping: Conditional result was False
2025-10-08 12:41:43.504383 | 
2025-10-08 12:41:43.504478 | TASK [Run molecule]
2025-10-08 12:41:44.514222 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-10-08 12:41:44.584440 | controller | INFO     Performing prerun with role_name_check=0...
2025-10-08 12:42:01.544798 | 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-08 12:42:01.545324 | 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-08 12:42:01.545814 | 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-08 12:42:01.546285 | 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-08 12:42:01.546766 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+a7a306bf was found installed in /home/zuul/.cache/ansible-compat/f9b5a8/collections/ansible_collections, only the first one will be used, 1.0.0+a7a306bf (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 12:42:01.547222 | 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-08 12:42:01.547677 | 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-08 12:42:01.548134 | 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-08 12:42:01.548592 | 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-08 12:42:01.549054 | 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-08 12:42:01.549516 | 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-08 12:42:01.549948 | 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-08 12:42:01.550392 | 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-08 12:42:01.550835 | 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-08 12:42:01.551316 | 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-08 12:42:01.561229 | controller | INFO     Running default > prepare
2025-10-08 12:42:02.321915 | controller |
2025-10-08 12:42:02.322000 | controller | PLAY [Prepare] *****************************************************************
2025-10-08 12:42:02.322115 | controller |
2025-10-08 12:42:02.322225 | controller | TASK [Gathering Facts] *********************************************************
2025-10-08 12:42:02.322328 | controller | Wednesday 08 October 2025  12:42:02 +0000 (0:00:00.023)       0:00:00.023 *****
2025-10-08 12:42:03.151715 | controller | ok: [instance]
2025-10-08 12:42:03.151779 | controller |
2025-10-08 12:42:03.151885 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-10-08 12:42:03.152018 | controller | Wednesday 08 October 2025  12:42:03 +0000 (0:00:00.830)       0:00:00.854 *****
2025-10-08 12:42:03.169968 | controller | skipping: [instance]
2025-10-08 12:42:03.170060 | controller |
2025-10-08 12:42:03.170167 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-10-08 12:42:03.170273 | controller | Wednesday 08 October 2025  12:42:03 +0000 (0:00:00.018)       0:00:00.872 *****
2025-10-08 12:42:03.213111 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-10-08 12:42:03.213204 | controller |
2025-10-08 12:42:03.213317 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-10-08 12:42:03.213437 | controller | Wednesday 08 October 2025  12:42:03 +0000 (0:00:00.042)       0:00:00.915 *****
2025-10-08 12:42:03.497640 | controller | ok: [instance]
2025-10-08 12:42:03.497716 | controller |
2025-10-08 12:42:03.497830 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-10-08 12:42:03.497937 | controller | Wednesday 08 October 2025  12:42:03 +0000 (0:00:00.284)       0:00:01.199 *****
2025-10-08 12:42:03.806239 | controller | ok: [instance]
2025-10-08 12:42:03.806330 | controller |
2025-10-08 12:42:03.806462 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-10-08 12:42:03.806574 | controller | Wednesday 08 October 2025  12:42:03 +0000 (0:00:00.308)       0:00:01.508 *****
2025-10-08 12:42:04.482697 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-10-08 12:42:04.482803 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-10-08 12:42:04.482914 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-10-08 12:42:04.483042 | controller |
2025-10-08 12:42:04.483146 | controller | TASK [Deploy repo-setup] *******************************************************
2025-10-08 12:42:04.483255 | controller | Wednesday 08 October 2025  12:42:04 +0000 (0:00:00.676)       0:00:02.185 *****
2025-10-08 12:42:04.542736 | controller |
2025-10-08 12:42:04.542853 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-10-08 12:42:04.542992 | controller | Wednesday 08 October 2025  12:42:04 +0000 (0:00:00.059)       0:00:02.244 *****
2025-10-08 12:42:05.095862 | controller | changed: [instance] => (item=tmp)
2025-10-08 12:42:05.095918 | controller | changed: [instance] => (item=artifacts/repositories)
2025-10-08 12:42:05.096060 | controller | changed: [instance] => (item=venv/repo_setup)
2025-10-08 12:42:05.096159 | controller |
2025-10-08 12:42:05.096267 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-10-08 12:42:05.096370 | controller | Wednesday 08 October 2025  12:42:05 +0000 (0:00:00.553)       0:00:02.798 *****
2025-10-08 12:42:05.906200 | controller | ok: [instance]
2025-10-08 12:42:05.906252 | controller |
2025-10-08 12:42:05.906531 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-10-08 12:42:07.112021 | controller | Wednesday 08 October 2025  12:42:05 +0000 (0:00:00.810)       0:00:03.608 *****
2025-10-08 12:42:07.112054 | controller | changed: [instance]
2025-10-08 12:42:07.112263 | controller |
2025-10-08 12:42:07.112283 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-10-08 12:42:15.060617 | controller | Wednesday 08 October 2025  12:42:07 +0000 (0:00:01.205)       0:00:04.814 *****
2025-10-08 12:42:15.060653 | controller | changed: [instance]
2025-10-08 12:42:15.799933 | controller |
2025-10-08 12:42:15.799994 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-10-08 12:42:15.800003 | controller | Wednesday 08 October 2025  12:42:15 +0000 (0:00:07.948)       0:00:12.762 *****
2025-10-08 12:42:15.800014 | controller | changed: [instance]
2025-10-08 12:42:15.823037 | controller |
2025-10-08 12:42:15.823070 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-10-08 12:42:15.823079 | controller | Wednesday 08 October 2025  12:42:15 +0000 (0:00:00.739)       0:00:13.501 *****
2025-10-08 12:42:15.823090 | controller | skipping: [instance]
2025-10-08 12:42:16.682113 | controller |
2025-10-08 12:42:16.682147 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-10-08 12:42:16.682155 | controller | Wednesday 08 October 2025  12:42:15 +0000 (0:00:00.023)       0:00:13.525 *****
2025-10-08 12:42:16.682165 | controller | changed: [instance]
2025-10-08 12:42:16.682191 | controller |
2025-10-08 12:42:16.682472 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-10-08 12:42:16.719512 | controller | Wednesday 08 October 2025  12:42:16 +0000 (0:00:00.859)       0:00:14.384 *****
2025-10-08 12:42:16.719550 | controller | skipping: [instance]
2025-10-08 12:42:16.754975 | controller |
2025-10-08 12:42:16.755008 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-10-08 12:42:16.755016 | controller | Wednesday 08 October 2025  12:42:16 +0000 (0:00:00.037)       0:00:14.421 *****
2025-10-08 12:42:16.755026 | controller | skipping: [instance]
2025-10-08 12:42:16.790440 | controller |
2025-10-08 12:42:16.790488 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-10-08 12:42:16.790496 | controller | Wednesday 08 October 2025  12:42:16 +0000 (0:00:00.034)       0:00:14.456 *****
2025-10-08 12:42:16.790506 | controller | skipping: [instance]
2025-10-08 12:42:16.790654 | controller |
2025-10-08 12:42:16.790805 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-10-08 12:42:16.790948 | controller | Wednesday 08 October 2025  12:42:16 +0000 (0:00:00.036)       0:00:14.492 *****
2025-10-08 12:42:17.348675 | controller | changed: [instance]
2025-10-08 12:42:17.799643 | controller |
2025-10-08 12:42:17.799677 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-10-08 12:42:17.799685 | controller | Wednesday 08 October 2025  12:42:17 +0000 (0:00:00.557)       0:00:15.050 *****
2025-10-08 12:42:17.799695 | controller | changed: [instance]
2025-10-08 12:42:17.827423 | controller |
2025-10-08 12:42:17.827453 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-10-08 12:42:17.827461 | controller | Wednesday 08 October 2025  12:42:17 +0000 (0:00:00.450)       0:00:15.501 *****
2025-10-08 12:42:17.827491 | controller | skipping: [instance]
2025-10-08 12:42:17.855532 | controller |
2025-10-08 12:42:17.855564 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-10-08 12:42:17.855572 | controller | Wednesday 08 October 2025  12:42:17 +0000 (0:00:00.027)       0:00:15.529 *****
2025-10-08 12:42:17.855581 | controller | skipping: [instance]
2025-10-08 12:42:17.883038 | controller |
2025-10-08 12:42:17.883068 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-10-08 12:42:17.883077 | controller | Wednesday 08 October 2025  12:42:17 +0000 (0:00:00.028)       0:00:15.557 *****
2025-10-08 12:42:17.883090 | controller | skipping: [instance]
2025-10-08 12:42:17.883119 | controller |
2025-10-08 12:42:17.883126 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-10-08 12:42:17.883134 | controller | Wednesday 08 October 2025  12:42:17 +0000 (0:00:00.027)       0:00:15.585 *****
2025-10-08 12:42:17.919489 | controller | ok: [instance]
2025-10-08 12:42:17.919622 | controller |
2025-10-08 12:42:17.919744 | controller | TASK [repo_setup : Create download directory] **********************************
2025-10-08 12:42:17.919864 | controller | Wednesday 08 October 2025  12:42:17 +0000 (0:00:00.036)       0:00:15.621 *****
2025-10-08 12:42:17.945281 | controller | skipping: [instance]
2025-10-08 12:42:17.945400 | controller |
2025-10-08 12:42:17.945540 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-10-08 12:42:17.945662 | controller | Wednesday 08 October 2025  12:42:17 +0000 (0:00:00.025)       0:00:15.647 *****
2025-10-08 12:42:17.971767 | controller | skipping: [instance]
2025-10-08 12:42:17.998584 | controller |
2025-10-08 12:42:17.998616 | controller | TASK [Download the RPM] ********************************************************
2025-10-08 12:42:17.998626 | controller | Wednesday 08 October 2025  12:42:17 +0000 (0:00:00.026)       0:00:15.673 *****
2025-10-08 12:42:17.998644 | controller | skipping: [instance]
2025-10-08 12:42:18.024379 | controller |
2025-10-08 12:42:18.024405 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-10-08 12:42:18.024412 | controller | Wednesday 08 October 2025  12:42:17 +0000 (0:00:00.026)       0:00:15.700 *****
2025-10-08 12:42:18.024422 | controller | skipping: [instance]
2025-10-08 12:42:18.049903 | controller |
2025-10-08 12:42:18.049926 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-10-08 12:42:18.049934 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.026)       0:00:15.726 *****
2025-10-08 12:42:18.049943 | controller | skipping: [instance]
2025-10-08 12:42:18.076552 | controller |
2025-10-08 12:42:18.076575 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-10-08 12:42:18.076582 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.025)       0:00:15.752 *****
2025-10-08 12:42:18.076592 | controller | skipping: [instance]
2025-10-08 12:42:18.101915 | controller |
2025-10-08 12:42:18.101944 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-10-08 12:42:18.101976 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.026)       0:00:15.778 *****
2025-10-08 12:42:18.101993 | controller | skipping: [instance]
2025-10-08 12:42:18.102168 | controller |
2025-10-08 12:42:18.102326 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-10-08 12:42:18.102485 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.025)       0:00:15.804 *****
2025-10-08 12:42:18.284633 | controller | ok: [instance]
2025-10-08 12:42:18.488017 | controller |
2025-10-08 12:42:18.488046 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-10-08 12:42:18.488054 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.182)       0:00:15.986 *****
2025-10-08 12:42:18.488064 | controller | changed: [instance]
2025-10-08 12:42:18.488308 | controller |
2025-10-08 12:42:18.488323 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-10-08 12:42:18.715130 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.203)       0:00:16.190 *****
2025-10-08 12:42:18.715165 | controller | changed: [instance]
2025-10-08 12:42:18.735015 | controller |
2025-10-08 12:42:18.735041 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-10-08 12:42:18.735051 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.226)       0:00:16.417 *****
2025-10-08 12:42:18.735062 | controller | skipping: [instance]
2025-10-08 12:42:18.735196 | controller |
2025-10-08 12:42:18.735208 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-10-08 12:42:18.735216 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.020)       0:00:16.437 *****
2025-10-08 12:42:18.755590 | controller | skipping: [instance]
2025-10-08 12:42:18.777246 | controller |
2025-10-08 12:42:18.777274 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-10-08 12:42:18.777281 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.020)       0:00:16.457 *****
2025-10-08 12:42:18.777291 | controller | skipping: [instance]
2025-10-08 12:42:18.797659 | controller |
2025-10-08 12:42:18.797688 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-10-08 12:42:18.797696 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.021)       0:00:16.479 *****
2025-10-08 12:42:18.797706 | controller | skipping: [instance]
2025-10-08 12:42:18.817985 | controller |
2025-10-08 12:42:18.818011 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-10-08 12:42:18.818026 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.020)       0:00:16.499 *****
2025-10-08 12:42:18.818038 | controller | skipping: [instance]
2025-10-08 12:42:18.838270 | controller |
2025-10-08 12:42:18.838290 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-10-08 12:42:18.838303 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.020)       0:00:16.520 *****
2025-10-08 12:42:18.838314 | controller | skipping: [instance]
2025-10-08 12:42:18.853546 | controller |
2025-10-08 12:42:18.853568 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-10-08 12:42:18.853576 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.020)       0:00:16.540 *****
2025-10-08 12:42:18.853586 | controller | skipping: [instance]
2025-10-08 12:42:18.880865 | controller |
2025-10-08 12:42:18.880889 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-10-08 12:42:18.880898 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.015)       0:00:16.555 *****
2025-10-08 12:42:18.880910 | controller | skipping: [instance]
2025-10-08 12:42:18.896211 | controller |
2025-10-08 12:42:18.896234 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-10-08 12:42:18.896242 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.027)       0:00:16.583 *****
2025-10-08 12:42:18.896253 | controller | skipping: [instance]
2025-10-08 12:42:18.915488 | controller |
2025-10-08 12:42:18.915510 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-10-08 12:42:18.915517 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.015)       0:00:16.598 *****
2025-10-08 12:42:18.915526 | controller | skipping: [instance]
2025-10-08 12:42:18.943947 | controller |
2025-10-08 12:42:18.943988 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-10-08 12:42:18.943995 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.019)       0:00:16.617 *****
2025-10-08 12:42:18.944005 | controller | skipping: [instance]
2025-10-08 12:42:18.975046 | controller |
2025-10-08 12:42:18.975082 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-10-08 12:42:18.975090 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.028)       0:00:16.646 *****
2025-10-08 12:42:18.975101 | controller | skipping: [instance]
2025-10-08 12:42:18.975126 | controller |
2025-10-08 12:42:18.975134 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-10-08 12:42:18.975248 | controller | Wednesday 08 October 2025  12:42:18 +0000 (0:00:00.031)       0:00:16.677 *****
2025-10-08 12:42:19.007939 | controller | skipping: [instance]
2025-10-08 12:42:19.039500 | controller |
2025-10-08 12:42:19.039524 | controller | TASK [test_deps : Install additional packages] *********************************
2025-10-08 12:42:19.039532 | controller | Wednesday 08 October 2025  12:42:19 +0000 (0:00:00.032)       0:00:16.710 *****
2025-10-08 12:42:19.039542 | controller | skipping: [instance]
2025-10-08 12:43:04.533501 | controller |
2025-10-08 12:43:04.533532 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-10-08 12:43:04.533540 | controller | Wednesday 08 October 2025  12:42:19 +0000 (0:00:00.031)       0:00:16.741 *****
2025-10-08 12:43:04.533550 | controller | ok: [instance]
2025-10-08 12:43:05.729063 | controller |
2025-10-08 12:43:05.729096 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-10-08 12:43:05.729104 | controller | Wednesday 08 October 2025  12:43:04 +0000 (0:00:45.493)       0:01:02.235 *****
2025-10-08 12:43:05.729114 | controller | ok: [instance]
2025-10-08 12:43:05.729362 | controller |
2025-10-08 12:43:05.729377 | controller | TASK [test_deps : Install extra packages] **************************************
2025-10-08 12:43:09.485434 | controller | Wednesday 08 October 2025  12:43:05 +0000 (0:00:01.195)       0:01:03.431 *****
2025-10-08 12:43:09.485512 | controller | changed: [instance]
2025-10-08 12:43:09.485796 | controller |
2025-10-08 12:43:09.686504 | controller | TASK [libvirt_manager : Ensure output directory exists] ************************
2025-10-08 12:43:09.686535 | controller | Wednesday 08 October 2025  12:43:09 +0000 (0:00:03.756)       0:01:07.187 *****
2025-10-08 12:43:09.686546 | controller | ok: [instance]
2025-10-08 12:43:09.871190 | controller |
2025-10-08 12:43:09.871220 | controller | TASK [libvirt_manager : Get vmx/svm extensions from /proc/cpuinfo] *************
2025-10-08 12:43:09.871229 | controller | Wednesday 08 October 2025  12:43:09 +0000 (0:00:00.200)       0:01:07.388 *****
2025-10-08 12:43:09.871239 | controller | changed: [instance]
2025-10-08 12:43:10.054697 | controller |
2025-10-08 12:43:10.054728 | controller | TASK [libvirt_manager : Check if KVM is enabled] *******************************
2025-10-08 12:43:10.054736 | controller | Wednesday 08 October 2025  12:43:09 +0000 (0:00:00.184)       0:01:07.573 *****
2025-10-08 12:43:10.054746 | controller | ok: [instance]
2025-10-08 12:43:10.083528 | controller |
2025-10-08 12:43:10.083556 | controller | TASK [libvirt_manager : Fail if KVM not enabled] *******************************
2025-10-08 12:43:10.083570 | controller | Wednesday 08 October 2025  12:43:10 +0000 (0:00:00.183)       0:01:07.756 *****
2025-10-08 12:43:10.083580 | controller | skipping: [instance]
2025-10-08 12:43:10.102486 | controller |
2025-10-08 12:43:10.102511 | controller | TASK [libvirt_manager : Check if VMX virtualization] ***************************
2025-10-08 12:43:10.102519 | controller | Wednesday 08 October 2025  12:43:10 +0000 (0:00:00.028)       0:01:07.785 *****
2025-10-08 12:43:10.102528 | controller | skipping: [instance]
2025-10-08 12:43:10.122679 | controller |
2025-10-08 12:43:10.122707 | controller | TASK [libvirt_manager : Check if SVM virtualization] ***************************
2025-10-08 12:43:10.122714 | controller | Wednesday 08 October 2025  12:43:10 +0000 (0:00:00.018)       0:01:07.804 *****
2025-10-08 12:43:10.122724 | controller | ok: [instance]
2025-10-08 12:43:10.151701 | controller |
2025-10-08 12:43:10.151732 | controller | TASK [libvirt_manager : Enable VMX virtualization] *****************************
2025-10-08 12:43:10.151741 | controller | Wednesday 08 October 2025  12:43:10 +0000 (0:00:00.019)       0:01:07.824 *****
2025-10-08 12:43:10.151750 | controller | skipping: [instance]
2025-10-08 12:44:19.778454 | controller |
2025-10-08 12:44:19.778488 | controller | TASK [libvirt_manager : Install packages required for using KVM] ***************
2025-10-08 12:44:19.778496 | controller | Wednesday 08 October 2025  12:43:10 +0000 (0:00:00.029)       0:01:07.853 *****
2025-10-08 12:44:19.778507 | controller | changed: [instance]
2025-10-08 12:44:19.778562 | controller |
2025-10-08 12:44:19.778716 | controller | TASK [libvirt_manager : Create rules.d polkit folder] **************************
2025-10-08 12:44:19.988173 | controller | Wednesday 08 October 2025  12:44:19 +0000 (0:01:09.627)       0:02:17.480 *****
2025-10-08 12:44:19.988206 | controller | changed: [instance]
2025-10-08 12:44:20.378054 | controller |
2025-10-08 12:44:20.378084 | controller | TASK [libvirt_manager : Enable UNIX socket PolicyKit auth] *********************
2025-10-08 12:44:20.378093 | controller | Wednesday 08 October 2025  12:44:19 +0000 (0:00:00.209)       0:02:17.690 *****
2025-10-08 12:44:20.378103 | controller | changed: [instance]
2025-10-08 12:44:20.967492 | controller |
2025-10-08 12:44:20.967522 | controller | TASK [libvirt_manager : Restart service polkit service] ************************
2025-10-08 12:44:20.967531 | controller | Wednesday 08 October 2025  12:44:20 +0000 (0:00:00.389)       0:02:18.079 *****
2025-10-08 12:44:20.967541 | controller | changed: [instance]
2025-10-08 12:44:21.166012 | controller |
2025-10-08 12:44:21.166043 | controller | TASK [libvirt_manager : Remove directory for service override] *****************
2025-10-08 12:44:21.166052 | controller | Wednesday 08 October 2025  12:44:20 +0000 (0:00:00.589)       0:02:18.669 *****
2025-10-08 12:44:21.166062 | controller | ok: [instance]
2025-10-08 12:44:21.874513 | controller |
2025-10-08 12:44:21.874544 | controller | TASK [libvirt_manager : Reload systemctl and start/enable virtproxyd.service] ***
2025-10-08 12:44:21.874553 | controller | Wednesday 08 October 2025  12:44:21 +0000 (0:00:00.198)       0:02:18.868 *****
2025-10-08 12:44:21.874563 | controller | ok: [instance]
2025-10-08 12:44:21.874868 | controller |
2025-10-08 12:44:22.767520 | controller | TASK [libvirt_manager : Ensure firewalld service is up] ************************
2025-10-08 12:44:22.767551 | controller | Wednesday 08 October 2025  12:44:21 +0000 (0:00:00.708)       0:02:19.576 *****
2025-10-08 12:44:22.767564 | controller | changed: [instance]
2025-10-08 12:44:22.851813 | controller |
2025-10-08 12:44:22.851861 | controller | TASK [libvirt_manager : Ensure libvirt modular driver daemons are started.] ****
2025-10-08 12:44:22.851871 | controller | Wednesday 08 October 2025  12:44:22 +0000 (0:00:00.892)       0:02:20.469 *****
2025-10-08 12:44:22.851882 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=qemu)
2025-10-08 12:44:22.852346 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=interface)
2025-10-08 12:44:22.852385 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=network)
2025-10-08 12:44:22.852393 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nodedev)
2025-10-08 12:44:22.852398 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nwfilter)
2025-10-08 12:44:22.852406 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=secret)
2025-10-08 12:44:22.852508 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=storage)
2025-10-08 12:44:22.852642 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=proxy)
2025-10-08 12:44:22.852890 | controller |
2025-10-08 12:44:22.852911 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for qemu.] *********
2025-10-08 12:44:23.234510 | controller | Wednesday 08 October 2025  12:44:22 +0000 (0:00:00.084)       0:02:20.554 *****
2025-10-08 12:44:23.234546 | controller | changed: [instance]
2025-10-08 12:44:23.610326 | controller |
2025-10-08 12:44:23.610358 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for qemu.] **********
2025-10-08 12:44:23.610366 | controller | Wednesday 08 October 2025  12:44:23 +0000 (0:00:00.382)       0:02:20.936 *****
2025-10-08 12:44:23.610377 | controller | changed: [instance]
2025-10-08 12:44:23.977677 | controller |
2025-10-08 12:44:23.977714 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for qemu.] **************
2025-10-08 12:44:23.977723 | controller | Wednesday 08 October 2025  12:44:23 +0000 (0:00:00.375)       0:02:21.312 *****
2025-10-08 12:44:23.977733 | controller | changed: [instance]
2025-10-08 12:44:24.360139 | controller |
2025-10-08 12:44:24.360171 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for interface.] ****
2025-10-08 12:44:24.360180 | controller | Wednesday 08 October 2025  12:44:23 +0000 (0:00:00.367)       0:02:21.679 *****
2025-10-08 12:44:24.360196 | controller | changed: [instance]
2025-10-08 12:44:24.734000 | controller |
2025-10-08 12:44:24.734069 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for interface.] *****
2025-10-08 12:44:24.734082 | controller | Wednesday 08 October 2025  12:44:24 +0000 (0:00:00.382)       0:02:22.062 *****
2025-10-08 12:44:24.734097 | controller | changed: [instance]
2025-10-08 12:44:25.096326 | controller |
2025-10-08 12:44:25.096360 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for interface.] *********
2025-10-08 12:44:25.096368 | controller | Wednesday 08 October 2025  12:44:24 +0000 (0:00:00.373)       0:02:22.435 *****
2025-10-08 12:44:25.096378 | controller | changed: [instance]
2025-10-08 12:44:25.439383 | controller |
2025-10-08 12:44:25.439416 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for network.] ******
2025-10-08 12:44:25.439424 | controller | Wednesday 08 October 2025  12:44:25 +0000 (0:00:00.362)       0:02:22.798 *****
2025-10-08 12:44:25.439435 | controller | changed: [instance]
2025-10-08 12:44:25.784404 | controller |
2025-10-08 12:44:25.784434 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for network.] *******
2025-10-08 12:44:25.784442 | controller | Wednesday 08 October 2025  12:44:25 +0000 (0:00:00.343)       0:02:23.141 *****
2025-10-08 12:44:25.784452 | controller | changed: [instance]
2025-10-08 12:44:26.127087 | controller |
2025-10-08 12:44:26.127117 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for network.] ***********
2025-10-08 12:44:26.127126 | controller | Wednesday 08 October 2025  12:44:25 +0000 (0:00:00.345)       0:02:23.486 *****
2025-10-08 12:44:26.127136 | controller | changed: [instance]
2025-10-08 12:44:26.454297 | controller |
2025-10-08 12:44:26.454327 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nodedev.] ******
2025-10-08 12:44:26.454335 | controller | Wednesday 08 October 2025  12:44:26 +0000 (0:00:00.342)       0:02:23.829 *****
2025-10-08 12:44:26.454345 | controller | changed: [instance]
2025-10-08 12:44:26.800791 | controller |
2025-10-08 12:44:26.800827 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nodedev.] *******
2025-10-08 12:44:26.800836 | controller | Wednesday 08 October 2025  12:44:26 +0000 (0:00:00.327)       0:02:24.156 *****
2025-10-08 12:44:26.800846 | controller | changed: [instance]
2025-10-08 12:44:27.146456 | controller |
2025-10-08 12:44:27.146487 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nodedev.] ***********
2025-10-08 12:44:27.146495 | controller | Wednesday 08 October 2025  12:44:26 +0000 (0:00:00.346)       0:02:24.502 *****
2025-10-08 12:44:27.146505 | controller | changed: [instance]
2025-10-08 12:44:27.489564 | controller |
2025-10-08 12:44:27.489600 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nwfilter.] *****
2025-10-08 12:44:27.489609 | controller | Wednesday 08 October 2025  12:44:27 +0000 (0:00:00.345)       0:02:24.848 *****
2025-10-08 12:44:27.489619 | controller | changed: [instance]
2025-10-08 12:44:27.846915 | controller |
2025-10-08 12:44:27.846945 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nwfilter.] ******
2025-10-08 12:44:27.847000 | controller | Wednesday 08 October 2025  12:44:27 +0000 (0:00:00.342)       0:02:25.191 *****
2025-10-08 12:44:27.847013 | controller | changed: [instance]
2025-10-08 12:44:28.199396 | controller |
2025-10-08 12:44:28.199425 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nwfilter.] **********
2025-10-08 12:44:28.199433 | controller | Wednesday 08 October 2025  12:44:27 +0000 (0:00:00.357)       0:02:25.548 *****
2025-10-08 12:44:28.199443 | controller | changed: [instance]
2025-10-08 12:44:28.539558 | controller |
2025-10-08 12:44:28.539589 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for secret.] *******
2025-10-08 12:44:28.539598 | controller | Wednesday 08 October 2025  12:44:28 +0000 (0:00:00.352)       0:02:25.901 *****
2025-10-08 12:44:28.539608 | controller | changed: [instance]
2025-10-08 12:44:28.889671 | controller |
2025-10-08 12:44:28.889702 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for secret.] ********
2025-10-08 12:44:28.889711 | controller | Wednesday 08 October 2025  12:44:28 +0000 (0:00:00.340)       0:02:26.241 *****
2025-10-08 12:44:28.889721 | controller | changed: [instance]
2025-10-08 12:44:29.232032 | controller |
2025-10-08 12:44:29.232063 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for secret.] ************
2025-10-08 12:44:29.232071 | controller | Wednesday 08 October 2025  12:44:28 +0000 (0:00:00.350)       0:02:26.591 *****
2025-10-08 12:44:29.232081 | controller | changed: [instance]
2025-10-08 12:44:29.232103 | controller |
2025-10-08 12:44:29.232111 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for storage.] ******
2025-10-08 12:44:29.232167 | controller | Wednesday 08 October 2025  12:44:29 +0000 (0:00:00.342)       0:02:26.934 *****
2025-10-08 12:44:29.572334 | controller | changed: [instance]
2025-10-08 12:44:29.915130 | controller |
2025-10-08 12:44:29.915159 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for storage.] *******
2025-10-08 12:44:29.915173 | controller | Wednesday 08 October 2025  12:44:29 +0000 (0:00:00.340)       0:02:27.274 *****
2025-10-08 12:44:29.915183 | controller | changed: [instance]
2025-10-08 12:44:30.254771 | controller |
2025-10-08 12:44:30.254801 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for storage.] ***********
2025-10-08 12:44:30.254810 | controller | Wednesday 08 October 2025  12:44:29 +0000 (0:00:00.342)       0:02:27.617 *****
2025-10-08 12:44:30.254819 | controller | changed: [instance]
2025-10-08 12:44:30.594995 | controller |
2025-10-08 12:44:30.595028 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for proxy.] ********
2025-10-08 12:44:30.595037 | controller | Wednesday 08 October 2025  12:44:30 +0000 (0:00:00.338)       0:02:27.955 *****
2025-10-08 12:44:30.595047 | controller | changed: [instance]
2025-10-08 12:44:30.934745 | controller |
2025-10-08 12:44:30.934779 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for proxy.] *********
2025-10-08 12:44:30.934787 | controller | Wednesday 08 October 2025  12:44:30 +0000 (0:00:00.341)       0:02:28.297 *****
2025-10-08 12:44:30.934797 | controller | changed: [instance]
2025-10-08 12:44:31.271797 | controller |
2025-10-08 12:44:31.271829 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for proxy.] *************
2025-10-08 12:44:31.271838 | controller | Wednesday 08 October 2025  12:44:30 +0000 (0:00:00.339)       0:02:28.636 *****
2025-10-08 12:44:31.271855 | controller | changed: [instance]
2025-10-08 12:44:31.292474 | controller |
2025-10-08 12:44:31.292506 | controller | TASK [libvirt_manager : Manage service for older releases] *********************
2025-10-08 12:44:31.292514 | controller | Wednesday 08 October 2025  12:44:31 +0000 (0:00:00.337)       0:02:28.973 *****
2025-10-08 12:44:31.292524 | controller | skipping: [instance]
2025-10-08 12:44:31.562050 | controller |
2025-10-08 12:44:31.562084 | controller | TASK [libvirt_manager : Get libvirt group users] *******************************
2025-10-08 12:44:31.562093 | controller | Wednesday 08 October 2025  12:44:31 +0000 (0:00:00.020)       0:02:28.994 *****
2025-10-08 12:44:31.562104 | controller | ok: [instance]
2025-10-08 12:44:31.562282 | controller |
2025-10-08 12:44:31.562315 | controller | TASK [libvirt_manager : Add user if not exists in libvirt group] ***************
2025-10-08 12:44:31.982389 | controller | Wednesday 08 October 2025  12:44:31 +0000 (0:00:00.269)       0:02:29.264 *****
2025-10-08 12:44:31.982424 | controller | changed: [instance]
2025-10-08 12:44:32.315472 | controller |
2025-10-08 12:44:32.315505 | controller | TASK [libvirt_manager : Allow QEMU on home directory for the storage access] ***
2025-10-08 12:44:32.315513 | controller | Wednesday 08 October 2025  12:44:31 +0000 (0:00:00.419)       0:02:29.684 *****
2025-10-08 12:44:32.315523 | controller | changed: [instance]
2025-10-08 12:44:32.623040 | controller |
2025-10-08 12:44:32.623073 | controller | TASK [libvirt_manager : Inject system connection parameters in bashrc] *********
2025-10-08 12:44:32.623081 | controller | Wednesday 08 October 2025  12:44:32 +0000 (0:00:00.333)       0:02:30.017 *****
2025-10-08 12:44:32.623091 | controller | [WARNING]: Reset is not implemented for this connection
2025-10-08 12:44:32.634741 | controller | changed: [instance]
2025-10-08 12:44:34.237078 | controller |
2025-10-08 12:44:34.237110 | controller | TASK [libvirt_manager : Ensure we reload user env] *****************************
2025-10-08 12:44:34.237118 | controller | Wednesday 08 October 2025  12:44:32 +0000 (0:00:00.302)       0:02:30.320 *****
2025-10-08 12:44:34.237124 | controller |
2025-10-08 12:44:34.237130 | controller | TASK [discover_latest_image : Get latest image] ********************************
2025-10-08 12:44:34.237135 | controller | Wednesday 08 October 2025  12:44:32 +0000 (0:00:00.016)       0:02:30.336 *****
2025-10-08 12:44:34.237144 | controller | changed: [instance]
2025-10-08 12:44:34.264029 | controller |
2025-10-08 12:44:34.264060 | controller | TASK [discover_latest_image : Export facts accordingly] ************************
2025-10-08 12:44:34.264069 | controller | Wednesday 08 October 2025  12:44:34 +0000 (0:00:01.602)       0:02:31.939 *****
2025-10-08 12:44:34.264092 | controller | ok: [instance]
2025-10-08 12:44:34.284082 | controller |
2025-10-08 12:44:34.284121 | controller | TASK [Load networking definition] **********************************************
2025-10-08 12:44:34.284131 | controller | Wednesday 08 October 2025  12:44:34 +0000 (0:00:00.027)       0:02:31.966 *****
2025-10-08 12:44:34.284144 | controller | ok: [instance]
2025-10-08 12:44:34.284174 | controller |
2025-10-08 12:44:34.284183 | controller | TASK [libvirt_manager : Import layout generator if needed] *********************
2025-10-08 12:44:34.284193 | controller | Wednesday 08 October 2025  12:44:34 +0000 (0:00:00.020)       0:02:31.986 *****
2025-10-08 12:44:34.314106 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/generate_layout.yml for instance
2025-10-08 12:44:34.314216 | controller |
2025-10-08 12:44:34.314229 | controller | TASK [libvirt_manager : Chose right parameter for layout definition] ***********
2025-10-08 12:44:34.314240 | controller | Wednesday 08 October 2025  12:44:34 +0000 (0:00:00.029)       0:02:32.016 *****
2025-10-08 12:44:34.347075 | controller | ok: [instance]
2025-10-08 12:44:34.347191 | controller |
2025-10-08 12:44:34.347204 | controller | TASK [libvirt_manager : Patch the layout if needed] ****************************
2025-10-08 12:44:34.347216 | controller | Wednesday 08 October 2025  12:44:34 +0000 (0:00:00.033)       0:02:32.049 *****
2025-10-08 12:44:34.405564 | controller | skipping: [instance]
2025-10-08 12:44:34.835496 | controller |
2025-10-08 12:44:34.835537 | controller | TASK [libvirt_manager : Enable forwarding in the libvirt zone] *****************
2025-10-08 12:44:34.835546 | controller | Wednesday 08 October 2025  12:44:34 +0000 (0:00:00.058)       0:02:32.107 *****
2025-10-08 12:44:34.835558 | controller | changed: [instance]
2025-10-08 12:44:35.357618 | controller |
2025-10-08 12:44:35.357659 | controller | TASK [libvirt_manager : Enable masquerading for public traffic] ****************
2025-10-08 12:44:35.357676 | controller | Wednesday 08 October 2025  12:44:34 +0000 (0:00:00.429)       0:02:32.537 *****
2025-10-08 12:44:35.357688 | controller | changed: [instance]
2025-10-08 12:44:35.357695 | controller |
2025-10-08 12:44:35.357701 | controller | TASK [libvirt_manager : Ensure firewalld is restarts] **************************
2025-10-08 12:44:35.357706 | controller | Wednesday 08 October 2025  12:44:35 +0000 (0:00:00.512)       0:02:33.050 *****
2025-10-08 12:44:35.357712 | controller |
2025-10-08 12:44:35.357717 | controller | RUNNING HANDLER [libvirt_manager : Restart firewalld] **************************
2025-10-08 12:44:35.357724 | controller | Wednesday 08 October 2025  12:44:35 +0000 (0:00:00.008)       0:02:33.059 *****
2025-10-08 12:44:36.158301 | controller | changed: [instance]
2025-10-08 12:44:36.186807 | controller |
2025-10-08 12:44:36.186842 | controller | TASK [Deploy virtualbmc] *******************************************************
2025-10-08 12:44:36.186850 | controller | Wednesday 08 October 2025  12:44:36 +0000 (0:00:00.801)       0:02:33.860 *****
2025-10-08 12:44:36.186862 | controller | skipping: [instance]
2025-10-08 12:44:36.214038 | controller |
2025-10-08 12:44:36.214069 | controller | TASK [libvirt_manager : Let the project know we have vbmc available] ***********
2025-10-08 12:44:36.214077 | controller | Wednesday 08 October 2025  12:44:36 +0000 (0:00:00.028)       0:02:33.888 *****
2025-10-08 12:44:36.214088 | controller | skipping: [instance]
2025-10-08 12:44:36.214252 | controller |
2025-10-08 12:44:36.214264 | controller | TASK [libvirt_manager : Create needed workload directory] **********************
2025-10-08 12:44:36.802491 | controller | Wednesday 08 October 2025  12:44:36 +0000 (0:00:00.027)       0:02:33.916 *****
2025-10-08 12:44:36.802526 | controller | changed: [instance] => (item=workload)
2025-10-08 12:44:37.243315 | controller | changed: [instance] => (item=reproducer-inventory)
2025-10-08 12:44:37.243353 | controller | changed: [instance] => (item=volumes)
2025-10-08 12:44:37.243362 | controller |
2025-10-08 12:44:37.243368 | controller | TASK [libvirt_manager : Allow QEMU on workload directory] **********************
2025-10-08 12:44:37.243374 | controller | Wednesday 08 October 2025  12:44:36 +0000 (0:00:00.587)       0:02:34.504 *****
2025-10-08 12:44:37.243385 | controller | changed: [instance] => (item=workload)
2025-10-08 12:44:37.315679 | controller | changed: [instance] => (item=volumes)
2025-10-08 12:44:37.315712 | controller |
2025-10-08 12:44:37.315720 | controller | TASK [libvirt_manager : Generate networking data] ******************************
2025-10-08 12:44:37.315727 | controller | Wednesday 08 October 2025  12:44:37 +0000 (0:00:00.440)       0:02:34.945 *****
2025-10-08 12:44:37.315736 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/generate_networking_data.yml for instance
2025-10-08 12:44:37.333477 | controller |
2025-10-08 12:44:37.333502 | controller | TASK [libvirt_manager : Ensure fact is existing, and empty] ********************
2025-10-08 12:44:37.333510 | controller | Wednesday 08 October 2025  12:44:37 +0000 (0:00:00.072)       0:02:35.017 *****
2025-10-08 12:44:37.333519 | controller | ok: [instance]
2025-10-08 12:44:37.523805 | controller |
2025-10-08 12:44:37.523835 | controller | TASK [libvirt_manager : Check if we get an existing interfaces-info.yml] *******
2025-10-08 12:44:37.523843 | controller | Wednesday 08 October 2025  12:44:37 +0000 (0:00:00.017)       0:02:35.035 *****
2025-10-08 12:44:37.523854 | controller | ok: [instance]
2025-10-08 12:44:37.550978 | controller |
2025-10-08 12:44:37.551010 | controller | TASK [libvirt_manager : Load file if exists] ***********************************
2025-10-08 12:44:37.551020 | controller | Wednesday 08 October 2025  12:44:37 +0000 (0:00:00.190)       0:02:35.225 *****
2025-10-08 12:44:37.551033 | controller | skipping: [instance]
2025-10-08 12:44:37.577437 | controller |
2025-10-08 12:44:37.577474 | controller | TASK [libvirt_manager : Update fact with existing content] *********************
2025-10-08 12:44:37.577484 | controller | Wednesday 08 October 2025  12:44:37 +0000 (0:00:00.027)       0:02:35.253 *****
2025-10-08 12:44:37.577496 | controller | skipping: [instance]
2025-10-08 12:44:37.625385 | controller |
2025-10-08 12:44:37.625419 | controller | TASK [libvirt_manager : Generate VM list] **************************************
2025-10-08 12:44:37.625428 | controller | Wednesday 08 October 2025  12:44:37 +0000 (0:00:00.026)       0:02:35.279 *****
2025-10-08 12:44:37.625447 | controller | ok: [instance]
2025-10-08 12:44:37.716082 | controller |
2025-10-08 12:44:37.716118 | controller | TASK [libvirt_manager : Generate/update mapping all nodes] *********************
2025-10-08 12:44:37.716135 | controller | Wednesday 08 October 2025  12:44:37 +0000 (0:00:00.047)       0:02:35.327 *****
2025-10-08 12:44:37.716148 | controller | ok: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
2025-10-08 12:44:37.748443 | controller |
2025-10-08 12:44:37.748473 | controller | TASK [libvirt_manager : Append baremetal nodes if needed] **********************
2025-10-08 12:44:37.748482 | controller | Wednesday 08 October 2025  12:44:37 +0000 (0:00:00.090)       0:02:35.418 *****
2025-10-08 12:44:37.748492 | controller | skipping: [instance]
2025-10-08 12:44:38.108408 | controller |
2025-10-08 12:44:38.108440 | controller | TASK [libvirt_manager : Dump MAC mapping] **************************************
2025-10-08 12:44:38.108449 | controller | Wednesday 08 October 2025  12:44:37 +0000 (0:00:00.032)       0:02:35.450 *****
2025-10-08 12:44:38.108459 | controller | changed: [instance]
2025-10-08 12:44:38.169552 | controller |
2025-10-08 12:44:38.169583 | controller | TASK [libvirt_manager : Inject all VMs in the inventory] ***********************
2025-10-08 12:44:38.169591 | controller | Wednesday 08 October 2025  12:44:38 +0000 (0:00:00.360)       0:02:35.810 *****
2025-10-08 12:44:38.169601 | controller | changed: [instance] => (item=Adding compute-0 to computes)
2025-10-08 12:44:38.191804 | controller |
2025-10-08 12:44:38.191828 | controller | TASK [networking_mapper : Check for Networking Definition file existence] ******
2025-10-08 12:44:38.191836 | controller | Wednesday 08 October 2025  12:44:38 +0000 (0:00:00.061)       0:02:35.871 *****
2025-10-08 12:44:38.191846 | controller | skipping: [instance]
2025-10-08 12:44:38.213776 | controller |
2025-10-08 12:44:38.213800 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2025-10-08 12:44:38.213808 | controller | Wednesday 08 October 2025  12:44:38 +0000 (0:00:00.022)       0:02:35.894 *****
2025-10-08 12:44:38.213817 | controller | skipping: [instance]
2025-10-08 12:44:38.236047 | controller |
2025-10-08 12:44:38.236081 | controller | TASK [networking_mapper : Check for interfaces info file existence] ************
2025-10-08 12:44:38.236090 | controller | Wednesday 08 October 2025  12:44:38 +0000 (0:00:00.022)       0:02:35.916 *****
2025-10-08 12:44:38.236100 | controller | skipping: [instance]
2025-10-08 12:44:38.236275 | controller |
2025-10-08 12:44:38.236296 | controller | TASK [networking_mapper : Load the interfaces info from file] ******************
2025-10-08 12:44:38.258456 | controller | Wednesday 08 October 2025  12:44:38 +0000 (0:00:00.022)       0:02:35.938 *****
2025-10-08 12:44:38.258483 | controller | skipping: [instance]
2025-10-08 12:44:38.275964 | controller |
2025-10-08 12:44:38.275984 | controller | TASK [networking_mapper : Ensure local fact is empty] **************************
2025-10-08 12:44:38.275991 | controller | Wednesday 08 October 2025  12:44:38 +0000 (0:00:00.022)       0:02:35.960 *****
2025-10-08 12:44:38.276000 | controller | ok: [instance]
2025-10-08 12:44:38.348063 | controller |
2025-10-08 12:44:38.348102 | controller | TASK [networking_mapper : Set the input Networking Definition and patch it if needed] ***
2025-10-08 12:44:38.348113 | controller | Wednesday 08 October 2025  12:44:38 +0000 (0:00:00.017)       0:02:35.978 *****
2025-10-08 12:44:38.348126 | 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-08 12:44:38.348164 | controller |
2025-10-08 12:44:38.348174 | controller | TASK [networking_mapper : Gather facts if requested] ***************************
2025-10-08 12:44:38.348265 | controller | Wednesday 08 October 2025  12:44:38 +0000 (0:00:00.072)       0:02:36.050 *****
2025-10-08 12:44:38.366818 | controller | skipping: [instance]
2025-10-08 12:44:38.566039 | controller |
2025-10-08 12:44:38.566071 | controller | TASK [networking_mapper : Ensure CI infrastructure dir exists] *****************
2025-10-08 12:44:38.566080 | controller | Wednesday 08 October 2025  12:44:38 +0000 (0:00:00.018)       0:02:36.069 *****
2025-10-08 12:44:38.566090 | controller | changed: [instance]
2025-10-08 12:44:38.986361 | controller |
2025-10-08 12:44:38.986395 | controller | TASK [networking_mapper : Write the Networking Definition to file] *************
2025-10-08 12:44:38.986403 | controller | Wednesday 08 October 2025  12:44:38 +0000 (0:00:00.198)       0:02:36.268 *****
2025-10-08 12:44:38.986413 | controller | changed: [instance]
2025-10-08 12:44:39.035460 | controller |
2025-10-08 12:44:39.035502 | controller | TASK [networking_mapper : Call the networking mapper] **************************
2025-10-08 12:44:39.035511 | controller | Wednesday 08 October 2025  12:44:38 +0000 (0:00:00.420)       0:02:36.688 *****
2025-10-08 12:44:39.035521 | controller | ok: [instance]
2025-10-08 12:44:39.061022 | controller |
2025-10-08 12:44:39.061052 | controller | TASK [networking_mapper : Set networking mapper facts] *************************
2025-10-08 12:44:39.061060 | controller | Wednesday 08 October 2025  12:44:39 +0000 (0:00:00.049)       0:02:36.737 *****
2025-10-08 12:44:39.061070 | controller | ok: [instance]
2025-10-08 12:44:39.061092 | controller |
2025-10-08 12:44:39.061099 | controller | TASK [networking_mapper : Write the Networking Environment Definition to file] ***
2025-10-08 12:44:39.061106 | controller | Wednesday 08 October 2025  12:44:39 +0000 (0:00:00.025)       0:02:36.763 *****
2025-10-08 12:44:39.451554 | controller | changed: [instance]
2025-10-08 12:44:39.520439 | controller |
2025-10-08 12:44:39.520473 | controller | TASK [libvirt_manager : Manage networks if needed] *****************************
2025-10-08 12:44:39.520481 | controller | Wednesday 08 October 2025  12:44:39 +0000 (0:00:00.390)       0:02:37.153 *****
2025-10-08 12:44:39.520491 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/create_networks.yml for instance
2025-10-08 12:44:39.560420 | controller |
2025-10-08 12:44:39.560448 | controller | TASK [libvirt_manager : Define the localized variables for performing the tasks here.] ***
2025-10-08 12:44:39.560456 | controller | Wednesday 08 October 2025  12:44:39 +0000 (0:00:00.068)       0:02:37.222 *****
2025-10-08 12:44:39.560466 | controller | ok: [instance] => (item=public)
2025-10-08 12:44:40.312572 | controller |
2025-10-08 12:44:40.312604 | controller | TASK [libvirt_manager : Ensure networks are defined] ***************************
2025-10-08 12:44:40.312613 | controller | Wednesday 08 October 2025  12:44:39 +0000 (0:00:00.040)       0:02:37.262 *****
2025-10-08 12:44:40.312623 | controller | changed: [instance] => (item=cifmw-public)
2025-10-08 12:44:40.643607 | controller |
2025-10-08 12:44:40.643639 | controller | TASK [libvirt_manager : Ensure networks are created/started] *******************
2025-10-08 12:44:40.643647 | controller | Wednesday 08 October 2025  12:44:40 +0000 (0:00:00.751)       0:02:38.014 *****
2025-10-08 12:44:40.643657 | controller | ok: [instance] => (item=cifmw-public)
2025-10-08 12:44:40.872342 | controller |
2025-10-08 12:44:40.872372 | controller | TASK [libvirt_manager : Ensure networks are active] ****************************
2025-10-08 12:44:40.872380 | controller | Wednesday 08 October 2025  12:44:40 +0000 (0:00:00.331)       0:02:38.345 *****
2025-10-08 12:44:40.872394 | controller | ok: [instance] => (item=cifmw-public)
2025-10-08 12:44:41.109365 | controller |
2025-10-08 12:44:41.109396 | controller | TASK [libvirt_manager : Ensure networks enabled to autostart] ******************
2025-10-08 12:44:41.109404 | controller | Wednesday 08 October 2025  12:44:40 +0000 (0:00:00.228)       0:02:38.574 *****
2025-10-08 12:44:41.109414 | controller | changed: [instance] => (item=cifmw-public)
2025-10-08 12:44:41.160553 | controller |
2025-10-08 12:44:41.160576 | controller | TASK [libvirt_manager : Add a dummy interface to bridges if required] **********
2025-10-08 12:44:41.160583 | controller | Wednesday 08 October 2025  12:44:41 +0000 (0:00:00.237)       0:02:38.811 *****
2025-10-08 12:44:41.160593 | 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-08 12:44:41.335696 | controller |
2025-10-08 12:44:41.335726 | controller | TASK [libvirt_manager : Fetch present bridge interfaces] ***********************
2025-10-08 12:44:41.335734 | controller | Wednesday 08 October 2025  12:44:41 +0000 (0:00:00.051)       0:02:38.862 *****
2025-10-08 12:44:41.335744 | controller | ok: [instance]
2025-10-08 12:44:41.540804 | controller |
2025-10-08 12:44:41.540833 | controller | TASK [libvirt_manager : Fetch bridges ports link info] *************************
2025-10-08 12:44:41.540842 | controller | Wednesday 08 October 2025  12:44:41 +0000 (0:00:00.174)       0:02:39.037 *****
2025-10-08 12:44:41.540851 | controller | ok: [instance] => (item=cifmw-public)
2025-10-08 12:44:41.603597 | controller |
2025-10-08 12:44:41.603628 | controller | TASK [Create dummy interfaces to ensure bridges are UP] ************************
2025-10-08 12:44:41.603636 | controller | Wednesday 08 October 2025  12:44:41 +0000 (0:00:00.205)       0:02:39.242 *****
2025-10-08 12:44:41.603646 | controller |
2025-10-08 12:44:41.639033 | controller | TASK [ci_nmstate : Ensure we have needed facts] ********************************
2025-10-08 12:44:41.639061 | controller | Wednesday 08 October 2025  12:44:41 +0000 (0:00:00.062)       0:02:39.305 *****
2025-10-08 12:44:41.639072 | controller | skipping: [instance]
2025-10-08 12:44:41.639096 | controller |
2025-10-08 12:44:41.639305 | controller | TASK [ci_nmstate : Install required packages on instance] **********************
2025-10-08 12:44:49.392410 | controller | Wednesday 08 October 2025  12:44:41 +0000 (0:00:00.035)       0:02:39.341 *****
2025-10-08 12:44:49.392446 | controller | changed: [instance]
2025-10-08 12:44:49.593049 | controller |
2025-10-08 12:44:49.593079 | controller | TASK [ci_nmstate : Create the target NMstate dump directory] *******************
2025-10-08 12:44:49.593087 | controller | Wednesday 08 October 2025  12:44:49 +0000 (0:00:07.752)       0:02:47.094 *****
2025-10-08 12:44:49.593097 | controller | changed: [instance]
2025-10-08 12:44:49.593121 | controller |
2025-10-08 12:44:49.593128 | controller | TASK [ci_nmstate : Save nmstate state for instance] ****************************
2025-10-08 12:44:49.593135 | controller | Wednesday 08 October 2025  12:44:49 +0000 (0:00:00.200)       0:02:47.295 *****
2025-10-08 12:44:49.962034 | controller | changed: [instance]
2025-10-08 12:44:49.962353 | controller |
2025-10-08 12:44:51.653043 | controller | TASK [ci_nmstate : Apply the desidered state on instance] **********************
2025-10-08 12:44:51.653074 | controller | Wednesday 08 October 2025  12:44:49 +0000 (0:00:00.369)       0:02:47.664 *****
2025-10-08 12:44:51.653086 | controller | changed: [instance]
2025-10-08 12:44:51.653111 | controller |
2025-10-08 12:44:51.653273 | controller | TASK [ci_nmstate : Save nmstate debugging data for instance] *******************
2025-10-08 12:44:52.008841 | controller | Wednesday 08 October 2025  12:44:51 +0000 (0:00:01.690)       0:02:49.355 *****
2025-10-08 12:44:52.008875 | controller | changed: [instance]
2025-10-08 12:44:52.040069 | controller |
2025-10-08 12:44:52.040105 | controller | TASK [Create extra network configuration] **************************************
2025-10-08 12:44:52.040114 | controller | Wednesday 08 October 2025  12:44:52 +0000 (0:00:00.355)       0:02:49.710 *****
2025-10-08 12:44:52.040125 | controller | skipping: [instance]
2025-10-08 12:44:52.068441 | controller |
2025-10-08 12:44:52.068478 | controller | TASK [libvirt_manager : Ensure extra networks is in correct zone] **************
2025-10-08 12:44:52.068489 | controller | Wednesday 08 October 2025  12:44:52 +0000 (0:00:00.031)       0:02:49.742 *****
2025-10-08 12:44:52.068501 | controller | skipping: [instance]
2025-10-08 12:44:52.480527 | controller |
2025-10-08 12:44:52.480569 | controller | TASK [libvirt_manager : Refresh networking facts on host] **********************
2025-10-08 12:44:52.480579 | controller | Wednesday 08 October 2025  12:44:52 +0000 (0:00:00.028)       0:02:49.770 *****
2025-10-08 12:44:52.480591 | controller | ok: [instance]
2025-10-08 12:44:52.596975 | controller |
2025-10-08 12:44:52.597006 | controller | TASK [libvirt_manager : Build needed network/dnsmasq related content] **********
2025-10-08 12:44:52.597014 | controller | Wednesday 08 October 2025  12:44:52 +0000 (0:00:00.411)       0:02:50.182 *****
2025-10-08 12:44:52.597024 | controller | ok: [instance] => (item=cifmw-public)
2025-10-08 12:44:53.810621 | controller |
2025-10-08 12:44:53.810653 | controller | TASK [dnsmasq : Install needed packages] ***************************************
2025-10-08 12:44:53.810662 | controller | Wednesday 08 October 2025  12:44:52 +0000 (0:00:00.116)       0:02:50.299 *****
2025-10-08 12:44:53.810672 | controller | ok: [instance]
2025-10-08 12:44:57.406619 | controller |
2025-10-08 12:44:57.406654 | controller | TASK [dnsmasq : Ensure SELinux knows about the new files and directories] ******
2025-10-08 12:44:57.406662 | controller | Wednesday 08 October 2025  12:44:53 +0000 (0:00:01.213)       0:02:51.512 *****
2025-10-08 12:44:57.406672 | controller | changed: [instance] => (item={'target': '/etc/cifmw-dnsmasq.conf', 'setype': 'dnsmasq_etc_t'})
2025-10-08 12:44:57.635521 | controller | changed: [instance] => (item={'target': '/etc/cifmw-dnsmasq.d(/.*)?', 'setype': 'dnsmasq_etc_t'})
2025-10-08 12:44:57.635553 | controller | changed: [instance] => (item={'target': '/var/run/cifmw-dnsmasq.pid', 'setype': 'dnsmasq_var_run_t'})
2025-10-08 12:44:57.635561 | controller |
2025-10-08 12:44:57.635567 | controller | TASK [dnsmasq : Manage configuration directory] ********************************
2025-10-08 12:44:57.635573 | controller | Wednesday 08 October 2025  12:44:57 +0000 (0:00:03.595)       0:02:55.108 *****
2025-10-08 12:44:57.635582 | controller | changed: [instance]
2025-10-08 12:44:58.022414 | controller |
2025-10-08 12:44:58.022447 | controller | TASK [dnsmasq : Manage systemd unit file] **************************************
2025-10-08 12:44:58.022456 | controller | Wednesday 08 October 2025  12:44:57 +0000 (0:00:00.229)       0:02:55.337 *****
2025-10-08 12:44:58.022466 | controller | changed: [instance]
2025-10-08 12:44:58.428078 | controller |
2025-10-08 12:44:58.428111 | controller | TASK [dnsmasq : Manage base configuration file] ********************************
2025-10-08 12:44:58.428119 | controller | Wednesday 08 October 2025  12:44:58 +0000 (0:00:00.386)       0:02:55.724 *****
2025-10-08 12:44:58.428129 | controller | changed: [instance]
2025-10-08 12:44:58.428154 | controller |
2025-10-08 12:44:58.428387 | controller | TASK [dnsmasq : Render listener configuration] *********************************
2025-10-08 12:44:58.457072 | controller | Wednesday 08 October 2025  12:44:58 +0000 (0:00:00.405)       0:02:56.130 *****
2025-10-08 12:44:58.457117 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/listener.yml for instance
2025-10-08 12:44:58.457151 | controller |
2025-10-08 12:44:58.457380 | controller | TASK [dnsmasq : Create listener configuration file] ****************************
2025-10-08 12:44:58.867067 | controller | Wednesday 08 October 2025  12:44:58 +0000 (0:00:00.028)       0:02:56.159 *****
2025-10-08 12:44:58.867104 | controller | changed: [instance]
2025-10-08 12:44:58.867296 | controller |
2025-10-08 12:44:58.867332 | controller | TASK [dnsmasq : Remove listener configuration file] ****************************
2025-10-08 12:44:58.887407 | controller | Wednesday 08 October 2025  12:44:58 +0000 (0:00:00.410)       0:02:56.569 *****
2025-10-08 12:44:58.887447 | controller | skipping: [instance]
2025-10-08 12:44:58.917880 | controller |
2025-10-08 12:44:58.917908 | controller | TASK [dnsmasq : Render dns configuration] **************************************
2025-10-08 12:44:58.917916 | controller | Wednesday 08 October 2025  12:44:58 +0000 (0:00:00.020)       0:02:56.589 *****
2025-10-08 12:44:58.917927 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/dns.yml for instance
2025-10-08 12:44:59.303612 | controller |
2025-10-08 12:44:59.303645 | controller | TASK [dnsmasq : Create dns configuration file] *********************************
2025-10-08 12:44:59.303653 | controller | Wednesday 08 October 2025  12:44:58 +0000 (0:00:00.030)       0:02:56.620 *****
2025-10-08 12:44:59.303663 | controller | changed: [instance]
2025-10-08 12:44:59.322906 | controller |
2025-10-08 12:44:59.322966 | controller | TASK [dnsmasq : Remove dns configuration file] *********************************
2025-10-08 12:44:59.322983 | controller | Wednesday 08 October 2025  12:44:59 +0000 (0:00:00.385)       0:02:57.005 *****
2025-10-08 12:44:59.322994 | controller | skipping: [instance]
2025-10-08 12:44:59.547909 | controller |
2025-10-08 12:44:59.547971 | controller | TASK [dnsmasq : Add localhost addresses from defined dnsmasq listen addresses to loopback interface] ***
2025-10-08 12:44:59.547984 | controller | Wednesday 08 October 2025  12:44:59 +0000 (0:00:00.019)       0:02:57.025 *****
2025-10-08 12:44:59.547994 | controller | ok: [instance] => (item=127.0.0.2)
2025-10-08 12:45:00.280032 | controller |
2025-10-08 12:45:00.280067 | controller | TASK [dnsmasq : Enable and start service] **************************************
2025-10-08 12:45:00.280075 | controller | Wednesday 08 October 2025  12:44:59 +0000 (0:00:00.224)       0:02:57.249 *****
2025-10-08 12:45:00.280085 | controller | changed: [instance]
2025-10-08 12:45:00.298692 | controller |
2025-10-08 12:45:00.298721 | controller | TASK [dnsmasq : Stop service] **************************************************
2025-10-08 12:45:00.298729 | controller | Wednesday 08 October 2025  12:45:00 +0000 (0:00:00.731)       0:02:57.981 *****
2025-10-08 12:45:00.298739 | controller | skipping: [instance]
2025-10-08 12:45:00.317740 | controller |
2025-10-08 12:45:00.317773 | controller | TASK [dnsmasq : Remove unit file] **********************************************
2025-10-08 12:45:00.317780 | controller | Wednesday 08 October 2025  12:45:00 +0000 (0:00:00.018)       0:02:58.000 *****
2025-10-08 12:45:00.317790 | controller | skipping: [instance]
2025-10-08 12:45:00.346685 | controller |
2025-10-08 12:45:00.346721 | controller | TASK [dnsmasq : Remove main configuration files] *******************************
2025-10-08 12:45:00.346731 | controller | Wednesday 08 October 2025  12:45:00 +0000 (0:00:00.018)       0:02:58.019 *****
2025-10-08 12:45:00.346743 | controller | skipping: [instance] => (item=/etc/cifmw-dnsmasq.conf)
2025-10-08 12:45:00.415498 | controller | skipping: [instance] => (item=/etc/cifmw-dnsmasq.d)
2025-10-08 12:45:00.415533 | controller | skipping: [instance]
2025-10-08 12:45:00.415544 | controller |
2025-10-08 12:45:00.415551 | controller | TASK [Create dnsmasq networks] *************************************************
2025-10-08 12:45:00.415559 | controller | Wednesday 08 October 2025  12:45:00 +0000 (0:00:00.028)       0:02:58.048 *****
2025-10-08 12:45:00.415570 | controller |
2025-10-08 12:45:00.442039 | controller | TASK [dnsmasq : Assert mandatory parameter] ************************************
2025-10-08 12:45:00.442069 | controller | Wednesday 08 October 2025  12:45:00 +0000 (0:00:00.069)       0:02:58.117 *****
2025-10-08 12:45:00.442081 | controller | ok: [instance] => changed=false
2025-10-08 12:45:00.442339 | controller |   msg: All assertions passed
2025-10-08 12:45:00.442359 | controller |
2025-10-08 12:45:00.477491 | controller | TASK [dnsmasq : Assert mandatory parameters for new network] *******************
2025-10-08 12:45:00.477520 | controller | Wednesday 08 October 2025  12:45:00 +0000 (0:00:00.026)       0:02:58.144 *****
2025-10-08 12:45:00.477532 | controller | ok: [instance] => changed=false
2025-10-08 12:45:00.911114 | controller |   msg: All assertions passed
2025-10-08 12:45:00.911147 | controller |
2025-10-08 12:45:00.911155 | controller | TASK [dnsmasq : Create network] ************************************************
2025-10-08 12:45:00.911161 | controller | Wednesday 08 October 2025  12:45:00 +0000 (0:00:00.035)       0:02:58.179 *****
2025-10-08 12:45:00.911171 | controller | changed: [instance]
2025-10-08 12:45:00.928040 | controller |
2025-10-08 12:45:00.928074 | controller | TASK [dnsmasq : Remove network] ************************************************
2025-10-08 12:45:00.928082 | controller | Wednesday 08 October 2025  12:45:00 +0000 (0:00:00.433)       0:02:58.613 *****
2025-10-08 12:45:00.928093 | controller | skipping: [instance]
2025-10-08 12:45:00.949763 | controller |
2025-10-08 12:45:00.949796 | controller | TASK [dnsmasq : Remove dhcp host files] ****************************************
2025-10-08 12:45:00.949806 | controller | Wednesday 08 October 2025  12:45:00 +0000 (0:00:00.017)       0:02:58.630 *****
2025-10-08 12:45:00.949820 | controller | skipping: [instance]
2025-10-08 12:45:01.260041 | controller |
2025-10-08 12:45:01.260072 | controller | TASK [libvirt_manager : Ensure network is in correct zone] *********************
2025-10-08 12:45:01.260081 | controller | Wednesday 08 October 2025  12:45:00 +0000 (0:00:00.021)       0:02:58.652 *****
2025-10-08 12:45:01.260098 | controller | changed: [instance] => (item=cifmw-public)
2025-10-08 12:45:01.287494 | controller |
2025-10-08 12:45:01.287524 | controller | TASK [libvirt_manager : Extract IP address from network bridges] ***************
2025-10-08 12:45:01.287532 | controller | Wednesday 08 October 2025  12:45:01 +0000 (0:00:00.309)       0:02:58.961 *****
2025-10-08 12:45:01.287543 | 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-08 12:45:01.602085 | controller |
2025-10-08 12:45:01.602116 | controller | TASK [libvirt_manager : Extract IP address from network bridges] ***************
2025-10-08 12:45:01.602125 | controller | Wednesday 08 October 2025  12:45:01 +0000 (0:00:00.027)       0:02:58.989 *****
2025-10-08 12:45:01.602135 | controller | ok: [instance]
2025-10-08 12:45:01.633022 | controller |
2025-10-08 12:45:01.633055 | controller | TASK [libvirt_manager : Set network_bridge_info fact with network and address] ***
2025-10-08 12:45:01.633063 | controller | Wednesday 08 October 2025  12:45:01 +0000 (0:00:00.314)       0:02:59.304 *****
2025-10-08 12:45:01.633073 | controller | ok: [instance]
2025-10-08 12:45:01.633101 | controller |
2025-10-08 12:45:01.633109 | controller | TASK [libvirt_manager : Output _network_data] **********************************
2025-10-08 12:45:01.633264 | controller | Wednesday 08 October 2025  12:45:01 +0000 (0:00:00.031)       0:02:59.335 *****
2025-10-08 12:45:01.984471 | controller | changed: [instance]
2025-10-08 12:45:02.337846 | controller |
2025-10-08 12:45:02.337876 | controller | TASK [libvirt_manager : Output pub_net] ****************************************
2025-10-08 12:45:02.337884 | controller | Wednesday 08 October 2025  12:45:01 +0000 (0:00:00.351)       0:02:59.686 *****
2025-10-08 12:45:02.337894 | controller | changed: [instance]
2025-10-08 12:45:02.685807 | controller |
2025-10-08 12:45:02.685839 | controller | TASK [libvirt_manager : Output _cifmw_libvirt_manager_layout] ******************
2025-10-08 12:45:02.685847 | controller | Wednesday 08 October 2025  12:45:02 +0000 (0:00:00.353)       0:03:00.039 *****
2025-10-08 12:45:02.685857 | controller | changed: [instance]
2025-10-08 12:45:02.803470 | controller |
2025-10-08 12:45:02.803500 | controller | TASK [libvirt_manager : Expose patch for networking_mapper] ********************
2025-10-08 12:45:02.803508 | controller | Wednesday 08 October 2025  12:45:02 +0000 (0:00:00.347)       0:03:00.387 *****
2025-10-08 12:45:02.803518 | controller | ok: [instance]
2025-10-08 12:45:03.162043 | controller |
2025-10-08 12:45:03.162080 | controller | TASK [libvirt_manager : Save networking_mapper patch] **************************
2025-10-08 12:45:03.162089 | controller | Wednesday 08 October 2025  12:45:02 +0000 (0:00:00.117)       0:03:00.505 *****
2025-10-08 12:45:03.162100 | controller | changed: [instance]
2025-10-08 12:45:03.186442 | controller |
2025-10-08 12:45:03.186466 | controller | TASK [networking_mapper : Check for Networking Definition file existence] ******
2025-10-08 12:45:03.186474 | controller | Wednesday 08 October 2025  12:45:03 +0000 (0:00:00.358)       0:03:00.864 *****
2025-10-08 12:45:03.186483 | controller | skipping: [instance]
2025-10-08 12:45:03.212706 | controller |
2025-10-08 12:45:03.212728 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************
2025-10-08 12:45:03.212735 | controller | Wednesday 08 October 2025  12:45:03 +0000 (0:00:00.024)       0:03:00.888 *****
2025-10-08 12:45:03.212744 | controller | skipping: [instance]
2025-10-08 12:45:03.239581 | controller |
2025-10-08 12:45:03.239602 | controller | TASK [networking_mapper : Check for interfaces info file existence] ************
2025-10-08 12:45:03.239610 | controller | Wednesday 08 October 2025  12:45:03 +0000 (0:00:00.026)       0:03:00.914 *****
2025-10-08 12:45:03.239619 | controller | skipping: [instance]
2025-10-08 12:45:03.264344 | controller |
2025-10-08 12:45:03.264373 | controller | TASK [networking_mapper : Load the interfaces info from file] ******************
2025-10-08 12:45:03.264381 | controller | Wednesday 08 October 2025  12:45:03 +0000 (0:00:00.026)       0:03:00.941 *****
2025-10-08 12:45:03.264390 | controller | skipping: [instance]
2025-10-08 12:45:03.283519 | controller |
2025-10-08 12:45:03.283540 | controller | TASK [networking_mapper : Ensure local fact is empty] **************************
2025-10-08 12:45:03.283548 | controller | Wednesday 08 October 2025  12:45:03 +0000 (0:00:00.024)       0:03:00.966 *****
2025-10-08 12:45:03.283557 | controller | ok: [instance]
2025-10-08 12:45:03.367087 | controller |
2025-10-08 12:45:03.367126 | controller | TASK [networking_mapper : Set the input Networking Definition and patch it if needed] ***
2025-10-08 12:45:03.367136 | controller | Wednesday 08 October 2025  12:45:03 +0000 (0:00:00.019)       0:03:00.985 *****
2025-10-08 12:45:03.367150 | 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-08 12:45:03.367186 | controller | ok: [instance] => (item={'networks': {'public': {'network-v4': '192.168.110.0/24'}}, 'group-templates': {'computes': {'networks': {'public': None}}}})
2025-10-08 12:45:03.367447 | controller |
2025-10-08 12:45:03.367482 | controller | TASK [networking_mapper : Gather facts if requested] ***************************
2025-10-08 12:45:03.385448 | controller | Wednesday 08 October 2025  12:45:03 +0000 (0:00:00.083)       0:03:01.069 *****
2025-10-08 12:45:03.385477 | controller | skipping: [instance]
2025-10-08 12:45:03.592654 | controller |
2025-10-08 12:45:03.592685 | controller | TASK [networking_mapper : Ensure CI infrastructure dir exists] *****************
2025-10-08 12:45:03.592693 | controller | Wednesday 08 October 2025  12:45:03 +0000 (0:00:00.018)       0:03:01.087 *****
2025-10-08 12:45:03.592703 | controller | ok: [instance]
2025-10-08 12:45:04.017027 | controller |
2025-10-08 12:45:04.017059 | controller | TASK [networking_mapper : Write the Networking Definition to file] *************
2025-10-08 12:45:04.017067 | controller | Wednesday 08 October 2025  12:45:03 +0000 (0:00:00.206)       0:03:01.294 *****
2025-10-08 12:45:04.017077 | controller | changed: [instance]
2025-10-08 12:45:04.017254 | controller |
2025-10-08 12:45:04.017268 | controller | TASK [networking_mapper : Call the networking mapper] **************************
2025-10-08 12:45:04.067501 | controller | Wednesday 08 October 2025  12:45:04 +0000 (0:00:00.424)       0:03:01.719 *****
2025-10-08 12:45:04.067538 | controller | ok: [instance]
2025-10-08 12:45:04.095594 | controller |
2025-10-08 12:45:04.095626 | controller | TASK [networking_mapper : Set networking mapper facts] *************************
2025-10-08 12:45:04.095634 | controller | Wednesday 08 October 2025  12:45:04 +0000 (0:00:00.050)       0:03:01.769 *****
2025-10-08 12:45:04.095651 | controller | ok: [instance]
2025-10-08 12:45:04.528057 | controller |
2025-10-08 12:45:04.528088 | controller | TASK [networking_mapper : Write the Networking Environment Definition to file] ***
2025-10-08 12:45:04.528096 | controller | Wednesday 08 October 2025  12:45:04 +0000 (0:00:00.028)       0:03:01.797 *****
2025-10-08 12:45:04.528107 | controller | changed: [instance]
2025-10-08 12:45:04.528171 | controller |
2025-10-08 12:45:04.528205 | controller | TASK [libvirt_manager : Be sure to save current state of networking_mapper environment] ***
2025-10-08 12:45:04.528223 | controller | Wednesday 08 October 2025  12:45:04 +0000 (0:00:00.432)       0:03:02.230 *****
2025-10-08 12:45:04.551070 | controller | ok: [instance]
2025-10-08 12:45:04.551120 | controller |
2025-10-08 12:45:04.551130 | controller | TASK [libvirt_manager : Unset patch] *******************************************
2025-10-08 12:45:04.551212 | controller | Wednesday 08 October 2025  12:45:04 +0000 (0:00:00.023)       0:03:02.253 *****
2025-10-08 12:45:04.567727 | controller | ok: [instance]
2025-10-08 12:45:04.585029 | controller |
2025-10-08 12:45:04.585067 | controller | TASK [libvirt_manager : Initialize empty _lm_dhcp_entries fact] ****************
2025-10-08 12:45:04.585078 | controller | Wednesday 08 October 2025  12:45:04 +0000 (0:00:00.016)       0:03:02.270 *****
2025-10-08 12:45:04.585090 | controller | ok: [instance]
2025-10-08 12:45:04.585299 | controller |
2025-10-08 12:45:04.637883 | controller | TASK [libvirt_manager : Reserve IPs on networks] *******************************
2025-10-08 12:45:04.637915 | controller | Wednesday 08 October 2025  12:45:04 +0000 (0:00:00.017)       0:03:02.287 *****
2025-10-08 12:45:04.637926 | 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-08 12:45:04.693526 | 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-08 12:45:04.693558 | 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-08 12:45:04.693566 | 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-08 12:45:04.693572 | 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-08 12:45:04.693577 | controller |
2025-10-08 12:45:04.693583 | controller | TASK [libvirt_manager : Loop on host IPs] **************************************
2025-10-08 12:45:04.693589 | controller | Wednesday 08 October 2025  12:45:04 +0000 (0:00:00.052)       0:03:02.339 *****
2025-10-08 12:45:04.693599 | controller | skipping: [instance] => (item=compute-0 - ctlplane)
2025-10-08 12:45:04.746367 | controller | skipping: [instance]
2025-10-08 12:45:04.746397 | controller |
2025-10-08 12:45:04.746405 | controller | TASK [libvirt_manager : Loop on host IPs] **************************************
2025-10-08 12:45:04.746411 | controller | Wednesday 08 October 2025  12:45:04 +0000 (0:00:00.055)       0:03:02.395 *****
2025-10-08 12:45:04.746421 | controller | skipping: [instance] => (item=compute-0 - internalapi)
2025-10-08 12:45:04.798062 | controller | skipping: [instance]
2025-10-08 12:45:04.798097 | controller |
2025-10-08 12:45:04.798107 | controller | TASK [libvirt_manager : Loop on host IPs] **************************************
2025-10-08 12:45:04.798115 | controller | Wednesday 08 October 2025  12:45:04 +0000 (0:00:00.052)       0:03:02.448 *****
2025-10-08 12:45:04.798127 | controller | skipping: [instance] => (item=compute-0 - storage)
2025-10-08 12:45:04.798155 | controller | skipping: [instance]
2025-10-08 12:45:04.798162 | controller |
2025-10-08 12:45:04.798171 | controller | TASK [libvirt_manager : Loop on host IPs] **************************************
2025-10-08 12:45:04.798301 | controller | Wednesday 08 October 2025  12:45:04 +0000 (0:00:00.051)       0:03:02.500 *****
2025-10-08 12:45:04.852684 | controller | skipping: [instance] => (item=compute-0 - tenant)
2025-10-08 12:45:04.925808 | controller | skipping: [instance]
2025-10-08 12:45:04.925838 | controller |
2025-10-08 12:45:04.925846 | controller | TASK [libvirt_manager : Loop on host IPs] **************************************
2025-10-08 12:45:04.925853 | controller | Wednesday 08 October 2025  12:45:04 +0000 (0:00:00.054)       0:03:02.554 *****
2025-10-08 12:45:04.925863 | controller | ok: [instance] => (item=compute-0 - public)
2025-10-08 12:45:05.002452 | controller |
2025-10-08 12:45:05.002489 | controller | TASK [Inject DHCP entries for net {{ net_name }}] ******************************
2025-10-08 12:45:05.002499 | controller | Wednesday 08 October 2025  12:45:04 +0000 (0:00:00.073)       0:03:02.627 *****
2025-10-08 12:45:05.002512 | controller |
2025-10-08 12:45:05.040562 | controller | TASK [dnsmasq : Ensure we have the right data and type] ************************
2025-10-08 12:45:05.040595 | controller | Wednesday 08 October 2025  12:45:04 +0000 (0:00:00.076)       0:03:02.704 *****
2025-10-08 12:45:05.040608 | controller | ok: [instance]
2025-10-08 12:45:05.085078 | controller |
2025-10-08 12:45:05.085115 | controller | TASK [dnsmasq : Assert we have needed host data] *******************************
2025-10-08 12:45:05.085124 | controller | Wednesday 08 October 2025  12:45:05 +0000 (0:00:00.038)       0:03:02.742 *****
2025-10-08 12:45:05.085136 | controller | ok: [instance] => (item={'network': 'public', 'name': 'compute-0', 'state': 'present', 'mac': '52:54:00:14:ad:4d', 'ips': ['192.168.110.10', '']})
2025-10-08 12:45:05.085164 | controller |
2025-10-08 12:45:05.085174 | controller | TASK [dnsmasq : Ensure networks exists] ****************************************
2025-10-08 12:45:05.085243 | controller | Wednesday 08 October 2025  12:45:05 +0000 (0:00:00.044)       0:03:02.787 *****
2025-10-08 12:45:05.129877 | 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-08 12:45:05.312585 | controller |
2025-10-08 12:45:05.312615 | controller | TASK [dnsmasq : Check network file status] *************************************
2025-10-08 12:45:05.312623 | controller | Wednesday 08 October 2025  12:45:05 +0000 (0:00:00.044)       0:03:02.831 *****
2025-10-08 12:45:05.312633 | controller | ok: [instance]
2025-10-08 12:45:05.335074 | controller |
2025-10-08 12:45:05.335106 | controller | TASK [dnsmasq : Assert network exists] *****************************************
2025-10-08 12:45:05.335120 | controller | Wednesday 08 October 2025  12:45:05 +0000 (0:00:00.182)       0:03:03.014 *****
2025-10-08 12:45:05.335131 | controller | ok: [instance]
2025-10-08 12:45:05.335155 | controller |
2025-10-08 12:45:05.335162 | controller | TASK [dnsmasq : Initialize empty dhcp_host_entries] ****************************
2025-10-08 12:45:05.335169 | controller | Wednesday 08 October 2025  12:45:05 +0000 (0:00:00.022)       0:03:03.037 *****
2025-10-08 12:45:05.353759 | controller | ok: [instance]
2025-10-08 12:45:05.433072 | controller |
2025-10-08 12:45:05.433106 | controller | TASK [dnsmasq : Compute entry] *************************************************
2025-10-08 12:45:05.433116 | controller | Wednesday 08 October 2025  12:45:05 +0000 (0:00:00.018)       0:03:03.055 *****
2025-10-08 12:45:05.433128 | controller | ok: [instance] => (item={'network': 'public', 'name': 'compute-0', 'state': 'present', 'mac': '52:54:00:14:ad:4d', 'ips': ['192.168.110.10', '']})
2025-10-08 12:45:05.433367 | controller |
2025-10-08 12:45:05.433409 | controller | TASK [dnsmasq : Create add/remove sets] ****************************************
2025-10-08 12:45:05.469540 | controller | Wednesday 08 October 2025  12:45:05 +0000 (0:00:00.079)       0:03:03.135 *****
2025-10-08 12:45:05.469575 | controller | ok: [instance]
2025-10-08 12:45:05.854387 | controller |
2025-10-08 12:45:05.854422 | controller | TASK [dnsmasq : Add DHCP entries] **********************************************
2025-10-08 12:45:05.854430 | controller | Wednesday 08 October 2025  12:45:05 +0000 (0:00:00.036)       0:03:03.171 *****
2025-10-08 12:45:05.854463 | controller | changed: [instance] => (item={'file': 'public_compute-0_52:54:00:14:ad:4d', 'entry': '52:54:00:14:ad:4d,192.168.110.10,compute-0', 'state': 'present'})
2025-10-08 12:45:05.875490 | controller |
2025-10-08 12:45:05.875515 | controller | TASK [dnsmasq : Remove DHCP entries] *******************************************
2025-10-08 12:45:05.875522 | controller | Wednesday 08 October 2025  12:45:05 +0000 (0:00:00.384)       0:03:03.556 *****
2025-10-08 12:45:05.875532 | controller | skipping: [instance]
2025-10-08 12:45:05.974870 | controller |
2025-10-08 12:45:05.974904 | controller | TASK [libvirt_manager : Create per-network and .utility DNS entries] ***********
2025-10-08 12:45:05.974913 | controller | Wednesday 08 October 2025  12:45:05 +0000 (0:00:00.021)       0:03:03.577 *****
2025-10-08 12:45:05.974922 | controller | ok: [instance] => (item=compute-0)
2025-10-08 12:45:06.056162 | controller |
2025-10-08 12:45:06.056205 | controller | TASK [Inject VMs in the .utility zone] *****************************************
2025-10-08 12:45:06.056213 | controller | Wednesday 08 October 2025  12:45:05 +0000 (0:00:00.099)       0:03:03.676 *****
2025-10-08 12:45:06.056224 | controller |
2025-10-08 12:45:06.056432 | controller | TASK [dnsmasq : Assert we have needed host record data] ************************
2025-10-08 12:45:06.056581 | controller | Wednesday 08 October 2025  12:45:06 +0000 (0:00:00.080)       0:03:03.757 *****
2025-10-08 12:45:06.097410 | controller | ok: [instance]
2025-10-08 12:45:06.097609 | controller |
2025-10-08 12:45:06.097766 | controller | TASK [dnsmasq : Assert each address element have needed data] ******************
2025-10-08 12:45:06.097903 | controller | Wednesday 08 October 2025  12:45:06 +0000 (0:00:00.042)       0:03:03.799 *****
2025-10-08 12:45:06.195611 | 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-08 12:45:06.195803 | controller | ok: [instance] => (item={'names': ['compute-0.ctlplane.local', 'compute-0.ctlplane.local'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
2025-10-08 12:45:06.195998 | controller | ok: [instance] => (item={'names': ['compute-0.internalapi.local', 'compute-0.internalapi.local'], 'ips': ['172.17.0.10', ''], 'state': 'present'})
2025-10-08 12:45:06.196168 | controller | ok: [instance] => (item={'names': ['compute-0.public.local', 'compute-0.public.local'], 'ips': ['192.168.110.10', ''], 'state': 'present'})
2025-10-08 12:45:06.196318 | controller | ok: [instance] => (item={'names': ['compute-0.storage.local', 'compute-0.storage.local'], 'ips': ['172.18.0.10', ''], 'state': 'present'})
2025-10-08 12:45:06.196464 | controller | ok: [instance] => (item={'names': ['compute-0.tenant.local', 'compute-0.tenant.local'], 'ips': ['172.19.0.10', ''], 'state': 'present'})
2025-10-08 12:45:06.196592 | controller |
2025-10-08 12:45:06.196728 | controller | TASK [dnsmasq : Add/Remove address] ********************************************
2025-10-08 12:45:06.196877 | controller | Wednesday 08 October 2025  12:45:06 +0000 (0:00:00.098)       0:03:03.897 *****
2025-10-08 12:45:07.587127 | 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-08 12:45:07.587211 | controller | changed: [instance] => (item={'names': ['compute-0.ctlplane.local', 'compute-0.ctlplane.local'], 'ips': ['192.168.122.10', ''], 'state': 'present'})
2025-10-08 12:45:07.587244 | controller | changed: [instance] => (item={'names': ['compute-0.internalapi.local', 'compute-0.internalapi.local'], 'ips': ['172.17.0.10', ''], 'state': 'present'})
2025-10-08 12:45:07.587252 | controller | changed: [instance] => (item={'names': ['compute-0.public.local', 'compute-0.public.local'], 'ips': ['192.168.110.10', ''], 'state': 'present'})
2025-10-08 12:45:07.587259 | controller | changed: [instance] => (item={'names': ['compute-0.storage.local', 'compute-0.storage.local'], 'ips': ['172.18.0.10', ''], 'state': 'present'})
2025-10-08 12:45:07.587264 | controller | changed: [instance] => (item={'names': ['compute-0.tenant.local', 'compute-0.tenant.local'], 'ips': ['172.19.0.10', ''], 'state': 'present'})
2025-10-08 12:45:07.587270 | controller |
2025-10-08 12:45:07.587277 | controller | TASK [libvirt_manager : Ensure some domains are local] *************************
2025-10-08 12:45:07.587287 | controller | Wednesday 08 October 2025  12:45:07 +0000 (0:00:01.390)       0:03:05.288 *****
2025-10-08 12:45:07.984247 | controller | changed: [instance]
2025-10-08 12:45:08.859912 | controller |
2025-10-08 12:45:08.859943 | controller | TASK [libvirt_manager : Ensure dnsmasq is reloaded now] ************************
2025-10-08 12:45:08.859980 | controller | Wednesday 08 October 2025  12:45:07 +0000 (0:00:00.387)       0:03:05.676 *****
2025-10-08 12:45:08.859991 | controller |
2025-10-08 12:45:08.859997 | controller | RUNNING HANDLER [libvirt_manager : Restart firewalld] **************************
2025-10-08 12:45:08.860002 | controller | Wednesday 08 October 2025  12:45:07 +0000 (0:00:00.009)       0:03:05.685 *****
2025-10-08 12:45:08.860013 | controller | changed: [instance]
2025-10-08 12:45:09.231734 | controller |
2025-10-08 12:45:09.231767 | controller | RUNNING HANDLER [dnsmasq : Restart dnsmasq] ************************************
2025-10-08 12:45:09.231858 | controller | Wednesday 08 October 2025  12:45:08 +0000 (0:00:00.876)       0:03:06.561 *****
2025-10-08 12:45:09.231873 | controller | changed: [instance]
2025-10-08 12:45:09.588087 | controller |
2025-10-08 12:45:09.588121 | controller | RUNNING HANDLER [dnsmasq : Reload dnsmasq] *************************************
2025-10-08 12:45:09.588131 | controller | Wednesday 08 October 2025  12:45:09 +0000 (0:00:00.371)       0:03:06.933 *****
2025-10-08 12:45:09.588161 | controller | changed: [instance]
2025-10-08 12:45:09.588184 | controller |
2025-10-08 12:45:09.588194 | controller | TASK [libvirt_manager : Create group inventories] ******************************
2025-10-08 12:45:09.588299 | controller | Wednesday 08 October 2025  12:45:09 +0000 (0:00:00.356)       0:03:07.290 *****
2025-10-08 12:45:09.998921 | controller | changed: [instance] => (item=compute)
2025-10-08 12:45:10.412044 | controller |
2025-10-08 12:45:10.412076 | controller | TASK [libvirt_manager : Create "all" group inventory file] *********************
2025-10-08 12:45:10.412084 | controller | Wednesday 08 October 2025  12:45:09 +0000 (0:00:00.410)       0:03:07.700 *****
2025-10-08 12:45:10.412094 | controller | changed: [instance]
2025-10-08 12:45:10.412469 | controller |
2025-10-08 12:45:10.450800 | controller | TASK [libvirt_manager : Ensure storage pool is present.] ***********************
2025-10-08 12:45:10.450831 | controller | Wednesday 08 October 2025  12:45:10 +0000 (0:00:00.413)       0:03:08.114 *****
2025-10-08 12:45:10.450842 | controller | skipping: [instance]
2025-10-08 12:45:10.528762 | controller |
2025-10-08 12:45:10.528797 | controller | TASK [libvirt_manager : Ensure images are present] *****************************
2025-10-08 12:45:10.528805 | controller | Wednesday 08 October 2025  12:45:10 +0000 (0:00:00.038)       0:03:08.152 *****
2025-10-08 12:45:10.528816 | 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-08 12:45:10.548802 | controller |
2025-10-08 12:45:10.548834 | controller | TASK [libvirt_manager : Ensure directory exists] *******************************
2025-10-08 12:45:10.548842 | controller | Wednesday 08 October 2025  12:45:10 +0000 (0:00:00.077)       0:03:08.230 *****
2025-10-08 12:45:10.548852 | controller | skipping: [instance]
2025-10-08 12:45:10.568598 | controller |
2025-10-08 12:45:10.568627 | controller | TASK [libvirt_manager : Check if base image exists] ****************************
2025-10-08 12:45:10.568635 | controller | Wednesday 08 October 2025  12:45:10 +0000 (0:00:00.020)       0:03:08.250 *****
2025-10-08 12:45:10.568645 | controller | skipping: [instance]
2025-10-08 12:45:10.588723 | controller |
2025-10-08 12:45:10.588756 | controller | TASK [libvirt_manager : Download base image] ***********************************
2025-10-08 12:45:10.588766 | controller | Wednesday 08 October 2025  12:45:10 +0000 (0:00:00.019)       0:03:08.270 *****
2025-10-08 12:45:10.588777 | controller | skipping: [instance]
2025-10-08 12:45:10.608791 | controller |
2025-10-08 12:45:10.608819 | controller | TASK [libvirt_manager : Check image] *******************************************
2025-10-08 12:45:10.608827 | controller | Wednesday 08 October 2025  12:45:10 +0000 (0:00:00.019)       0:03:08.290 *****
2025-10-08 12:45:10.608837 | controller | skipping: [instance]
2025-10-08 12:45:10.628433 | controller |
2025-10-08 12:45:10.628461 | controller | TASK [libvirt_manager : Assert image status] ***********************************
2025-10-08 12:45:10.628469 | controller | Wednesday 08 October 2025  12:45:10 +0000 (0:00:00.020)       0:03:08.311 *****
2025-10-08 12:45:10.628479 | controller | skipping: [instance]
2025-10-08 12:45:10.648027 | controller |
2025-10-08 12:45:10.648056 | controller | TASK [libvirt_manager : Ensure image access rights] ****************************
2025-10-08 12:45:10.648064 | controller | Wednesday 08 October 2025  12:45:10 +0000 (0:00:00.019)       0:03:08.330 *****
2025-10-08 12:45:10.648074 | controller | skipping: [instance]
2025-10-08 12:45:10.827781 | controller |
2025-10-08 12:45:10.827820 | controller | TASK [libvirt_manager : Get ssh key state] *************************************
2025-10-08 12:45:10.827829 | controller | Wednesday 08 October 2025  12:45:10 +0000 (0:00:00.019)       0:03:08.350 *****
2025-10-08 12:45:10.827839 | controller | ok: [instance]
2025-10-08 12:45:11.215692 | controller |
2025-10-08 12:45:11.215722 | controller | TASK [libvirt_manager : Create temporary ssh keypair] **************************
2025-10-08 12:45:11.215730 | controller | Wednesday 08 October 2025  12:45:10 +0000 (0:00:00.179)       0:03:08.529 *****
2025-10-08 12:45:11.215740 | controller | changed: [instance]
2025-10-08 12:45:11.495121 | controller |
2025-10-08 12:45:11.495151 | controller | TASK [libvirt_manager : Slurp public key for later use] ************************
2025-10-08 12:45:11.495160 | controller | Wednesday 08 October 2025  12:45:11 +0000 (0:00:00.388)       0:03:08.917 *****
2025-10-08 12:45:11.495170 | controller | ok: [instance]
2025-10-08 12:45:11.664484 | controller |
2025-10-08 12:45:11.664516 | controller | TASK [libvirt_manager : Slurp private key for later use] ***********************
2025-10-08 12:45:11.664524 | controller | Wednesday 08 October 2025  12:45:11 +0000 (0:00:00.279)       0:03:09.197 *****
2025-10-08 12:45:11.664534 | controller | ok: [instance]
2025-10-08 12:45:12.061128 | controller |
2025-10-08 12:45:12.061169 | controller | TASK [libvirt_manager : Inject cifmw_reproducer_key.pub in hypervisor authorized_keys] ***
2025-10-08 12:45:12.061178 | controller | Wednesday 08 October 2025  12:45:11 +0000 (0:00:00.169)       0:03:09.366 *****
2025-10-08 12:45:12.061190 | controller | changed: [instance]
2025-10-08 12:45:12.061209 | controller |
2025-10-08 12:45:12.061353 | controller | TASK [libvirt_manager : Create fact holding network data for VMs] **************
2025-10-08 12:45:12.061394 | controller | Wednesday 08 October 2025  12:45:12 +0000 (0:00:00.396)       0:03:09.763 *****
2025-10-08 12:45:12.081727 | controller | ok: [instance]
2025-10-08 12:45:12.314085 | controller |
2025-10-08 12:45:12.314116 | controller | TASK [libvirt_manager : List existing networks] ********************************
2025-10-08 12:45:12.314124 | controller | Wednesday 08 October 2025  12:45:12 +0000 (0:00:00.020)       0:03:09.783 *****
2025-10-08 12:45:12.314134 | controller | ok: [instance]
2025-10-08 12:45:12.726280 | controller |
2025-10-08 12:45:12.726322 | controller | TASK [libvirt_manager : Gather pool fact] **************************************
2025-10-08 12:45:12.726331 | controller | Wednesday 08 October 2025  12:45:12 +0000 (0:00:00.232)       0:03:10.016 *****
2025-10-08 12:45:12.726342 | controller | ok: [instance]
2025-10-08 12:45:12.726360 | controller |
2025-10-08 12:45:12.726600 | controller | TASK [libvirt_manager : Create and run VMs] ************************************
2025-10-08 12:45:12.788808 | controller | Wednesday 08 October 2025  12:45:12 +0000 (0:00:00.412)       0:03:10.428 *****
2025-10-08 12:45:12.788846 | 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-08 12:45:13.043209 | controller |
2025-10-08 12:45:13.043238 | controller | TASK [libvirt_manager : Create VM image for compute-0] *************************
2025-10-08 12:45:13.043247 | controller | Wednesday 08 October 2025  12:45:12 +0000 (0:00:00.062)       0:03:10.490 *****
2025-10-08 12:45:13.043256 | controller | changed: [instance]
2025-10-08 12:45:13.278045 | controller |
2025-10-08 12:45:13.278075 | controller | TASK [libvirt_manager : Ensure file ownership and rights for compute-0] ********
2025-10-08 12:45:13.278084 | controller | Wednesday 08 October 2025  12:45:13 +0000 (0:00:00.254)       0:03:10.745 *****
2025-10-08 12:45:13.278093 | controller | changed: [instance]
2025-10-08 12:45:13.278116 | controller |
2025-10-08 12:45:13.278124 | controller | TASK [libvirt_manager : Define VMs for type compute-0] *************************
2025-10-08 12:45:13.278188 | controller | Wednesday 08 October 2025  12:45:13 +0000 (0:00:00.234)       0:03:10.980 *****
2025-10-08 12:45:14.334842 | controller | changed: [instance]
2025-10-08 12:45:14.358029 | controller |
2025-10-08 12:45:14.358056 | controller | TASK [libvirt_manager : Attach listed networks to the VMs compute-0] ***********
2025-10-08 12:45:14.358066 | controller | Wednesday 08 October 2025  12:45:14 +0000 (0:00:01.056)       0:03:12.037 *****
2025-10-08 12:45:14.358077 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/net_to_vms.yml for instance
2025-10-08 12:45:14.358369 | controller |
2025-10-08 12:45:14.358384 | controller | TASK [libvirt_manager : Attach {{ vm_item }} to {{ net_item }}] ****************
2025-10-08 12:45:14.388073 | controller | Wednesday 08 October 2025  12:45:14 +0000 (0:00:00.023)       0:03:12.060 *****
2025-10-08 12:45:14.388112 | 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-08 12:45:14.614897 | controller |
2025-10-08 12:45:14.614927 | controller | TASK [libvirt_manager : Get virtual network information] ***********************
2025-10-08 12:45:14.614935 | controller | Wednesday 08 October 2025  12:45:14 +0000 (0:00:00.029)       0:03:12.090 *****
2025-10-08 12:45:14.614945 | controller | ok: [instance]
2025-10-08 12:45:14.654900 | controller |
2025-10-08 12:45:14.654931 | controller | TASK [libvirt_manager : Create network to bridge mapping] **********************
2025-10-08 12:45:14.654945 | controller | Wednesday 08 October 2025  12:45:14 +0000 (0:00:00.226)       0:03:12.317 *****
2025-10-08 12:45:14.654970 | controller | ok: [instance] => (item=cifmw-public)
2025-10-08 12:45:14.655438 | controller | ok: [instance] => (item=default)
2025-10-08 12:45:14.655469 | controller |
2025-10-08 12:45:14.882613 | controller | TASK [libvirt_manager : Dump domain xml] ***************************************
2025-10-08 12:45:14.882642 | controller | Wednesday 08 October 2025  12:45:14 +0000 (0:00:00.040)       0:03:12.357 *****
2025-10-08 12:45:14.882653 | controller | ok: [instance]
2025-10-08 12:45:15.083839 | controller |
2025-10-08 12:45:15.083868 | controller | TASK [libvirt_manager : Extract networks from XML] *****************************
2025-10-08 12:45:15.083876 | controller | Wednesday 08 October 2025  12:45:14 +0000 (0:00:00.227)       0:03:12.584 *****
2025-10-08 12:45:15.083886 | controller | ok: [instance]
2025-10-08 12:45:15.376445 | controller |
2025-10-08 12:45:15.376477 | controller | TASK [libvirt_manager : Attach interface public on cifmw-compute-0] ************
2025-10-08 12:45:15.376485 | controller | Wednesday 08 October 2025  12:45:15 +0000 (0:00:00.201)       0:03:12.785 *****
2025-10-08 12:45:15.376496 | controller | changed: [instance]
2025-10-08 12:45:15.396129 | controller |
2025-10-08 12:45:15.396154 | controller | TASK [libvirt_manager : Attach spines/leafs networks to the VMs compute-0] *****
2025-10-08 12:45:15.396162 | controller | Wednesday 08 October 2025  12:45:15 +0000 (0:00:00.292)       0:03:13.078 *****
2025-10-08 12:45:15.396171 | controller | skipping: [instance]
2025-10-08 12:45:15.422402 | controller |
2025-10-08 12:45:15.422425 | controller | TASK [libvirt_manager : Create the requested extra disks for compute-0] ********
2025-10-08 12:45:15.422433 | controller | Wednesday 08 October 2025  12:45:15 +0000 (0:00:00.019)       0:03:13.098 *****
2025-10-08 12:45:15.422447 | controller | skipping: [instance]
2025-10-08 12:45:15.448488 | controller |
2025-10-08 12:45:15.448509 | controller | TASK [libvirt_manager : Find volume attachments for VM compute-0] **************
2025-10-08 12:45:15.448516 | controller | Wednesday 08 October 2025  12:45:15 +0000 (0:00:00.026)       0:03:13.124 *****
2025-10-08 12:45:15.448525 | controller | skipping: [instance]
2025-10-08 12:45:15.473491 | controller |
2025-10-08 12:45:15.473513 | controller | TASK [libvirt_manager : Attach volumes for VM compute-0] ***********************
2025-10-08 12:45:15.473521 | controller | Wednesday 08 October 2025  12:45:15 +0000 (0:00:00.026)       0:03:13.150 *****
2025-10-08 12:45:15.473530 | controller | skipping: [instance]
2025-10-08 12:45:15.695787 | controller |
2025-10-08 12:45:15.695816 | controller | TASK [libvirt_manager : Get VM UUID] *******************************************
2025-10-08 12:45:15.695825 | controller | Wednesday 08 October 2025  12:45:15 +0000 (0:00:00.024)       0:03:13.175 *****
2025-10-08 12:45:15.695834 | controller | changed: [instance]
2025-10-08 12:45:15.729628 | controller |
2025-10-08 12:45:15.729653 | controller | TASK [libvirt_manager : Inject UUID in dataset] ********************************
2025-10-08 12:45:15.729661 | controller | Wednesday 08 October 2025  12:45:15 +0000 (0:00:00.222)       0:03:13.397 *****
2025-10-08 12:45:15.729670 | controller | ok: [instance]
2025-10-08 12:45:15.749715 | controller |
2025-10-08 12:45:15.749738 | controller | TASK [libvirt_manager : Create cloud-init ISO] *********************************
2025-10-08 12:45:15.749747 | controller | Wednesday 08 October 2025  12:45:15 +0000 (0:00:00.034)       0:03:13.431 *****
2025-10-08 12:45:15.749758 | controller | skipping: [instance]
2025-10-08 12:45:15.769875 | controller |
2025-10-08 12:45:15.769908 | controller | TASK [libvirt_manager : Attach cloud-init ISO if exists] ***********************
2025-10-08 12:45:15.769916 | controller | Wednesday 08 October 2025  12:45:15 +0000 (0:00:00.020)       0:03:13.452 *****
2025-10-08 12:45:15.769926 | controller | skipping: [instance]
2025-10-08 12:45:15.813345 | controller |
2025-10-08 12:45:15.813373 | controller | TASK [libvirt_manager : Attach additional devices if specified] ****************
2025-10-08 12:45:15.813381 | controller | Wednesday 08 October 2025  12:45:15 +0000 (0:00:00.020)       0:03:13.472 *****
2025-10-08 12:45:15.813391 | controller | skipping: [instance]
2025-10-08 12:45:15.847641 | controller |
2025-10-08 12:45:15.847672 | controller | TASK [libvirt_manager : Start (power-on) VMs] **********************************
2025-10-08 12:45:15.847680 | controller | Wednesday 08 October 2025  12:45:15 +0000 (0:00:00.043)       0:03:13.515 *****
2025-10-08 12:45:15.847696 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/start_vms.yml for instance
2025-10-08 12:45:15.877087 | controller |
2025-10-08 12:45:15.877126 | controller | TASK [libvirt_manager : Refresh oooq_pool before starting VMs] *****************
2025-10-08 12:45:15.877137 | controller | Wednesday 08 October 2025  12:45:15 +0000 (0:00:00.034)       0:03:13.549 *****
2025-10-08 12:45:15.877150 | controller | skipping: [instance]
2025-10-08 12:45:15.877181 | controller |
2025-10-08 12:45:15.877379 | controller | TASK [libvirt_manager : Start VMs for type {{ vm_type }}] **********************
2025-10-08 12:45:15.921041 | controller | Wednesday 08 October 2025  12:45:15 +0000 (0:00:00.029)       0:03:13.579 *****
2025-10-08 12:45:15.921074 | controller | skipping: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
2025-10-08 12:45:15.965070 | controller | skipping: [instance]
2025-10-08 12:45:15.965105 | controller |
2025-10-08 12:45:15.965115 | controller | TASK [libvirt_manager : Wait for SSH on started VMs] ***************************
2025-10-08 12:45:15.965123 | controller | Wednesday 08 October 2025  12:45:15 +0000 (0:00:00.043)       0:03:13.622 *****
2025-10-08 12:45:15.965134 | controller | skipping: [instance] => (item=compute-0.utility)
2025-10-08 12:45:15.965163 | controller | skipping: [instance]
2025-10-08 12:45:15.965171 | controller |
2025-10-08 12:45:15.965177 | controller | TASK [libvirt_manager : Ensure we get SSH on nodes] ****************************
2025-10-08 12:45:15.965186 | controller | Wednesday 08 October 2025  12:45:15 +0000 (0:00:00.044)       0:03:13.667 *****
2025-10-08 12:45:15.992527 | 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-08 12:45:16.030068 | controller | skipping: [instance]
2025-10-08 12:45:16.030101 | controller |
2025-10-08 12:45:16.030111 | controller | TASK [libvirt_manager : Configure managed VMs] *********************************
2025-10-08 12:45:16.030118 | controller | Wednesday 08 October 2025  12:45:15 +0000 (0:00:00.027)       0:03:13.694 *****
2025-10-08 12:45:16.030130 | controller | skipping: [instance] => (item={'key': 'compute-0', 'value': 'compute'})
2025-10-08 12:45:16.067798 | controller | skipping: [instance]
2025-10-08 12:45:16.067829 | controller |
2025-10-08 12:45:16.067837 | controller | TASK [Create VBMC entity] ******************************************************
2025-10-08 12:45:16.067844 | controller | Wednesday 08 October 2025  12:45:16 +0000 (0:00:00.037)       0:03:13.732 *****
2025-10-08 12:45:16.067854 | controller | skipping: [instance] => (item=compute-0)
2025-10-08 12:45:16.294363 | controller | skipping: [instance]
2025-10-08 12:45:16.294392 | controller |
2025-10-08 12:45:16.294400 | controller | TASK [libvirt_manager : List running virtual machines.] ************************
2025-10-08 12:45:16.294406 | controller | Wednesday 08 October 2025  12:45:16 +0000 (0:00:00.037)       0:03:13.770 *****
2025-10-08 12:45:16.294415 | controller | ok: [instance]
2025-10-08 12:45:16.653140 | controller |
2025-10-08 12:45:16.653171 | controller | TASK [libvirt_manager : Dump UUIDs] ********************************************
2025-10-08 12:45:16.653185 | controller | Wednesday 08 October 2025  12:45:16 +0000 (0:00:00.226)       0:03:13.996 *****
2025-10-08 12:45:16.653196 | controller | changed: [instance]
2025-10-08 12:45:16.684201 | controller |
2025-10-08 12:45:16.684234 | controller | TASK [Ensure fresh vbmc listing] ***********************************************
2025-10-08 12:45:16.684241 | controller | Wednesday 08 October 2025  12:45:16 +0000 (0:00:00.358)       0:03:14.355 *****
2025-10-08 12:45:16.684251 | controller | skipping: [instance]
2025-10-08 12:45:16.715011 | controller |
2025-10-08 12:45:16.715046 | controller | TASK [libvirt_manager : Update vbmc related fact] ******************************
2025-10-08 12:45:16.715054 | controller | Wednesday 08 October 2025  12:45:16 +0000 (0:00:00.030)       0:03:14.386 *****
2025-10-08 12:45:16.715064 | controller | skipping: [instance]
2025-10-08 12:45:16.746661 | controller |
2025-10-08 12:45:16.746698 | controller | TASK [libvirt_manager : Dump vbmc known hosts] *********************************
2025-10-08 12:45:16.746708 | controller | Wednesday 08 October 2025  12:45:16 +0000 (0:00:00.030)       0:03:14.416 *****
2025-10-08 12:45:16.746719 | controller | skipping: [instance]
2025-10-08 12:45:16.772755 | controller |
2025-10-08 12:45:16.772799 | controller | TASK [libvirt_manager : Copy authorized_keys] **********************************
2025-10-08 12:45:16.772807 | controller | Wednesday 08 October 2025  12:45:16 +0000 (0:00:00.031)       0:03:14.448 *****
2025-10-08 12:45:16.772818 | controller | skipping: [instance]
2025-10-08 12:45:16.773009 | controller |
2025-10-08 12:45:16.773164 | controller | TASK [libvirt_manager : Enable root access on CRC] *****************************
2025-10-08 12:45:16.773303 | controller | Wednesday 08 October 2025  12:45:16 +0000 (0:00:00.026)       0:03:14.475 *****
2025-10-08 12:45:16.816400 | controller | skipping: [instance]
2025-10-08 12:45:16.816566 | controller |
2025-10-08 12:45:16.816707 | controller | PLAY RECAP *********************************************************************
2025-10-08 12:45:16.816872 | controller | instance                   : ok=190  changed=92   unreachable=0    failed=0    skipped=89   rescued=0    ignored=0
2025-10-08 12:45:16.817044 | controller |
2025-10-08 12:45:16.817185 | controller | Wednesday 08 October 2025  12:45:16 +0000 (0:00:00.043)       0:03:14.518 *****
2025-10-08 12:45:16.817325 | controller | ===============================================================================
2025-10-08 12:45:16.817479 | controller | libvirt_manager : Install packages required for using KVM -------------- 69.63s
2025-10-08 12:45:16.817612 | controller | test_deps : Install selinux python libs -------------------------------- 45.49s
2025-10-08 12:45:16.817742 | controller | repo_setup : Initialize python venv and install requirements ------------ 7.95s
2025-10-08 12:45:16.817879 | controller | ci_nmstate : Install required packages on instance ---------------------- 7.75s
2025-10-08 12:45:16.818048 | controller | test_deps : Install extra packages -------------------------------------- 3.76s
2025-10-08 12:45:16.818183 | controller | dnsmasq : Ensure SELinux knows about the new files and directories ------ 3.60s
2025-10-08 12:45:16.818313 | controller | ci_nmstate : Apply the desidered state on instance ---------------------- 1.69s
2025-10-08 12:45:16.818445 | controller | libvirt_manager : Restart firewalld ------------------------------------- 1.68s
2025-10-08 12:45:16.818574 | controller | discover_latest_image : Get latest image -------------------------------- 1.60s
2025-10-08 12:45:16.818703 | controller | dnsmasq : Add/Remove address -------------------------------------------- 1.39s
2025-10-08 12:45:16.818829 | controller | dnsmasq : Install needed packages --------------------------------------- 1.21s
2025-10-08 12:45:16.818973 | controller | repo_setup : Get repo-setup repository ---------------------------------- 1.21s
2025-10-08 12:45:16.819142 | controller | test_deps : Install python yaml libs ------------------------------------ 1.20s
2025-10-08 12:45:16.819274 | controller | libvirt_manager : Define VMs for type compute-0 ------------------------- 1.06s
2025-10-08 12:45:16.819401 | controller | libvirt_manager : Ensure firewalld service is up ------------------------ 0.89s
2025-10-08 12:45:16.819538 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.86s
2025-10-08 12:45:16.819665 | controller | Gathering Facts --------------------------------------------------------- 0.83s
2025-10-08 12:45:16.819799 | controller | repo_setup : Make sure git-core package is installed -------------------- 0.81s
2025-10-08 12:45:16.819931 | controller | libvirt_manager : Ensure networks are defined --------------------------- 0.75s
2025-10-08 12:45:16.820098 | controller | repo_setup : Install repo-setup package --------------------------------- 0.74s
2025-10-08 12:45:16.901647 | controller | INFO     Running default > converge
2025-10-08 12:45:17.372319 | controller |
2025-10-08 12:45:18.298154 | controller | PLAY [Converge] ****************************************************************
2025-10-08 12:45:18.298224 | controller |
2025-10-08 12:45:18.298234 | controller | TASK [Gathering Facts] *********************************************************
2025-10-08 12:45:18.298240 | controller | Wednesday 08 October 2025  12:45:17 +0000 (0:00:00.019)       0:00:00.019 *****
2025-10-08 12:45:18.298252 | controller | ok: [instance]
2025-10-08 12:45:18.620136 | controller |
2025-10-08 12:45:18.620167 | controller | TASK [virtualbmc : Ensure needed directories exist] ****************************
2025-10-08 12:45:18.620175 | controller | Wednesday 08 October 2025  12:45:18 +0000 (0:00:00.926)       0:00:00.945 *****
2025-10-08 12:45:18.620185 | controller | ok: [instance] => (item={'key': '/home/zuul/.ssh', 'mode': '0700'})
2025-10-08 12:45:19.997485 | controller |
2025-10-08 12:45:19.997519 | controller | TASK [podman : Ensure podman is installed] *************************************
2025-10-08 12:45:19.997527 | controller | Wednesday 08 October 2025  12:45:18 +0000 (0:00:00.322)       0:00:01.267 *****
2025-10-08 12:45:19.997537 | controller | ok: [instance]
2025-10-08 12:45:20.339107 | controller |
2025-10-08 12:45:20.339140 | controller | TASK [podman : Enable loginctl linger for ansible_user_id] *********************
2025-10-08 12:45:20.339149 | controller | Wednesday 08 October 2025  12:45:19 +0000 (0:00:01.377)       0:00:02.644 *****
2025-10-08 12:45:20.339159 | controller | changed: [instance]
2025-10-08 12:45:20.363105 | controller |
2025-10-08 12:45:20.363146 | controller | TASK [podman : Ensure subordinate UID entry exists for zuul] *******************
2025-10-08 12:45:20.363155 | controller | Wednesday 08 October 2025  12:45:20 +0000 (0:00:00.341)       0:00:02.986 *****
2025-10-08 12:45:20.363166 | controller | skipping: [instance]
2025-10-08 12:45:20.383867 | controller |
2025-10-08 12:45:20.383894 | controller | TASK [podman : Ensure subordinate GID entry exists for zuul] *******************
2025-10-08 12:45:20.383902 | controller | Wednesday 08 October 2025  12:45:20 +0000 (0:00:00.024)       0:00:03.010 *****
2025-10-08 12:45:20.383911 | controller | skipping: [instance]
2025-10-08 12:45:20.409722 | controller |
2025-10-08 12:45:20.409752 | controller | TASK [podman : Run podman system migrate if subuid/subgid files were changed] ***
2025-10-08 12:45:20.409760 | controller | Wednesday 08 October 2025  12:45:20 +0000 (0:00:00.020)       0:00:03.031 *****
2025-10-08 12:45:20.409770 | controller | skipping: [instance]
2025-10-08 12:45:20.837208 | controller |
2025-10-08 12:45:20.837252 | controller | TASK [virtualbmc : Check if container already exists] **************************
2025-10-08 12:45:20.837262 | controller | Wednesday 08 October 2025  12:45:20 +0000 (0:00:00.025)       0:00:03.057 *****
2025-10-08 12:45:20.837276 | controller | ok: [instance]
2025-10-08 12:45:20.837318 | controller |
2025-10-08 12:45:20.837328 | controller | TASK [virtualbmc : Create ssh key for VBMC] ************************************
2025-10-08 12:45:20.837338 | controller | Wednesday 08 October 2025  12:45:20 +0000 (0:00:00.427)       0:00:03.484 *****
2025-10-08 12:45:21.190690 | controller | changed: [instance]
2025-10-08 12:45:27.053055 | controller |
2025-10-08 12:45:27.053086 | controller | TASK [virtualbmc : Pull vbmc container image] **********************************
2025-10-08 12:45:27.053094 | controller | Wednesday 08 October 2025  12:45:21 +0000 (0:00:00.353)       0:00:03.837 *****
2025-10-08 12:45:27.053104 | controller | changed: [instance]
2025-10-08 12:45:27.053304 | controller |
2025-10-08 12:45:27.053318 | controller | TASK [virtualbmc : Allow VBMC temporary key] ***********************************
2025-10-08 12:45:27.441079 | controller | Wednesday 08 October 2025  12:45:27 +0000 (0:00:05.862)       0:00:09.700 *****
2025-10-08 12:45:27.441116 | controller | changed: [instance]
2025-10-08 12:45:27.441141 | controller |
2025-10-08 12:45:27.441150 | controller | TASK [virtualbmc : Create ssh_config snippet for VBMC] *************************
2025-10-08 12:45:27.441276 | controller | Wednesday 08 October 2025  12:45:27 +0000 (0:00:00.388)       0:00:10.088 *****
2025-10-08 12:45:28.005391 | controller | changed: [instance]
2025-10-08 12:45:28.337413 | controller |
2025-10-08 12:45:28.337444 | controller | TASK [virtualbmc : Create vbmc server configuration file] **********************
2025-10-08 12:45:28.337453 | controller | Wednesday 08 October 2025  12:45:28 +0000 (0:00:00.564)       0:00:10.652 *****
2025-10-08 12:45:28.337463 | controller | changed: [instance]
2025-10-08 12:45:28.683215 | controller |
2025-10-08 12:45:28.683250 | controller | TASK [virtualbmc : Create undying vbmcd service script] ************************
2025-10-08 12:45:28.683261 | controller | Wednesday 08 October 2025  12:45:28 +0000 (0:00:00.331)       0:00:10.984 *****
2025-10-08 12:45:28.683272 | controller | changed: [instance]
2025-10-08 12:45:29.441104 | controller |
2025-10-08 12:45:29.441139 | controller | TASK [virtualbmc : Create and start vbmc container] ****************************
2025-10-08 12:45:29.441147 | controller | Wednesday 08 October 2025  12:45:28 +0000 (0:00:00.345)       0:00:11.330 *****
2025-10-08 12:45:29.441157 | controller | changed: [instance]
2025-10-08 12:45:29.470886 | controller |
2025-10-08 12:45:29.470923 | controller | TASK [virtualbmc : Assert we have required data] *******************************
2025-10-08 12:45:29.470931 | controller | Wednesday 08 October 2025  12:45:29 +0000 (0:00:00.757)       0:00:12.088 *****
2025-10-08 12:45:29.470963 | controller | ok: [instance] => changed=false
2025-10-08 12:45:29.969820 | controller |   msg: All assertions passed
2025-10-08 12:45:29.969850 | controller |
2025-10-08 12:45:29.969859 | controller | TASK [virtualbmc : Get existing known VBMC nodes] ******************************
2025-10-08 12:45:29.969865 | controller | Wednesday 08 October 2025  12:45:29 +0000 (0:00:00.029)       0:00:12.117 *****
2025-10-08 12:45:29.969875 | controller | changed: [instance]
2025-10-08 12:45:29.993076 | controller |
2025-10-08 12:45:29.993109 | controller | TASK [virtualbmc : Expose known hosts] *****************************************
2025-10-08 12:45:29.993117 | controller | Wednesday 08 October 2025  12:45:29 +0000 (0:00:00.499)       0:00:12.617 *****
2025-10-08 12:45:29.993127 | controller | ok: [instance]
2025-10-08 12:45:30.020452 | controller |
2025-10-08 12:45:30.020482 | controller | TASK [virtualbmc : Stop host in VBMC] ******************************************
2025-10-08 12:45:30.020490 | controller | Wednesday 08 October 2025  12:45:29 +0000 (0:00:00.023)       0:00:12.640 *****
2025-10-08 12:45:30.020500 | controller | skipping: [instance]
2025-10-08 12:45:30.775659 | controller |
2025-10-08 12:45:30.775693 | controller | TASK [virtualbmc : Add new host to VBMC] ***************************************
2025-10-08 12:45:30.775701 | controller | Wednesday 08 October 2025  12:45:30 +0000 (0:00:00.027)       0:00:12.667 *****
2025-10-08 12:45:30.775712 | controller | changed: [instance]
2025-10-08 12:45:31.324046 | controller |
2025-10-08 12:45:31.324078 | controller | TASK [virtualbmc : Start new host in VBMC] *************************************
2025-10-08 12:45:31.324086 | controller | Wednesday 08 October 2025  12:45:30 +0000 (0:00:00.755)       0:00:13.422 *****
2025-10-08 12:45:31.324097 | controller | changed: [instance]
2025-10-08 12:45:31.324240 | controller |
2025-10-08 12:45:31.324279 | controller | TASK [Stop VM using IPMI] ******************************************************
2025-10-08 12:45:31.324293 | controller | Wednesday 08 October 2025  12:45:31 +0000 (0:00:00.548)       0:00:13.971 *****
2025-10-08 12:45:31.743086 | controller | changed: [instance]
2025-10-08 12:45:32.103112 | controller |
2025-10-08 12:45:32.103156 | controller | TASK [List VMs from the hypervisor] ********************************************
2025-10-08 12:45:32.103165 | controller | Wednesday 08 October 2025  12:45:31 +0000 (0:00:00.418)       0:00:14.390 *****
2025-10-08 12:45:32.103176 | controller | ok: [instance]
2025-10-08 12:45:32.103195 | controller |
2025-10-08 12:45:32.103418 | controller | TASK [Ensure VM is stopped] ****************************************************
2025-10-08 12:45:32.126565 | controller | Wednesday 08 October 2025  12:45:32 +0000 (0:00:00.360)       0:00:14.750 *****
2025-10-08 12:45:32.126600 | controller | ok: [instance] => changed=false
2025-10-08 12:45:32.608054 | controller |   msg: All assertions passed
2025-10-08 12:45:32.608092 | controller |
2025-10-08 12:45:32.608100 | controller | TASK [virtualbmc : Get existing known VBMC nodes] ******************************
2025-10-08 12:45:32.608107 | controller | Wednesday 08 October 2025  12:45:32 +0000 (0:00:00.023)       0:00:14.773 *****
2025-10-08 12:45:32.608117 | controller | changed: [instance]
2025-10-08 12:45:32.608281 | controller |
2025-10-08 12:45:32.608294 | controller | TASK [virtualbmc : Expose known hosts] *****************************************
2025-10-08 12:45:32.608302 | controller | Wednesday 08 October 2025  12:45:32 +0000 (0:00:00.481)       0:00:15.255 *****
2025-10-08 12:45:32.637107 | controller | ok: [instance]
2025-10-08 12:45:32.637169 | controller |
2025-10-08 12:45:32.637182 | controller | TASK [Ensure we have the needed fact] ******************************************
2025-10-08 12:45:32.637289 | controller | Wednesday 08 October 2025  12:45:32 +0000 (0:00:00.029)       0:00:15.284 *****
2025-10-08 12:45:32.667880 | controller | ok: [instance] => changed=false
2025-10-08 12:45:32.711108 | controller |   msg: All assertions passed
2025-10-08 12:45:32.711141 | controller |
2025-10-08 12:45:32.711149 | controller | TASK [Expose known hosts] ******************************************************
2025-10-08 12:45:32.711156 | controller | Wednesday 08 October 2025  12:45:32 +0000 (0:00:00.030)       0:00:15.315 *****
2025-10-08 12:45:32.711165 | controller | ok: [instance] =>
2025-10-08 12:45:32.711191 | controller |   cifmw_virtualbmc_known_hosts:
2025-10-08 12:45:32.711198 | controller |   - Address: 127.0.0.1
2025-10-08 12:45:32.711203 | controller |     Domain name: cifmw-compute-0
2025-10-08 12:45:32.711209 | controller |     Port: 6241
2025-10-08 12:45:32.711214 | controller |     Status: running
2025-10-08 12:45:32.711228 | controller |
2025-10-08 12:45:32.711394 | controller | TASK [virtualbmc : Assert we have required data] *******************************
2025-10-08 12:45:32.743059 | controller | Wednesday 08 October 2025  12:45:32 +0000 (0:00:00.043)       0:00:15.358 *****
2025-10-08 12:45:32.743097 | controller | ok: [instance] => changed=false
2025-10-08 12:45:32.743479 | controller |   msg: All assertions passed
2025-10-08 12:45:33.287630 | controller |
2025-10-08 12:45:33.287659 | controller | TASK [virtualbmc : Get existing known VBMC nodes] ******************************
2025-10-08 12:45:33.287668 | controller | Wednesday 08 October 2025  12:45:32 +0000 (0:00:00.032)       0:00:15.390 *****
2025-10-08 12:45:33.287678 | controller | changed: [instance]
2025-10-08 12:45:33.307087 | controller |
2025-10-08 12:45:33.307115 | controller | TASK [virtualbmc : Expose known hosts] *****************************************
2025-10-08 12:45:33.307124 | controller | Wednesday 08 October 2025  12:45:33 +0000 (0:00:00.544)       0:00:15.935 *****
2025-10-08 12:45:33.307134 | controller | ok: [instance]
2025-10-08 12:45:33.767278 | controller |
2025-10-08 12:45:33.767309 | controller | TASK [virtualbmc : Stop host in VBMC] ******************************************
2025-10-08 12:45:33.767318 | controller | Wednesday 08 October 2025  12:45:33 +0000 (0:00:00.019)       0:00:15.954 *****
2025-10-08 12:45:33.767328 | controller | changed: [instance]
2025-10-08 12:45:34.209461 | controller |
2025-10-08 12:45:34.209493 | controller | TASK [virtualbmc : Add new host to VBMC] ***************************************
2025-10-08 12:45:34.209501 | controller | Wednesday 08 October 2025  12:45:33 +0000 (0:00:00.459)       0:00:16.414 *****
2025-10-08 12:45:34.209511 | controller | changed: [instance]
2025-10-08 12:45:34.243417 | controller |
2025-10-08 12:45:34.243446 | controller | TASK [virtualbmc : Start new host in VBMC] *************************************
2025-10-08 12:45:34.243454 | controller | Wednesday 08 October 2025  12:45:34 +0000 (0:00:00.442)       0:00:16.856 *****
2025-10-08 12:45:34.243464 | controller | skipping: [instance]
2025-10-08 12:45:34.683893 | controller |
2025-10-08 12:45:34.683924 | controller | TASK [virtualbmc : Get existing known VBMC nodes] ******************************
2025-10-08 12:45:34.683932 | controller | Wednesday 08 October 2025  12:45:34 +0000 (0:00:00.034)       0:00:16.890 *****
2025-10-08 12:45:34.683942 | controller | changed: [instance]
2025-10-08 12:45:34.707027 | controller |
2025-10-08 12:45:34.707070 | controller | TASK [virtualbmc : Expose known hosts] *****************************************
2025-10-08 12:45:34.707079 | controller | Wednesday 08 October 2025  12:45:34 +0000 (0:00:00.440)       0:00:17.331 *****
2025-10-08 12:45:34.707088 | controller | ok: [instance]
2025-10-08 12:45:34.707358 | controller |
2025-10-08 12:45:34.707375 | controller | TASK [Ensure we have the needed fact] ******************************************
2025-10-08 12:45:34.748023 | controller | Wednesday 08 October 2025  12:45:34 +0000 (0:00:00.023)       0:00:17.354 *****
2025-10-08 12:45:34.748064 | controller | ok: [instance] => changed=false
2025-10-08 12:45:34.748089 | controller |   msg: All assertions passed
2025-10-08 12:45:34.748096 | controller |
2025-10-08 12:45:34.748102 | controller | PLAY RECAP *********************************************************************
2025-10-08 12:45:34.748108 | controller | instance                   : ok=32   changed=17   unreachable=0    failed=0    skipped=5    rescued=0    ignored=0
2025-10-08 12:45:34.748113 | controller |
2025-10-08 12:45:34.748119 | controller | Wednesday 08 October 2025  12:45:34 +0000 (0:00:00.038)       0:00:17.393 *****
2025-10-08 12:45:34.748124 | controller | ===============================================================================
2025-10-08 12:45:34.748129 | controller | virtualbmc : Pull vbmc container image ---------------------------------- 5.86s
2025-10-08 12:45:34.748135 | controller | podman : Ensure podman is installed ------------------------------------- 1.38s
2025-10-08 12:45:34.748140 | controller | Gathering Facts --------------------------------------------------------- 0.93s
2025-10-08 12:45:34.748145 | controller | virtualbmc : Create and start vbmc container ---------------------------- 0.76s
2025-10-08 12:45:34.748150 | controller | virtualbmc : Add new host to VBMC --------------------------------------- 0.76s
2025-10-08 12:45:34.748156 | controller | virtualbmc : Create ssh_config snippet for VBMC ------------------------- 0.56s
2025-10-08 12:45:34.748161 | controller | virtualbmc : Start new host in VBMC ------------------------------------- 0.55s
2025-10-08 12:45:34.748171 | controller | virtualbmc : Get existing known VBMC nodes ------------------------------ 0.54s
2025-10-08 12:45:34.748176 | controller | virtualbmc : Get existing known VBMC nodes ------------------------------ 0.50s
2025-10-08 12:45:34.748181 | controller | virtualbmc : Get existing known VBMC nodes ------------------------------ 0.48s
2025-10-08 12:45:34.748187 | controller | virtualbmc : Stop host in VBMC ------------------------------------------ 0.46s
2025-10-08 12:45:34.748192 | controller | virtualbmc : Add new host to VBMC --------------------------------------- 0.44s
2025-10-08 12:45:34.748200 | controller | virtualbmc : Get existing known VBMC nodes ------------------------------ 0.44s
2025-10-08 12:45:34.748206 | controller | virtualbmc : Check if container already exists -------------------------- 0.43s
2025-10-08 12:45:34.748211 | controller | Stop VM using IPMI ------------------------------------------------------ 0.42s
2025-10-08 12:45:34.748218 | controller | virtualbmc : Allow VBMC temporary key ----------------------------------- 0.39s
2025-10-08 12:45:34.748382 | controller | List VMs from the hypervisor -------------------------------------------- 0.36s
2025-10-08 12:45:34.748526 | controller | virtualbmc : Create ssh key for VBMC ------------------------------------ 0.35s
2025-10-08 12:45:34.748666 | controller | virtualbmc : Create undying vbmcd service script ------------------------ 0.35s
2025-10-08 12:45:34.748805 | controller | podman : Enable loginctl linger for ansible_user_id --------------------- 0.34s
2025-10-08 12:45:34.805392 | controller | INFO     Running default > cleanup
2025-10-08 12:45:35.300759 | controller |
2025-10-08 12:45:35.301011 | controller | PLAY [Cleanup] *****************************************************************
2025-10-08 12:45:35.301189 | controller |
2025-10-08 12:45:35.301334 | controller | TASK [Gathering Facts] *********************************************************
2025-10-08 12:45:35.301476 | controller | Wednesday 08 October 2025  12:45:35 +0000 (0:00:00.016)       0:00:00.016 *****
2025-10-08 12:45:36.160519 | controller | ok: [instance]
2025-10-08 12:45:36.959567 | controller |
2025-10-08 12:45:36.959601 | controller | TASK [libvirt_manager : Get installed packages list] ***************************
2025-10-08 12:45:36.959610 | controller | Wednesday 08 October 2025  12:45:36 +0000 (0:00:00.859)       0:00:00.876 *****
2025-10-08 12:45:36.959620 | controller | ok: [instance]
2025-10-08 12:45:39.263497 | controller |
2025-10-08 12:45:39.263529 | controller | TASK [libvirt_manager : Populate service facts] ********************************
2025-10-08 12:45:39.263537 | controller | Wednesday 08 October 2025  12:45:36 +0000 (0:00:00.798)       0:00:01.675 *****
2025-10-08 12:45:39.263548 | controller | ok: [instance]
2025-10-08 12:45:40.167075 | controller |
2025-10-08 12:45:40.167109 | controller | TASK [libvirt_manager : Start virtqemud socket service] ************************
2025-10-08 12:45:40.167119 | controller | Wednesday 08 October 2025  12:45:39 +0000 (0:00:02.304)       0:00:03.979 *****
2025-10-08 12:45:40.167131 | controller | ok: [instance] => (item=virtqemud.service)
2025-10-08 12:45:40.167163 | controller | ok: [instance] => (item=virtqemud.socket)
2025-10-08 12:45:40.167190 | controller |
2025-10-08 12:45:40.167488 | controller | TASK [libvirt_manager : Set _is_deepscrub internal fact] ***********************
2025-10-08 12:45:40.220721 | controller | Wednesday 08 October 2025  12:45:40 +0000 (0:00:00.903)       0:00:04.883 *****
2025-10-08 12:45:40.220759 | controller | ok: [instance]
2025-10-08 12:45:40.622856 | controller |
2025-10-08 12:45:40.622886 | controller | TASK [libvirt_manager : List all of the existing virtual machines] *************
2025-10-08 12:45:40.622894 | controller | Wednesday 08 October 2025  12:45:40 +0000 (0:00:00.053)       0:00:04.936 *****
2025-10-08 12:45:40.622904 | controller | ok: [instance]
2025-10-08 12:45:41.014996 | controller |
2025-10-08 12:45:41.015028 | controller | TASK [libvirt_manager : Get pool configuration] ********************************
2025-10-08 12:45:41.015036 | controller | Wednesday 08 October 2025  12:45:40 +0000 (0:00:00.402)       0:00:05.338 *****
2025-10-08 12:45:41.015056 | controller | ok: [instance]
2025-10-08 12:45:41.098106 | controller |
2025-10-08 12:45:41.098139 | controller | TASK [libvirt_manager : Filter out target environment] *************************
2025-10-08 12:45:41.098147 | controller | Wednesday 08 October 2025  12:45:41 +0000 (0:00:00.392)       0:00:05.731 *****
2025-10-08 12:45:41.098157 | controller | ok: [instance]
2025-10-08 12:45:41.206064 | controller |
2025-10-08 12:45:41.206096 | controller | TASK [libvirt_manager : Expose cleanup list] ***********************************
2025-10-08 12:45:41.206105 | controller | Wednesday 08 October 2025  12:45:41 +0000 (0:00:00.082)       0:00:05.814 *****
2025-10-08 12:45:41.206115 | controller | ok: [instance] =>
2025-10-08 12:45:41.206138 | controller |   cleanup_vms:
2025-10-08 12:45:41.206145 | controller |   - cifmw-compute-0
2025-10-08 12:45:41.206151 | controller |
2025-10-08 12:45:41.206158 | controller | TASK [libvirt_manager : Clean ssh known_hosts] *********************************
2025-10-08 12:45:41.206266 | controller | Wednesday 08 October 2025  12:45:41 +0000 (0:00:00.108)       0:00:05.922 *****
2025-10-08 12:45:41.551784 | controller | ok: [instance] => (item=cifmw-compute-0)
2025-10-08 12:45:41.880655 | controller |
2025-10-08 12:45:41.880684 | controller | TASK [libvirt_manager : Destroy machine] ***************************************
2025-10-08 12:45:41.880692 | controller | Wednesday 08 October 2025  12:45:41 +0000 (0:00:00.345)       0:00:06.267 *****
2025-10-08 12:45:41.880706 | controller | ok: [instance] => (item=cifmw-compute-0)
2025-10-08 12:45:42.195768 | controller |
2025-10-08 12:45:42.195799 | controller | TASK [libvirt_manager : Undefine machine] **************************************
2025-10-08 12:45:42.195807 | controller | Wednesday 08 October 2025  12:45:41 +0000 (0:00:00.328)       0:00:06.596 *****
2025-10-08 12:45:42.195817 | controller | ok: [instance] => (item=cifmw-compute-0)
2025-10-08 12:45:42.583392 | controller |
2025-10-08 12:45:42.583424 | controller | TASK [libvirt_manager : (localhost) Clean ssh jumpers] *************************
2025-10-08 12:45:42.583432 | controller | Wednesday 08 October 2025  12:45:42 +0000 (0:00:00.315)       0:00:06.911 *****
2025-10-08 12:45:42.583442 | controller | ok: [instance -> localhost] => (item=cifmw-compute-0)
2025-10-08 12:45:42.853481 | controller |
2025-10-08 12:45:42.853514 | controller | TASK [libvirt_manager : (instance) Clean ssh jumpers] **************************
2025-10-08 12:45:42.853522 | controller | Wednesday 08 October 2025  12:45:42 +0000 (0:00:00.387)       0:00:07.299 *****
2025-10-08 12:45:42.853532 | controller | ok: [instance] => (item=cifmw-compute-0)
2025-10-08 12:45:43.254559 | controller |
2025-10-08 12:45:43.254592 | controller | TASK [libvirt_manager : Get network list] **************************************
2025-10-08 12:45:43.254601 | controller | Wednesday 08 October 2025  12:45:42 +0000 (0:00:00.269)       0:00:07.569 *****
2025-10-08 12:45:43.254611 | controller | ok: [instance]
2025-10-08 12:45:43.349849 | controller |
2025-10-08 12:45:43.349882 | controller | TASK [libvirt_manager : Filter out target nets] ********************************
2025-10-08 12:45:43.349890 | controller | Wednesday 08 October 2025  12:45:43 +0000 (0:00:00.401)       0:00:07.970 *****
2025-10-08 12:45:43.349901 | controller | ok: [instance]
2025-10-08 12:45:43.432238 | controller |
2025-10-08 12:45:43.432272 | controller | TASK [libvirt_manager : Expose cleanup list] ***********************************
2025-10-08 12:45:43.432282 | controller | Wednesday 08 October 2025  12:45:43 +0000 (0:00:00.095)       0:00:08.065 *****
2025-10-08 12:45:43.432294 | controller | ok: [instance] =>
2025-10-08 12:45:43.577914 | controller |   cleanup_nets:
2025-10-08 12:45:43.577974 | controller |   - cifmw-public
2025-10-08 12:45:43.577988 | controller |
2025-10-08 12:45:43.577997 | controller | TASK [Remove dnsmasq network bits] *********************************************
2025-10-08 12:45:43.578004 | controller | Wednesday 08 October 2025  12:45:43 +0000 (0:00:00.081)       0:00:08.147 *****
2025-10-08 12:45:43.578016 | controller |
2025-10-08 12:45:43.578041 | controller | TASK [dnsmasq : Assert mandatory parameter] ************************************
2025-10-08 12:45:43.578223 | controller | Wednesday 08 October 2025  12:45:43 +0000 (0:00:00.146)       0:00:08.294 *****
2025-10-08 12:45:43.663302 | controller | ok: [instance] => changed=false
2025-10-08 12:45:43.663417 | controller |   msg: All assertions passed
2025-10-08 12:45:43.663564 | controller |
2025-10-08 12:45:43.663661 | controller | TASK [dnsmasq : Assert mandatory parameters for new network] *******************
2025-10-08 12:45:43.663772 | controller | Wednesday 08 October 2025  12:45:43 +0000 (0:00:00.085)       0:00:08.379 *****
2025-10-08 12:45:43.743808 | controller | skipping: [instance]
2025-10-08 12:45:43.743917 | controller |
2025-10-08 12:45:43.744072 | controller | TASK [dnsmasq : Create network] ************************************************
2025-10-08 12:45:43.744201 | controller | Wednesday 08 October 2025  12:45:43 +0000 (0:00:00.080)       0:00:08.460 *****
2025-10-08 12:45:43.824247 | controller | skipping: [instance]
2025-10-08 12:45:43.824364 | controller |
2025-10-08 12:45:43.824484 | controller | TASK [dnsmasq : Remove network] ************************************************
2025-10-08 12:45:43.824602 | controller | Wednesday 08 October 2025  12:45:43 +0000 (0:00:00.080)       0:00:08.540 *****
2025-10-08 12:45:44.203088 | controller | ok: [instance]
2025-10-08 12:45:44.523498 | controller |
2025-10-08 12:45:44.523532 | controller | TASK [dnsmasq : Remove dhcp host files] ****************************************
2025-10-08 12:45:44.523542 | controller | Wednesday 08 October 2025  12:45:44 +0000 (0:00:00.378)       0:00:08.919 *****
2025-10-08 12:45:44.523555 | controller | ok: [instance]
2025-10-08 12:45:45.099798 | controller |
2025-10-08 12:45:45.099828 | controller | TASK [libvirt_manager : Destroy networks] **************************************
2025-10-08 12:45:45.099837 | controller | Wednesday 08 October 2025  12:45:44 +0000 (0:00:00.320)       0:00:09.239 *****
2025-10-08 12:45:45.099847 | controller | ok: [instance] => (item=cifmw-public)
2025-10-08 12:45:45.409989 | controller |
2025-10-08 12:45:45.410022 | controller | TASK [libvirt_manager : Undefine networks] *************************************
2025-10-08 12:45:45.410030 | controller | Wednesday 08 October 2025  12:45:45 +0000 (0:00:00.576)       0:00:09.815 *****
2025-10-08 12:45:45.410040 | controller | ok: [instance] => (item=cifmw-public)
2025-10-08 12:45:45.842090 | controller |
2025-10-08 12:45:45.842124 | controller | TASK [libvirt_manager : Ensure no trace of networks lays in nmcli] *************
2025-10-08 12:45:45.842133 | controller | Wednesday 08 October 2025  12:45:45 +0000 (0:00:00.309)       0:00:10.125 *****
2025-10-08 12:45:45.842144 | controller | ok: [instance] => (item=cifmw-public)
2025-10-08 12:45:46.192090 | controller |
2025-10-08 12:45:46.192126 | controller | TASK [libvirt_manager : Find dummy interface connection files] *****************
2025-10-08 12:45:46.192140 | controller | Wednesday 08 October 2025  12:45:45 +0000 (0:00:00.432)       0:00:10.557 *****
2025-10-08 12:45:46.192153 | controller | ok: [instance]
2025-10-08 12:45:46.192187 | controller |
2025-10-08 12:45:46.192198 | controller | TASK [libvirt_manager : Remove dummy interface connections] ********************
2025-10-08 12:45:46.506514 | controller | Wednesday 08 October 2025  12:45:46 +0000 (0:00:00.350)       0:00:10.908 *****
2025-10-08 12:45:46.506550 | 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': 1404724, 'dev': 64513, 'nlink': 1, 'atime': 1759927490.4531457, 'mtime': 1759927490.4531457, 'ctime': 1759927490.4531457, '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-08 12:45:47.011117 | controller |
2025-10-08 12:45:47.011152 | controller | TASK [libvirt_manager : Clean firewalld libvirt zone] **************************
2025-10-08 12:45:47.011161 | controller | Wednesday 08 October 2025  12:45:46 +0000 (0:00:00.314)       0:00:11.222 *****
2025-10-08 12:45:47.011171 | controller | changed: [instance] => (item=cifmw-public)
2025-10-08 12:45:47.407978 | controller |
2025-10-08 12:45:47.408022 | controller | TASK [libvirt_manager : Disable masquerade in firewalld default zone] **********
2025-10-08 12:45:47.408033 | controller | Wednesday 08 October 2025  12:45:47 +0000 (0:00:00.504)       0:00:11.726 *****
2025-10-08 12:45:47.408046 | controller | changed: [instance]
2025-10-08 12:45:47.408091 | controller |
2025-10-08 12:45:47.408305 | controller | TASK [libvirt_manager : Disable forward in firewalld libvirt zone] *************
2025-10-08 12:45:47.978536 | controller | Wednesday 08 October 2025  12:45:47 +0000 (0:00:00.397)       0:00:12.124 *****
2025-10-08 12:45:47.978572 | controller | changed: [instance]
2025-10-08 12:45:48.091913 | controller |
2025-10-08 12:45:48.091949 | controller | TASK [libvirt_manager : Remove cifmw storage pool] *****************************
2025-10-08 12:45:48.091982 | controller | Wednesday 08 October 2025  12:45:47 +0000 (0:00:00.569)       0:00:12.694 *****
2025-10-08 12:45:48.091999 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/storage_pool.yml for instance
2025-10-08 12:45:48.219791 | controller |
2025-10-08 12:45:48.219824 | controller | TASK [libvirt_manager : Ensure we have a known action] *************************
2025-10-08 12:45:48.219832 | controller | Wednesday 08 October 2025  12:45:48 +0000 (0:00:00.113)       0:00:12.807 *****
2025-10-08 12:45:48.219842 | controller | ok: [instance] => changed=false
2025-10-08 12:45:48.493485 | controller |   msg: All assertions passed
2025-10-08 12:45:48.493514 | controller |
2025-10-08 12:45:48.493522 | controller | TASK [libvirt_manager : Gather the status of cifmw-pool storage pool.] *********
2025-10-08 12:45:48.493528 | controller | Wednesday 08 October 2025  12:45:48 +0000 (0:00:00.127)       0:00:12.935 *****
2025-10-08 12:45:48.493538 | controller | changed: [instance]
2025-10-08 12:45:48.572121 | controller |
2025-10-08 12:45:48.572156 | controller | TASK [libvirt_manager : Create the storage pool] *******************************
2025-10-08 12:45:48.572166 | controller | Wednesday 08 October 2025  12:45:48 +0000 (0:00:00.273)       0:00:13.209 *****
2025-10-08 12:45:48.572178 | controller | skipping: [instance]
2025-10-08 12:45:48.572200 | controller |
2025-10-08 12:45:48.572216 | controller | TASK [libvirt_manager : Ensure the storage pool is started] ********************
2025-10-08 12:45:48.572236 | controller | Wednesday 08 October 2025  12:45:48 +0000 (0:00:00.078)       0:00:13.288 *****
2025-10-08 12:45:48.682084 | controller | skipping: [instance] => (item=pool-start)
2025-10-08 12:45:48.682119 | controller | skipping: [instance] => (item=pool-autostart)
2025-10-08 12:45:48.682128 | controller | skipping: [instance]
2025-10-08 12:45:48.682137 | controller |
2025-10-08 12:45:48.682144 | controller | TASK [libvirt_manager : Gather all the volumes in the pool to delete] **********
2025-10-08 12:45:48.682154 | controller | Wednesday 08 October 2025  12:45:48 +0000 (0:00:00.109)       0:00:13.397 *****
2025-10-08 12:45:48.760758 | controller | skipping: [instance]
2025-10-08 12:45:48.838937 | controller |
2025-10-08 12:45:48.838992 | controller | TASK [libvirt_manager : Remove the volumes from pool to delete] ****************
2025-10-08 12:45:48.839000 | controller | Wednesday 08 October 2025  12:45:48 +0000 (0:00:00.078)       0:00:13.476 *****
2025-10-08 12:45:48.839010 | controller | skipping: [instance]
2025-10-08 12:45:48.949084 | controller |
2025-10-08 12:45:48.949122 | controller | TASK [libvirt_manager : Delete storage pool] ***********************************
2025-10-08 12:45:48.949132 | controller | Wednesday 08 October 2025  12:45:48 +0000 (0:00:00.078)       0:00:13.555 *****
2025-10-08 12:45:48.949144 | controller | skipping: [instance] => (item=pool-destroy)
2025-10-08 12:45:48.949180 | controller | skipping: [instance] => (item=pool-undefine)
2025-10-08 12:45:48.949505 | controller | skipping: [instance]
2025-10-08 12:45:49.240449 | controller |
2025-10-08 12:45:49.240479 | controller | TASK [libvirt_manager : Refresh pools facts] ***********************************
2025-10-08 12:45:49.240487 | controller | Wednesday 08 October 2025  12:45:48 +0000 (0:00:00.110)       0:00:13.665 *****
2025-10-08 12:45:49.240497 | controller | ok: [instance]
2025-10-08 12:45:49.287108 | controller |
2025-10-08 12:45:49.287142 | controller | TASK [libvirt_manager : Remove overlay images from ocp_volume pools if exists] ***
2025-10-08 12:45:49.287152 | controller | Wednesday 08 October 2025  12:45:49 +0000 (0:00:00.291)       0:00:13.956 *****
2025-10-08 12:45:49.287164 | controller | skipping: [instance]
2025-10-08 12:45:49.287219 | controller |
2025-10-08 12:45:49.287236 | controller | TASK [libvirt_manager : Remove ocp_volumes storage pool] ***********************
2025-10-08 12:45:49.287246 | controller | Wednesday 08 October 2025  12:45:49 +0000 (0:00:00.046)       0:00:14.003 *****
2025-10-08 12:45:49.427751 | controller | skipping: [instance]
2025-10-08 12:45:49.473090 | controller |
2025-10-08 12:45:49.473122 | controller | TASK [libvirt_manager : Refresh all pools after actions] ***********************
2025-10-08 12:45:49.473131 | controller | Wednesday 08 October 2025  12:45:49 +0000 (0:00:00.140)       0:00:14.143 *****
2025-10-08 12:45:49.473140 | controller | skipping: [instance]
2025-10-08 12:45:49.473319 | controller |
2025-10-08 12:45:49.473339 | controller | TASK [libvirt_manager : Get temporary key status] ******************************
2025-10-08 12:45:49.766548 | controller | Wednesday 08 October 2025  12:45:49 +0000 (0:00:00.045)       0:00:14.189 *****
2025-10-08 12:45:49.766583 | controller | ok: [instance]
2025-10-08 12:45:49.815919 | controller |
2025-10-08 12:45:49.815970 | controller | TASK [libvirt_manager : Get public key] ****************************************
2025-10-08 12:45:49.815990 | controller | Wednesday 08 October 2025  12:45:49 +0000 (0:00:00.293)       0:00:14.482 *****
2025-10-08 12:45:49.816006 | controller | skipping: [instance]
2025-10-08 12:45:49.864836 | controller |
2025-10-08 12:45:49.864869 | controller | TASK [libvirt_manager : Remove public key] *************************************
2025-10-08 12:45:49.864877 | controller | Wednesday 08 October 2025  12:45:49 +0000 (0:00:00.049)       0:00:14.531 *****
2025-10-08 12:45:49.864887 | controller | skipping: [instance]
2025-10-08 12:45:49.917975 | controller |
2025-10-08 12:45:49.918007 | controller | TASK [libvirt_manager : Remove keypair] ****************************************
2025-10-08 12:45:49.918015 | controller | Wednesday 08 October 2025  12:45:49 +0000 (0:00:00.048)       0:00:14.580 *****
2025-10-08 12:45:49.918025 | controller | skipping: [instance] => (item=cifmw_reproducer_key.pub)
2025-10-08 12:45:50.125049 | controller | skipping: [instance] => (item=cifmw_reproducer_key)
2025-10-08 12:45:50.125103 | controller | skipping: [instance]
2025-10-08 12:45:50.125114 | controller |
2025-10-08 12:45:50.125121 | controller | TASK [libvirt_manager : List libvirt logs] *************************************
2025-10-08 12:45:50.125129 | controller | Wednesday 08 October 2025  12:45:49 +0000 (0:00:00.052)       0:00:14.633 *****
2025-10-08 12:45:50.125140 | controller | ok: [instance]
2025-10-08 12:45:50.125168 | controller |
2025-10-08 12:45:50.125178 | controller | TASK [libvirt_manager : Remove detected logs] **********************************
2025-10-08 12:45:50.125290 | controller | Wednesday 08 October 2025  12:45:50 +0000 (0:00:00.207)       0:00:14.841 *****
2025-10-08 12:45:50.159531 | controller | skipping: [instance]
2025-10-08 12:45:51.583100 | controller |
2025-10-08 12:45:51.583136 | controller | TASK [libvirt_manager : Remove workload and volumes] ***************************
2025-10-08 12:45:51.583145 | controller | Wednesday 08 October 2025  12:45:50 +0000 (0:00:00.034)       0:00:14.875 *****
2025-10-08 12:45:51.583155 | controller | changed: [instance] => (item=workload)
2025-10-08 12:45:51.584231 | controller | changed: [instance] => (item=volumes)
2025-10-08 12:45:51.584257 | controller | changed: [instance] => (item=artifacts/debug_network_data.yml)
2025-10-08 12:45:51.639126 | controller | changed: [instance] => (item=artifacts/debug_pub_net_value.txt)
2025-10-08 12:45:51.639164 | controller | changed: [instance] => (item=artifacts/debug_cifmw_libvirt_manager_layout.yml)
2025-10-08 12:45:51.639172 | controller | changed: [instance] => (item=artifacts/interfaces-info.yml)
2025-10-08 12:45:51.639179 | controller | changed: [instance] => (item=artifacts/libvirt-uuids.yml)
2025-10-08 12:45:51.639184 | controller | changed: [instance] => (item=artifacts/net-map-def-patch.yml)
2025-10-08 12:45:51.639190 | controller |
2025-10-08 12:45:51.639196 | controller | TASK [libvirt_manager : Deepscrub data] ****************************************
2025-10-08 12:45:51.639201 | controller | Wednesday 08 October 2025  12:45:51 +0000 (0:00:01.423)       0:00:16.299 *****
2025-10-08 12:45:51.639212 | controller | skipping: [instance] => (item=images)
2025-10-08 12:45:51.639240 | controller | skipping: [instance] => (item=artifacts/virtual-nodes.yml)
2025-10-08 12:45:51.639247 | controller | skipping: [instance]
2025-10-08 12:45:51.639253 | controller |
2025-10-08 12:45:51.639260 | controller | TASK [podman : Ensure podman is installed] *************************************
2025-10-08 12:45:51.639358 | controller | Wednesday 08 October 2025  12:45:51 +0000 (0:00:00.055)       0:00:16.354 *****
2025-10-08 12:45:53.041763 | controller | ok: [instance]
2025-10-08 12:45:53.301770 | controller |
2025-10-08 12:45:53.301807 | controller | TASK [podman : Enable loginctl linger for ansible_user_id] *********************
2025-10-08 12:45:53.301815 | controller | Wednesday 08 October 2025  12:45:53 +0000 (0:00:01.402)       0:00:17.757 *****
2025-10-08 12:45:53.301825 | controller | changed: [instance]
2025-10-08 12:45:53.369140 | controller |
2025-10-08 12:45:53.369178 | controller | TASK [podman : Ensure subordinate UID entry exists for zuul] *******************
2025-10-08 12:45:53.369187 | controller | Wednesday 08 October 2025  12:45:53 +0000 (0:00:00.259)       0:00:18.017 *****
2025-10-08 12:45:53.369197 | controller | skipping: [instance]
2025-10-08 12:45:53.369225 | controller |
2025-10-08 12:45:53.369473 | controller | TASK [podman : Ensure subordinate GID entry exists for zuul] *******************
2025-10-08 12:45:53.413075 | controller | Wednesday 08 October 2025  12:45:53 +0000 (0:00:00.067)       0:00:18.085 *****
2025-10-08 12:45:53.413125 | controller | skipping: [instance]
2025-10-08 12:45:53.413201 | controller |
2025-10-08 12:45:53.413217 | controller | TASK [podman : Run podman system migrate if subuid/subgid files were changed] ***
2025-10-08 12:45:53.413227 | controller | Wednesday 08 October 2025  12:45:53 +0000 (0:00:00.043)       0:00:18.129 *****
2025-10-08 12:45:53.482181 | controller | skipping: [instance]
2025-10-08 12:46:04.040596 | controller |
2025-10-08 12:46:04.040629 | controller | TASK [virtualbmc : Stop and remove vbmc container] *****************************
2025-10-08 12:46:04.040637 | controller | Wednesday 08 October 2025  12:45:53 +0000 (0:00:00.068)       0:00:18.197 *****
2025-10-08 12:46:04.040648 | controller | changed: [instance]
2025-10-08 12:46:05.182986 | controller |
2025-10-08 12:46:05.183018 | controller | TASK [virtualbmc : Remove vbmc container image] ********************************
2025-10-08 12:46:05.183030 | controller | Wednesday 08 October 2025  12:46:04 +0000 (0:00:10.558)       0:00:28.756 *****
2025-10-08 12:46:05.183041 | controller | changed: [instance]
2025-10-08 12:46:05.455865 | controller |
2025-10-08 12:46:05.455899 | controller | TASK [virtualbmc : Check if VBMC key exists] ***********************************
2025-10-08 12:46:05.455907 | controller | Wednesday 08 October 2025  12:46:05 +0000 (0:00:01.142)       0:00:29.898 *****
2025-10-08 12:46:05.455917 | controller | ok: [instance]
2025-10-08 12:46:05.728567 | controller |
2025-10-08 12:46:05.728601 | controller | TASK [virtualbmc : Slurp key] **************************************************
2025-10-08 12:46:05.728611 | controller | Wednesday 08 October 2025  12:46:05 +0000 (0:00:00.273)       0:00:30.171 *****
2025-10-08 12:46:05.728623 | controller | ok: [instance]
2025-10-08 12:46:06.107053 | controller |
2025-10-08 12:46:06.107082 | controller | TASK [virtualbmc : Revoke VBMC SSH access] *************************************
2025-10-08 12:46:06.107090 | controller | Wednesday 08 October 2025  12:46:05 +0000 (0:00:00.272)       0:00:30.444 *****
2025-10-08 12:46:06.107100 | controller | changed: [instance]
2025-10-08 12:46:06.107134 | controller |
2025-10-08 12:46:06.107143 | controller | TASK [virtualbmc : Remove vbmc files] ******************************************
2025-10-08 12:46:06.107265 | controller | Wednesday 08 October 2025  12:46:06 +0000 (0:00:00.378)       0:00:30.823 *****
2025-10-08 12:46:06.818043 | controller | changed: [instance] => (item=/home/zuul/.ssh/vbmc-key)
2025-10-08 12:46:06.818415 | controller | changed: [instance] => (item=/home/zuul/.ssh/vbmc-key.pub)
2025-10-08 12:46:06.818431 | controller | changed: [instance] => (item=/home/zuul/.ssh/virtualbmc.conf)
2025-10-08 12:46:06.818441 | controller | changed: [instance] => (item=/home/zuul/.ssh/vbmcd.sh)
2025-10-08 12:46:06.898985 | controller |
2025-10-08 12:46:06.899018 | controller | TASK [Clean remote ssh config] *************************************************
2025-10-08 12:46:06.899029 | controller | Wednesday 08 October 2025  12:46:06 +0000 (0:00:00.710)       0:00:31.534 *****
2025-10-08 12:46:06.899041 | controller |
2025-10-08 12:46:07.250143 | controller | TASK [ssh_jumper : Remove Include cifmw_ssh_config.d] **************************
2025-10-08 12:46:07.250204 | controller | Wednesday 08 October 2025  12:46:06 +0000 (0:00:00.080)       0:00:31.615 *****
2025-10-08 12:46:07.250219 | controller | ok: [instance]
2025-10-08 12:46:07.475615 | controller |
2025-10-08 12:46:07.475646 | controller | TASK [ssh_jumper : Remove cifmw_ssh_config.d directory] ************************
2025-10-08 12:46:07.475654 | controller | Wednesday 08 October 2025  12:46:07 +0000 (0:00:00.351)       0:00:31.966 *****
2025-10-08 12:46:07.475665 | controller | ok: [instance]
2025-10-08 12:46:07.556552 | controller |
2025-10-08 12:46:07.556583 | controller | TASK [Clean local ssh config] **************************************************
2025-10-08 12:46:07.556591 | controller | Wednesday 08 October 2025  12:46:07 +0000 (0:00:00.225)       0:00:32.191 *****
2025-10-08 12:46:07.556601 | controller |
2025-10-08 12:46:07.768188 | controller | TASK [ssh_jumper : Remove Include cifmw_ssh_config.d] **************************
2025-10-08 12:46:07.768237 | controller | Wednesday 08 October 2025  12:46:07 +0000 (0:00:00.081)       0:00:32.272 *****
2025-10-08 12:46:07.768253 | controller | ok: [instance -> localhost]
2025-10-08 12:46:08.011552 | controller |
2025-10-08 12:46:08.011586 | controller | TASK [ssh_jumper : Remove cifmw_ssh_config.d directory] ************************
2025-10-08 12:46:08.011595 | controller | Wednesday 08 October 2025  12:46:07 +0000 (0:00:00.211)       0:00:32.484 *****
2025-10-08 12:46:08.011605 | controller | ok: [instance -> localhost]
2025-10-08 12:46:08.083394 | controller |
2025-10-08 12:46:08.083430 | controller | TASK [dnsmasq : Cleaning dnsmasq] **********************************************
2025-10-08 12:46:08.083438 | controller | Wednesday 08 October 2025  12:46:08 +0000 (0:00:00.243)       0:00:32.727 *****
2025-10-08 12:46:08.083448 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/configure.yml for instance
2025-10-08 12:46:09.357504 | controller |
2025-10-08 12:46:09.357539 | controller | TASK [dnsmasq : Install needed packages] ***************************************
2025-10-08 12:46:09.357550 | controller | Wednesday 08 October 2025  12:46:08 +0000 (0:00:00.071)       0:00:32.799 *****
2025-10-08 12:46:09.357562 | controller | ok: [instance]
2025-10-08 12:46:12.882806 | controller |
2025-10-08 12:46:12.882838 | controller | TASK [dnsmasq : Ensure SELinux knows about the new files and directories] ******
2025-10-08 12:46:12.882846 | controller | Wednesday 08 October 2025  12:46:09 +0000 (0:00:01.274)       0:00:34.073 *****
2025-10-08 12:46:12.882856 | controller | changed: [instance] => (item={'target': '/etc/cifmw-dnsmasq.conf', 'setype': 'dnsmasq_etc_t'})
2025-10-08 12:46:13.130995 | controller | changed: [instance] => (item={'target': '/etc/cifmw-dnsmasq.d(/.*)?', 'setype': 'dnsmasq_etc_t'})
2025-10-08 12:46:13.131027 | controller | changed: [instance] => (item={'target': '/var/run/cifmw-dnsmasq.pid', 'setype': 'dnsmasq_var_run_t'})
2025-10-08 12:46:13.131035 | controller |
2025-10-08 12:46:13.131042 | controller | TASK [dnsmasq : Manage configuration directory] ********************************
2025-10-08 12:46:13.131047 | controller | Wednesday 08 October 2025  12:46:12 +0000 (0:00:03.525)       0:00:37.598 *****
2025-10-08 12:46:13.131057 | controller | changed: [instance]
2025-10-08 12:46:13.169923 | controller |
2025-10-08 12:46:13.169973 | controller | TASK [dnsmasq : Manage systemd unit file] **************************************
2025-10-08 12:46:13.169989 | controller | Wednesday 08 October 2025  12:46:13 +0000 (0:00:00.248)       0:00:37.846 *****
2025-10-08 12:46:13.169999 | controller | skipping: [instance]
2025-10-08 12:46:13.208114 | controller |
2025-10-08 12:46:13.208172 | controller | TASK [dnsmasq : Manage base configuration file] ********************************
2025-10-08 12:46:13.208182 | controller | Wednesday 08 October 2025  12:46:13 +0000 (0:00:00.039)       0:00:37.885 *****
2025-10-08 12:46:13.208195 | controller | skipping: [instance]
2025-10-08 12:46:13.274191 | controller |
2025-10-08 12:46:13.274223 | controller | TASK [dnsmasq : Render listener configuration] *********************************
2025-10-08 12:46:13.274231 | controller | Wednesday 08 October 2025  12:46:13 +0000 (0:00:00.038)       0:00:37.924 *****
2025-10-08 12:46:13.274241 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/listener.yml for instance
2025-10-08 12:46:13.313247 | controller |
2025-10-08 12:46:13.313275 | controller | TASK [dnsmasq : Create listener configuration file] ****************************
2025-10-08 12:46:13.313283 | controller | Wednesday 08 October 2025  12:46:13 +0000 (0:00:00.065)       0:00:37.990 *****
2025-10-08 12:46:13.313293 | controller | skipping: [instance]
2025-10-08 12:46:13.539645 | controller |
2025-10-08 12:46:13.539680 | controller | TASK [dnsmasq : Remove listener configuration file] ****************************
2025-10-08 12:46:13.539689 | controller | Wednesday 08 October 2025  12:46:13 +0000 (0:00:00.039)       0:00:38.029 *****
2025-10-08 12:46:13.539699 | controller | changed: [instance]
2025-10-08 12:46:13.606764 | controller |
2025-10-08 12:46:13.606791 | controller | TASK [dnsmasq : Render dns configuration] **************************************
2025-10-08 12:46:13.606799 | controller | Wednesday 08 October 2025  12:46:13 +0000 (0:00:00.226)       0:00:38.255 *****
2025-10-08 12:46:13.606809 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/dnsmasq/tasks/dns.yml for instance
2025-10-08 12:46:13.646987 | controller |
2025-10-08 12:46:13.647019 | controller | TASK [dnsmasq : Create dns configuration file] *********************************
2025-10-08 12:46:13.647027 | controller | Wednesday 08 October 2025  12:46:13 +0000 (0:00:00.067)       0:00:38.322 *****
2025-10-08 12:46:13.647037 | controller | skipping: [instance]
2025-10-08 12:46:13.901081 | controller |
2025-10-08 12:46:13.901118 | controller | TASK [dnsmasq : Remove dns configuration file] *********************************
2025-10-08 12:46:13.901127 | controller | Wednesday 08 October 2025  12:46:13 +0000 (0:00:00.040)       0:00:38.362 *****
2025-10-08 12:46:13.901157 | controller | changed: [instance]
2025-10-08 12:46:13.901178 | controller |
2025-10-08 12:46:13.901214 | controller | TASK [dnsmasq : Add localhost addresses from defined dnsmasq listen addresses to loopback interface] ***
2025-10-08 12:46:13.901367 | controller | Wednesday 08 October 2025  12:46:13 +0000 (0:00:00.254)       0:00:38.617 *****
2025-10-08 12:46:13.940693 | controller | skipping: [instance]
2025-10-08 12:46:13.979845 | controller |
2025-10-08 12:46:13.979877 | controller | TASK [dnsmasq : Enable and start service] **************************************
2025-10-08 12:46:13.979885 | controller | Wednesday 08 October 2025  12:46:13 +0000 (0:00:00.039)       0:00:38.656 *****
2025-10-08 12:46:13.979895 | controller | skipping: [instance]
2025-10-08 12:46:14.732795 | controller |
2025-10-08 12:46:14.732831 | controller | TASK [dnsmasq : Stop service] **************************************************
2025-10-08 12:46:14.732841 | controller | Wednesday 08 October 2025  12:46:13 +0000 (0:00:00.039)       0:00:38.695 *****
2025-10-08 12:46:14.732853 | controller | changed: [instance]
2025-10-08 12:46:14.949471 | controller |
2025-10-08 12:46:14.949501 | controller | TASK [dnsmasq : Remove unit file] **********************************************
2025-10-08 12:46:14.949509 | controller | Wednesday 08 October 2025  12:46:14 +0000 (0:00:00.752)       0:00:39.448 *****
2025-10-08 12:46:14.949519 | controller | changed: [instance]
2025-10-08 12:46:15.350682 | controller |
2025-10-08 12:46:15.350717 | controller | TASK [dnsmasq : Remove main configuration files] *******************************
2025-10-08 12:46:15.350734 | controller | Wednesday 08 October 2025  12:46:14 +0000 (0:00:00.216)       0:00:39.665 *****
2025-10-08 12:46:15.350744 | controller | changed: [instance] => (item=/etc/cifmw-dnsmasq.conf)
2025-10-08 12:46:15.643932 | controller | changed: [instance] => (item=/etc/cifmw-dnsmasq.d)
2025-10-08 12:46:15.643982 | controller |
2025-10-08 12:46:15.643990 | controller | TASK [dnsmasq : Remove lease file] *********************************************
2025-10-08 12:46:15.643996 | controller | Wednesday 08 October 2025  12:46:15 +0000 (0:00:00.401)       0:00:40.066 *****
2025-10-08 12:46:15.644007 | controller | changed: [instance]
2025-10-08 12:46:16.900932 | controller |
2025-10-08 12:46:16.900989 | controller | TASK [podman : Ensure podman is installed] *************************************
2025-10-08 12:46:16.900999 | controller | Wednesday 08 October 2025  12:46:15 +0000 (0:00:00.292)       0:00:40.359 *****
2025-10-08 12:46:16.901012 | controller | ok: [instance]
2025-10-08 12:46:17.136709 | controller |
2025-10-08 12:46:17.136740 | controller | TASK [podman : Enable loginctl linger for ansible_user_id] *********************
2025-10-08 12:46:17.136748 | controller | Wednesday 08 October 2025  12:46:16 +0000 (0:00:01.257)       0:00:41.616 *****
2025-10-08 12:46:17.136758 | controller | changed: [instance]
2025-10-08 12:46:17.182085 | controller |
2025-10-08 12:46:17.182120 | controller | TASK [podman : Ensure subordinate UID entry exists for zuul] *******************
2025-10-08 12:46:17.182132 | controller | Wednesday 08 October 2025  12:46:17 +0000 (0:00:00.235)       0:00:41.852 *****
2025-10-08 12:46:17.182144 | controller | skipping: [instance]
2025-10-08 12:46:17.224059 | controller |
2025-10-08 12:46:17.224092 | controller | TASK [podman : Ensure subordinate GID entry exists for zuul] *******************
2025-10-08 12:46:17.224101 | controller | Wednesday 08 October 2025  12:46:17 +0000 (0:00:00.045)       0:00:41.898 *****
2025-10-08 12:46:17.224112 | controller | skipping: [instance]
2025-10-08 12:46:17.319802 | controller |
2025-10-08 12:46:17.319833 | controller | TASK [podman : Run podman system migrate if subuid/subgid files were changed] ***
2025-10-08 12:46:17.319842 | controller | Wednesday 08 October 2025  12:46:17 +0000 (0:00:00.041)       0:00:41.940 *****
2025-10-08 12:46:17.319851 | controller | skipping: [instance]
2025-10-08 12:46:17.635100 | controller |
2025-10-08 12:46:17.635144 | controller | TASK [virtualbmc : Stop and remove vbmc container] *****************************
2025-10-08 12:46:17.635166 | controller | Wednesday 08 October 2025  12:46:17 +0000 (0:00:00.095)       0:00:42.035 *****
2025-10-08 12:46:17.635180 | controller | ok: [instance]
2025-10-08 12:46:17.942830 | controller |
2025-10-08 12:46:17.942864 | controller | TASK [virtualbmc : Remove vbmc container image] ********************************
2025-10-08 12:46:17.942875 | controller | Wednesday 08 October 2025  12:46:17 +0000 (0:00:00.315)       0:00:42.351 *****
2025-10-08 12:46:17.942887 | controller | ok: [instance]
2025-10-08 12:46:18.141051 | controller |
2025-10-08 12:46:18.141085 | controller | TASK [virtualbmc : Check if VBMC key exists] ***********************************
2025-10-08 12:46:18.141096 | controller | Wednesday 08 October 2025  12:46:17 +0000 (0:00:00.307)       0:00:42.658 *****
2025-10-08 12:46:18.141108 | controller | ok: [instance]
2025-10-08 12:46:18.179034 | controller |
2025-10-08 12:46:18.179064 | controller | TASK [virtualbmc : Slurp key] **************************************************
2025-10-08 12:46:18.179073 | controller | Wednesday 08 October 2025  12:46:18 +0000 (0:00:00.198)       0:00:42.857 *****
2025-10-08 12:46:18.179084 | controller | skipping: [instance]
2025-10-08 12:46:18.179283 | controller |
2025-10-08 12:46:18.179306 | controller | TASK [virtualbmc : Revoke VBMC SSH access] *************************************
2025-10-08 12:46:18.216673 | controller | Wednesday 08 October 2025  12:46:18 +0000 (0:00:00.038)       0:00:42.895 *****
2025-10-08 12:46:18.216700 | controller | skipping: [instance]
2025-10-08 12:46:19.019082 | controller |
2025-10-08 12:46:19.019122 | controller | TASK [virtualbmc : Remove vbmc files] ******************************************
2025-10-08 12:46:19.019131 | controller | Wednesday 08 October 2025  12:46:18 +0000 (0:00:00.037)       0:00:42.932 *****
2025-10-08 12:46:19.019141 | controller | ok: [instance] => (item=/home/zuul/.ssh/vbmc-key)
2025-10-08 12:46:19.851974 | controller | ok: [instance] => (item=/home/zuul/.ssh/vbmc-key.pub)
2025-10-08 12:46:19.852013 | controller | ok: [instance] => (item=/home/zuul/.ssh/virtualbmc.conf)
2025-10-08 12:46:19.852021 | controller | ok: [instance] => (item=/home/zuul/.ssh/vbmcd.sh)
2025-10-08 12:46:19.852028 | controller |
2025-10-08 12:46:19.852033 | controller | RUNNING HANDLER [libvirt_manager : Restart firewalld] **************************
2025-10-08 12:46:19.852039 | controller | Wednesday 08 October 2025  12:46:19 +0000 (0:00:00.801)       0:00:43.734 *****
2025-10-08 12:46:19.852051 | controller | changed: [instance]
2025-10-08 12:46:19.852079 | controller |
2025-10-08 12:46:19.852086 | controller | PLAY RECAP *********************************************************************
2025-10-08 12:46:19.852092 | controller | instance                   : ok=66   changed=21   unreachable=0    failed=0    skipped=29   rescued=0    ignored=0
2025-10-08 12:46:19.852097 | controller |
2025-10-08 12:46:19.852103 | controller | Wednesday 08 October 2025  12:46:19 +0000 (0:00:00.832)       0:00:44.566 *****
2025-10-08 12:46:19.852108 | controller | ===============================================================================
2025-10-08 12:46:19.852113 | controller | virtualbmc : Stop and remove vbmc container ---------------------------- 10.56s
2025-10-08 12:46:19.852118 | controller | dnsmasq : Ensure SELinux knows about the new files and directories ------ 3.53s
2025-10-08 12:46:19.852124 | controller | libvirt_manager : Populate service facts -------------------------------- 2.30s
2025-10-08 12:46:19.852129 | controller | libvirt_manager : Remove workload and volumes --------------------------- 1.42s
2025-10-08 12:46:19.852134 | controller | podman : Ensure podman is installed ------------------------------------- 1.40s
2025-10-08 12:46:19.852139 | controller | dnsmasq : Install needed packages --------------------------------------- 1.27s
2025-10-08 12:46:19.852145 | controller | podman : Ensure podman is installed ------------------------------------- 1.26s
2025-10-08 12:46:19.852150 | controller | virtualbmc : Remove vbmc container image -------------------------------- 1.14s
2025-10-08 12:46:19.852166 | controller | libvirt_manager : Start virtqemud socket service ------------------------ 0.90s
2025-10-08 12:46:19.852175 | controller | Gathering Facts --------------------------------------------------------- 0.86s
2025-10-08 12:46:19.852183 | controller | libvirt_manager : Restart firewalld ------------------------------------- 0.83s
2025-10-08 12:46:19.852206 | controller | virtualbmc : Remove vbmc files ------------------------------------------ 0.80s
2025-10-08 12:46:19.852873 | controller | libvirt_manager : Get installed packages list --------------------------- 0.80s
2025-10-08 12:46:19.852906 | controller | dnsmasq : Stop service -------------------------------------------------- 0.75s
2025-10-08 12:46:19.930908 | controller | virtualbmc : Remove vbmc files ------------------------------------------ 0.71s
2025-10-08 12:46:19.930940 | controller | libvirt_manager : Destroy networks -------------------------------------- 0.58s
2025-10-08 12:46:19.930948 | controller | libvirt_manager : Disable forward in firewalld libvirt zone ------------- 0.57s
2025-10-08 12:46:19.930979 | controller | libvirt_manager : Clean firewalld libvirt zone -------------------------- 0.50s
2025-10-08 12:46:19.930985 | controller | libvirt_manager : Ensure no trace of networks lays in nmcli ------------- 0.43s
2025-10-08 12:46:19.930990 | controller | libvirt_manager : List all of the existing virtual machines ------------- 0.40s
2025-10-08 12:46:19.931000 | controller | INFO     Writing /tmp/report.html report.
2025-10-08 12:46:20.351772 | [controller] Waiting on logger
2025-10-08 12:46:25.522299 | [controller] Waiting on logger
2025-10-08 12:46:35.954398 | [controller] Waiting on logger
2025-10-08 12:46:46.386390 | [controller] Waiting on logger
2025-10-08 12:46:50.023999 | [Zuul] Log Stream did not terminate
2025-10-08 12:46:50.024162 | controller | changed
2025-10-08 12:46:50.052604 | 
2025-10-08 12:46:50.052679 | PLAY RECAP
2025-10-08 12:46:50.052728 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-08 12:46:50.052752 | 
2025-10-08 12:46:50.143804 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-08 12:46:50.144666 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-08 12:46:50.688213 | 
2025-10-08 12:46:50.688322 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-10-08 12:46:50.708820 | 
2025-10-08 12:46:50.708938 | TASK [Filter out host if needed]
2025-10-08 12:46:50.717544 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-10-08 12:46:50.722073 | 
2025-10-08 12:46:50.722143 | TASK [Ensure file is present]
2025-10-08 12:46:51.041051 | controller | ok
2025-10-08 12:46:51.048256 | 
2025-10-08 12:46:51.048340 | TASK [Manage molecule report file]
2025-10-08 12:46:51.069982 | [controller] Waiting on logger
2025-10-08 12:47:00.438978 | [controller] Waiting on logger
2025-10-08 12:47:10.834434 | [controller] Waiting on logger
2025-10-08 12:47:21.266349 | [controller] Waiting on logger
2025-10-08 12:47:21.405669 | [Zuul] Log Stream did not terminate
2025-10-08 12:47:21.405869 | controller | changed
2025-10-08 12:47:21.411364 | 
2025-10-08 12:47:21.411431 | TASK [Check if we get ci-framework-data basedir]
2025-10-08 12:47:21.604132 | controller | ok
2025-10-08 12:47:21.610768 | 
2025-10-08 12:47:21.610861 | TASK [Create ci-framework-data log directory for zuul]
2025-10-08 12:47:21.946067 | controller | changed
2025-10-08 12:47:21.965753 | 
2025-10-08 12:47:21.965846 | TASK [Copy ci-framework interesting files]
2025-10-08 12:47:26.997873 | controller | changed
2025-10-08 12:47:27.004141 | 
2025-10-08 12:47:27.004229 | TASK [Get SELinux listing]
2025-10-08 12:47:27.026691 | [controller] Waiting on logger
2025-10-08 12:47:34.706422 | [controller] Waiting on logger
2025-10-08 12:47:48.786513 | [controller] Waiting on logger
2025-10-08 12:47:55.378452 | [controller] Waiting on logger
2025-10-08 12:47:57.273834 | [Zuul] Log Stream did not terminate
2025-10-08 12:47:57.274015 | controller | changed
2025-10-08 12:47:57.286089 | 
2025-10-08 12:47:57.286161 | TASK [Generate log index]
2025-10-08 12:47:57.944389 | controller | changed
2025-10-08 12:47:57.949169 | 
2025-10-08 12:47:57.949236 | TASK [Get some env related data]
2025-10-08 12:48:02.979427 | controller | changed
2025-10-08 12:48:02.985259 | 
2025-10-08 12:48:02.985343 | TASK [Generate list of logs to collect in home directory]
2025-10-08 12:48:03.289379 | controller | ok: All paths examined
2025-10-08 12:48:03.295047 | 
2025-10-08 12:48:03.295132 | LOOP [Copy logs from home directory]
2025-10-08 12:48:03.678210 | controller | changed:
2025-10-08 12:48:03.678309 | controller | {
2025-10-08 12:48:03.678337 | controller |   "atime": 1759927285.6576116,
2025-10-08 12:48:03.678358 | controller |   "ctime": 1759927301.6938112,
2025-10-08 12:48:03.678382 | controller |   "dev": 64513,
2025-10-08 12:48:03.678402 | controller |   "gid": 1000,
2025-10-08 12:48:03.678420 | controller |   "gr_name": "zuul",
2025-10-08 12:48:03.678437 | controller |   "inode": 4449721,
2025-10-08 12:48:03.678453 | controller |   "isblk": false,
2025-10-08 12:48:03.678469 | controller |   "ischr": false,
2025-10-08 12:48:03.678485 | controller |   "isdir": false,
2025-10-08 12:48:03.678500 | controller |   "isfifo": false,
2025-10-08 12:48:03.678515 | controller |   "isgid": false,
2025-10-08 12:48:03.678534 | controller |   "islnk": false,
2025-10-08 12:48:03.678551 | controller |   "isreg": true,
2025-10-08 12:48:03.678568 | controller |   "issock": false,
2025-10-08 12:48:03.678584 | controller |   "isuid": false,
2025-10-08 12:48:03.678599 | controller |   "mode": "0644",
2025-10-08 12:48:03.678614 | controller |   "mtime": 1759927301.6938112,
2025-10-08 12:48:03.678630 | controller |   "nlink": 1,
2025-10-08 12:48:03.678645 | controller |   "path": "/home/zuul/ansible.log",
2025-10-08 12:48:03.678663 | controller |   "pw_name": "zuul",
2025-10-08 12:48:03.678680 | controller |   "rgrp": true,
2025-10-08 12:48:03.678695 | controller |   "roth": true,
2025-10-08 12:48:03.678711 | controller |   "rusr": true,
2025-10-08 12:48:03.678726 | controller |   "size": 6749,
2025-10-08 12:48:03.678742 | controller |   "uid": 1000,
2025-10-08 12:48:03.678758 | controller |   "wgrp": false,
2025-10-08 12:48:03.678774 | controller |   "woth": false,
2025-10-08 12:48:03.678790 | controller |   "wusr": true,
2025-10-08 12:48:03.678806 | controller |   "xgrp": false,
2025-10-08 12:48:03.678822 | controller |   "xoth": false,
2025-10-08 12:48:03.678837 | controller |   "xusr": false
2025-10-08 12:48:03.678851 | controller | }
2025-10-08 12:48:03.687145 | 
2025-10-08 12:48:03.687246 | TASK [Copy crio stats log file]
2025-10-08 12:48:03.711771 | controller | skipping: Conditional result was False
2025-10-08 12:48:03.718529 | 
2025-10-08 12:48:03.718602 | TASK [Get SELinux related data]
2025-10-08 12:48:03.761094 | [controller] Waiting on logger
2025-10-08 12:48:14.194594 | [controller] Waiting on logger
2025-10-08 12:48:23.538330 | [controller] Waiting on logger
2025-10-08 12:48:33.970352 | [controller] Waiting on logger
2025-10-08 12:48:33.977080 | [Zuul] Log Stream did not terminate
2025-10-08 12:48:33.977275 | controller | ERROR
2025-10-08 12:48:33.977381 | controller | {
2025-10-08 12:48:33.977412 | controller |   "delta": "0:00:00.008949",
2025-10-08 12:48:33.977434 | controller |   "end": "2025-10-08 12:48:03.947343",
2025-10-08 12:48:33.977453 | controller |   "msg": "non-zero return code",
2025-10-08 12:48:33.977471 | controller |   "rc": 1,
2025-10-08 12:48:33.977489 | controller |   "start": "2025-10-08 12:48:03.938394"
2025-10-08 12:48:33.977505 | controller | }
2025-10-08 12:48:33.977531 | controller | ERROR: Ignoring Errors
2025-10-08 12:48:33.982988 | 
2025-10-08 12:48:33.983087 | TASK [Create system configuration directory]
2025-10-08 12:48:34.184377 | controller | changed
2025-10-08 12:48:34.190029 | 
2025-10-08 12:48:34.190099 | TASK [Get some of the system configurations]
2025-10-08 12:48:39.218138 | controller | changed
2025-10-08 12:48:39.224072 | 
2025-10-08 12:48:39.224162 | TASK [Copy generated documentation if available]
2025-10-08 12:48:39.247773 | controller | skipping: Conditional result was False
2025-10-08 12:48:39.253780 | 
2025-10-08 12:48:39.253851 | TASK [Copy generated AsciiDoc documentation if available]
2025-10-08 12:48:39.268007 | controller | skipping: Conditional result was False
2025-10-08 12:48:39.274970 | 
2025-10-08 12:48:39.275049 | TASK [Compress logs bigger than 2MB]
2025-10-08 12:48:42.354367 | [controller] Waiting on logger
2025-10-08 12:48:52.786251 | [controller] Waiting on logger
2025-10-08 12:49:03.218350 | [controller] Waiting on logger
2025-10-08 12:49:09.498872 | [Zuul] Log Stream did not terminate
2025-10-08 12:49:09.499055 | controller | changed
2025-10-08 12:49:09.504821 | 
2025-10-08 12:49:09.504889 | TASK [Copy files from workspace on node]
2025-10-08 12:49:09.523290 | controller | ok
2025-10-08 12:49:09.547237 | 
2025-10-08 12:49:09.547310 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-08 12:49:09.570807 | controller | skipping: Conditional result was False
2025-10-08 12:49:09.577112 | 
2025-10-08 12:49:09.577188 | TASK [fetch-output : Set log path for single node]
2025-10-08 12:49:09.607115 | controller | ok
2025-10-08 12:49:09.611896 | 
2025-10-08 12:49:09.611995 | LOOP [fetch-output : Ensure local output dirs]
2025-10-08 12:49:09.875441 | controller -> localhost | ok: "/var/lib/zuul/builds/849a4dc819e84bd080920a22c783739b/work/logs"
2025-10-08 12:49:09.875659 | controller -> localhost | changed: All items complete
2025-10-08 12:49:09.875691 | 
2025-10-08 12:49:10.098508 | controller -> localhost | changed: "/var/lib/zuul/builds/849a4dc819e84bd080920a22c783739b/work/artifacts"
2025-10-08 12:49:10.343262 | controller -> localhost | changed: "/var/lib/zuul/builds/849a4dc819e84bd080920a22c783739b/work/docs"
2025-10-08 12:49:10.356995 | 
2025-10-08 12:49:10.357095 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-08 12:49:11.075075 | controller | changed:
2025-10-08 12:49:11.075247 | controller | .d..t...... ./
2025-10-08 12:49:11.075279 | controller | >f+++++++++ README.html
2025-10-08 12:49:11.075302 | controller | >f+++++++++ ansible-execution.log
2025-10-08 12:49:11.075325 | controller | >f+++++++++ ansible.log
2025-10-08 12:49:11.075345 | controller | >f+++++++++ dmesg.log
2025-10-08 12:49:11.075364 | controller | >f+++++++++ installed-pkgs.log
2025-10-08 12:49:11.076016 | controller | >f+++++++++ python.log
2025-10-08 12:49:11.076179 | controller | >f+++++++++ registries.conf
2025-10-08 12:49:11.076610 | controller | >f+++++++++ report.html
2025-10-08 12:49:11.076647 | controller | >f+++++++++ selinux-denials.log
2025-10-08 12:49:11.076670 | controller | >f+++++++++ selinux-listing.log
2025-10-08 12:49:11.076690 | controller | cd+++++++++ ci-framework-data/
2025-10-08 12:49:11.076709 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-10-08 12:49:11.076726 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-10-08 12:49:11.076744 | controller | cd+++++++++ ci-framework-data/artifacts/nmstate/
2025-10-08 12:49:11.076761 | controller | >f+++++++++ ci-framework-data/artifacts/nmstate/instance-final-state.yaml
2025-10-08 12:49:11.076777 | controller | >f+++++++++ ci-framework-data/artifacts/nmstate/instance-state.yaml
2025-10-08 12:49:11.076793 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-10-08 12:49:11.076809 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-10-08 12:49:11.076824 | controller | cd+++++++++ ci-framework-data/artifacts/repositories/
2025-10-08 12:49:11.076840 | controller | >f+++++++++ ci-framework-data/artifacts/repositories/delorean.repo.md5
2025-10-08 12:49:11.076856 | controller | cd+++++++++ ci-framework-data/logs/
2025-10-08 12:49:11.076873 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-10-08 12:49:11.076892 | controller | cd+++++++++ registries.conf.d/
2025-10-08 12:49:11.076945 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-10-08 12:49:11.076973 | controller | cd+++++++++ system-config/
2025-10-08 12:49:11.076993 | controller | cd+++++++++ system-config/libvirt/
2025-10-08 12:49:11.077010 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-10-08 12:49:11.077026 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-10-08 12:49:11.077043 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf
2025-10-08 12:49:11.077058 | controller | >f+++++++++ system-config/libvirt/network.conf
2025-10-08 12:49:11.077073 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf
2025-10-08 12:49:11.077088 | controller | >f+++++++++ system-config/libvirt/qemu.conf
2025-10-08 12:49:11.077103 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf
2025-10-08 12:49:11.077124 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf
2025-10-08 12:49:11.077141 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf
2025-10-08 12:49:11.077157 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf
2025-10-08 12:49:11.077172 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf
2025-10-08 12:49:11.077188 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf
2025-10-08 12:49:11.077205 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf
2025-10-08 12:49:11.077221 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf
2025-10-08 12:49:11.077237 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf
2025-10-08 12:49:11.077254 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf
2025-10-08 12:49:11.479766 | controller | changed: .d..t...... ./
2025-10-08 12:49:11.847657 | controller | changed: .d..t...... ./
2025-10-08 12:49:11.867832 | 
2025-10-08 12:49:11.867978 | TASK [Return artifact to Zuul]
2025-10-08 12:49:11.903545 | controller | ok
2025-10-08 12:49:11.923888 | 
2025-10-08 12:49:11.924020 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-10-08 12:49:11.924135 | 
2025-10-08 12:49:11.924163 | PLAY RECAP
2025-10-08 12:49:11.924202 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-10-08 12:49:11.924223 | 
2025-10-08 12:49:12.022300 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-08 12:49:12.023123 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-08 12:49:12.577009 | 
2025-10-08 12:49:12.577154 | PLAY [all]
2025-10-08 12:49:12.603035 | 
2025-10-08 12:49:12.603151 | TASK [include_role : fetch-output]
2025-10-08 12:49:12.631481 | controller | ok
2025-10-08 12:49:12.648636 | 
2025-10-08 12:49:12.648742 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-08 12:49:12.693094 | controller | skipping: Conditional result was False
2025-10-08 12:49:12.699570 | 
2025-10-08 12:49:12.699673 | TASK [fetch-output : Set log path for single node]
2025-10-08 12:49:12.731166 | controller | ok
2025-10-08 12:49:12.736502 | 
2025-10-08 12:49:12.736605 | LOOP [fetch-output : Ensure local output dirs]
2025-10-08 12:49:13.111311 | controller -> localhost | ok: "/var/lib/zuul/builds/849a4dc819e84bd080920a22c783739b/work/logs"
2025-10-08 12:49:13.293222 | controller -> localhost | ok: "/var/lib/zuul/builds/849a4dc819e84bd080920a22c783739b/work/artifacts"
2025-10-08 12:49:13.492707 | controller -> localhost | ok: "/var/lib/zuul/builds/849a4dc819e84bd080920a22c783739b/work/docs"
2025-10-08 12:49:13.507612 | 
2025-10-08 12:49:13.507708 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-08 12:49:14.017088 | controller | ok
2025-10-08 12:49:14.017298 | controller | ok: All items complete
2025-10-08 12:49:14.017333 | 
2025-10-08 12:49:14.392275 | controller | ok
2025-10-08 12:49:14.787304 | controller | ok
2025-10-08 12:49:14.798117 | 
2025-10-08 12:49:14.798207 | TASK [include_role : fetch-output-openshift]
2025-10-08 12:49:14.811811 | controller | skipping: Conditional result was False
2025-10-08 12:49:14.818128 | 
2025-10-08 12:49:14.818209 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-08 12:49:15.166332 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.008177
2025-10-08 12:49:15.358119 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006778
2025-10-08 12:49:15.382893 | 
2025-10-08 12:49:15.382998 | PLAY [all]
2025-10-08 12:49:15.396372 | 
2025-10-08 12:49:15.396440 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-08 12:49:15.823059 | controller | changed
2025-10-08 12:49:15.844357 | 
2025-10-08 12:49:15.844420 | PLAY RECAP
2025-10-08 12:49:15.844463 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-08 12:49:15.844486 | 
2025-10-08 12:49:15.921670 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-08 12:49:15.922516 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-08 12:49:16.484747 | 
2025-10-08 12:49:16.484853 | PLAY [localhost]
2025-10-08 12:49:16.503028 | 
2025-10-08 12:49:16.503108 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-08 12:49:16.868151 | localhost | changed
2025-10-08 12:49:16.872629 | 
2025-10-08 12:49:16.872707 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-08 12:49:16.911351 | localhost | ok
2025-10-08 12:49:16.919226 | 
2025-10-08 12:49:16.919307 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-08 12:49:17.233343 | localhost | changed
2025-10-08 12:49:17.240279 | 
2025-10-08 12:49:17.240375 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-08 12:49:17.805231 | localhost | changed
2025-10-08 12:49:17.811210 | 
2025-10-08 12:49:17.811292 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-08 12:49:18.157309 | localhost | Identity added: /var/lib/zuul/builds/849a4dc819e84bd080920a22c783739b/work/tmp/ansible.i3jkbowv (/var/lib/zuul/builds/849a4dc819e84bd080920a22c783739b/work/tmp/ansible.i3jkbowv)
2025-10-08 12:49:18.157487 | localhost | ok: Runtime: 0:00:00.006551
2025-10-08 12:49:18.161748 | 
2025-10-08 12:49:18.161821 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-08 12:49:18.398687 | localhost | ok: Runtime: 0:00:00.005370
2025-10-08 12:49:18.403479 | 
2025-10-08 12:49:18.403548 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-08 12:49:18.452736 | localhost | changed
2025-10-08 12:49:18.457220 | 
2025-10-08 12:49:18.457294 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-08 12:49:18.783602 | localhost | changed
2025-10-08 12:49:18.804729 | 
2025-10-08 12:49:18.804813 | PLAY [localhost]
2025-10-08 12:49:18.817188 | 
2025-10-08 12:49:18.817257 | TASK [Generate bulk log download script]
2025-10-08 12:49:18.836324 | localhost | ok
2025-10-08 12:49:18.848442 | 
2025-10-08 12:49:18.848516 | TASK [local-log-download : Check API endpoint is defined]
2025-10-08 12:49:18.876574 | localhost | ok: All assertions passed
2025-10-08 12:49:18.881612 | 
2025-10-08 12:49:18.881687 | TASK [local-log-download : Create download script]
2025-10-08 12:49:19.293997 | localhost -> localhost | changed
2025-10-08 12:49:19.302675 | 
2025-10-08 12:49:19.302756 | TASK [Register quick-download link]
2025-10-08 12:49:19.321754 | localhost | ok
2025-10-08 12:49:19.363619 | 
2025-10-08 12:49:19.363711 | PLAY [logserver.rdoproject.org]
2025-10-08 12:49:19.374291 | 
2025-10-08 12:49:19.374357 | TASK [Set zuul-log-path fact]
2025-10-08 12:49:19.390552 | logserver.rdoproject.org | ok
2025-10-08 12:49:19.400989 | 
2025-10-08 12:49:19.401082 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-08 12:49:19.427614 | logserver.rdoproject.org | ok
2025-10-08 12:49:19.433193 | 
2025-10-08 12:49:19.433283 | TASK [upload-logs : Create log directories]
2025-10-08 12:49:21.141642 | logserver.rdoproject.org | changed
2025-10-08 12:49:21.144980 | 
2025-10-08 12:49:21.145057 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-08 12:49:21.375818 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004935
2025-10-08 12:49:21.380586 | 
2025-10-08 12:49:21.380750 | TASK [upload-logs : Upload logs to log server]
2025-10-08 12:49:22.938247 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-08 12:49:22.941465 | 
2025-10-08 12:49:22.941537 | LOOP [upload-logs : Compress console log and json output]
2025-10-08 12:49:22.981749 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 12:49:22.990579 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 12:49:22.998975 | 
2025-10-08 12:49:22.999045 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-08 12:49:23.036216 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 12:49:23.036434 | 
2025-10-08 12:49:23.040292 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 12:49:23.047000 | 
2025-10-08 12:49:23.047072 | LOOP [upload-logs : Upload console log and json output]