2025-12-10 11:33:23.857222 | Job console starting...
2025-12-10 11:33:24.070158 | Updating repositories
2025-12-10 11:33:24.807378 | Preparing job workspace
2025-12-10 11:33:31.716249 | Running Ansible setup...
2025-12-10 11:33:34.476477 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-10 11:33:34.965065 | 
2025-12-10 11:33:34.965167 | PLAY [localhost]
2025-12-10 11:33:34.973652 | 
2025-12-10 11:33:34.973724 | TASK [Gathering Facts]
2025-12-10 11:33:35.759116 | localhost | ok
2025-12-10 11:33:35.772162 | 
2025-12-10 11:33:35.772241 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-10 11:33:36.069606 | localhost -> localhost | changed
2025-12-10 11:33:36.075161 | 
2025-12-10 11:33:36.075231 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-10 11:33:36.746781 | localhost -> localhost | changed
2025-12-10 11:33:36.755000 | 
2025-12-10 11:33:36.755077 | TASK [Setup log path fact]
2025-12-10 11:33:36.772433 | localhost | ok
2025-12-10 11:33:36.783718 | 
2025-12-10 11:33:36.783788 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-10 11:33:36.800690 | localhost | ok
2025-12-10 11:33:36.808257 | 
2025-12-10 11:33:36.808326 | TASK [emit-job-header : Print job information]
2025-12-10 11:33:36.835385 | # Job Information
2025-12-10 11:33:36.835498 | Ansible Version: 2.15.12
2025-12-10 11:33:36.835529 | Job: cifmw-molecule-nat64_appliance
2025-12-10 11:33:36.835553 | Pipeline: github-check
2025-12-10 11:33:36.835573 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-12-10 11:33:36.835595 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3545
2025-12-10 11:33:36.835617 | Log URL (when completed): https://logserver.rdoproject.org/b1d/rdoproject.org/b1dbf66fe9ab464d90e0238ab83e43c3/
2025-12-10 11:33:36.835648 | Event ID: e8c85890-d5bb-11f0-8f6a-588f85dc2eba
2025-12-10 11:33:36.839425 | 
2025-12-10 11:33:36.839490 | LOOP [emit-job-header : Print node information]
2025-12-10 11:33:36.922162 | localhost | ok:
2025-12-10 11:33:36.922318 | localhost | # Node Information
2025-12-10 11:33:36.922350 | localhost | Inventory Hostname: controller
2025-12-10 11:33:36.922375 | localhost | Hostname: np0005553491
2025-12-10 11:33:36.922396 | localhost | Username: zuul
2025-12-10 11:33:36.922417 | localhost | Distro: CentOS 9
2025-12-10 11:33:36.922436 | localhost | Provider: ibm-bm4-nodepool
2025-12-10 11:33:36.922453 | localhost | Region: regionOne
2025-12-10 11:33:36.922470 | localhost | Label: cloud-centos-9-stream-tripleo-ibm
2025-12-10 11:33:36.922487 | localhost | Product Name: OpenStack Compute
2025-12-10 11:33:36.922504 | localhost | Interface IP: 192.168.26.113
2025-12-10 11:33:36.941459 | 
2025-12-10 11:33:36.941538 | PLAY [all]
2025-12-10 11:33:36.947535 | 
2025-12-10 11:33:36.947600 | TASK [Gather network facts]
2025-12-10 11:33:37.311171 | controller | ok
2025-12-10 11:33:37.324687 | 
2025-12-10 11:33:37.324752 | TASK [include_role : start-zuul-console]
2025-12-10 11:33:37.341761 | controller | ok
2025-12-10 11:33:37.353386 | 
2025-12-10 11:33:37.353451 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-10 11:33:37.634291 | controller | ok
2025-12-10 11:33:37.642822 | 
2025-12-10 11:33:37.642881 | TASK [include_role : add-build-sshkey]
2025-12-10 11:33:37.659970 | controller | ok
2025-12-10 11:33:37.672082 | 
2025-12-10 11:33:37.672142 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-10 11:33:37.857079 | controller -> localhost | ok
2025-12-10 11:33:37.862264 | 
2025-12-10 11:33:37.862349 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-10 11:33:37.879460 | controller | ok
2025-12-10 11:33:37.891986 | controller | included: /var/lib/zuul/builds/b1dbf66fe9ab464d90e0238ab83e43c3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-10 11:33:37.897162 | 
2025-12-10 11:33:37.897221 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-10 11:33:38.314534 | controller -> localhost | Generating public/private rsa key pair.
2025-12-10 11:33:38.314697 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b1dbf66fe9ab464d90e0238ab83e43c3/work/b1dbf66fe9ab464d90e0238ab83e43c3_id_rsa.
2025-12-10 11:33:38.314729 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b1dbf66fe9ab464d90e0238ab83e43c3/work/b1dbf66fe9ab464d90e0238ab83e43c3_id_rsa.pub.
2025-12-10 11:33:38.314751 | controller -> localhost | The key fingerprint is:
2025-12-10 11:33:38.314770 | controller -> localhost | SHA256:zWRU5Eni/0qK4XTPhiXTfzIfEfHtYuYhwWJhE1RN20U zuul-build-sshkey
2025-12-10 11:33:38.314788 | controller -> localhost | The key's randomart image is:
2025-12-10 11:33:38.314806 | controller -> localhost | +---[RSA 3072]----+
2025-12-10 11:33:38.314824 | controller -> localhost | |         .O==o.oE|
2025-12-10 11:33:38.314840 | controller -> localhost | |         + B ..o=|
2025-12-10 11:33:38.314856 | controller -> localhost | |          * = ..+|
2025-12-10 11:33:38.314872 | controller -> localhost | |         * o . ..|
2025-12-10 11:33:38.314887 | controller -> localhost | |        S o.o =..|
2025-12-10 11:33:38.314902 | controller -> localhost | |          o o* o.|
2025-12-10 11:33:38.314973 | controller -> localhost | |        o .=..o. |
2025-12-10 11:33:38.314997 | controller -> localhost | |       o +.=..+ o|
2025-12-10 11:33:38.315015 | controller -> localhost | |        o ..+  =.|
2025-12-10 11:33:38.315031 | controller -> localhost | +----[SHA256]-----+
2025-12-10 11:33:38.315070 | controller -> localhost | ok: Runtime: 0:00:00.114336
2025-12-10 11:33:38.320108 | 
2025-12-10 11:33:38.320165 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-10 11:33:38.336886 | controller | ok
2025-12-10 11:33:38.345314 | controller | included: /var/lib/zuul/builds/b1dbf66fe9ab464d90e0238ab83e43c3/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-10 11:33:38.352213 | 
2025-12-10 11:33:38.352279 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-10 11:33:38.365305 | controller | skipping: Conditional result was False
2025-12-10 11:33:38.370344 | 
2025-12-10 11:33:38.370412 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-10 11:33:38.701796 | controller | changed
2025-12-10 11:33:38.707512 | 
2025-12-10 11:33:38.707574 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-10 11:33:38.888846 | controller | ok
2025-12-10 11:33:38.893345 | 
2025-12-10 11:33:38.893403 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-10 11:33:39.428390 | controller | changed
2025-12-10 11:33:39.433020 | 
2025-12-10 11:33:39.433082 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-10 11:33:39.968307 | controller | changed
2025-12-10 11:33:39.972901 | 
2025-12-10 11:33:39.972979 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-10 11:33:39.986610 | controller | skipping: Conditional result was False
2025-12-10 11:33:39.991487 | 
2025-12-10 11:33:39.991550 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-10 11:33:40.278870 | controller -> localhost | changed
2025-12-10 11:33:40.287720 | 
2025-12-10 11:33:40.287785 | TASK [add-build-sshkey : Add back temp key]
2025-12-10 11:33:40.494270 | controller -> localhost | Identity added: /var/lib/zuul/builds/b1dbf66fe9ab464d90e0238ab83e43c3/work/b1dbf66fe9ab464d90e0238ab83e43c3_id_rsa (zuul-build-sshkey)
2025-12-10 11:33:40.494514 | controller -> localhost | ok: Runtime: 0:00:00.006709
2025-12-10 11:33:40.500394 | 
2025-12-10 11:33:40.500462 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-10 11:33:40.780974 | controller | ok
2025-12-10 11:33:40.785128 | 
2025-12-10 11:33:40.785187 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-10 11:33:40.808300 | controller | skipping: Conditional result was False
2025-12-10 11:33:40.816648 | 
2025-12-10 11:33:40.816709 | TASK [include_role : validate-host]
2025-12-10 11:33:40.833135 | controller | ok
2025-12-10 11:33:40.851071 | 
2025-12-10 11:33:40.851133 | TASK [validate-host : Define zuul_info_dir fact]
2025-12-10 11:33:40.878070 | controller | ok
2025-12-10 11:33:40.882514 | 
2025-12-10 11:33:40.882577 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-12-10 11:33:41.067353 | controller -> localhost | ok
2025-12-10 11:33:41.072941 | 
2025-12-10 11:33:41.073016 | TASK [validate-host : Collect information about the host]
2025-12-10 11:33:41.689466 | controller | ok
2025-12-10 11:33:41.697434 | 
2025-12-10 11:33:41.697501 | TASK [validate-host : Sanitize hostname]
2025-12-10 11:33:41.755857 | controller | ok
2025-12-10 11:33:41.760452 | 
2025-12-10 11:33:41.760516 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-12-10 11:33:42.129946 | controller -> localhost | changed
2025-12-10 11:33:42.155771 | 
2025-12-10 11:33:42.155848 | TASK [validate-host : Collect information about zuul worker]
2025-12-10 11:33:42.467342 | controller | ok
2025-12-10 11:33:42.471748 | 
2025-12-10 11:33:42.471808 | TASK [validate-host : Write out all zuul information for each host]
2025-12-10 11:33:42.829600 | controller -> localhost | changed
2025-12-10 11:33:42.838440 | 
2025-12-10 11:33:42.838502 | TASK [include_role : prepare-workspace-openshift]
2025-12-10 11:33:42.851853 | controller | skipping: Conditional result was False
2025-12-10 11:33:42.856611 | 
2025-12-10 11:33:42.856676 | TASK [include_role : remove-zuul-sshkey]
2025-12-10 11:33:42.869678 | controller | skipping: Conditional result was False
2025-12-10 11:33:42.874517 | 
2025-12-10 11:33:42.874583 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-10 11:33:43.051625 | controller | ok: "logs"
2025-12-10 11:33:43.051899 | controller | ok: All items complete
2025-12-10 11:33:43.051949 | 
2025-12-10 11:33:43.213200 | controller | ok: "artifacts"
2025-12-10 11:33:43.373890 | controller | ok: "docs"
2025-12-10 11:33:43.381076 | 
2025-12-10 11:33:43.381179 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-10 11:33:43.568291 | controller | changed: "logs"
2025-12-10 11:33:43.730476 | controller | changed: "artifacts"
2025-12-10 11:33:43.894646 | controller | changed: "docs"
2025-12-10 11:33:43.913782 | 
2025-12-10 11:33:43.913860 | PLAY RECAP
2025-12-10 11:33:43.913902 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-10 11:33:43.913950 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-10 11:33:43.913970 | 
2025-12-10 11:33:43.980549 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-10 11:33:43.981314 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-12-10 11:33:44.493350 | 
2025-12-10 11:33:44.493446 | PLAY [all]
2025-12-10 11:33:44.511287 | 
2025-12-10 11:33:44.511356 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-12-10 11:33:44.560322 | controller | ok
2025-12-10 11:33:44.564881 | 
2025-12-10 11:33:44.564970 | TASK [mirror-info-fork : Create /etc/ci]
2025-12-10 11:33:44.877137 | controller | changed
2025-12-10 11:33:44.882084 | 
2025-12-10 11:33:44.882153 | TASK [mirror-info-fork : Install ci_mirror script]
2025-12-10 11:33:45.609686 | controller | changed
2025-12-10 11:33:45.619239 | 
2025-12-10 11:33:45.619312 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-12-10 11:33:45.944930 | controller | changed:
2025-12-10 11:33:45.945205 | controller | {
2025-12-10 11:33:45.945239 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-12-10 11:33:45.945270 | controller | }
2025-12-10 11:33:46.129808 | controller | changed:
2025-12-10 11:33:46.129934 | controller | {
2025-12-10 11:33:46.129969 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-12-10 11:33:46.129992 | controller | }
2025-12-10 11:33:46.316965 | controller | changed:
2025-12-10 11:33:46.317058 | controller | {
2025-12-10 11:33:46.317087 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-12-10 11:33:46.317217 | controller | }
2025-12-10 11:33:46.519977 | controller | changed:
2025-12-10 11:33:46.520078 | controller | {
2025-12-10 11:33:46.520112 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-12-10 11:33:46.520139 | controller | }
2025-12-10 11:33:46.712277 | controller | changed:
2025-12-10 11:33:46.712521 | controller | {
2025-12-10 11:33:46.712564 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-12-10 11:33:46.712591 | controller | }
2025-12-10 11:33:46.902991 | controller | changed:
2025-12-10 11:33:46.903081 | controller | {
2025-12-10 11:33:46.903109 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-12-10 11:33:46.903131 | controller | }
2025-12-10 11:33:47.098033 | controller | changed:
2025-12-10 11:33:47.098089 | controller | {
2025-12-10 11:33:47.098116 | 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-12-10 11:33:47.098137 | controller | }
2025-12-10 11:33:47.288547 | controller | changed:
2025-12-10 11:33:47.288598 | controller | {
2025-12-10 11:33:47.288626 | 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-12-10 11:33:47.288660 | controller | }
2025-12-10 11:33:47.477415 | controller | changed:
2025-12-10 11:33:47.477472 | controller | {
2025-12-10 11:33:47.477500 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-12-10 11:33:47.477520 | controller | }
2025-12-10 11:33:47.680248 | controller | changed:
2025-12-10 11:33:47.680300 | controller | {
2025-12-10 11:33:47.680327 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-12-10 11:33:47.680346 | controller | }
2025-12-10 11:33:47.868350 | controller | changed:
2025-12-10 11:33:47.868400 | controller | {
2025-12-10 11:33:47.868426 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-12-10 11:33:47.868446 | controller | }
2025-12-10 11:33:48.070692 | controller | changed:
2025-12-10 11:33:48.070764 | controller | {
2025-12-10 11:33:48.070791 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-12-10 11:33:48.070812 | controller | }
2025-12-10 11:33:48.239541 | controller | changed:
2025-12-10 11:33:48.239595 | controller | {
2025-12-10 11:33:48.239622 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-12-10 11:33:48.239653 | controller | }
2025-12-10 11:33:48.426753 | controller | changed:
2025-12-10 11:33:48.426803 | controller | {
2025-12-10 11:33:48.426828 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-12-10 11:33:48.426848 | controller | }
2025-12-10 11:33:48.613573 | controller | changed:
2025-12-10 11:33:48.613622 | controller | {
2025-12-10 11:33:48.613658 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-12-10 11:33:48.613678 | controller | }
2025-12-10 11:33:48.800367 | controller | changed:
2025-12-10 11:33:48.800514 | controller | {
2025-12-10 11:33:48.800551 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-12-10 11:33:48.800573 | controller | }
2025-12-10 11:33:48.988882 | controller | changed:
2025-12-10 11:33:48.988947 | controller | {
2025-12-10 11:33:48.988975 | 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-12-10 11:33:48.988996 | controller | }
2025-12-10 11:33:49.174610 | controller | changed:
2025-12-10 11:33:49.174720 | controller | {
2025-12-10 11:33:49.174748 | 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-12-10 11:33:49.174777 | controller | }
2025-12-10 11:33:49.360758 | controller | changed:
2025-12-10 11:33:49.360814 | controller | {
2025-12-10 11:33:49.360847 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-12-10 11:33:49.360873 | controller | }
2025-12-10 11:33:49.548884 | controller | changed:
2025-12-10 11:33:49.548949 | controller | {
2025-12-10 11:33:49.548977 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-12-10 11:33:49.548996 | controller | }
2025-12-10 11:33:49.744929 | controller | changed:
2025-12-10 11:33:49.744983 | controller | {
2025-12-10 11:33:49.745007 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-12-10 11:33:49.745025 | controller | }
2025-12-10 11:33:49.937017 | controller | changed:
2025-12-10 11:33:49.937067 | controller | {
2025-12-10 11:33:49.937095 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-12-10 11:33:49.937115 | controller | }
2025-12-10 11:33:50.124672 | controller | changed:
2025-12-10 11:33:50.124726 | controller | {
2025-12-10 11:33:50.124752 | 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-12-10 11:33:50.124773 | controller | }
2025-12-10 11:33:50.312462 | controller | changed:
2025-12-10 11:33:50.312511 | controller | {
2025-12-10 11:33:50.312537 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-12-10 11:33:50.312555 | controller | }
2025-12-10 11:33:50.498895 | controller | changed:
2025-12-10 11:33:50.498961 | controller | {
2025-12-10 11:33:50.498989 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-12-10 11:33:50.499008 | controller | }
2025-12-10 11:33:50.682864 | controller | changed:
2025-12-10 11:33:50.682928 | controller | {
2025-12-10 11:33:50.682960 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-12-10 11:33:50.682980 | controller | }
2025-12-10 11:33:50.698055 | 
2025-12-10 11:33:50.698119 | TASK [Set timezone to UTC]
2025-12-10 11:33:51.051605 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-12-10 11:33:51.056309 | 
2025-12-10 11:33:51.056371 | TASK [Create nodepool directory]
2025-12-10 11:33:51.236828 | controller | changed
2025-12-10 11:33:51.241879 | 
2025-12-10 11:33:51.241959 | TASK [Create nodepool sub_nodes file]
2025-12-10 11:33:51.694277 | controller | changed
2025-12-10 11:33:51.698977 | 
2025-12-10 11:33:51.699042 | TASK [Create nodepool sub_nodes_private file]
2025-12-10 11:33:52.192322 | controller | changed
2025-12-10 11:33:52.197650 | 
2025-12-10 11:33:52.197711 | LOOP [Populate nodepool sub_nodes file]
2025-12-10 11:33:52.225753 | 
2025-12-10 11:33:52.225873 | LOOP [Populate nodepool sub_nodes_private file]
2025-12-10 11:33:52.254658 | 
2025-12-10 11:33:52.254780 | TASK [Create nodepool primary file]
2025-12-10 11:33:52.277766 | controller | skipping: Conditional result was False
2025-12-10 11:33:52.283060 | 
2025-12-10 11:33:52.283144 | TASK [Create nodepool node_private for this node]
2025-12-10 11:33:52.819293 | controller | changed
2025-12-10 11:33:52.825552 | 
2025-12-10 11:33:52.825626 | LOOP [Copy ssh keys to nodepool directory]
2025-12-10 11:33:53.156850 | controller | ok: Item: id_rsa Runtime: 0:00:00.004932
2025-12-10 11:33:53.157096 | 
2025-12-10 11:33:53.322065 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.004547
2025-12-10 11:33:53.333069 | 
2025-12-10 11:33:53.333284 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-12-10 11:33:53.873440 | controller | changed
2025-12-10 11:33:53.878323 | 
2025-12-10 11:33:53.878395 | TASK [Validate sudoers config after edits]
2025-12-10 11:33:54.085773 | controller | /etc/sudoers: parsed OK
2025-12-10 11:33:54.085856 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-12-10 11:33:54.085867 | controller | /etc/sudoers.d/zuul: parsed OK
2025-12-10 11:33:54.085873 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-12-10 11:33:54.404273 | controller | ok: Runtime: 0:00:00.004678
2025-12-10 11:33:54.410003 | 
2025-12-10 11:33:54.410066 | TASK [Show the environment passed in to job shell scripts]
2025-12-10 11:33:54.602884 | controller | SHELL=/bin/bash
2025-12-10 11:33:54.602931 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-12-10 11:33:54.602940 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-12-10 11:33:54.602947 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/45/3545/11ceb037c2e13aca6615e502eef37c2d620754ed
2025-12-10 11:33:54.602952 | controller | PWD=/home/zuul
2025-12-10 11:33:54.602958 | controller | ZUUL_PIPELINE=github-check
2025-12-10 11:33:54.602964 | controller | LOGNAME=zuul
2025-12-10 11:33:54.603008 | controller | XDG_SESSION_TYPE=tty
2025-12-10 11:33:54.603018 | controller | _=/usr/bin/env
2025-12-10 11:33:54.603023 | controller | MOTD_SHOWN=pam
2025-12-10 11:33:54.603028 | controller | HOME=/home/zuul
2025-12-10 11:33:54.603034 | controller | LANG=en_US.UTF-8
2025-12-10 11:33:54.603039 | controller | SSH_CONNECTION=192.168.26.12 36332 192.168.26.113 22
2025-12-10 11:33:54.603044 | 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-12-10 11:33:54.603053 | controller | ZUUL_CHANGE_IDS=3545,11ceb037c2e13aca6615e502eef37c2d620754ed
2025-12-10 11:33:54.603059 | controller | WORKSPACE=/home/zuul/workspace
2025-12-10 11:33:54.603064 | controller | XDG_SESSION_CLASS=user
2025-12-10 11:33:54.603070 | controller | SELINUX_ROLE_REQUESTED=
2025-12-10 11:33:54.603075 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-12-10 11:33:54.603080 | controller | USER=zuul
2025-12-10 11:33:54.603086 | controller | ZUUL_VOTING=True
2025-12-10 11:33:54.603091 | controller | BUILD_TIMEOUT=1800000
2025-12-10 11:33:54.603096 | controller | SELINUX_USE_CURRENT_RANGE=
2025-12-10 11:33:54.603102 | controller | SHLVL=1
2025-12-10 11:33:54.603107 | controller | ZUUL_PATCHSET=11ceb037c2e13aca6615e502eef37c2d620754ed
2025-12-10 11:33:54.603112 | controller | XDG_SESSION_ID=1
2025-12-10 11:33:54.603117 | controller | ZUUL_BRANCH=main
2025-12-10 11:33:54.603123 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-12-10 11:33:54.603128 | controller | SSH_CLIENT=192.168.26.12 36332 22
2025-12-10 11:33:54.603133 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-12-10 11:33:54.603139 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-12-10 11:33:54.603146 | controller | which_declare=declare -f
2025-12-10 11:33:54.603152 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-12-10 11:33:54.603157 | controller | SELINUX_LEVEL_REQUESTED=
2025-12-10 11:33:54.603163 | controller | ZUUL_CHANGE=3545
2025-12-10 11:33:54.603169 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-12-10 11:33:54.603175 | controller | ZUUL_UUID=b1dbf66fe9ab464d90e0238ab83e43c3
2025-12-10 11:33:54.603191 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-12-10 11:33:54.603197 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-12-10 11:33:54.603202 | controller | }
2025-12-10 11:33:54.937192 | controller | ok: Runtime: 0:00:00.005121
2025-12-10 11:33:54.942806 | 
2025-12-10 11:33:54.942900 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-12-10 11:33:54.967046 | controller | skipping: Conditional result was False
2025-12-10 11:33:54.974071 | 
2025-12-10 11:33:54.974198 | TASK [Symlink /home/zuul-worker/workspace]
2025-12-10 11:33:55.497738 | controller | skipping: Conditional result was False
2025-12-10 11:33:55.504323 | 
2025-12-10 11:33:55.504434 | TASK [Ensure legacy workspace directory]
2025-12-10 11:33:55.686953 | controller | changed
2025-12-10 11:33:55.704897 | 
2025-12-10 11:33:55.704980 | PLAY RECAP
2025-12-10 11:33:55.705030 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-10 11:33:55.705054 | 
2025-12-10 11:33:55.784448 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-12-10 11:33:55.785219 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-12-10 11:33:56.295501 | 
2025-12-10 11:33:56.295603 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-12-10 11:33:56.315405 | 
2025-12-10 11:33:56.315478 | TASK [Create zuul-output directory]
2025-12-10 11:33:56.618320 | controller | changed
2025-12-10 11:33:56.623331 | 
2025-12-10 11:33:56.623405 | TASK [Slurp Zuul inventory test]
2025-12-10 11:33:56.890558 | controller -> localhost | ok
2025-12-10 11:33:56.896808 | 
2025-12-10 11:33:56.896977 | TASK [Save zuul inventory]
2025-12-10 11:33:57.613438 | controller | changed
2025-12-10 11:33:57.618474 | 
2025-12-10 11:33:57.618544 | TASK [Save zuul vars without the change_message]
2025-12-10 11:33:58.173797 | controller | changed
2025-12-10 11:33:58.191735 | 
2025-12-10 11:33:58.191803 | PLAY RECAP
2025-12-10 11:33:58.191847 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-10 11:33:58.191879 | 
2025-12-10 11:33:58.256187 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-12-10 11:33:58.256957 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-12-10 11:33:58.798062 | 
2025-12-10 11:33:58.798156 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-12-10 11:33:58.818098 | 
2025-12-10 11:33:58.818171 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-12-10 11:33:58.836490 | controller | ok
2025-12-10 11:33:58.852904 | 
2025-12-10 11:33:58.852999 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-12-10 11:33:58.887346 | controller | skipping: Conditional result was False
2025-12-10 11:33:58.893219 | 
2025-12-10 11:33:58.893290 | TASK [mirror-info-fork : Create /etc/ci]
2025-12-10 11:33:59.197361 | controller | ok
2025-12-10 11:33:59.203025 | 
2025-12-10 11:33:59.203104 | TASK [mirror-info-fork : Install ci_mirror script]
2025-12-10 11:33:59.779885 | controller | ok
2025-12-10 11:33:59.790173 | 
2025-12-10 11:33:59.790237 | TASK [Prepare workspace]
2025-12-10 11:33:59.807529 | controller | ok
2025-12-10 11:33:59.823611 | 
2025-12-10 11:33:59.823688 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-10 11:34:00.136039 | controller | ok
2025-12-10 11:34:00.141838 | 
2025-12-10 11:34:00.141922 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-10 11:34:02.514668 | controller | Output suppressed because no_log was given
2025-12-10 11:34:02.523961 | 
2025-12-10 11:34:02.524029 | LOOP [Create zuul-output directory]
2025-12-10 11:34:02.705692 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-12-10 11:34:02.856797 | controller | ok: "/home/zuul/zuul-output/logs"
2025-12-10 11:34:02.868844 | 
2025-12-10 11:34:02.868949 | TASK [Install required packages]
2025-12-10 11:34:49.157663 | controller | changed
2025-12-10 11:34:49.162624 | 
2025-12-10 11:34:49.162686 | TASK [Install venv]
2025-12-10 11:35:48.657423 | controller | changed
2025-12-10 11:35:48.679882 | 
2025-12-10 11:35:48.679955 | PLAY RECAP
2025-12-10 11:35:48.679999 | controller | ok: 7 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-12-10 11:35:48.680021 | 
2025-12-10 11:35:48.752256 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-12-10 11:35:48.753133 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-12-10 11:35:49.255579 | 
2025-12-10 11:35:49.255677 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-12-10 11:35:49.276262 | 
2025-12-10 11:35:49.276335 | TASK [Gather required facts]
2025-12-10 11:35:49.721283 | controller | ok
2025-12-10 11:35:49.726542 | 
2025-12-10 11:35:49.726700 | TASK [Load environment var if instructed to]
2025-12-10 11:35:49.761572 | controller | skipping: Conditional result was False
2025-12-10 11:35:49.767522 | 
2025-12-10 11:35:49.767585 | TASK [Ensure group_vars dir exists]
2025-12-10 11:35:50.113144 | controller | ok
2025-12-10 11:35:50.118991 | 
2025-12-10 11:35:50.119053 | TASK [Print related variables]
2025-12-10 11:35:50.149324 | controller | ok:
2025-12-10 11:35:50.149464 | controller | mol_config_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config_local.yml
2025-12-10 11:35:50.149494 | controller | roles_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/nat64_appliance
2025-12-10 11:35:50.154243 | 
2025-12-10 11:35:50.154307 | TASK [Run molecule]
2025-12-10 11:35:51.069480 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-12-10 11:35:51.192131 | controller | INFO     Performing prerun with role_name_check=0...
2025-12-10 11:36:07.232515 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:36:07.232939 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:36:07.233357 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:36:07.233774 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:36:07.234216 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+11ceb037 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.0.0+11ceb037 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:36:07.234665 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:36:07.235112 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:36:07.235544 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:36:07.236000 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:36:07.236393 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:36:07.236797 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:36:07.237204 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:36:07.237590 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:36:07.238024 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:36:07.238429 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:36:07.247277 | controller | INFO     Running build > prepare
2025-12-10 11:36:07.874593 | controller |
2025-12-10 11:36:07.874708 | controller | PLAY [Prepare] *****************************************************************
2025-12-10 11:36:07.874801 | controller |
2025-12-10 11:36:07.874904 | controller | TASK [Gathering Facts] *********************************************************
2025-12-10 11:36:07.874998 | controller | Wednesday 10 December 2025  11:36:07 +0000 (0:00:00.018)       0:00:00.018 ****
2025-12-10 11:36:08.630134 | controller | ok: [instance]
2025-12-10 11:36:08.630209 | controller |
2025-12-10 11:36:08.630308 | controller | TASK [Create custom basedir] ***************************************************
2025-12-10 11:36:08.630415 | controller | Wednesday 10 December 2025  11:36:08 +0000 (0:00:00.755)       0:00:00.774 ****
2025-12-10 11:36:08.905848 | controller | ok: [instance]
2025-12-10 11:36:08.905910 | controller |
2025-12-10 11:36:08.906017 | controller | TASK [Install some debug utils] ************************************************
2025-12-10 11:36:08.906114 | controller | Wednesday 10 December 2025  11:36:08 +0000 (0:00:00.274)       0:00:01.048 ****
2025-12-10 11:36:13.796730 | controller | changed: [instance]
2025-12-10 11:36:13.796783 | controller |
2025-12-10 11:36:13.796898 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-12-10 11:36:13.797005 | controller | Wednesday 10 December 2025  11:36:13 +0000 (0:00:04.891)       0:00:05.940 ****
2025-12-10 11:36:13.813796 | controller | skipping: [instance]
2025-12-10 11:36:13.813899 | controller |
2025-12-10 11:36:13.814019 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-12-10 11:36:13.814138 | controller | Wednesday 10 December 2025  11:36:13 +0000 (0:00:00.017)       0:00:05.958 ****
2025-12-10 11:36:13.853979 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-12-10 11:36:13.854052 | controller |
2025-12-10 11:36:13.854146 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-12-10 11:36:13.854241 | controller | Wednesday 10 December 2025  11:36:13 +0000 (0:00:00.040)       0:00:05.998 ****
2025-12-10 11:36:14.125838 | controller | ok: [instance]
2025-12-10 11:36:14.125917 | controller |
2025-12-10 11:36:14.126031 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-12-10 11:36:14.126139 | controller | Wednesday 10 December 2025  11:36:14 +0000 (0:00:00.271)       0:00:06.270 ****
2025-12-10 11:36:14.337103 | controller | ok: [instance]
2025-12-10 11:36:14.337176 | controller |
2025-12-10 11:36:14.337277 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-12-10 11:36:14.337380 | controller | Wednesday 10 December 2025  11:36:14 +0000 (0:00:00.211)       0:00:06.481 ****
2025-12-10 11:36:14.991717 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-12-10 11:36:14.991804 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-12-10 11:36:14.991905 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-12-10 11:36:14.992001 | controller |
2025-12-10 11:36:14.992091 | controller | TASK [Deploy repo-setup] *******************************************************
2025-12-10 11:36:14.992185 | controller | Wednesday 10 December 2025  11:36:14 +0000 (0:00:00.654)       0:00:07.135 ****
2025-12-10 11:36:15.047143 | controller |
2025-12-10 11:36:15.047259 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-12-10 11:36:15.047359 | controller | Wednesday 10 December 2025  11:36:15 +0000 (0:00:00.055)       0:00:07.191 ****
2025-12-10 11:36:15.551227 | controller | changed: [instance] => (item=tmp)
2025-12-10 11:36:15.551291 | controller | changed: [instance] => (item=artifacts/repositories)
2025-12-10 11:36:15.551394 | controller | changed: [instance] => (item=venv/repo_setup)
2025-12-10 11:36:15.551477 | controller |
2025-12-10 11:36:15.551579 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-12-10 11:36:15.551691 | controller | Wednesday 10 December 2025  11:36:15 +0000 (0:00:00.503)       0:00:07.695 ****
2025-12-10 11:36:16.188730 | controller | ok: [instance]
2025-12-10 11:36:16.189058 | controller |
2025-12-10 11:36:17.247670 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-12-10 11:36:17.247700 | controller | Wednesday 10 December 2025  11:36:16 +0000 (0:00:00.637)       0:00:08.332 ****
2025-12-10 11:36:17.247712 | controller | changed: [instance]
2025-12-10 11:36:17.247920 | controller |
2025-12-10 11:36:17.247933 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-12-10 11:36:24.704970 | controller | Wednesday 10 December 2025  11:36:17 +0000 (0:00:01.058)       0:00:09.391 ****
2025-12-10 11:36:24.705004 | controller | changed: [instance]
2025-12-10 11:36:25.380676 | controller |
2025-12-10 11:36:25.380705 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-12-10 11:36:25.380713 | controller | Wednesday 10 December 2025  11:36:24 +0000 (0:00:07.456)       0:00:16.848 ****
2025-12-10 11:36:25.380723 | controller | changed: [instance]
2025-12-10 11:36:25.380880 | controller |
2025-12-10 11:36:25.380890 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-12-10 11:36:25.380898 | controller | Wednesday 10 December 2025  11:36:25 +0000 (0:00:00.675)       0:00:17.524 ****
2025-12-10 11:36:25.402245 | controller | skipping: [instance]
2025-12-10 11:36:26.179441 | controller |
2025-12-10 11:36:26.179469 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-12-10 11:36:26.179477 | controller | Wednesday 10 December 2025  11:36:25 +0000 (0:00:00.021)       0:00:17.546 ****
2025-12-10 11:36:26.179487 | controller | changed: [instance]
2025-12-10 11:36:26.214443 | controller |
2025-12-10 11:36:26.214461 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-12-10 11:36:26.214468 | controller | Wednesday 10 December 2025  11:36:26 +0000 (0:00:00.776)       0:00:18.322 ****
2025-12-10 11:36:26.214477 | controller | skipping: [instance]
2025-12-10 11:36:26.246369 | controller |
2025-12-10 11:36:26.246404 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-12-10 11:36:26.246418 | controller | Wednesday 10 December 2025  11:36:26 +0000 (0:00:00.035)       0:00:18.358 ****
2025-12-10 11:36:26.246429 | controller | skipping: [instance]
2025-12-10 11:36:26.278886 | controller |
2025-12-10 11:36:26.278937 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-12-10 11:36:26.278951 | controller | Wednesday 10 December 2025  11:36:26 +0000 (0:00:00.031)       0:00:18.389 ****
2025-12-10 11:36:26.278967 | controller | skipping: [instance]
2025-12-10 11:36:26.279225 | controller |
2025-12-10 11:36:26.279483 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-12-10 11:36:26.279636 | controller | Wednesday 10 December 2025  11:36:26 +0000 (0:00:00.033)       0:00:18.423 ****
2025-12-10 11:36:26.806733 | controller | changed: [instance]
2025-12-10 11:36:27.219675 | controller |
2025-12-10 11:36:27.219696 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-12-10 11:36:27.219703 | controller | Wednesday 10 December 2025  11:36:26 +0000 (0:00:00.527)       0:00:18.950 ****
2025-12-10 11:36:27.219714 | controller | changed: [instance]
2025-12-10 11:36:27.219848 | controller |
2025-12-10 11:36:27.219858 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-12-10 11:36:27.219866 | controller | Wednesday 10 December 2025  11:36:27 +0000 (0:00:00.413)       0:00:19.363 ****
2025-12-10 11:36:27.247518 | controller | skipping: [instance]
2025-12-10 11:36:27.274744 | controller |
2025-12-10 11:36:27.274761 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-12-10 11:36:27.274768 | controller | Wednesday 10 December 2025  11:36:27 +0000 (0:00:00.027)       0:00:19.391 ****
2025-12-10 11:36:27.274776 | controller | skipping: [instance]
2025-12-10 11:36:27.301514 | controller |
2025-12-10 11:36:27.301531 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-12-10 11:36:27.301538 | controller | Wednesday 10 December 2025  11:36:27 +0000 (0:00:00.027)       0:00:19.418 ****
2025-12-10 11:36:27.301546 | controller | skipping: [instance]
2025-12-10 11:36:27.336492 | controller |
2025-12-10 11:36:27.336509 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-12-10 11:36:27.336516 | controller | Wednesday 10 December 2025  11:36:27 +0000 (0:00:00.026)       0:00:19.445 ****
2025-12-10 11:36:27.336529 | controller | ok: [instance]
2025-12-10 11:36:27.362317 | controller |
2025-12-10 11:36:27.362336 | controller | TASK [repo_setup : Create download directory] **********************************
2025-12-10 11:36:27.362343 | controller | Wednesday 10 December 2025  11:36:27 +0000 (0:00:00.034)       0:00:19.480 ****
2025-12-10 11:36:27.362354 | controller | skipping: [instance]
2025-12-10 11:36:27.387948 | controller |
2025-12-10 11:36:27.387965 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-12-10 11:36:27.387972 | controller | Wednesday 10 December 2025  11:36:27 +0000 (0:00:00.025)       0:00:19.506 ****
2025-12-10 11:36:27.387980 | controller | skipping: [instance]
2025-12-10 11:36:27.412341 | controller |
2025-12-10 11:36:27.412357 | controller | TASK [Download the RPM] ********************************************************
2025-12-10 11:36:27.412364 | controller | Wednesday 10 December 2025  11:36:27 +0000 (0:00:00.025)       0:00:19.532 ****
2025-12-10 11:36:27.412372 | controller | skipping: [instance]
2025-12-10 11:36:27.436705 | controller |
2025-12-10 11:36:27.436738 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-12-10 11:36:27.436747 | controller | Wednesday 10 December 2025  11:36:27 +0000 (0:00:00.024)       0:00:19.556 ****
2025-12-10 11:36:27.436759 | controller | skipping: [instance]
2025-12-10 11:36:27.436779 | controller |
2025-12-10 11:36:27.436789 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-12-10 11:36:27.436798 | controller | Wednesday 10 December 2025  11:36:27 +0000 (0:00:00.024)       0:00:19.580 ****
2025-12-10 11:36:27.461021 | controller | skipping: [instance]
2025-12-10 11:36:27.461114 | controller |
2025-12-10 11:36:27.461221 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-12-10 11:36:27.461322 | controller | Wednesday 10 December 2025  11:36:27 +0000 (0:00:00.024)       0:00:19.605 ****
2025-12-10 11:36:27.488544 | controller | skipping: [instance]
2025-12-10 11:36:27.488657 | controller |
2025-12-10 11:36:27.488776 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-12-10 11:36:27.488882 | controller | Wednesday 10 December 2025  11:36:27 +0000 (0:00:00.027)       0:00:19.632 ****
2025-12-10 11:36:27.513769 | controller | skipping: [instance]
2025-12-10 11:36:27.513862 | controller |
2025-12-10 11:36:27.513982 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-12-10 11:36:27.514086 | controller | Wednesday 10 December 2025  11:36:27 +0000 (0:00:00.025)       0:00:19.658 ****
2025-12-10 11:36:27.681637 | controller | ok: [instance]
2025-12-10 11:36:27.681697 | controller |
2025-12-10 11:36:27.681800 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-12-10 11:36:27.681896 | controller | Wednesday 10 December 2025  11:36:27 +0000 (0:00:00.167)       0:00:19.825 ****
2025-12-10 11:36:27.873846 | controller | changed: [instance]
2025-12-10 11:36:27.873891 | controller |
2025-12-10 11:36:27.874020 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-12-10 11:36:27.874122 | controller | Wednesday 10 December 2025  11:36:27 +0000 (0:00:00.192)       0:00:20.018 ****
2025-12-10 11:36:28.088945 | controller | changed: [instance]
2025-12-10 11:36:28.089013 | controller |
2025-12-10 11:36:28.089253 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-12-10 11:36:28.108846 | controller | Wednesday 10 December 2025  11:36:28 +0000 (0:00:00.214)       0:00:20.233 ****
2025-12-10 11:36:28.108864 | controller | skipping: [instance]
2025-12-10 11:36:28.127263 | controller |
2025-12-10 11:36:28.127284 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-12-10 11:36:28.127294 | controller | Wednesday 10 December 2025  11:36:28 +0000 (0:00:00.019)       0:00:20.252 ****
2025-12-10 11:36:28.127305 | controller | skipping: [instance]
2025-12-10 11:36:28.144820 | controller |
2025-12-10 11:36:28.144838 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-12-10 11:36:28.144846 | controller | Wednesday 10 December 2025  11:36:28 +0000 (0:00:00.018)       0:00:20.271 ****
2025-12-10 11:36:28.144855 | controller | skipping: [instance]
2025-12-10 11:36:28.163118 | controller |
2025-12-10 11:36:28.163132 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-12-10 11:36:28.163144 | controller | Wednesday 10 December 2025  11:36:28 +0000 (0:00:00.017)       0:00:20.288 ****
2025-12-10 11:36:28.163152 | controller | skipping: [instance]
2025-12-10 11:36:28.182503 | controller |
2025-12-10 11:36:28.182522 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-12-10 11:36:28.182529 | controller | Wednesday 10 December 2025  11:36:28 +0000 (0:00:00.018)       0:00:20.307 ****
2025-12-10 11:36:28.182539 | controller | skipping: [instance]
2025-12-10 11:36:28.182727 | controller |
2025-12-10 11:36:28.182905 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-12-10 11:36:28.183085 | controller | Wednesday 10 December 2025  11:36:28 +0000 (0:00:00.019)       0:00:20.326 ****
2025-12-10 11:36:28.201873 | controller | skipping: [instance]
2025-12-10 11:36:28.202030 | controller |
2025-12-10 11:36:28.202188 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-12-10 11:36:28.202334 | controller | Wednesday 10 December 2025  11:36:28 +0000 (0:00:00.019)       0:00:20.346 ****
2025-12-10 11:36:28.216064 | controller | skipping: [instance]
2025-12-10 11:36:28.216249 | controller |
2025-12-10 11:36:28.216434 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-12-10 11:36:28.216654 | controller | Wednesday 10 December 2025  11:36:28 +0000 (0:00:00.014)       0:00:20.360 ****
2025-12-10 11:36:28.239910 | controller | skipping: [instance]
2025-12-10 11:36:28.240129 | controller |
2025-12-10 11:36:28.240278 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-12-10 11:36:28.240401 | controller | Wednesday 10 December 2025  11:36:28 +0000 (0:00:00.023)       0:00:20.384 ****
2025-12-10 11:36:28.253033 | controller | skipping: [instance]
2025-12-10 11:36:28.253216 | controller |
2025-12-10 11:36:28.253352 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-12-10 11:36:28.253476 | controller | Wednesday 10 December 2025  11:36:28 +0000 (0:00:00.013)       0:00:20.397 ****
2025-12-10 11:36:28.270446 | controller | skipping: [instance]
2025-12-10 11:36:28.270635 | controller |
2025-12-10 11:36:28.270814 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-12-10 11:36:28.270991 | controller | Wednesday 10 December 2025  11:36:28 +0000 (0:00:00.017)       0:00:20.414 ****
2025-12-10 11:36:28.297195 | controller | skipping: [instance]
2025-12-10 11:36:28.297342 | controller |
2025-12-10 11:36:28.297474 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-12-10 11:36:28.297622 | controller | Wednesday 10 December 2025  11:36:28 +0000 (0:00:00.026)       0:00:20.441 ****
2025-12-10 11:36:28.321999 | controller | skipping: [instance]
2025-12-10 11:36:28.322189 | controller |
2025-12-10 11:36:28.322374 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-12-10 11:36:28.322496 | controller | Wednesday 10 December 2025  11:36:28 +0000 (0:00:00.024)       0:00:20.466 ****
2025-12-10 11:36:28.346465 | controller | skipping: [instance]
2025-12-10 11:36:28.346682 | controller |
2025-12-10 11:36:28.346874 | controller | TASK [test_deps : Install additional packages] *********************************
2025-12-10 11:36:28.347081 | controller | Wednesday 10 December 2025  11:36:28 +0000 (0:00:00.024)       0:00:20.490 ****
2025-12-10 11:36:28.371261 | controller | skipping: [instance]
2025-12-10 11:36:28.371426 | controller |
2025-12-10 11:36:28.371619 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-12-10 11:36:28.371773 | controller | Wednesday 10 December 2025  11:36:28 +0000 (0:00:00.024)       0:00:20.515 ****
2025-12-10 11:37:06.653579 | controller | ok: [instance]
2025-12-10 11:37:07.756207 | controller |
2025-12-10 11:37:07.756237 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-12-10 11:37:07.756245 | controller | Wednesday 10 December 2025  11:37:06 +0000 (0:00:38.281)       0:00:58.797 ****
2025-12-10 11:37:07.756255 | controller | ok: [instance]
2025-12-10 11:37:07.786420 | controller |
2025-12-10 11:37:07.786438 | controller | TASK [test_deps : Install extra packages] **************************************
2025-12-10 11:37:07.786445 | controller | Wednesday 10 December 2025  11:37:07 +0000 (0:00:01.102)       0:00:59.899 ****
2025-12-10 11:37:07.786454 | controller | skipping: [instance]
2025-12-10 11:37:07.971142 | controller |
2025-12-10 11:37:07.971170 | controller | TASK [libvirt_manager : Ensure output directory exists] ************************
2025-12-10 11:37:07.971178 | controller | Wednesday 10 December 2025  11:37:07 +0000 (0:00:00.030)       0:00:59.930 ****
2025-12-10 11:37:07.971194 | controller | ok: [instance]
2025-12-10 11:37:08.155016 | controller |
2025-12-10 11:37:08.155039 | controller | TASK [libvirt_manager : Get vmx/svm extensions from /proc/cpuinfo] *************
2025-12-10 11:37:08.155047 | controller | Wednesday 10 December 2025  11:37:07 +0000 (0:00:00.184)       0:01:00.114 ****
2025-12-10 11:37:08.155057 | controller | changed: [instance]
2025-12-10 11:37:08.330657 | controller |
2025-12-10 11:37:08.330682 | controller | TASK [libvirt_manager : Check if KVM is enabled] *******************************
2025-12-10 11:37:08.330690 | controller | Wednesday 10 December 2025  11:37:08 +0000 (0:00:00.184)       0:01:00.298 ****
2025-12-10 11:37:08.330699 | controller | ok: [instance]
2025-12-10 11:37:08.330961 | controller |
2025-12-10 11:37:08.330975 | controller | TASK [libvirt_manager : Fail if KVM not enabled] *******************************
2025-12-10 11:37:08.359669 | controller | Wednesday 10 December 2025  11:37:08 +0000 (0:00:00.175)       0:01:00.474 ****
2025-12-10 11:37:08.359693 | controller | skipping: [instance]
2025-12-10 11:37:08.359761 | controller |
2025-12-10 11:37:08.359778 | controller | TASK [libvirt_manager : Check if VMX virtualization] ***************************
2025-12-10 11:37:08.359789 | controller | Wednesday 10 December 2025  11:37:08 +0000 (0:00:00.028)       0:01:00.503 ****
2025-12-10 11:37:08.376372 | controller | skipping: [instance]
2025-12-10 11:37:08.394628 | controller |
2025-12-10 11:37:08.394643 | controller | TASK [libvirt_manager : Check if SVM virtualization] ***************************
2025-12-10 11:37:08.394649 | controller | Wednesday 10 December 2025  11:37:08 +0000 (0:00:00.016)       0:01:00.520 ****
2025-12-10 11:37:08.394657 | controller | ok: [instance]
2025-12-10 11:37:08.419330 | controller |
2025-12-10 11:37:08.419345 | controller | TASK [libvirt_manager : Enable VMX virtualization] *****************************
2025-12-10 11:37:08.419352 | controller | Wednesday 10 December 2025  11:37:08 +0000 (0:00:00.018)       0:01:00.538 ****
2025-12-10 11:37:08.419359 | controller | skipping: [instance]
2025-12-10 11:38:40.720868 | controller |
2025-12-10 11:38:40.720899 | controller | TASK [libvirt_manager : Install packages required for using KVM] ***************
2025-12-10 11:38:40.720907 | controller | Wednesday 10 December 2025  11:37:08 +0000 (0:00:00.024)       0:01:00.563 ****
2025-12-10 11:38:40.720917 | controller | changed: [instance]
2025-12-10 11:38:40.925810 | controller |
2025-12-10 11:38:40.925835 | controller | TASK [libvirt_manager : Create rules.d polkit folder] **************************
2025-12-10 11:38:40.925843 | controller | Wednesday 10 December 2025  11:38:40 +0000 (0:01:32.301)       0:02:32.864 ****
2025-12-10 11:38:40.925852 | controller | changed: [instance]
2025-12-10 11:38:41.298083 | controller |
2025-12-10 11:38:41.298112 | controller | TASK [libvirt_manager : Enable UNIX socket PolicyKit auth] *********************
2025-12-10 11:38:41.298120 | controller | Wednesday 10 December 2025  11:38:40 +0000 (0:00:00.205)       0:02:33.069 ****
2025-12-10 11:38:41.298130 | controller | changed: [instance]
2025-12-10 11:38:41.943443 | controller |
2025-12-10 11:38:41.943472 | controller | TASK [libvirt_manager : Restart service polkit service] ************************
2025-12-10 11:38:41.943480 | controller | Wednesday 10 December 2025  11:38:41 +0000 (0:00:00.372)       0:02:33.441 ****
2025-12-10 11:38:41.943489 | controller | changed: [instance]
2025-12-10 11:38:42.166984 | controller |
2025-12-10 11:38:42.167015 | controller | TASK [libvirt_manager : Remove directory for service override] *****************
2025-12-10 11:38:42.167023 | controller | Wednesday 10 December 2025  11:38:41 +0000 (0:00:00.645)       0:02:34.087 ****
2025-12-10 11:38:42.167033 | controller | ok: [instance]
2025-12-10 11:38:42.863400 | controller |
2025-12-10 11:38:42.863428 | controller | TASK [libvirt_manager : Reload systemctl and start/enable virtproxyd.service] ***
2025-12-10 11:38:42.863435 | controller | Wednesday 10 December 2025  11:38:42 +0000 (0:00:00.223)       0:02:34.310 ****
2025-12-10 11:38:42.863445 | controller | ok: [instance]
2025-12-10 11:38:43.695726 | controller |
2025-12-10 11:38:43.695758 | controller | TASK [libvirt_manager : Ensure firewalld service is up] ************************
2025-12-10 11:38:43.695767 | controller | Wednesday 10 December 2025  11:38:42 +0000 (0:00:00.696)       0:02:35.006 ****
2025-12-10 11:38:43.695784 | controller | changed: [instance]
2025-12-10 11:38:43.775150 | controller |
2025-12-10 11:38:43.775180 | controller | TASK [libvirt_manager : Ensure libvirt modular driver daemons are started.] ****
2025-12-10 11:38:43.775188 | controller | Wednesday 10 December 2025  11:38:43 +0000 (0:00:00.832)       0:02:35.839 ****
2025-12-10 11:38:43.775198 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=qemu)
2025-12-10 11:38:43.775222 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=interface)
2025-12-10 11:38:43.775230 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=network)
2025-12-10 11:38:43.775250 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nodedev)
2025-12-10 11:38:43.775937 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nwfilter)
2025-12-10 11:38:44.117969 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=secret)
2025-12-10 11:38:44.117999 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=storage)
2025-12-10 11:38:44.118006 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=proxy)
2025-12-10 11:38:44.118011 | controller |
2025-12-10 11:38:44.118017 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for qemu.] *********
2025-12-10 11:38:44.118023 | controller | Wednesday 10 December 2025  11:38:43 +0000 (0:00:00.079)       0:02:35.919 ****
2025-12-10 11:38:44.118032 | controller | changed: [instance]
2025-12-10 11:38:44.445809 | controller |
2025-12-10 11:38:44.445838 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for qemu.] **********
2025-12-10 11:38:44.445852 | controller | Wednesday 10 December 2025  11:38:44 +0000 (0:00:00.342)       0:02:36.261 ****
2025-12-10 11:38:44.445862 | controller | changed: [instance]
2025-12-10 11:38:44.770053 | controller |
2025-12-10 11:38:44.770078 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for qemu.] **************
2025-12-10 11:38:44.770085 | controller | Wednesday 10 December 2025  11:38:44 +0000 (0:00:00.327)       0:02:36.589 ****
2025-12-10 11:38:44.770095 | controller | changed: [instance]
2025-12-10 11:38:45.098502 | controller |
2025-12-10 11:38:45.098528 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for interface.] ****
2025-12-10 11:38:45.098535 | controller | Wednesday 10 December 2025  11:38:44 +0000 (0:00:00.324)       0:02:36.913 ****
2025-12-10 11:38:45.098545 | controller | changed: [instance]
2025-12-10 11:38:45.425284 | controller |
2025-12-10 11:38:45.425315 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for interface.] *****
2025-12-10 11:38:45.425323 | controller | Wednesday 10 December 2025  11:38:45 +0000 (0:00:00.328)       0:02:37.242 ****
2025-12-10 11:38:45.425334 | controller | changed: [instance]
2025-12-10 11:38:45.755061 | controller |
2025-12-10 11:38:45.755094 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for interface.] *********
2025-12-10 11:38:45.755102 | controller | Wednesday 10 December 2025  11:38:45 +0000 (0:00:00.326)       0:02:37.569 ****
2025-12-10 11:38:45.755112 | controller | changed: [instance]
2025-12-10 11:38:46.121423 | controller |
2025-12-10 11:38:46.121454 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for network.] ******
2025-12-10 11:38:46.121462 | controller | Wednesday 10 December 2025  11:38:45 +0000 (0:00:00.329)       0:02:37.898 ****
2025-12-10 11:38:46.121472 | controller | changed: [instance]
2025-12-10 11:38:46.439533 | controller |
2025-12-10 11:38:46.439557 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for network.] *******
2025-12-10 11:38:46.439565 | controller | Wednesday 10 December 2025  11:38:46 +0000 (0:00:00.366)       0:02:38.265 ****
2025-12-10 11:38:46.439575 | controller | changed: [instance]
2025-12-10 11:38:46.752027 | controller |
2025-12-10 11:38:46.752061 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for network.] ***********
2025-12-10 11:38:46.752070 | controller | Wednesday 10 December 2025  11:38:46 +0000 (0:00:00.318)       0:02:38.583 ****
2025-12-10 11:38:46.752080 | controller | changed: [instance]
2025-12-10 11:38:47.061312 | controller |
2025-12-10 11:38:47.061340 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nodedev.] ******
2025-12-10 11:38:47.061351 | controller | Wednesday 10 December 2025  11:38:46 +0000 (0:00:00.312)       0:02:38.895 ****
2025-12-10 11:38:47.061363 | controller | changed: [instance]
2025-12-10 11:38:47.372473 | controller |
2025-12-10 11:38:47.372503 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nodedev.] *******
2025-12-10 11:38:47.372511 | controller | Wednesday 10 December 2025  11:38:47 +0000 (0:00:00.309)       0:02:39.205 ****
2025-12-10 11:38:47.372520 | controller | changed: [instance]
2025-12-10 11:38:47.678425 | controller |
2025-12-10 11:38:47.678454 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nodedev.] ***********
2025-12-10 11:38:47.678462 | controller | Wednesday 10 December 2025  11:38:47 +0000 (0:00:00.311)       0:02:39.516 ****
2025-12-10 11:38:47.678472 | controller | changed: [instance]
2025-12-10 11:38:47.995273 | controller |
2025-12-10 11:38:47.995297 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nwfilter.] *****
2025-12-10 11:38:47.995304 | controller | Wednesday 10 December 2025  11:38:47 +0000 (0:00:00.305)       0:02:39.822 ****
2025-12-10 11:38:47.995313 | controller | changed: [instance]
2025-12-10 11:38:48.299378 | controller |
2025-12-10 11:38:48.299398 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nwfilter.] ******
2025-12-10 11:38:48.299406 | controller | Wednesday 10 December 2025  11:38:47 +0000 (0:00:00.317)       0:02:40.139 ****
2025-12-10 11:38:48.299414 | controller | changed: [instance]
2025-12-10 11:38:48.602377 | controller |
2025-12-10 11:38:48.602408 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nwfilter.] **********
2025-12-10 11:38:48.602418 | controller | Wednesday 10 December 2025  11:38:48 +0000 (0:00:00.304)       0:02:40.443 ****
2025-12-10 11:38:48.602428 | controller | changed: [instance]
2025-12-10 11:38:48.904878 | controller |
2025-12-10 11:38:48.904908 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for secret.] *******
2025-12-10 11:38:48.904916 | controller | Wednesday 10 December 2025  11:38:48 +0000 (0:00:00.302)       0:02:40.746 ****
2025-12-10 11:38:48.904926 | controller | changed: [instance]
2025-12-10 11:38:49.224590 | controller |
2025-12-10 11:38:49.224657 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for secret.] ********
2025-12-10 11:38:49.224669 | controller | Wednesday 10 December 2025  11:38:48 +0000 (0:00:00.302)       0:02:41.048 ****
2025-12-10 11:38:49.224689 | controller | changed: [instance]
2025-12-10 11:38:49.548260 | controller |
2025-12-10 11:38:49.548284 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for secret.] ************
2025-12-10 11:38:49.548292 | controller | Wednesday 10 December 2025  11:38:49 +0000 (0:00:00.319)       0:02:41.368 ****
2025-12-10 11:38:49.548302 | controller | changed: [instance]
2025-12-10 11:38:49.879388 | controller |
2025-12-10 11:38:49.879419 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for storage.] ******
2025-12-10 11:38:49.879427 | controller | Wednesday 10 December 2025  11:38:49 +0000 (0:00:00.323)       0:02:41.692 ****
2025-12-10 11:38:49.879436 | controller | changed: [instance]
2025-12-10 11:38:50.192474 | controller |
2025-12-10 11:38:50.192504 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for storage.] *******
2025-12-10 11:38:50.192511 | controller | Wednesday 10 December 2025  11:38:49 +0000 (0:00:00.330)       0:02:42.023 ****
2025-12-10 11:38:50.192521 | controller | changed: [instance]
2025-12-10 11:38:50.504206 | controller |
2025-12-10 11:38:50.504236 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for storage.] ***********
2025-12-10 11:38:50.504244 | controller | Wednesday 10 December 2025  11:38:50 +0000 (0:00:00.313)       0:02:42.336 ****
2025-12-10 11:38:50.504254 | controller | changed: [instance]
2025-12-10 11:38:50.831982 | controller |
2025-12-10 11:38:50.832009 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for proxy.] ********
2025-12-10 11:38:50.832017 | controller | Wednesday 10 December 2025  11:38:50 +0000 (0:00:00.311)       0:02:42.648 ****
2025-12-10 11:38:50.832033 | controller | changed: [instance]
2025-12-10 11:38:51.154122 | controller |
2025-12-10 11:38:51.154152 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for proxy.] *********
2025-12-10 11:38:51.154160 | controller | Wednesday 10 December 2025  11:38:50 +0000 (0:00:00.327)       0:02:42.975 ****
2025-12-10 11:38:51.154169 | controller | changed: [instance]
2025-12-10 11:38:51.468705 | controller |
2025-12-10 11:38:51.468737 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for proxy.] *************
2025-12-10 11:38:51.468746 | controller | Wednesday 10 December 2025  11:38:51 +0000 (0:00:00.322)       0:02:43.297 ****
2025-12-10 11:38:51.468756 | controller | changed: [instance]
2025-12-10 11:38:51.485708 | controller |
2025-12-10 11:38:51.485740 | controller | TASK [libvirt_manager : Manage service for older releases] *********************
2025-12-10 11:38:51.485748 | controller | Wednesday 10 December 2025  11:38:51 +0000 (0:00:00.314)       0:02:43.612 ****
2025-12-10 11:38:51.485758 | controller | skipping: [instance]
2025-12-10 11:38:51.485906 | controller |
2025-12-10 11:38:51.485927 | controller | TASK [libvirt_manager : Get libvirt group users] *******************************
2025-12-10 11:38:51.754065 | controller | Wednesday 10 December 2025  11:38:51 +0000 (0:00:00.017)       0:02:43.629 ****
2025-12-10 11:38:51.754092 | controller | ok: [instance]
2025-12-10 11:38:52.124993 | controller |
2025-12-10 11:38:52.125026 | controller | TASK [libvirt_manager : Add user if not exists in libvirt group] ***************
2025-12-10 11:38:52.125034 | controller | Wednesday 10 December 2025  11:38:51 +0000 (0:00:00.268)       0:02:43.897 ****
2025-12-10 11:38:52.125044 | controller | changed: [instance]
2025-12-10 11:38:52.412571 | controller |
2025-12-10 11:38:52.412593 | controller | TASK [libvirt_manager : Allow QEMU on home directory for the storage access] ***
2025-12-10 11:38:52.412625 | controller | Wednesday 10 December 2025  11:38:52 +0000 (0:00:00.370)       0:02:44.268 ****
2025-12-10 11:38:52.412635 | controller | changed: [instance]
2025-12-10 11:38:52.674351 | controller |
2025-12-10 11:38:52.674368 | controller | TASK [libvirt_manager : Inject system connection parameters in bashrc] *********
2025-12-10 11:38:52.674375 | controller | Wednesday 10 December 2025  11:38:52 +0000 (0:00:00.287)       0:02:44.556 ****
2025-12-10 11:38:52.674384 | controller | [WARNING]: Reset is not implemented for this connection
2025-12-10 11:38:52.694726 | controller | changed: [instance]
2025-12-10 11:38:52.694784 | controller |
2025-12-10 11:38:52.694805 | controller | TASK [libvirt_manager : Ensure we reload user env] *****************************
2025-12-10 11:38:52.695662 | controller | Wednesday 10 December 2025  11:38:52 +0000 (0:00:00.257)       0:02:44.813 ****
2025-12-10 11:38:52.697347 | controller |
2025-12-10 11:38:52.697366 | controller | PLAY RECAP *********************************************************************
2025-12-10 11:38:52.697375 | controller | instance                   : ok=68   changed=43   unreachable=0    failed=0    skipped=34   rescued=0    ignored=0
2025-12-10 11:38:52.697380 | controller |
2025-12-10 11:38:52.697385 | controller | Wednesday 10 December 2025  11:38:52 +0000 (0:00:00.024)       0:02:44.838 ****
2025-12-10 11:38:52.697397 | controller | ===============================================================================
2025-12-10 11:38:52.750631 | controller | libvirt_manager : Install packages required for using KVM -------------- 92.30s
2025-12-10 11:38:52.750662 | controller | test_deps : Install selinux python libs -------------------------------- 38.28s
2025-12-10 11:38:52.750670 | controller | repo_setup : Initialize python venv and install requirements ------------ 7.46s
2025-12-10 11:38:52.750676 | controller | Install some debug utils ------------------------------------------------ 4.89s
2025-12-10 11:38:52.750682 | controller | test_deps : Install python yaml libs ------------------------------------ 1.10s
2025-12-10 11:38:52.750687 | controller | repo_setup : Get repo-setup repository ---------------------------------- 1.06s
2025-12-10 11:38:52.750692 | controller | libvirt_manager : Ensure firewalld service is up ------------------------ 0.83s
2025-12-10 11:38:52.750698 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.78s
2025-12-10 11:38:52.750703 | controller | Gathering Facts --------------------------------------------------------- 0.76s
2025-12-10 11:38:52.750709 | controller | libvirt_manager : Reload systemctl and start/enable virtproxyd.service --- 0.70s
2025-12-10 11:38:52.750714 | controller | repo_setup : Install repo-setup package --------------------------------- 0.68s
2025-12-10 11:38:52.750724 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.65s
2025-12-10 11:38:52.750730 | controller | libvirt_manager : Restart service polkit service ------------------------ 0.65s
2025-12-10 11:38:52.750735 | controller | repo_setup : Make sure git-core package is installed -------------------- 0.64s
2025-12-10 11:38:52.750741 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.53s
2025-12-10 11:38:52.750746 | controller | repo_setup : Ensure directories are present ----------------------------- 0.50s
2025-12-10 11:38:52.750751 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.41s
2025-12-10 11:38:52.750757 | controller | libvirt_manager : Enable UNIX socket PolicyKit auth --------------------- 0.37s
2025-12-10 11:38:52.750762 | controller | libvirt_manager : Add user if not exists in libvirt group --------------- 0.37s
2025-12-10 11:38:52.750767 | controller | libvirt_manager : Ensure read-write socket is enabled for network. ------ 0.37s
2025-12-10 11:38:52.750776 | controller | INFO     Running build > converge
2025-12-10 11:38:53.145352 | controller |
2025-12-10 11:38:53.909616 | controller | PLAY [Converge] ****************************************************************
2025-12-10 11:38:53.909658 | controller |
2025-12-10 11:38:53.909667 | controller | TASK [Gathering Facts] *********************************************************
2025-12-10 11:38:53.909673 | controller | Wednesday 10 December 2025  11:38:53 +0000 (0:00:00.011)       0:00:00.011 ****
2025-12-10 11:38:53.909682 | controller | ok: [instance]
2025-12-10 11:38:54.251990 | controller |
2025-12-10 11:38:54.252008 | controller | TASK [Crate SSH keypair] *******************************************************
2025-12-10 11:38:54.252016 | controller | Wednesday 10 December 2025  11:38:53 +0000 (0:00:00.764)       0:00:00.776 ****
2025-12-10 11:38:54.252024 | controller | changed: [instance]
2025-12-10 11:38:54.715098 | controller |
2025-12-10 11:38:54.715125 | controller | TASK [Enable forwarding in the libvirt zone] ***********************************
2025-12-10 11:38:54.715133 | controller | Wednesday 10 December 2025  11:38:54 +0000 (0:00:00.342)       0:00:01.119 ****
2025-12-10 11:38:54.715142 | controller | changed: [instance]
2025-12-10 11:38:55.584787 | controller |
2025-12-10 11:38:55.584818 | controller | TASK [Restart firewalld.service] ***********************************************
2025-12-10 11:38:55.584826 | controller | Wednesday 10 December 2025  11:38:54 +0000 (0:00:00.462)       0:00:01.582 ****
2025-12-10 11:38:55.584836 | controller | changed: [instance]
2025-12-10 11:38:55.585075 | controller |
2025-12-10 11:38:55.585089 | controller | TASK [Discover latest image] ***************************************************
2025-12-10 11:38:55.623478 | controller | Wednesday 10 December 2025  11:38:55 +0000 (0:00:00.869)       0:00:02.451 ****
2025-12-10 11:38:55.623500 | controller |
2025-12-10 11:38:57.409305 | controller | TASK [discover_latest_image : Get latest image] ********************************
2025-12-10 11:38:57.409333 | controller | Wednesday 10 December 2025  11:38:55 +0000 (0:00:00.039)       0:00:02.490 ****
2025-12-10 11:38:57.409350 | controller | changed: [instance]
2025-12-10 11:38:57.434499 | controller |
2025-12-10 11:38:57.434514 | controller | TASK [discover_latest_image : Export facts accordingly] ************************
2025-12-10 11:38:57.434521 | controller | Wednesday 10 December 2025  11:38:57 +0000 (0:00:01.785)       0:00:04.276 ****
2025-12-10 11:38:57.434529 | controller | ok: [instance]
2025-12-10 11:39:16.892273 | controller |
2025-12-10 11:39:16.892306 | controller | TASK [Download latest image] ***************************************************
2025-12-10 11:39:16.892315 | controller | Wednesday 10 December 2025  11:38:57 +0000 (0:00:00.025)       0:00:04.301 ****
2025-12-10 11:39:16.892325 | controller | changed: [instance]
2025-12-10 11:39:16.930638 | controller |
2025-12-10 11:39:16.930657 | controller | TASK [Build nat64 appliance image] *********************************************
2025-12-10 11:39:16.930665 | controller | Wednesday 10 December 2025  11:39:16 +0000 (0:00:19.457)       0:00:23.759 ****
2025-12-10 11:39:16.930673 | controller |
2025-12-10 11:39:17.382109 | controller | TASK [nat64_appliance : Ensure needed directories exist] ***********************
2025-12-10 11:39:17.382137 | controller | Wednesday 10 December 2025  11:39:16 +0000 (0:00:00.038)       0:00:23.797 ****
2025-12-10 11:39:17.382155 | controller | ok: [instance] => (item=artifacts)
2025-12-10 11:39:17.565237 | controller | ok: [instance] => (item=logs)
2025-12-10 11:39:17.565264 | controller |
2025-12-10 11:39:17.565272 | controller | TASK [nat64_appliance : Ensure working directory exists] ***********************
2025-12-10 11:39:17.565278 | controller | Wednesday 10 December 2025  11:39:17 +0000 (0:00:00.451)       0:00:24.248 ****
2025-12-10 11:39:17.565287 | controller | changed: [instance]
2025-12-10 11:39:21.994529 | controller |
2025-12-10 11:39:21.994558 | controller | TASK [nat64_appliance : Install required RPM packages] *************************
2025-12-10 11:39:21.994565 | controller | Wednesday 10 December 2025  11:39:17 +0000 (0:00:00.183)       0:00:24.432 ****
2025-12-10 11:39:21.994574 | controller | ok: [instance]
2025-12-10 11:39:29.511106 | controller |
2025-12-10 11:39:29.511136 | controller | TASK [nat64_appliance : Install diskimage-builder in virtualenv] ***************
2025-12-10 11:39:29.511144 | controller | Wednesday 10 December 2025  11:39:21 +0000 (0:00:04.429)       0:00:28.861 ****
2025-12-10 11:39:29.511153 | controller | changed: [instance]
2025-12-10 11:39:38.761220 | controller |
2025-12-10 11:39:38.761249 | controller | TASK [nat64_appliance : Copy files to cifmw_nat64_appliance_dir] ***************
2025-12-10 11:39:38.761258 | controller | Wednesday 10 December 2025  11:39:29 +0000 (0:00:07.516)       0:00:36.378 ****
2025-12-10 11:39:38.761268 | controller | changed: [instance] => (item=elements/)
2025-12-10 11:39:39.832684 | controller | changed: [instance] => (item=nat64-appliance.yaml)
2025-12-10 11:39:39.832712 | controller |
2025-12-10 11:39:39.832719 | controller | TASK [nat64_appliance : Clone edpm-image-builder (reset-bls-entries dib element)] ***
2025-12-10 11:39:39.832725 | controller | Wednesday 10 December 2025  11:39:38 +0000 (0:00:09.249)       0:00:45.627 ****
2025-12-10 11:39:39.832735 | controller | changed: [instance]
2025-12-10 11:39:39.832758 | controller |
2025-12-10 11:39:39.832960 | controller | TASK [nat64_appliance : Build the nat64-appliance image using DIB] *************
2025-12-10 11:44:05.792738 | controller | Wednesday 10 December 2025  11:39:39 +0000 (0:00:01.071)       0:00:46.699 ****
2025-12-10 11:44:05.793019 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_000_build_the_nat64_appliance.log
2025-12-10 11:44:05.827711 | controller | changed: [instance]
2025-12-10 11:44:05.827745 | controller |
2025-12-10 11:44:05.827753 | controller | TASK [nat64_appliance : Download pre-built NAT64 appliance image] **************
2025-12-10 11:44:05.827760 | controller | Wednesday 10 December 2025  11:44:05 +0000 (0:04:25.959)       0:05:12.659 ****
2025-12-10 11:44:05.827771 | controller | skipping: [instance]
2025-12-10 11:44:05.827802 | controller |
2025-12-10 11:44:05.827811 | controller | TASK [Fix permissions on logs dir - because we ran dib as root] ****************
2025-12-10 11:44:05.827986 | controller | Wednesday 10 December 2025  11:44:05 +0000 (0:00:00.035)       0:05:12.694 ****
2025-12-10 11:44:06.030170 | controller | changed: [instance]
2025-12-10 11:44:13.067043 | controller |
2025-12-10 11:44:13.067074 | controller | TASK [Fix permissions on nat64_appliance dir - because we ran dib as root] *****
2025-12-10 11:44:13.067082 | controller | Wednesday 10 December 2025  11:44:06 +0000 (0:00:00.202)       0:05:12.897 ****
2025-12-10 11:44:13.067091 | controller | changed: [instance]
2025-12-10 11:44:13.111320 | controller |
2025-12-10 11:44:13.111344 | controller | TASK [Deploy the nat64 appliance and networks] *********************************
2025-12-10 11:44:13.111354 | controller | Wednesday 10 December 2025  11:44:13 +0000 (0:00:07.036)       0:05:19.933 ****
2025-12-10 11:44:13.111366 | controller |
2025-12-10 11:44:13.164446 | controller | TASK [nat64_appliance : Set MAC address facts] *********************************
2025-12-10 11:44:13.164469 | controller | Wednesday 10 December 2025  11:44:13 +0000 (0:00:00.044)       0:05:19.978 ****
2025-12-10 11:44:13.164483 | controller | ok: [instance]
2025-12-10 11:44:13.914801 | controller |
2025-12-10 11:44:13.914832 | controller | TASK [nat64_appliance : Create the IPv4 libvirt network for nat64] *************
2025-12-10 11:44:13.914846 | controller | Wednesday 10 December 2025  11:44:13 +0000 (0:00:00.052)       0:05:20.031 ****
2025-12-10 11:44:13.914857 | controller | changed: [instance]
2025-12-10 11:44:13.914961 | controller |
2025-12-10 11:44:13.914973 | controller | TASK [nat64_appliance : Ensure the IPv4 libvirt network for nat64 is created/started] ***
2025-12-10 11:44:13.915104 | controller | Wednesday 10 December 2025  11:44:13 +0000 (0:00:00.750)       0:05:20.782 ****
2025-12-10 11:44:14.221722 | controller | ok: [instance]
2025-12-10 11:44:14.221832 | controller |
2025-12-10 11:44:14.221862 | controller | TASK [nat64_appliance : Ensure the IPv4 libvirt network for nat64 is active] ***
2025-12-10 11:44:14.221874 | controller | Wednesday 10 December 2025  11:44:14 +0000 (0:00:00.306)       0:05:21.088 ****
2025-12-10 11:44:14.449165 | controller | ok: [instance]
2025-12-10 11:44:14.657685 | controller |
2025-12-10 11:44:14.657713 | controller | TASK [nat64_appliance : Ensure the IPv4 libvirt network for nat64 is enabled to autostart] ***
2025-12-10 11:44:14.657721 | controller | Wednesday 10 December 2025  11:44:14 +0000 (0:00:00.227)       0:05:21.316 ****
2025-12-10 11:44:14.657731 | controller | changed: [instance]
2025-12-10 11:44:14.657753 | controller |
2025-12-10 11:44:14.657761 | controller | TASK [nat64_appliance : Create the IPv6 libvirt network for nat64] *************
2025-12-10 11:44:14.657909 | controller | Wednesday 10 December 2025  11:44:14 +0000 (0:00:00.208)       0:05:21.524 ****
2025-12-10 11:44:14.882499 | controller | changed: [instance]
2025-12-10 11:44:15.115174 | controller |
2025-12-10 11:44:15.115204 | controller | TASK [nat64_appliance : Ensure the IPv6 libvirt network for nat64 is created/started] ***
2025-12-10 11:44:15.115212 | controller | Wednesday 10 December 2025  11:44:14 +0000 (0:00:00.224)       0:05:21.749 ****
2025-12-10 11:44:15.115221 | controller | ok: [instance]
2025-12-10 11:44:15.317468 | controller |
2025-12-10 11:44:15.317496 | controller | TASK [nat64_appliance : Ensure the IPv6 libvirt network for nat64 network is active] ***
2025-12-10 11:44:15.317504 | controller | Wednesday 10 December 2025  11:44:15 +0000 (0:00:00.232)       0:05:21.982 ****
2025-12-10 11:44:15.317514 | controller | ok: [instance]
2025-12-10 11:44:15.531047 | controller |
2025-12-10 11:44:15.531070 | controller | TASK [nat64_appliance : Ensure the IPv6 libvirt network for nat64 is enabled to autostart] ***
2025-12-10 11:44:15.531077 | controller | Wednesday 10 December 2025  11:44:15 +0000 (0:00:00.202)       0:05:22.184 ****
2025-12-10 11:44:15.531087 | controller | changed: [instance]
2025-12-10 11:44:16.278337 | controller |
2025-12-10 11:44:16.278366 | controller | TASK [nat64_appliance : Make sure all bridges are in the libvirt firewalld zone] ***
2025-12-10 11:44:16.278375 | controller | Wednesday 10 December 2025  11:44:15 +0000 (0:00:00.213)       0:05:22.398 ****
2025-12-10 11:44:16.278385 | controller | changed: [instance] => (item=br-64v6)
2025-12-10 11:44:17.093978 | controller | changed: [instance] => (item=br-64v4)
2025-12-10 11:44:17.094006 | controller |
2025-12-10 11:44:17.094014 | controller | TASK [nat64_appliance : Restart firewalld.service] *****************************
2025-12-10 11:44:17.094019 | controller | Wednesday 10 December 2025  11:44:16 +0000 (0:00:00.746)       0:05:23.145 ****
2025-12-10 11:44:17.094028 | controller | changed: [instance]
2025-12-10 11:44:17.124356 | controller |
2025-12-10 11:44:17.124375 | controller | TASK [nat64_appliance : Generate nat64-appliance UUID] *************************
2025-12-10 11:44:17.124383 | controller | Wednesday 10 December 2025  11:44:17 +0000 (0:00:00.815)       0:05:23.960 ****
2025-12-10 11:44:17.124391 | controller | ok: [instance]
2025-12-10 11:44:17.158096 | controller |
2025-12-10 11:44:17.158113 | controller | TASK [Create the config-drive ISO for the nat64-appliance] *********************
2025-12-10 11:44:17.158119 | controller | Wednesday 10 December 2025  11:44:17 +0000 (0:00:00.030)       0:05:23.991 ****
2025-12-10 11:44:17.158128 | controller |
2025-12-10 11:44:17.528431 | controller | TASK [config_drive : Ensure needed directories exist] **************************
2025-12-10 11:44:17.528462 | controller | Wednesday 10 December 2025  11:44:17 +0000 (0:00:00.033)       0:05:24.025 ****
2025-12-10 11:44:17.528473 | controller | ok: [instance] => (item=artifacts)
2025-12-10 11:44:18.884999 | controller | ok: [instance] => (item=logs)
2025-12-10 11:44:18.885027 | controller |
2025-12-10 11:44:18.885035 | controller | TASK [config_drive : Install required RPM packages] ****************************
2025-12-10 11:44:18.885041 | controller | Wednesday 10 December 2025  11:44:17 +0000 (0:00:00.369)       0:05:24.395 ****
2025-12-10 11:44:18.885050 | controller | ok: [instance]
2025-12-10 11:44:19.082260 | controller |
2025-12-10 11:44:19.082290 | controller | TASK [config_drive : Crate config drive instance directory] ********************
2025-12-10 11:44:19.082299 | controller | Wednesday 10 December 2025  11:44:18 +0000 (0:00:01.356)       0:05:25.752 ****
2025-12-10 11:44:19.082309 | controller | changed: [instance]
2025-12-10 11:44:19.427630 | controller |
2025-12-10 11:44:19.427660 | controller | TASK [config_drive : Generate meta-data] ***************************************
2025-12-10 11:44:19.427668 | controller | Wednesday 10 December 2025  11:44:19 +0000 (0:00:00.197)       0:05:25.949 ****
2025-12-10 11:44:19.427684 | controller | changed: [instance]
2025-12-10 11:44:19.794018 | controller |
2025-12-10 11:44:19.794049 | controller | TASK [config_drive : Generate user-data] ***************************************
2025-12-10 11:44:19.794057 | controller | Wednesday 10 December 2025  11:44:19 +0000 (0:00:00.345)       0:05:26.294 ****
2025-12-10 11:44:19.794066 | controller | changed: [instance]
2025-12-10 11:44:20.142532 | controller |
2025-12-10 11:44:20.142564 | controller | TASK [config_drive : Generate network-data] ************************************
2025-12-10 11:44:20.142573 | controller | Wednesday 10 December 2025  11:44:19 +0000 (0:00:00.366)       0:05:26.661 ****
2025-12-10 11:44:20.142583 | controller | changed: [instance]
2025-12-10 11:44:20.316234 | controller |
2025-12-10 11:44:20.316263 | controller | TASK [config_drive : Check ISO availability] ***********************************
2025-12-10 11:44:20.316272 | controller | Wednesday 10 December 2025  11:44:20 +0000 (0:00:00.348)       0:05:27.009 ****
2025-12-10 11:44:20.316282 | controller | ok: [instance]
2025-12-10 11:44:20.332641 | controller |
2025-12-10 11:44:20.332669 | controller | TASK [config_drive : Assert we don't try to change an existing ISO] ************
2025-12-10 11:44:20.332677 | controller | Wednesday 10 December 2025  11:44:20 +0000 (0:00:00.173)       0:05:27.183 ****
2025-12-10 11:44:20.332687 | controller | skipping: [instance]
2025-12-10 11:44:20.545683 | controller |
2025-12-10 11:44:20.545718 | controller | TASK [config_drive : Generate nocloud iso image] *******************************
2025-12-10 11:44:20.545726 | controller | Wednesday 10 December 2025  11:44:20 +0000 (0:00:00.016)       0:05:27.199 ****
2025-12-10 11:44:20.545736 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_001_generate_nocloud_iso.log
2025-12-10 11:44:20.545759 | controller | changed: [instance]
2025-12-10 11:44:20.545766 | controller |
2025-12-10 11:44:20.545773 | controller | TASK [nat64_appliance : Define nat64-appliance VM] *****************************
2025-12-10 11:44:20.545863 | controller | Wednesday 10 December 2025  11:44:20 +0000 (0:00:00.213)       0:05:27.412 ****
2025-12-10 11:44:21.661033 | controller | changed: [instance]
2025-12-10 11:44:22.189642 | controller |
2025-12-10 11:44:22.189670 | controller | TASK [nat64_appliance : Start nat64-appliance VM] ******************************
2025-12-10 11:44:22.189678 | controller | Wednesday 10 December 2025  11:44:21 +0000 (0:00:01.115)       0:05:28.527 ****
2025-12-10 11:44:22.189688 | controller | changed: [instance]
2025-12-10 11:44:22.211531 | controller |
2025-12-10 11:44:22.211565 | controller | TASK [nat64_appliance : Set nat64 facts] ***************************************
2025-12-10 11:44:22.211573 | controller | Wednesday 10 December 2025  11:44:22 +0000 (0:00:00.528)       0:05:29.056 ****
2025-12-10 11:44:22.211581 | controller | ok: [instance]
2025-12-10 11:44:22.247759 | controller |
2025-12-10 11:44:22.247789 | controller | TASK [Set MAC address facts] ***************************************************
2025-12-10 11:44:22.247797 | controller | Wednesday 10 December 2025  11:44:22 +0000 (0:00:00.022)       0:05:29.078 ****
2025-12-10 11:44:22.247807 | controller | ok: [instance]
2025-12-10 11:44:22.473996 | controller |
2025-12-10 11:44:22.474023 | controller | TASK [Define a IPv6 network for test node] *************************************
2025-12-10 11:44:22.474031 | controller | Wednesday 10 December 2025  11:44:22 +0000 (0:00:00.036)       0:05:29.114 ****
2025-12-10 11:44:22.474041 | controller | changed: [instance]
2025-12-10 11:44:22.734386 | controller |
2025-12-10 11:44:22.734417 | controller | TASK [Create a IPv6 network for test node] *************************************
2025-12-10 11:44:22.734425 | controller | Wednesday 10 December 2025  11:44:22 +0000 (0:00:00.224)       0:05:29.339 ****
2025-12-10 11:44:22.734434 | controller | ok: [instance]
2025-12-10 11:44:22.944553 | controller |
2025-12-10 11:44:22.944582 | controller | TASK [Ensure the IPv6 network for test node is active] *************************
2025-12-10 11:44:22.944590 | controller | Wednesday 10 December 2025  11:44:22 +0000 (0:00:00.262)       0:05:29.601 ****
2025-12-10 11:44:22.944616 | controller | ok: [instance]
2025-12-10 11:44:23.164562 | controller |
2025-12-10 11:44:23.164609 | controller | TASK [Ensure the IPv6 network for test node is enabled to autostart] ***********
2025-12-10 11:44:23.164628 | controller | Wednesday 10 December 2025  11:44:22 +0000 (0:00:00.210)       0:05:29.811 ****
2025-12-10 11:44:23.164640 | controller | changed: [instance]
2025-12-10 11:44:23.503132 | controller |
2025-12-10 11:44:23.503166 | controller | TASK [Make sure br-mol bridge is in the libvirt firewalld zone] ****************
2025-12-10 11:44:23.503174 | controller | Wednesday 10 December 2025  11:44:23 +0000 (0:00:00.219)       0:05:30.031 ****
2025-12-10 11:44:23.503184 | controller | changed: [instance]
2025-12-10 11:44:24.385408 | controller |
2025-12-10 11:44:24.385441 | controller | TASK [Restart firewalld.service] ***********************************************
2025-12-10 11:44:24.385450 | controller | Wednesday 10 December 2025  11:44:23 +0000 (0:00:00.338)       0:05:30.369 ****
2025-12-10 11:44:24.385460 | controller | changed: [instance]
2025-12-10 11:44:24.420052 | controller |
2025-12-10 11:44:24.420095 | controller | TASK [Generate test node UUID] *************************************************
2025-12-10 11:44:24.420111 | controller | Wednesday 10 December 2025  11:44:24 +0000 (0:00:00.882)       0:05:31.252 ****
2025-12-10 11:44:24.420123 | controller | ok: [instance]
2025-12-10 11:44:33.151453 | controller |
2025-12-10 11:44:33.151491 | controller | TASK [Make an a copy of the discovered/downloaded image] ***********************
2025-12-10 11:44:33.151500 | controller | Wednesday 10 December 2025  11:44:24 +0000 (0:00:00.033)       0:05:31.285 ****
2025-12-10 11:44:33.151511 | controller | changed: [instance]
2025-12-10 11:44:33.200269 | controller |
2025-12-10 11:44:33.200289 | controller | TASK [Create the config-drive ISO for the test node] ***************************
2025-12-10 11:44:33.200297 | controller | Wednesday 10 December 2025  11:44:33 +0000 (0:00:08.732)       0:05:40.017 ****
2025-12-10 11:44:33.200306 | controller |
2025-12-10 11:44:33.584475 | controller | TASK [config_drive : Ensure needed directories exist] **************************
2025-12-10 11:44:33.584509 | controller | Wednesday 10 December 2025  11:44:33 +0000 (0:00:00.049)       0:05:40.067 ****
2025-12-10 11:44:33.584522 | controller | ok: [instance] => (item=artifacts)
2025-12-10 11:44:34.842716 | controller | ok: [instance] => (item=logs)
2025-12-10 11:44:34.842749 | controller |
2025-12-10 11:44:34.842758 | controller | TASK [config_drive : Install required RPM packages] ****************************
2025-12-10 11:44:34.842764 | controller | Wednesday 10 December 2025  11:44:33 +0000 (0:00:00.380)       0:05:40.448 ****
2025-12-10 11:44:34.842774 | controller | ok: [instance]
2025-12-10 11:44:35.055257 | controller |
2025-12-10 11:44:35.055285 | controller | TASK [config_drive : Crate config drive instance directory] ********************
2025-12-10 11:44:35.055293 | controller | Wednesday 10 December 2025  11:44:34 +0000 (0:00:01.261)       0:05:41.709 ****
2025-12-10 11:44:35.055303 | controller | changed: [instance]
2025-12-10 11:44:35.411136 | controller |
2025-12-10 11:44:35.411164 | controller | TASK [config_drive : Generate meta-data] ***************************************
2025-12-10 11:44:35.411172 | controller | Wednesday 10 December 2025  11:44:35 +0000 (0:00:00.212)       0:05:41.922 ****
2025-12-10 11:44:35.411182 | controller | changed: [instance]
2025-12-10 11:44:35.764872 | controller |
2025-12-10 11:44:35.764897 | controller | TASK [config_drive : Generate user-data] ***************************************
2025-12-10 11:44:35.764905 | controller | Wednesday 10 December 2025  11:44:35 +0000 (0:00:00.355)       0:05:42.277 ****
2025-12-10 11:44:35.764914 | controller | changed: [instance]
2025-12-10 11:44:36.123758 | controller |
2025-12-10 11:44:36.123786 | controller | TASK [config_drive : Generate network-data] ************************************
2025-12-10 11:44:36.123795 | controller | Wednesday 10 December 2025  11:44:35 +0000 (0:00:00.354)       0:05:42.631 ****
2025-12-10 11:44:36.123805 | controller | changed: [instance]
2025-12-10 11:44:36.356348 | controller |
2025-12-10 11:44:36.356374 | controller | TASK [config_drive : Check ISO availability] ***********************************
2025-12-10 11:44:36.356382 | controller | Wednesday 10 December 2025  11:44:36 +0000 (0:00:00.352)       0:05:42.984 ****
2025-12-10 11:44:36.356392 | controller | ok: [instance]
2025-12-10 11:44:36.373983 | controller |
2025-12-10 11:44:36.374006 | controller | TASK [config_drive : Assert we don't try to change an existing ISO] ************
2025-12-10 11:44:36.374014 | controller | Wednesday 10 December 2025  11:44:36 +0000 (0:00:00.238)       0:05:43.223 ****
2025-12-10 11:44:36.374024 | controller | skipping: [instance]
2025-12-10 11:44:36.589362 | controller |
2025-12-10 11:44:36.589397 | controller | TASK [config_drive : Generate nocloud iso image] *******************************
2025-12-10 11:44:36.589405 | controller | Wednesday 10 December 2025  11:44:36 +0000 (0:00:00.017)       0:05:43.241 ****
2025-12-10 11:44:36.589416 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_002_generate_nocloud_iso.log
2025-12-10 11:44:36.867361 | controller | changed: [instance]
2025-12-10 11:44:36.867390 | controller |
2025-12-10 11:44:36.867399 | controller | TASK [Define test-node VM] *****************************************************
2025-12-10 11:44:36.867406 | controller | Wednesday 10 December 2025  11:44:36 +0000 (0:00:00.214)       0:05:43.455 ****
2025-12-10 11:44:36.867415 | controller | changed: [instance]
2025-12-10 11:44:37.347054 | controller |
2025-12-10 11:44:37.347097 | controller | TASK [Start test-node VM] ******************************************************
2025-12-10 11:44:37.347106 | controller | Wednesday 10 December 2025  11:44:36 +0000 (0:00:00.275)       0:05:43.731 ****
2025-12-10 11:44:37.347116 | controller | changed: [instance]
2025-12-10 11:45:02.983641 | controller |
2025-12-10 11:45:02.983681 | controller | TASK [Wait for test node to be reachable via ssh] ******************************
2025-12-10 11:45:02.983690 | controller | Wednesday 10 December 2025  11:44:37 +0000 (0:00:00.481)       0:05:44.213 ****
2025-12-10 11:45:02.983701 | controller | ok: [instance]
2025-12-10 11:45:03.005363 | controller |
2025-12-10 11:45:03.005390 | controller | TASK [Add test node to inventory] **********************************************
2025-12-10 11:45:03.005399 | controller | Wednesday 10 December 2025  11:45:02 +0000 (0:00:25.636)       0:06:09.850 ****
2025-12-10 11:45:03.005467 | controller | changed: [instance]
2025-12-10 11:45:03.027712 | controller |
2025-12-10 11:45:03.027750 | controller | TASK [Add nat64 appliance to the invetory] *************************************
2025-12-10 11:45:03.027759 | controller | Wednesday 10 December 2025  11:45:03 +0000 (0:00:00.021)       0:06:09.872 ****
2025-12-10 11:45:03.027770 | controller | changed: [instance]
2025-12-10 11:45:03.027788 | controller |
2025-12-10 11:45:03.027795 | controller | TASK [Wait a little to let the test instance boot.] ****************************
2025-12-10 11:45:03.027802 | controller | Wednesday 10 December 2025  11:45:03 +0000 (0:00:00.020)       0:06:09.893 ****
2025-12-10 11:45:23.068555 | controller | Pausing for 20 seconds
2025-12-10 11:45:23.068625 | controller | ok: [instance]
2025-12-10 11:45:23.068638 | controller |
2025-12-10 11:45:23.068855 | controller | TASK [Run some commands to test the nat64-appliance DNS64 functions] ***********
2025-12-10 11:45:29.539005 | controller | Wednesday 10 December 2025  11:45:23 +0000 (0:00:20.042)       0:06:29.935 ****
2025-12-10 11:45:29.539039 | controller | changed: [instance]
2025-12-10 11:45:30.507762 | controller |
2025-12-10 11:45:30.507794 | controller | TASK [Grab some info from the test node] ***************************************
2025-12-10 11:45:30.507802 | controller | Wednesday 10 December 2025  11:45:29 +0000 (0:00:06.470)       0:06:36.406 ****
2025-12-10 11:45:30.507812 | controller | changed: [instance -> test-node(2620:cf:cf:aaaa::101)]
2025-12-10 11:45:30.507834 | controller |
2025-12-10 11:45:30.508014 | controller | TASK [Grab some info from the nat64 appliance] *********************************
2025-12-10 11:45:31.517695 | controller | Wednesday 10 December 2025  11:45:30 +0000 (0:00:00.968)       0:06:37.374 ****
2025-12-10 11:45:31.517734 | controller | changed: [instance -> nat64-appliance(172.31.255.2)]
2025-12-10 11:45:31.518324 | controller |
2025-12-10 11:45:31.518774 | controller | TASK [Grab the journal from the nat64 appliance] *******************************
2025-12-10 11:45:31.518827 | controller | Wednesday 10 December 2025  11:45:31 +0000 (0:00:01.009)       0:06:38.384 ****
2025-12-10 11:45:32.109069 | controller | changed: [instance -> nat64-appliance(172.31.255.2)]
2025-12-10 11:45:32.109191 | controller |
2025-12-10 11:45:32.109221 | controller | TASK [Grab some info from hypervisor] ******************************************
2025-12-10 11:45:32.109233 | controller | Wednesday 10 December 2025  11:45:32 +0000 (0:00:00.591)       0:06:38.976 ****
2025-12-10 11:45:32.608668 | controller | changed: [instance]
2025-12-10 11:45:32.952718 | controller |
2025-12-10 11:45:32.952751 | controller | TASK [Write test-node info to file] ********************************************
2025-12-10 11:45:32.952759 | controller | Wednesday 10 December 2025  11:45:32 +0000 (0:00:00.499)       0:06:39.475 ****
2025-12-10 11:45:32.952769 | controller | changed: [instance]
2025-12-10 11:45:33.282156 | controller |
2025-12-10 11:45:33.282185 | controller | TASK [Write nat64-appliance info to file] **************************************
2025-12-10 11:45:33.282194 | controller | Wednesday 10 December 2025  11:45:32 +0000 (0:00:00.344)       0:06:39.819 ****
2025-12-10 11:45:33.282204 | controller | changed: [instance]
2025-12-10 11:45:33.612361 | controller |
2025-12-10 11:45:33.612390 | controller | TASK [Write nat64-appliance journal to file] ***********************************
2025-12-10 11:45:33.612397 | controller | Wednesday 10 December 2025  11:45:33 +0000 (0:00:00.329)       0:06:40.149 ****
2025-12-10 11:45:33.612406 | controller | changed: [instance]
2025-12-10 11:45:33.925399 | controller |
2025-12-10 11:45:33.925422 | controller | TASK [Write nat64-appliance DNS64 debug to file] *******************************
2025-12-10 11:45:33.925430 | controller | Wednesday 10 December 2025  11:45:33 +0000 (0:00:00.330)       0:06:40.479 ****
2025-12-10 11:45:33.925439 | controller | changed: [instance]
2025-12-10 11:45:34.257216 | controller |
2025-12-10 11:45:34.257256 | controller | TASK [Write hypervisor info to file] *******************************************
2025-12-10 11:45:34.257264 | controller | Wednesday 10 December 2025  11:45:33 +0000 (0:00:00.313)       0:06:40.792 ****
2025-12-10 11:45:34.257275 | controller | changed: [instance]
2025-12-10 11:45:35.839765 | controller |
2025-12-10 11:45:35.839798 | controller | TASK [Ping example.com (delegate to test-node)] ********************************
2025-12-10 11:45:35.839806 | controller | Wednesday 10 December 2025  11:45:34 +0000 (0:00:00.331)       0:06:41.124 ****
2025-12-10 11:45:35.839816 | controller | changed: [instance -> test-node(2620:cf:cf:aaaa::101)]
2025-12-10 11:45:35.839974 | controller |
2025-12-10 11:45:35.840005 | controller | TASK [Debug the ping example.com result] ***************************************
2025-12-10 11:45:35.877683 | controller | Wednesday 10 December 2025  11:45:35 +0000 (0:00:01.582)       0:06:42.706 ****
2025-12-10 11:45:35.877715 | controller | ok: [instance] => (item=0) =>
2025-12-10 11:45:35.879648 | controller |   msg: '0'
2025-12-10 11:45:35.879665 | controller | ok: [instance] => (item=['PING example.com(a23-220-75-232.deploy.static.akamaitechnologies.com (2620:cf:cf:fcff::17dc:4be8)) 56 data bytes', '64 bytes from a23-220-75-232.deploy.static.akamaitechnologies.com (2620:cf:cf:fcff::17dc:4be8): icmp_seq=1 ttl=44 time=39.1 ms', '64 bytes from a23-220-75-232.deploy.static.akamaitechnologies.com (2620:cf:cf:fcff::17dc:4be8): icmp_seq=2 ttl=44 time=39.3 ms', '', '--- example.com ping statistics ---', '2 packets transmitted, 2 received, 0% packet loss, time 1001ms', 'rtt min/avg/max/mdev = 39.145/39.236/39.327/0.091 ms']) =>
2025-12-10 11:45:35.879763 | controller |   msg:
2025-12-10 11:45:35.879771 | controller |   - PING example.com(a23-220-75-232.deploy.static.akamaitechnologies.com (2620:cf:cf:fcff::17dc:4be8)) 56 data bytes
2025-12-10 11:45:35.879777 | controller |   - '64 bytes from a23-220-75-232.deploy.static.akamaitechnologies.com (2620:cf:cf:fcff::17dc:4be8): icmp_seq=1 ttl=44 time=39.1 ms'
2025-12-10 11:45:35.879783 | controller |   - '64 bytes from a23-220-75-232.deploy.static.akamaitechnologies.com (2620:cf:cf:fcff::17dc:4be8): icmp_seq=2 ttl=44 time=39.3 ms'
2025-12-10 11:45:35.879789 | controller |   - ''
2025-12-10 11:45:35.879794 | controller |   - '--- example.com ping statistics ---'
2025-12-10 11:45:35.879799 | controller |   - 2 packets transmitted, 2 received, 0% packet loss, time 1001ms
2025-12-10 11:45:35.879804 | controller |   - rtt min/avg/max/mdev = 39.145/39.236/39.327/0.091 ms
2025-12-10 11:45:35.879809 | controller | ok: [instance] => (item=[]) =>
2025-12-10 11:45:35.879815 | controller |   msg: []
2025-12-10 11:45:35.879820 | controller |
2025-12-10 11:45:35.879825 | controller | PLAY RECAP *********************************************************************
2025-12-10 11:45:35.879830 | controller | instance                   : ok=74   changed=50   unreachable=0    failed=0    skipped=3    rescued=0    ignored=0
2025-12-10 11:45:35.879835 | controller |
2025-12-10 11:45:35.879840 | controller | Wednesday 10 December 2025  11:45:35 +0000 (0:00:00.037)       0:06:42.744 ****
2025-12-10 11:45:35.879845 | controller | ===============================================================================
2025-12-10 11:45:35.879857 | controller | nat64_appliance : Build the nat64-appliance image using DIB ----------- 265.96s
2025-12-10 11:45:35.879862 | controller | Wait for test node to be reachable via ssh ----------------------------- 25.64s
2025-12-10 11:45:35.879874 | controller | Wait a little to let the test instance boot. --------------------------- 20.04s
2025-12-10 11:45:35.879879 | controller | Download latest image -------------------------------------------------- 19.46s
2025-12-10 11:45:35.879884 | controller | nat64_appliance : Copy files to cifmw_nat64_appliance_dir --------------- 9.25s
2025-12-10 11:45:35.879889 | controller | Make an a copy of the discovered/downloaded image ----------------------- 8.73s
2025-12-10 11:45:35.879894 | controller | nat64_appliance : Install diskimage-builder in virtualenv --------------- 7.52s
2025-12-10 11:45:35.879902 | controller | Fix permissions on nat64_appliance dir - because we ran dib as root ----- 7.04s
2025-12-10 11:45:35.879979 | controller | Run some commands to test the nat64-appliance DNS64 functions ----------- 6.47s
2025-12-10 11:45:35.879989 | controller | nat64_appliance : Install required RPM packages ------------------------- 4.43s
2025-12-10 11:45:35.880085 | controller | discover_latest_image : Get latest image -------------------------------- 1.79s
2025-12-10 11:45:35.880201 | controller | Ping example.com (delegate to test-node) -------------------------------- 1.58s
2025-12-10 11:45:35.880299 | controller | config_drive : Install required RPM packages ---------------------------- 1.36s
2025-12-10 11:45:35.880397 | controller | config_drive : Install required RPM packages ---------------------------- 1.26s
2025-12-10 11:45:35.880496 | controller | nat64_appliance : Define nat64-appliance VM ----------------------------- 1.12s
2025-12-10 11:45:35.880627 | controller | nat64_appliance : Clone edpm-image-builder (reset-bls-entries dib element) --- 1.07s
2025-12-10 11:45:35.880740 | controller | Grab some info from the nat64 appliance --------------------------------- 1.01s
2025-12-10 11:45:35.880840 | controller | Grab some info from the test node --------------------------------------- 0.97s
2025-12-10 11:45:35.880944 | controller | Restart firewalld.service ----------------------------------------------- 0.88s
2025-12-10 11:45:35.881043 | controller | Restart firewalld.service ----------------------------------------------- 0.87s
2025-12-10 11:45:35.938120 | controller | INFO     Running build > cleanup
2025-12-10 11:45:36.354311 | controller |
2025-12-10 11:45:36.354498 | controller | PLAY [Cleanup] *****************************************************************
2025-12-10 11:45:36.354660 | controller |
2025-12-10 11:45:36.354799 | controller | TASK [Gathering Facts] *********************************************************
2025-12-10 11:45:36.354927 | controller | Wednesday 10 December 2025  11:45:36 +0000 (0:00:00.043)       0:00:00.044 ****
2025-12-10 11:45:37.243813 | controller | ok: [instance]
2025-12-10 11:45:37.785553 | controller |
2025-12-10 11:45:37.785586 | controller | TASK [Destroy the test-node] ***************************************************
2025-12-10 11:45:37.785594 | controller | Wednesday 10 December 2025  11:45:37 +0000 (0:00:00.889)       0:00:00.933 ****
2025-12-10 11:45:37.785706 | controller | ok: [instance]
2025-12-10 11:45:37.988701 | controller |
2025-12-10 11:45:37.988735 | controller | TASK [Undefine the test-node] **************************************************
2025-12-10 11:45:37.988743 | controller | Wednesday 10 December 2025  11:45:37 +0000 (0:00:00.541)       0:00:01.475 ****
2025-12-10 11:45:37.988752 | controller | ok: [instance]
2025-12-10 11:45:37.988774 | controller |
2025-12-10 11:45:37.988793 | controller | TASK [Destroy the test network] ************************************************
2025-12-10 11:45:37.988917 | controller | Wednesday 10 December 2025  11:45:37 +0000 (0:00:00.203)       0:00:01.678 ****
2025-12-10 11:45:38.324691 | controller | ok: [instance]
2025-12-10 11:45:38.527989 | controller |
2025-12-10 11:45:38.528025 | controller | TASK [Undefine the test network] ***********************************************
2025-12-10 11:45:38.528033 | controller | Wednesday 10 December 2025  11:45:38 +0000 (0:00:00.335)       0:00:02.014 ****
2025-12-10 11:45:38.528049 | controller | ok: [instance]
2025-12-10 11:45:38.558568 | controller |
2025-12-10 11:45:38.558595 | controller | TASK [Cleanup the nat64 appliance and networks] ********************************
2025-12-10 11:45:38.558648 | controller | Wednesday 10 December 2025  11:45:38 +0000 (0:00:00.203)       0:00:02.218 ****
2025-12-10 11:45:38.558662 | controller |
2025-12-10 11:45:38.832593 | controller | TASK [nat64_appliance : Cleaning up nat64_appliance image] *********************
2025-12-10 11:45:38.832648 | controller | Wednesday 10 December 2025  11:45:38 +0000 (0:00:00.030)       0:00:02.248 ****
2025-12-10 11:45:38.832664 | controller | changed: [instance]
2025-12-10 11:45:39.098982 | controller |
2025-12-10 11:45:39.099013 | controller | TASK [nat64_appliance : Get virtqemud socket] **********************************
2025-12-10 11:45:39.099021 | controller | Wednesday 10 December 2025  11:45:38 +0000 (0:00:00.273)       0:00:02.522 ****
2025-12-10 11:45:39.099031 | controller | ok: [instance]
2025-12-10 11:45:39.320215 | controller |
2025-12-10 11:45:39.320241 | controller | TASK [nat64_appliance : List VMs] **********************************************
2025-12-10 11:45:39.320249 | controller | Wednesday 10 December 2025  11:45:39 +0000 (0:00:00.266)       0:00:02.788 ****
2025-12-10 11:45:39.320258 | controller | ok: [instance]
2025-12-10 11:45:39.532473 | controller |
2025-12-10 11:45:39.532497 | controller | TASK [nat64_appliance : Get nat64_appliance VM state] **************************
2025-12-10 11:45:39.532504 | controller | Wednesday 10 December 2025  11:45:39 +0000 (0:00:00.221)       0:00:03.010 ****
2025-12-10 11:45:39.532513 | controller | ok: [instance]
2025-12-10 11:45:39.981066 | controller |
2025-12-10 11:45:39.981108 | controller | TASK [nat64_appliance : Stop the nat64_appliance VM] ***************************
2025-12-10 11:45:39.981117 | controller | Wednesday 10 December 2025  11:45:39 +0000 (0:00:00.212)       0:00:03.222 ****
2025-12-10 11:45:39.981127 | controller | ok: [instance]
2025-12-10 11:45:40.194298 | controller |
2025-12-10 11:45:40.194322 | controller | TASK [nat64_appliance : Undefine the nat64_appliance VM] ***********************
2025-12-10 11:45:40.194329 | controller | Wednesday 10 December 2025  11:45:39 +0000 (0:00:00.448)       0:00:03.670 ****
2025-12-10 11:45:40.194339 | controller | ok: [instance]
2025-12-10 11:45:40.931725 | controller |
2025-12-10 11:45:40.931764 | controller | TASK [nat64_appliance : Destroy the nat64 networks] ****************************
2025-12-10 11:45:40.931776 | controller | Wednesday 10 December 2025  11:45:40 +0000 (0:00:00.213)       0:00:03.884 ****
2025-12-10 11:45:40.931789 | controller | ok: [instance] => (item=nat64-net-v4)
2025-12-10 11:45:40.931823 | controller | ok: [instance] => (item=nat64-net-v6)
2025-12-10 11:45:40.931834 | controller |
2025-12-10 11:45:40.932089 | controller | TASK [nat64_appliance : Undefine the nat64 networks] ***************************
2025-12-10 11:45:41.367735 | controller | Wednesday 10 December 2025  11:45:40 +0000 (0:00:00.737)       0:00:04.621 ****
2025-12-10 11:45:41.367769 | controller | ok: [instance] => (item=nat64-net-v4)
2025-12-10 11:45:41.367805 | controller | ok: [instance] => (item=nat64-net-v6)
2025-12-10 11:45:41.369576 | controller |
2025-12-10 11:45:41.413796 | controller | PLAY RECAP *********************************************************************
2025-12-10 11:45:41.413815 | controller | instance                   : ok=13   changed=1    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-12-10 11:45:41.413823 | controller |
2025-12-10 11:45:41.413829 | controller | Wednesday 10 December 2025  11:45:41 +0000 (0:00:00.436)       0:00:05.058 ****
2025-12-10 11:45:41.413834 | controller | ===============================================================================
2025-12-10 11:45:41.413839 | controller | Gathering Facts --------------------------------------------------------- 0.89s
2025-12-10 11:45:41.413844 | controller | nat64_appliance : Destroy the nat64 networks ---------------------------- 0.74s
2025-12-10 11:45:41.413849 | controller | Destroy the test-node --------------------------------------------------- 0.54s
2025-12-10 11:45:41.413854 | controller | nat64_appliance : Stop the nat64_appliance VM --------------------------- 0.45s
2025-12-10 11:45:41.413859 | controller | nat64_appliance : Undefine the nat64 networks --------------------------- 0.44s
2025-12-10 11:45:41.413864 | controller | Destroy the test network ------------------------------------------------ 0.34s
2025-12-10 11:45:41.413869 | controller | nat64_appliance : Cleaning up nat64_appliance image --------------------- 0.27s
2025-12-10 11:45:41.413874 | controller | nat64_appliance : Get virtqemud socket ---------------------------------- 0.27s
2025-12-10 11:45:41.413879 | controller | nat64_appliance : List VMs ---------------------------------------------- 0.22s
2025-12-10 11:45:41.413884 | controller | nat64_appliance : Undefine the nat64_appliance VM ----------------------- 0.21s
2025-12-10 11:45:41.413894 | controller | nat64_appliance : Get nat64_appliance VM state -------------------------- 0.21s
2025-12-10 11:45:41.413902 | controller | Undefine the test network ----------------------------------------------- 0.20s
2025-12-10 11:45:41.413907 | controller | Undefine the test-node -------------------------------------------------- 0.20s
2025-12-10 11:45:41.413912 | controller | Cleanup the nat64 appliance and networks -------------------------------- 0.03s
2025-12-10 11:45:41.413920 | controller | INFO     Performing prerun with role_name_check=0...
2025-12-10 11:45:59.149085 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:45:59.149595 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:45:59.150097 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:45:59.150544 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:45:59.151043 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+11ceb037 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.0.0+11ceb037 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:45:59.151486 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:45:59.151955 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:45:59.152400 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:45:59.152858 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:45:59.153304 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:45:59.153961 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:45:59.154417 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:45:59.154895 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:45:59.155347 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:45:59.155897 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/1fc58a/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-12-10 11:45:59.164039 | controller | INFO     Running download > prepare
2025-12-10 11:45:59.611151 | controller |
2025-12-10 11:45:59.611321 | controller | PLAY [Prepare] *****************************************************************
2025-12-10 11:45:59.611444 | controller |
2025-12-10 11:45:59.611567 | controller | TASK [Gathering Facts] *********************************************************
2025-12-10 11:45:59.611722 | controller | Wednesday 10 December 2025  11:45:59 +0000 (0:00:00.024)       0:00:00.024 ****
2025-12-10 11:46:00.506002 | controller | ok: [instance]
2025-12-10 11:46:00.854886 | controller |
2025-12-10 11:46:00.854927 | controller | TASK [Create custom basedir] ***************************************************
2025-12-10 11:46:00.854937 | controller | Wednesday 10 December 2025  11:46:00 +0000 (0:00:00.894)       0:00:00.918 ****
2025-12-10 11:46:00.854947 | controller | ok: [instance]
2025-12-10 11:46:02.214357 | controller |
2025-12-10 11:46:02.214390 | controller | TASK [Install some debug utils] ************************************************
2025-12-10 11:46:02.214398 | controller | Wednesday 10 December 2025  11:46:00 +0000 (0:00:00.348)       0:00:01.267 ****
2025-12-10 11:46:02.214408 | controller | ok: [instance]
2025-12-10 11:46:02.243622 | controller |
2025-12-10 11:46:02.243650 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-12-10 11:46:02.243660 | controller | Wednesday 10 December 2025  11:46:02 +0000 (0:00:01.359)       0:00:02.627 ****
2025-12-10 11:46:02.243673 | controller | skipping: [instance]
2025-12-10 11:46:02.298402 | controller |
2025-12-10 11:46:02.298424 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-12-10 11:46:02.298433 | controller | Wednesday 10 December 2025  11:46:02 +0000 (0:00:00.029)       0:00:02.656 ****
2025-12-10 11:46:02.298445 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-12-10 11:46:02.616058 | controller |
2025-12-10 11:46:02.616088 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-12-10 11:46:02.616097 | controller | Wednesday 10 December 2025  11:46:02 +0000 (0:00:00.055)       0:00:02.711 ****
2025-12-10 11:46:02.616106 | controller | ok: [instance]
2025-12-10 11:46:02.857201 | controller |
2025-12-10 11:46:02.857238 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-12-10 11:46:02.857246 | controller | Wednesday 10 December 2025  11:46:02 +0000 (0:00:00.317)       0:00:03.029 ****
2025-12-10 11:46:02.857257 | controller | ok: [instance]
2025-12-10 11:46:03.576691 | controller |
2025-12-10 11:46:03.576726 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-12-10 11:46:03.576735 | controller | Wednesday 10 December 2025  11:46:02 +0000 (0:00:00.240)       0:00:03.269 ****
2025-12-10 11:46:03.576745 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-12-10 11:46:03.576771 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-12-10 11:46:03.576779 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-12-10 11:46:03.577123 | controller |
2025-12-10 11:46:03.645925 | controller | TASK [Deploy repo-setup] *******************************************************
2025-12-10 11:46:03.645992 | controller | Wednesday 10 December 2025  11:46:03 +0000 (0:00:00.719)       0:00:03.989 ****
2025-12-10 11:46:03.646011 | controller |
2025-12-10 11:46:04.263663 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-12-10 11:46:04.263695 | controller | Wednesday 10 December 2025  11:46:03 +0000 (0:00:00.069)       0:00:04.058 ****
2025-12-10 11:46:04.263707 | controller | ok: [instance] => (item=tmp)
2025-12-10 11:46:05.474246 | controller | ok: [instance] => (item=artifacts/repositories)
2025-12-10 11:46:05.474284 | controller | ok: [instance] => (item=venv/repo_setup)
2025-12-10 11:46:05.474292 | controller |
2025-12-10 11:46:05.474299 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-12-10 11:46:05.474310 | controller | Wednesday 10 December 2025  11:46:04 +0000 (0:00:00.617)       0:00:04.676 ****
2025-12-10 11:46:05.474321 | controller | ok: [instance]
2025-12-10 11:46:06.091568 | controller |
2025-12-10 11:46:06.091620 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-12-10 11:46:06.091632 | controller | Wednesday 10 December 2025  11:46:05 +0000 (0:00:01.210)       0:00:05.886 ****
2025-12-10 11:46:06.091643 | controller | ok: [instance]
2025-12-10 11:46:07.414756 | controller |
2025-12-10 11:46:07.414787 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-12-10 11:46:07.414794 | controller | Wednesday 10 December 2025  11:46:06 +0000 (0:00:00.617)       0:00:06.504 ****
2025-12-10 11:46:07.414810 | controller | ok: [instance]
2025-12-10 11:46:07.702301 | controller |
2025-12-10 11:46:07.702325 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-12-10 11:46:07.702333 | controller | Wednesday 10 December 2025  11:46:07 +0000 (0:00:01.323)       0:00:07.827 ****
2025-12-10 11:46:07.702342 | controller | ok: [instance]
2025-12-10 11:46:07.731716 | controller |
2025-12-10 11:46:07.731755 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-12-10 11:46:07.731767 | controller | Wednesday 10 December 2025  11:46:07 +0000 (0:00:00.287)       0:00:08.115 ****
2025-12-10 11:46:07.731781 | controller | skipping: [instance]
2025-12-10 11:46:07.731812 | controller |
2025-12-10 11:46:07.731823 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-12-10 11:46:07.731931 | controller | Wednesday 10 December 2025  11:46:07 +0000 (0:00:00.029)       0:00:08.145 ****
2025-12-10 11:46:08.583357 | controller | changed: [instance]
2025-12-10 11:46:08.633680 | controller |
2025-12-10 11:46:08.633706 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-12-10 11:46:08.633717 | controller | Wednesday 10 December 2025  11:46:08 +0000 (0:00:00.851)       0:00:08.996 ****
2025-12-10 11:46:08.633729 | controller | skipping: [instance]
2025-12-10 11:46:08.634055 | controller |
2025-12-10 11:46:08.681315 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-12-10 11:46:08.681340 | controller | Wednesday 10 December 2025  11:46:08 +0000 (0:00:00.050)       0:00:09.047 ****
2025-12-10 11:46:08.681355 | controller | skipping: [instance]
2025-12-10 11:46:08.727208 | controller |
2025-12-10 11:46:08.727225 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-12-10 11:46:08.727233 | controller | Wednesday 10 December 2025  11:46:08 +0000 (0:00:00.047)       0:00:09.094 ****
2025-12-10 11:46:08.727241 | controller | skipping: [instance]
2025-12-10 11:46:09.287319 | controller |
2025-12-10 11:46:09.287350 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-12-10 11:46:09.287358 | controller | Wednesday 10 December 2025  11:46:08 +0000 (0:00:00.045)       0:00:09.140 ****
2025-12-10 11:46:09.287368 | controller | changed: [instance]
2025-12-10 11:46:09.669727 | controller |
2025-12-10 11:46:09.669761 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-12-10 11:46:09.669770 | controller | Wednesday 10 December 2025  11:46:09 +0000 (0:00:00.559)       0:00:09.699 ****
2025-12-10 11:46:09.669780 | controller | ok: [instance]
2025-12-10 11:46:09.708779 | controller |
2025-12-10 11:46:09.708807 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-12-10 11:46:09.708818 | controller | Wednesday 10 December 2025  11:46:09 +0000 (0:00:00.382)       0:00:10.082 ****
2025-12-10 11:46:09.708829 | controller | skipping: [instance]
2025-12-10 11:46:09.745259 | controller |
2025-12-10 11:46:09.745285 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-12-10 11:46:09.745294 | controller | Wednesday 10 December 2025  11:46:09 +0000 (0:00:00.039)       0:00:10.121 ****
2025-12-10 11:46:09.745303 | controller | skipping: [instance]
2025-12-10 11:46:09.782556 | controller |
2025-12-10 11:46:09.782579 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-12-10 11:46:09.782589 | controller | Wednesday 10 December 2025  11:46:09 +0000 (0:00:00.036)       0:00:10.158 ****
2025-12-10 11:46:09.782620 | controller | skipping: [instance]
2025-12-10 11:46:09.829187 | controller |
2025-12-10 11:46:09.829206 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-12-10 11:46:09.829220 | controller | Wednesday 10 December 2025  11:46:09 +0000 (0:00:00.037)       0:00:10.195 ****
2025-12-10 11:46:09.829229 | controller | ok: [instance]
2025-12-10 11:46:09.898958 | controller |
2025-12-10 11:46:09.898992 | controller | TASK [repo_setup : Create download directory] **********************************
2025-12-10 11:46:09.899005 | controller | Wednesday 10 December 2025  11:46:09 +0000 (0:00:00.046)       0:00:10.242 ****
2025-12-10 11:46:09.899020 | controller | skipping: [instance]
2025-12-10 11:46:09.899273 | controller |
2025-12-10 11:46:09.899434 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-12-10 11:46:09.899571 | controller | Wednesday 10 December 2025  11:46:09 +0000 (0:00:00.070)       0:00:10.312 ****
2025-12-10 11:46:09.934999 | controller | skipping: [instance]
2025-12-10 11:46:09.935179 | controller |
2025-12-10 11:46:09.935357 | controller | TASK [Download the RPM] ********************************************************
2025-12-10 11:46:09.935498 | controller | Wednesday 10 December 2025  11:46:09 +0000 (0:00:00.036)       0:00:10.348 ****
2025-12-10 11:46:09.969287 | controller | skipping: [instance]
2025-12-10 11:46:09.969530 | controller |
2025-12-10 11:46:09.969711 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-12-10 11:46:09.969849 | controller | Wednesday 10 December 2025  11:46:09 +0000 (0:00:00.034)       0:00:10.382 ****
2025-12-10 11:46:10.002431 | controller | skipping: [instance]
2025-12-10 11:46:10.002590 | controller |
2025-12-10 11:46:10.002756 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-12-10 11:46:10.002882 | controller | Wednesday 10 December 2025  11:46:10 +0000 (0:00:00.033)       0:00:10.415 ****
2025-12-10 11:46:10.041015 | controller | skipping: [instance]
2025-12-10 11:46:10.041258 | controller |
2025-12-10 11:46:10.041488 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-12-10 11:46:10.041721 | controller | Wednesday 10 December 2025  11:46:10 +0000 (0:00:00.038)       0:00:10.454 ****
2025-12-10 11:46:10.077105 | controller | skipping: [instance]
2025-12-10 11:46:10.077271 | controller |
2025-12-10 11:46:10.077432 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-12-10 11:46:10.077585 | controller | Wednesday 10 December 2025  11:46:10 +0000 (0:00:00.036)       0:00:10.490 ****
2025-12-10 11:46:10.111046 | controller | skipping: [instance]
2025-12-10 11:46:10.111227 | controller |
2025-12-10 11:46:10.111396 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-12-10 11:46:10.111557 | controller | Wednesday 10 December 2025  11:46:10 +0000 (0:00:00.033)       0:00:10.524 ****
2025-12-10 11:46:10.311427 | controller | ok: [instance]
2025-12-10 11:46:10.530492 | controller |
2025-12-10 11:46:10.530521 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-12-10 11:46:10.530529 | controller | Wednesday 10 December 2025  11:46:10 +0000 (0:00:00.200)       0:00:10.724 ****
2025-12-10 11:46:10.530539 | controller | changed: [instance]
2025-12-10 11:46:10.794020 | controller |
2025-12-10 11:46:10.794050 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-12-10 11:46:10.794058 | controller | Wednesday 10 December 2025  11:46:10 +0000 (0:00:00.218)       0:00:10.943 ****
2025-12-10 11:46:10.794067 | controller | changed: [instance]
2025-12-10 11:46:10.823188 | controller |
2025-12-10 11:46:10.823215 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-12-10 11:46:10.823223 | controller | Wednesday 10 December 2025  11:46:10 +0000 (0:00:00.263)       0:00:11.206 ****
2025-12-10 11:46:10.823233 | controller | skipping: [instance]
2025-12-10 11:46:10.853030 | controller |
2025-12-10 11:46:10.853049 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-12-10 11:46:10.853057 | controller | Wednesday 10 December 2025  11:46:10 +0000 (0:00:00.029)       0:00:11.236 ****
2025-12-10 11:46:10.853065 | controller | skipping: [instance]
2025-12-10 11:46:10.879650 | controller |
2025-12-10 11:46:10.879677 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-12-10 11:46:10.879685 | controller | Wednesday 10 December 2025  11:46:10 +0000 (0:00:00.030)       0:00:11.266 ****
2025-12-10 11:46:10.879695 | controller | skipping: [instance]
2025-12-10 11:46:10.906961 | controller |
2025-12-10 11:46:10.906984 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-12-10 11:46:10.906994 | controller | Wednesday 10 December 2025  11:46:10 +0000 (0:00:00.026)       0:00:11.292 ****
2025-12-10 11:46:10.907005 | controller | skipping: [instance]
2025-12-10 11:46:10.932812 | controller |
2025-12-10 11:46:10.932831 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-12-10 11:46:10.932838 | controller | Wednesday 10 December 2025  11:46:10 +0000 (0:00:00.027)       0:00:11.319 ****
2025-12-10 11:46:10.932847 | controller | skipping: [instance]
2025-12-10 11:46:10.960533 | controller |
2025-12-10 11:46:10.960556 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-12-10 11:46:10.960565 | controller | Wednesday 10 December 2025  11:46:10 +0000 (0:00:00.026)       0:00:11.346 ****
2025-12-10 11:46:10.960576 | controller | skipping: [instance]
2025-12-10 11:46:10.960773 | controller |
2025-12-10 11:46:10.960970 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-12-10 11:46:10.961137 | controller | Wednesday 10 December 2025  11:46:10 +0000 (0:00:00.027)       0:00:11.373 ****
2025-12-10 11:46:10.983454 | controller | skipping: [instance]
2025-12-10 11:46:10.983619 | controller |
2025-12-10 11:46:10.983773 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-12-10 11:46:10.983922 | controller | Wednesday 10 December 2025  11:46:10 +0000 (0:00:00.022)       0:00:11.396 ****
2025-12-10 11:46:11.020473 | controller | skipping: [instance]
2025-12-10 11:46:11.020689 | controller |
2025-12-10 11:46:11.020865 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-12-10 11:46:11.021063 | controller | Wednesday 10 December 2025  11:46:11 +0000 (0:00:00.036)       0:00:11.433 ****
2025-12-10 11:46:11.045581 | controller | skipping: [instance]
2025-12-10 11:46:11.045794 | controller |
2025-12-10 11:46:11.046166 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-12-10 11:46:11.046329 | controller | Wednesday 10 December 2025  11:46:11 +0000 (0:00:00.025)       0:00:11.458 ****
2025-12-10 11:46:11.075025 | controller | skipping: [instance]
2025-12-10 11:46:11.075265 | controller |
2025-12-10 11:46:11.075500 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-12-10 11:46:11.075690 | controller | Wednesday 10 December 2025  11:46:11 +0000 (0:00:00.029)       0:00:11.488 ****
2025-12-10 11:46:11.113357 | controller | skipping: [instance]
2025-12-10 11:46:11.113537 | controller |
2025-12-10 11:46:11.113718 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-12-10 11:46:11.113859 | controller | Wednesday 10 December 2025  11:46:11 +0000 (0:00:00.038)       0:00:11.526 ****
2025-12-10 11:46:11.152803 | controller | skipping: [instance]
2025-12-10 11:46:11.152951 | controller |
2025-12-10 11:46:11.153270 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-12-10 11:46:11.153400 | controller | Wednesday 10 December 2025  11:46:11 +0000 (0:00:00.039)       0:00:11.566 ****
2025-12-10 11:46:11.189360 | controller | skipping: [instance]
2025-12-10 11:46:11.189526 | controller |
2025-12-10 11:46:11.189721 | controller | TASK [test_deps : Install additional packages] *********************************
2025-12-10 11:46:11.189868 | controller | Wednesday 10 December 2025  11:46:11 +0000 (0:00:00.036)       0:00:11.602 ****
2025-12-10 11:46:11.225257 | controller | skipping: [instance]
2025-12-10 11:46:11.225449 | controller |
2025-12-10 11:46:11.225679 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-12-10 11:46:11.225865 | controller | Wednesday 10 December 2025  11:46:11 +0000 (0:00:00.035)       0:00:11.638 ****
2025-12-10 11:46:50.235307 | controller | ok: [instance]
2025-12-10 11:46:51.420556 | controller |
2025-12-10 11:46:51.420587 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-12-10 11:46:51.420609 | controller | Wednesday 10 December 2025  11:46:50 +0000 (0:00:39.009)       0:00:50.648 ****
2025-12-10 11:46:51.420623 | controller | ok: [instance]
2025-12-10 11:46:51.457540 | controller |
2025-12-10 11:46:51.457558 | controller | TASK [test_deps : Install extra packages] **************************************
2025-12-10 11:46:51.457565 | controller | Wednesday 10 December 2025  11:46:51 +0000 (0:00:01.185)       0:00:51.833 ****
2025-12-10 11:46:51.457578 | controller | skipping: [instance]
2025-12-10 11:46:51.647762 | controller |
2025-12-10 11:46:51.647795 | controller | TASK [libvirt_manager : Ensure output directory exists] ************************
2025-12-10 11:46:51.647803 | controller | Wednesday 10 December 2025  11:46:51 +0000 (0:00:00.037)       0:00:51.870 ****
2025-12-10 11:46:51.647814 | controller | ok: [instance]
2025-12-10 11:46:51.647833 | controller |
2025-12-10 11:46:51.647864 | controller | TASK [libvirt_manager : Get vmx/svm extensions from /proc/cpuinfo] *************
2025-12-10 11:46:51.647973 | controller | Wednesday 10 December 2025  11:46:51 +0000 (0:00:00.190)       0:00:52.061 ****
2025-12-10 11:46:51.828212 | controller | changed: [instance]
2025-12-10 11:46:51.828284 | controller |
2025-12-10 11:46:51.828395 | controller | TASK [libvirt_manager : Check if KVM is enabled] *******************************
2025-12-10 11:46:51.828497 | controller | Wednesday 10 December 2025  11:46:51 +0000 (0:00:00.180)       0:00:52.241 ****
2025-12-10 11:46:52.005285 | controller | ok: [instance]
2025-12-10 11:46:52.005351 | controller |
2025-12-10 11:46:52.005447 | controller | TASK [libvirt_manager : Fail if KVM not enabled] *******************************
2025-12-10 11:46:52.005551 | controller | Wednesday 10 December 2025  11:46:52 +0000 (0:00:00.177)       0:00:52.418 ****
2025-12-10 11:46:52.034820 | controller | skipping: [instance]
2025-12-10 11:46:52.034899 | controller |
2025-12-10 11:46:52.034993 | controller | TASK [libvirt_manager : Check if VMX virtualization] ***************************
2025-12-10 11:46:52.035083 | controller | Wednesday 10 December 2025  11:46:52 +0000 (0:00:00.029)       0:00:52.448 ****
2025-12-10 11:46:52.055164 | controller | skipping: [instance]
2025-12-10 11:46:52.077133 | controller |
2025-12-10 11:46:52.077155 | controller | TASK [libvirt_manager : Check if SVM virtualization] ***************************
2025-12-10 11:46:52.077166 | controller | Wednesday 10 December 2025  11:46:52 +0000 (0:00:00.019)       0:00:52.468 ****
2025-12-10 11:46:52.077177 | controller | ok: [instance]
2025-12-10 11:46:52.128755 | controller |
2025-12-10 11:46:52.128796 | controller | TASK [libvirt_manager : Enable VMX virtualization] *****************************
2025-12-10 11:46:52.128807 | controller | Wednesday 10 December 2025  11:46:52 +0000 (0:00:00.021)       0:00:52.490 ****
2025-12-10 11:46:52.128821 | controller | skipping: [instance]
2025-12-10 11:46:53.268593 | controller |
2025-12-10 11:46:53.268646 | controller | TASK [libvirt_manager : Install packages required for using KVM] ***************
2025-12-10 11:46:53.268655 | controller | Wednesday 10 December 2025  11:46:52 +0000 (0:00:00.051)       0:00:52.542 ****
2025-12-10 11:46:53.268665 | controller | ok: [instance]
2025-12-10 11:46:53.473475 | controller |
2025-12-10 11:46:53.473496 | controller | TASK [libvirt_manager : Create rules.d polkit folder] **************************
2025-12-10 11:46:53.473503 | controller | Wednesday 10 December 2025  11:46:53 +0000 (0:00:01.139)       0:00:53.681 ****
2025-12-10 11:46:53.473512 | controller | ok: [instance]
2025-12-10 11:46:53.850036 | controller |
2025-12-10 11:46:53.850063 | controller | TASK [libvirt_manager : Enable UNIX socket PolicyKit auth] *********************
2025-12-10 11:46:53.850076 | controller | Wednesday 10 December 2025  11:46:53 +0000 (0:00:00.205)       0:00:53.886 ****
2025-12-10 11:46:53.850086 | controller | ok: [instance]
2025-12-10 11:46:53.873414 | controller |
2025-12-10 11:46:53.873430 | controller | TASK [libvirt_manager : Restart service polkit service] ************************
2025-12-10 11:46:53.873437 | controller | Wednesday 10 December 2025  11:46:53 +0000 (0:00:00.376)       0:00:54.263 ****
2025-12-10 11:46:53.873445 | controller | skipping: [instance]
2025-12-10 11:46:54.071346 | controller |
2025-12-10 11:46:54.071364 | controller | TASK [libvirt_manager : Remove directory for service override] *****************
2025-12-10 11:46:54.071371 | controller | Wednesday 10 December 2025  11:46:53 +0000 (0:00:00.023)       0:00:54.286 ****
2025-12-10 11:46:54.071379 | controller | ok: [instance]
2025-12-10 11:46:54.705685 | controller |
2025-12-10 11:46:54.705718 | controller | TASK [libvirt_manager : Reload systemctl and start/enable virtproxyd.service] ***
2025-12-10 11:46:54.705726 | controller | Wednesday 10 December 2025  11:46:54 +0000 (0:00:00.197)       0:00:54.484 ****
2025-12-10 11:46:54.705737 | controller | ok: [instance]
2025-12-10 11:46:55.010721 | controller |
2025-12-10 11:46:55.010759 | controller | TASK [libvirt_manager : Ensure firewalld service is up] ************************
2025-12-10 11:46:55.010773 | controller | Wednesday 10 December 2025  11:46:54 +0000 (0:00:00.633)       0:00:55.118 ****
2025-12-10 11:46:55.010786 | controller | ok: [instance]
2025-12-10 11:46:55.093698 | controller |
2025-12-10 11:46:55.093735 | controller | TASK [libvirt_manager : Ensure libvirt modular driver daemons are started.] ****
2025-12-10 11:46:55.093748 | controller | Wednesday 10 December 2025  11:46:55 +0000 (0:00:00.305)       0:00:55.423 ****
2025-12-10 11:46:55.093765 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=qemu)
2025-12-10 11:46:55.093831 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=interface)
2025-12-10 11:46:55.093858 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=network)
2025-12-10 11:46:55.093869 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nodedev)
2025-12-10 11:46:55.093874 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=nwfilter)
2025-12-10 11:46:55.093880 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=secret)
2025-12-10 11:46:55.093885 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=storage)
2025-12-10 11:46:55.093890 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/libvirt_manager/tasks/drivers.yml for instance => (item=proxy)
2025-12-10 11:46:55.093895 | controller |
2025-12-10 11:46:55.093905 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for qemu.] *********
2025-12-10 11:46:55.594596 | controller | Wednesday 10 December 2025  11:46:55 +0000 (0:00:00.082)       0:00:55.506 ****
2025-12-10 11:46:55.594654 | controller | ok: [instance]
2025-12-10 11:46:55.903742 | controller |
2025-12-10 11:46:55.903782 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for qemu.] **********
2025-12-10 11:46:55.903793 | controller | Wednesday 10 December 2025  11:46:55 +0000 (0:00:00.501)       0:00:56.007 ****
2025-12-10 11:46:55.903807 | controller | ok: [instance]
2025-12-10 11:46:56.204934 | controller |
2025-12-10 11:46:56.204970 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for qemu.] **************
2025-12-10 11:46:56.204979 | controller | Wednesday 10 December 2025  11:46:55 +0000 (0:00:00.309)       0:00:56.316 ****
2025-12-10 11:46:56.204989 | controller | ok: [instance]
2025-12-10 11:46:56.205008 | controller |
2025-12-10 11:46:56.205091 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for interface.] ****
2025-12-10 11:46:56.205185 | controller | Wednesday 10 December 2025  11:46:56 +0000 (0:00:00.301)       0:00:56.618 ****
2025-12-10 11:46:56.521845 | controller | ok: [instance]
2025-12-10 11:46:56.521913 | controller |
2025-12-10 11:46:56.522174 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for interface.] *****
2025-12-10 11:46:56.828832 | controller | Wednesday 10 December 2025  11:46:56 +0000 (0:00:00.316)       0:00:56.935 ****
2025-12-10 11:46:56.828869 | controller | ok: [instance]
2025-12-10 11:46:57.137293 | controller |
2025-12-10 11:46:57.137316 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for interface.] *********
2025-12-10 11:46:57.137324 | controller | Wednesday 10 December 2025  11:46:56 +0000 (0:00:00.306)       0:00:57.241 ****
2025-12-10 11:46:57.137333 | controller | ok: [instance]
2025-12-10 11:46:57.447025 | controller |
2025-12-10 11:46:57.447051 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for network.] ******
2025-12-10 11:46:57.447059 | controller | Wednesday 10 December 2025  11:46:57 +0000 (0:00:00.308)       0:00:57.550 ****
2025-12-10 11:46:57.447069 | controller | ok: [instance]
2025-12-10 11:46:57.756444 | controller |
2025-12-10 11:46:57.756472 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for network.] *******
2025-12-10 11:46:57.756480 | controller | Wednesday 10 December 2025  11:46:57 +0000 (0:00:00.309)       0:00:57.860 ****
2025-12-10 11:46:57.756495 | controller | ok: [instance]
2025-12-10 11:46:58.070145 | controller |
2025-12-10 11:46:58.070170 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for network.] ***********
2025-12-10 11:46:58.070177 | controller | Wednesday 10 December 2025  11:46:57 +0000 (0:00:00.309)       0:00:58.169 ****
2025-12-10 11:46:58.070186 | controller | ok: [instance]
2025-12-10 11:46:58.400505 | controller |
2025-12-10 11:46:58.400538 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nodedev.] ******
2025-12-10 11:46:58.400546 | controller | Wednesday 10 December 2025  11:46:58 +0000 (0:00:00.313)       0:00:58.483 ****
2025-12-10 11:46:58.400562 | controller | ok: [instance]
2025-12-10 11:46:58.744834 | controller |
2025-12-10 11:46:58.744866 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nodedev.] *******
2025-12-10 11:46:58.744874 | controller | Wednesday 10 December 2025  11:46:58 +0000 (0:00:00.330)       0:00:58.813 ****
2025-12-10 11:46:58.744884 | controller | ok: [instance]
2025-12-10 11:46:59.080568 | controller |
2025-12-10 11:46:59.080614 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nodedev.] ***********
2025-12-10 11:46:59.080626 | controller | Wednesday 10 December 2025  11:46:58 +0000 (0:00:00.344)       0:00:59.157 ****
2025-12-10 11:46:59.080637 | controller | ok: [instance]
2025-12-10 11:46:59.391319 | controller |
2025-12-10 11:46:59.391349 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for nwfilter.] *****
2025-12-10 11:46:59.391358 | controller | Wednesday 10 December 2025  11:46:59 +0000 (0:00:00.335)       0:00:59.493 ****
2025-12-10 11:46:59.391368 | controller | ok: [instance]
2025-12-10 11:46:59.702970 | controller |
2025-12-10 11:46:59.702991 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for nwfilter.] ******
2025-12-10 11:46:59.702999 | controller | Wednesday 10 December 2025  11:46:59 +0000 (0:00:00.310)       0:00:59.804 ****
2025-12-10 11:46:59.703008 | controller | ok: [instance]
2025-12-10 11:47:00.014219 | controller |
2025-12-10 11:47:00.014241 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for nwfilter.] **********
2025-12-10 11:47:00.014248 | controller | Wednesday 10 December 2025  11:46:59 +0000 (0:00:00.311)       0:01:00.116 ****
2025-12-10 11:47:00.014257 | controller | ok: [instance]
2025-12-10 11:47:00.340028 | controller |
2025-12-10 11:47:00.340055 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for secret.] *******
2025-12-10 11:47:00.340063 | controller | Wednesday 10 December 2025  11:47:00 +0000 (0:00:00.311)       0:01:00.427 ****
2025-12-10 11:47:00.340072 | controller | ok: [instance]
2025-12-10 11:47:00.649686 | controller |
2025-12-10 11:47:00.649720 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for secret.] ********
2025-12-10 11:47:00.649729 | controller | Wednesday 10 December 2025  11:47:00 +0000 (0:00:00.325)       0:01:00.753 ****
2025-12-10 11:47:00.649739 | controller | ok: [instance]
2025-12-10 11:47:00.649765 | controller |
2025-12-10 11:47:00.649773 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for secret.] ************
2025-12-10 11:47:00.649919 | controller | Wednesday 10 December 2025  11:47:00 +0000 (0:00:00.309)       0:01:01.063 ****
2025-12-10 11:47:00.968375 | controller | ok: [instance]
2025-12-10 11:47:01.291720 | controller |
2025-12-10 11:47:01.291752 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for storage.] ******
2025-12-10 11:47:01.291761 | controller | Wednesday 10 December 2025  11:47:00 +0000 (0:00:00.318)       0:01:01.381 ****
2025-12-10 11:47:01.291771 | controller | ok: [instance]
2025-12-10 11:47:01.629263 | controller |
2025-12-10 11:47:01.629311 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for storage.] *******
2025-12-10 11:47:01.629319 | controller | Wednesday 10 December 2025  11:47:01 +0000 (0:00:00.323)       0:01:01.704 ****
2025-12-10 11:47:01.629330 | controller | ok: [instance]
2025-12-10 11:47:01.992542 | controller |
2025-12-10 11:47:01.992580 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for storage.] ***********
2025-12-10 11:47:01.992588 | controller | Wednesday 10 December 2025  11:47:01 +0000 (0:00:00.337)       0:01:02.042 ****
2025-12-10 11:47:01.992630 | controller | ok: [instance]
2025-12-10 11:47:02.337754 | controller |
2025-12-10 11:47:02.337791 | controller | TASK [libvirt_manager : Ensure read-write socket is enabled for proxy.] ********
2025-12-10 11:47:02.337799 | controller | Wednesday 10 December 2025  11:47:01 +0000 (0:00:00.363)       0:01:02.405 ****
2025-12-10 11:47:02.337816 | controller | ok: [instance]
2025-12-10 11:47:02.337842 | controller |
2025-12-10 11:47:02.337850 | controller | TASK [libvirt_manager : Ensure read-only socket is enabled for proxy.] *********
2025-12-10 11:47:02.663223 | controller | Wednesday 10 December 2025  11:47:02 +0000 (0:00:00.345)       0:01:02.750 ****
2025-12-10 11:47:02.663262 | controller | ok: [instance]
2025-12-10 11:47:02.983656 | controller |
2025-12-10 11:47:02.983679 | controller | TASK [libvirt_manager : Ensure admin socket is enabled for proxy.] *************
2025-12-10 11:47:02.983687 | controller | Wednesday 10 December 2025  11:47:02 +0000 (0:00:00.325)       0:01:03.076 ****
2025-12-10 11:47:02.983697 | controller | ok: [instance]
2025-12-10 11:47:03.006542 | controller |
2025-12-10 11:47:03.006559 | controller | TASK [libvirt_manager : Manage service for older releases] *********************
2025-12-10 11:47:03.006566 | controller | Wednesday 10 December 2025  11:47:02 +0000 (0:00:00.320)       0:01:03.396 ****
2025-12-10 11:47:03.006574 | controller | skipping: [instance]
2025-12-10 11:47:03.289915 | controller |
2025-12-10 11:47:03.289945 | controller | TASK [libvirt_manager : Get libvirt group users] *******************************
2025-12-10 11:47:03.289959 | controller | Wednesday 10 December 2025  11:47:03 +0000 (0:00:00.022)       0:01:03.419 ****
2025-12-10 11:47:03.289969 | controller | ok: [instance]
2025-12-10 11:47:03.662224 | controller |
2025-12-10 11:47:03.662247 | controller | TASK [libvirt_manager : Add user if not exists in libvirt group] ***************
2025-12-10 11:47:03.662255 | controller | Wednesday 10 December 2025  11:47:03 +0000 (0:00:00.283)       0:01:03.702 ****
2025-12-10 11:47:03.662264 | controller | ok: [instance]
2025-12-10 11:47:03.953707 | controller |
2025-12-10 11:47:03.953727 | controller | TASK [libvirt_manager : Allow QEMU on home directory for the storage access] ***
2025-12-10 11:47:03.953734 | controller | Wednesday 10 December 2025  11:47:03 +0000 (0:00:00.372)       0:01:04.075 ****
2025-12-10 11:47:03.953751 | controller | ok: [instance]
2025-12-10 11:47:04.235440 | controller |
2025-12-10 11:47:04.235457 | controller | TASK [libvirt_manager : Inject system connection parameters in bashrc] *********
2025-12-10 11:47:04.235464 | controller | Wednesday 10 December 2025  11:47:03 +0000 (0:00:00.291)       0:01:04.366 ****
2025-12-10 11:47:04.235473 | controller | [WARNING]: Reset is not implemented for this connection
2025-12-10 11:47:04.265790 | controller | ok: [instance]
2025-12-10 11:47:04.265868 | controller |
2025-12-10 11:47:04.265884 | controller | TASK [libvirt_manager : Ensure we reload user env] *****************************
2025-12-10 11:47:04.265895 | controller | Wednesday 10 December 2025  11:47:04 +0000 (0:00:00.275)       0:01:04.642 ****
2025-12-10 11:47:04.265905 | controller |
2025-12-10 11:47:04.265915 | controller | PLAY RECAP *********************************************************************
2025-12-10 11:47:04.265925 | controller | instance                   : ok=67   changed=5    unreachable=0    failed=0    skipped=35   rescued=0    ignored=0
2025-12-10 11:47:04.265938 | controller |
2025-12-10 11:47:04.265972 | controller | Wednesday 10 December 2025  11:47:04 +0000 (0:00:00.036)       0:01:04.678 ****
2025-12-10 11:47:04.265986 | controller | ===============================================================================
2025-12-10 11:47:04.266022 | controller | test_deps : Install selinux python libs -------------------------------- 39.01s
2025-12-10 11:47:04.267501 | controller | Install some debug utils ------------------------------------------------ 1.36s
2025-12-10 11:47:04.327412 | controller | repo_setup : Initialize python venv and install requirements ------------ 1.32s
2025-12-10 11:47:04.327431 | controller | repo_setup : Make sure git-core package is installed -------------------- 1.21s
2025-12-10 11:47:04.327438 | controller | test_deps : Install python yaml libs ------------------------------------ 1.19s
2025-12-10 11:47:04.327443 | controller | libvirt_manager : Install packages required for using KVM --------------- 1.14s
2025-12-10 11:47:04.327448 | controller | Gathering Facts --------------------------------------------------------- 0.89s
2025-12-10 11:47:04.327453 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.85s
2025-12-10 11:47:04.327458 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.72s
2025-12-10 11:47:04.327463 | controller | libvirt_manager : Reload systemctl and start/enable virtproxyd.service --- 0.63s
2025-12-10 11:47:04.327468 | controller | repo_setup : Ensure directories are present ----------------------------- 0.62s
2025-12-10 11:47:04.327477 | controller | repo_setup : Get repo-setup repository ---------------------------------- 0.62s
2025-12-10 11:47:04.327482 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.56s
2025-12-10 11:47:04.327487 | controller | libvirt_manager : Ensure read-write socket is enabled for qemu. --------- 0.50s
2025-12-10 11:47:04.327492 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.38s
2025-12-10 11:47:04.327497 | controller | libvirt_manager : Enable UNIX socket PolicyKit auth --------------------- 0.38s
2025-12-10 11:47:04.327502 | controller | libvirt_manager : Add user if not exists in libvirt group --------------- 0.37s
2025-12-10 11:47:04.327507 | controller | libvirt_manager : Ensure admin socket is enabled for storage. ----------- 0.36s
2025-12-10 11:47:04.327512 | controller | Create custom basedir --------------------------------------------------- 0.35s
2025-12-10 11:47:04.327519 | controller | libvirt_manager : Ensure read-write socket is enabled for proxy. -------- 0.35s
2025-12-10 11:47:04.327527 | controller | INFO     Running download > converge
2025-12-10 11:47:04.657410 | controller | ERROR! 'always' is not a valid attribute for a Play
2025-12-10 11:47:04.657556 | controller |
2025-12-10 11:47:04.657739 | controller | The error appears to be in '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/nat64_appliance/molecule/download/converge.yml': line 23, column 3, but may
2025-12-10 11:47:04.657869 | controller | be elsewhere in the file depending on the exact syntax problem.
2025-12-10 11:47:04.657986 | controller |
2025-12-10 11:47:04.658105 | controller | The offending line appears to be:
2025-12-10 11:47:04.658220 | controller |
2025-12-10 11:47:04.658347 | controller |
2025-12-10 11:47:04.658469 | controller | - name: Converge - Test build and download modes
2025-12-10 11:47:04.658585 | controller |   ^ here
2025-12-10 11:47:04.689914 | controller | CRITICAL Ansible return code was 4, command was: ['ansible-playbook', '--inventory', '/home/zuul/.cache/molecule/nat64_appliance/download/inventory', '--skip-tags', 'molecule-notest,notest', '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/nat64_appliance/molecule/download/converge.yml']
2025-12-10 11:47:04.690371 | controller | WARNING  An error occurred during the test sequence action: 'converge'. Cleaning up.
2025-12-10 11:47:04.698660 | controller | INFO     Running download > cleanup
2025-12-10 11:47:05.079896 | controller |
2025-12-10 11:47:05.080117 | controller | PLAY [Cleanup] *****************************************************************
2025-12-10 11:47:05.080243 | controller |
2025-12-10 11:47:05.080382 | controller | TASK [Gathering Facts] *********************************************************
2025-12-10 11:47:05.080508 | controller | Wednesday 10 December 2025  11:47:05 +0000 (0:00:00.014)       0:00:00.014 ****
2025-12-10 11:47:05.889189 | controller | ok: [instance]
2025-12-10 11:47:06.171525 | controller |
2025-12-10 11:47:06.171561 | controller | TASK [Stop HTTP server if running] *********************************************
2025-12-10 11:47:06.171570 | controller | Wednesday 10 December 2025  11:47:05 +0000 (0:00:00.809)       0:00:00.823 ****
2025-12-10 11:47:06.171581 | controller | fatal: [instance]: FAILED! => changed=true
2025-12-10 11:47:06.178465 | controller |   cmd: |-
2025-12-10 11:47:06.178487 | controller |     if [ -f /tmp/nat64_http_server.pid ]; then
2025-12-10 11:47:06.178496 | controller |       kill $(cat /tmp/nat64_http_server.pid) || true
2025-12-10 11:47:06.178504 | controller |       rm -f /tmp/nat64_http_server.pid /tmp/nat64_http_server.log
2025-12-10 11:47:06.178511 | controller |     fi
2025-12-10 11:47:06.178518 | controller |     pkill -f "python3 -m http.server 8765" || true
2025-12-10 11:47:06.178525 | controller |   delta: '0:00:00.018364'
2025-12-10 11:47:06.178531 | controller |   end: '2025-12-10 11:47:06.146391'
2025-12-10 11:47:06.178538 | controller |   msg: non-zero return code
2025-12-10 11:47:06.178545 | controller |   rc: -15
2025-12-10 11:47:06.178552 | controller |   start: '2025-12-10 11:47:06.128027'
2025-12-10 11:47:06.178559 | controller |   stderr: ''
2025-12-10 11:47:06.178566 | controller |   stderr_lines: <omitted>
2025-12-10 11:47:06.178572 | controller |   stdout: ''
2025-12-10 11:47:06.178579 | controller |   stdout_lines: <omitted>
2025-12-10 11:47:06.178589 | controller | ...ignoring
2025-12-10 11:47:06.213668 | controller |
2025-12-10 11:47:06.213692 | controller | TASK [Cleanup nat64 appliance] *************************************************
2025-12-10 11:47:06.213707 | controller | Wednesday 10 December 2025  11:47:06 +0000 (0:00:00.289)       0:00:01.113 ****
2025-12-10 11:47:06.213718 | controller |
2025-12-10 11:47:06.214000 | controller | TASK [nat64_appliance : Cleaning up nat64_appliance image] *********************
2025-12-10 11:47:06.505480 | controller | Wednesday 10 December 2025  11:47:06 +0000 (0:00:00.035)       0:00:01.148 ****
2025-12-10 11:47:06.505511 | controller | ok: [instance]
2025-12-10 11:47:06.777522 | controller |
2025-12-10 11:47:06.777556 | controller | TASK [nat64_appliance : Get virtqemud socket] **********************************
2025-12-10 11:47:06.777565 | controller | Wednesday 10 December 2025  11:47:06 +0000 (0:00:00.291)       0:00:01.440 ****
2025-12-10 11:47:06.777575 | controller | ok: [instance]
2025-12-10 11:47:07.100416 | controller |
2025-12-10 11:47:07.100446 | controller | TASK [nat64_appliance : List VMs] **********************************************
2025-12-10 11:47:07.100453 | controller | Wednesday 10 December 2025  11:47:06 +0000 (0:00:00.272)       0:00:01.712 ****
2025-12-10 11:47:07.100463 | controller | ok: [instance]
2025-12-10 11:47:07.121070 | controller |
2025-12-10 11:47:07.121089 | controller | TASK [nat64_appliance : Get nat64_appliance VM state] **************************
2025-12-10 11:47:07.121096 | controller | Wednesday 10 December 2025  11:47:07 +0000 (0:00:00.323)       0:00:02.035 ****
2025-12-10 11:47:07.121105 | controller | skipping: [instance]
2025-12-10 11:47:07.140705 | controller |
2025-12-10 11:47:07.140722 | controller | TASK [nat64_appliance : Stop the nat64_appliance VM] ***************************
2025-12-10 11:47:07.140729 | controller | Wednesday 10 December 2025  11:47:07 +0000 (0:00:00.020)       0:00:02.056 ****
2025-12-10 11:47:07.140737 | controller | skipping: [instance]
2025-12-10 11:47:07.161320 | controller |
2025-12-10 11:47:07.161337 | controller | TASK [nat64_appliance : Undefine the nat64_appliance VM] ***********************
2025-12-10 11:47:07.161344 | controller | Wednesday 10 December 2025  11:47:07 +0000 (0:00:00.019)       0:00:02.075 ****
2025-12-10 11:47:07.161352 | controller | skipping: [instance]
2025-12-10 11:47:07.674735 | controller |
2025-12-10 11:47:07.674772 | controller | TASK [nat64_appliance : Destroy the nat64 networks] ****************************
2025-12-10 11:47:07.674783 | controller | Wednesday 10 December 2025  11:47:07 +0000 (0:00:00.020)       0:00:02.096 ****
2025-12-10 11:47:07.674795 | controller | ok: [instance] => (item=nat64-net-v4)
2025-12-10 11:47:07.674833 | controller | ok: [instance] => (item=nat64-net-v6)
2025-12-10 11:47:07.674864 | controller |
2025-12-10 11:47:07.675119 | controller | TASK [nat64_appliance : Undefine the nat64 networks] ***************************
2025-12-10 11:47:08.134762 | controller | Wednesday 10 December 2025  11:47:07 +0000 (0:00:00.513)       0:00:02.609 ****
2025-12-10 11:47:08.134806 | controller | ok: [instance] => (item=nat64-net-v4)
2025-12-10 11:47:08.134832 | controller | ok: [instance] => (item=nat64-net-v6)
2025-12-10 11:47:08.134839 | controller |
2025-12-10 11:47:08.134846 | controller | PLAY RECAP *********************************************************************
2025-12-10 11:47:08.134852 | controller | instance                   : ok=7    changed=1    unreachable=0    failed=0    skipped=3    rescued=0    ignored=1
2025-12-10 11:47:08.134857 | controller |
2025-12-10 11:47:08.134863 | controller | Wednesday 10 December 2025  11:47:08 +0000 (0:00:00.459)       0:00:03.068 ****
2025-12-10 11:47:08.134868 | controller | ===============================================================================
2025-12-10 11:47:08.134873 | controller | Gathering Facts --------------------------------------------------------- 0.81s
2025-12-10 11:47:08.134879 | controller | nat64_appliance : Destroy the nat64 networks ---------------------------- 0.51s
2025-12-10 11:47:08.134886 | controller | nat64_appliance : Undefine the nat64 networks --------------------------- 0.46s
2025-12-10 11:47:08.134911 | controller | nat64_appliance : List VMs ---------------------------------------------- 0.32s
2025-12-10 11:47:08.135626 | controller | nat64_appliance : Cleaning up nat64_appliance image --------------------- 0.29s
2025-12-10 11:47:08.189862 | controller | Stop HTTP server if running --------------------------------------------- 0.29s
2025-12-10 11:47:08.189886 | controller | nat64_appliance : Get virtqemud socket ---------------------------------- 0.27s
2025-12-10 11:47:08.189894 | controller | Cleanup nat64 appliance ------------------------------------------------- 0.04s
2025-12-10 11:47:08.189904 | controller | nat64_appliance : Get nat64_appliance VM state -------------------------- 0.02s
2025-12-10 11:47:08.189910 | controller | nat64_appliance : Undefine the nat64_appliance VM ----------------------- 0.02s
2025-12-10 11:47:08.189916 | controller | nat64_appliance : Stop the nat64_appliance VM --------------------------- 0.02s
2025-12-10 11:47:08.189924 | controller | INFO     Running download > destroy
2025-12-10 11:47:08.190298 | controller | WARNING  Skipping, instances are delegated.
2025-12-10 11:47:08.190675 | controller | INFO     Pruning extra files from scenario ephemeral directory
2025-12-10 11:47:08.192276 | controller | INFO     Writing /tmp/report.html report.
2025-12-10 11:47:08.447967 | [controller] Waiting on logger
2025-12-10 11:47:13.586472 | [controller] Waiting on logger
2025-12-10 11:47:24.018500 | [controller] Waiting on logger
2025-12-10 11:47:34.450342 | [controller] Waiting on logger
2025-12-10 11:47:38.272101 | [Zuul] Log Stream did not terminate
2025-12-10 11:47:38.272390 | controller | ERROR
2025-12-10 11:47:38.272510 | controller | {
2025-12-10 11:47:38.272559 | controller |   "delta": "0:11:17.750514",
2025-12-10 11:47:38.272592 | controller |   "end": "2025-12-10 11:47:08.240973",
2025-12-10 11:47:38.272623 | controller |   "msg": "non-zero return code",
2025-12-10 11:47:38.272650 | controller |   "rc": 1,
2025-12-10 11:47:38.272676 | controller |   "start": "2025-12-10 11:35:50.490459"
2025-12-10 11:47:38.272705 | controller | }
failure
2025-12-10 11:47:38.317802 | 
2025-12-10 11:47:38.317852 | PLAY RECAP
2025-12-10 11:47:38.317892 | controller | ok: 3 changed: 0 unreachable: 0 failed: 1 skipped: 1 rescued: 0 ignored: 0
2025-12-10 11:47:38.317943 | 
2025-12-10 11:47:38.374809 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-12-10 11:47:38.375600 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-12-10 11:47:38.889181 | 
2025-12-10 11:47:38.889282 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-12-10 11:47:38.909091 | 
2025-12-10 11:47:38.909167 | TASK [Filter out host if needed]
2025-12-10 11:47:38.917425 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-12-10 11:47:38.921790 | 
2025-12-10 11:47:38.921856 | TASK [Ensure file is present]
2025-12-10 11:47:39.223562 | controller | ok
2025-12-10 11:47:39.230228 | 
2025-12-10 11:47:39.230300 | TASK [Manage molecule report file]
2025-12-10 11:47:39.252852 | [controller] Waiting on logger
2025-12-10 11:47:48.594495 | [controller] Waiting on logger
2025-12-10 11:47:59.026424 | [controller] Waiting on logger
2025-12-10 11:48:09.458460 | [controller] Waiting on logger
2025-12-10 11:48:09.552680 | [Zuul] Log Stream did not terminate
2025-12-10 11:48:09.552942 | controller | changed
2025-12-10 11:48:09.558189 | 
2025-12-10 11:48:09.558246 | TASK [Check if we get ci-framework-data basedir]
2025-12-10 11:48:09.749458 | controller | ok
2025-12-10 11:48:09.754315 | 
2025-12-10 11:48:09.754377 | TASK [Create ci-framework-data log directory for zuul]
2025-12-10 11:48:10.045170 | controller | changed
2025-12-10 11:48:10.049856 | 
2025-12-10 11:48:10.049928 | TASK [Copy ci-framework interesting files]
2025-12-10 11:48:15.074334 | controller | changed
2025-12-10 11:48:15.079535 | 
2025-12-10 11:48:15.079596 | TASK [Get SELinux listing]
2025-12-10 11:48:15.101187 | [controller] Waiting on logger
2025-12-10 11:48:20.850495 | [controller] Waiting on logger
2025-12-10 11:48:21.348230 | controller | changed
2025-12-10 11:48:21.353929 | 
2025-12-10 11:48:21.353997 | TASK [Generate log index]
2025-12-10 11:48:21.928621 | controller | changed
2025-12-10 11:48:21.933250 | 
2025-12-10 11:48:21.933315 | TASK [Get some env related data]
2025-12-10 11:48:21.955468 | [controller] Waiting on logger
2025-12-10 11:48:34.418468 | [controller] Waiting on logger
2025-12-10 11:48:43.826620 | [controller] Waiting on logger
2025-12-10 11:48:53.100239 | [Zuul] Log Stream did not terminate
2025-12-10 11:48:53.100465 | controller | changed
2025-12-10 11:48:53.105743 | 
2025-12-10 11:48:53.105804 | TASK [Generate list of logs to collect in home directory]
2025-12-10 11:48:53.386953 | controller | ok: All paths examined
2025-12-10 11:48:53.391996 | 
2025-12-10 11:48:53.392066 | LOOP [Copy logs from home directory]
2025-12-10 11:48:53.695159 | controller | changed:
2025-12-10 11:48:53.695261 | controller | {
2025-12-10 11:48:53.695288 | controller |   "atime": 1765366532.8620033,
2025-12-10 11:48:53.695307 | controller |   "ctime": 1765366548.2351677,
2025-12-10 11:48:53.695325 | controller |   "dev": 64513,
2025-12-10 11:48:53.695341 | controller |   "gid": 1000,
2025-12-10 11:48:53.695357 | controller |   "gr_name": "zuul",
2025-12-10 11:48:53.695372 | controller |   "inode": 4335157,
2025-12-10 11:48:53.695386 | controller |   "isblk": false,
2025-12-10 11:48:53.695400 | controller |   "ischr": false,
2025-12-10 11:48:53.695413 | controller |   "isdir": false,
2025-12-10 11:48:53.695427 | controller |   "isfifo": false,
2025-12-10 11:48:53.695442 | controller |   "isgid": false,
2025-12-10 11:48:53.695457 | controller |   "islnk": false,
2025-12-10 11:48:53.695471 | controller |   "isreg": true,
2025-12-10 11:48:53.695486 | controller |   "issock": false,
2025-12-10 11:48:53.695501 | controller |   "isuid": false,
2025-12-10 11:48:53.695515 | controller |   "mode": "0644",
2025-12-10 11:48:53.695529 | controller |   "mtime": 1765366548.2351677,
2025-12-10 11:48:53.695542 | controller |   "nlink": 1,
2025-12-10 11:48:53.695559 | controller |   "path": "/home/zuul/ansible.log",
2025-12-10 11:48:53.695573 | controller |   "pw_name": "zuul",
2025-12-10 11:48:53.695587 | controller |   "rgrp": true,
2025-12-10 11:48:53.695600 | controller |   "roth": true,
2025-12-10 11:48:53.695613 | controller |   "rusr": true,
2025-12-10 11:48:53.695626 | controller |   "size": 6749,
2025-12-10 11:48:53.695639 | controller |   "uid": 1000,
2025-12-10 11:48:53.695653 | controller |   "wgrp": false,
2025-12-10 11:48:53.695667 | controller |   "woth": false,
2025-12-10 11:48:53.695680 | controller |   "wusr": true,
2025-12-10 11:48:53.695694 | controller |   "xgrp": false,
2025-12-10 11:48:53.695708 | controller |   "xoth": false,
2025-12-10 11:48:53.695722 | controller |   "xusr": false
2025-12-10 11:48:53.695736 | controller | }
2025-12-10 11:48:53.708854 | 
2025-12-10 11:48:53.708965 | TASK [Copy crio stats log file]
2025-12-10 11:48:53.722571 | controller | skipping: Conditional result was False
2025-12-10 11:48:53.727820 | 
2025-12-10 11:48:53.727883 | TASK [Get SELinux related data]
2025-12-10 11:48:53.748635 | [controller] Waiting on logger
2025-12-10 11:49:04.178426 | [controller] Waiting on logger
2025-12-10 11:49:13.559005 | [controller] Waiting on logger
2025-12-10 11:49:23.948347 | [Zuul] Log Stream did not terminate
2025-12-10 11:49:23.948663 | controller | ERROR
2025-12-10 11:49:23.948817 | controller | {
2025-12-10 11:49:23.948848 | controller |   "delta": "0:00:00.008187",
2025-12-10 11:49:23.948867 | controller |   "end": "2025-12-10 11:48:53.919479",
2025-12-10 11:49:23.948884 | controller |   "msg": "non-zero return code",
2025-12-10 11:49:23.948899 | controller |   "rc": 1,
2025-12-10 11:49:23.948936 | controller |   "start": "2025-12-10 11:48:53.911292"
2025-12-10 11:49:23.948956 | controller | }
2025-12-10 11:49:23.948980 | controller | ERROR: Ignoring Errors
2025-12-10 11:49:23.954237 | 
2025-12-10 11:49:23.954303 | TASK [Create system configuration directory]
2025-12-10 11:49:23.957524 | [controller] Waiting on logger
2025-12-10 11:49:24.125191 | controller | changed
2025-12-10 11:49:24.129420 | 
2025-12-10 11:49:24.129475 | TASK [Get some of the system configurations]
2025-12-10 11:49:27.218592 | [controller] Waiting on logger
2025-12-10 11:49:43.666584 | [controller] Waiting on logger
2025-12-10 11:49:45.842667 | [controller] Waiting on logger
2025-12-10 11:49:54.347304 | [Zuul] Log Stream did not terminate
2025-12-10 11:49:54.347642 | controller | changed
2025-12-10 11:49:54.353052 | 
2025-12-10 11:49:54.353130 | TASK [Copy generated documentation if available]
2025-12-10 11:49:54.366511 | controller | skipping: Conditional result was False
2025-12-10 11:49:54.371501 | 
2025-12-10 11:49:54.371559 | TASK [Copy generated AsciiDoc documentation if available]
2025-12-10 11:49:54.384181 | controller | skipping: Conditional result was False
2025-12-10 11:49:54.389263 | 
2025-12-10 11:49:54.389320 | TASK [Compress logs bigger than 2MB]
2025-12-10 11:49:57.490688 | [controller] Waiting on logger
2025-12-10 11:50:07.922644 | [controller] Waiting on logger
2025-12-10 11:50:18.354542 | [controller] Waiting on logger
2025-12-10 11:50:24.586998 | [Zuul] Log Stream did not terminate
2025-12-10 11:50:24.587241 | controller | changed
2025-12-10 11:50:24.592357 | 
2025-12-10 11:50:24.592422 | TASK [Copy files from workspace on node]
2025-12-10 11:50:24.609750 | controller | ok
2025-12-10 11:50:24.629518 | 
2025-12-10 11:50:24.629590 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-10 11:50:24.642338 | controller | skipping: Conditional result was False
2025-12-10 11:50:24.646938 | 
2025-12-10 11:50:24.646998 | TASK [fetch-output : Set log path for single node]
2025-12-10 11:50:24.673572 | controller | ok
2025-12-10 11:50:24.679048 | 
2025-12-10 11:50:24.679111 | LOOP [fetch-output : Ensure local output dirs]
2025-12-10 11:50:24.861137 | controller -> localhost | ok: "/var/lib/zuul/builds/b1dbf66fe9ab464d90e0238ab83e43c3/work/logs"
2025-12-10 11:50:24.861353 | controller -> localhost | changed: All items complete
2025-12-10 11:50:24.861384 | 
2025-12-10 11:50:25.023405 | controller -> localhost | changed: "/var/lib/zuul/builds/b1dbf66fe9ab464d90e0238ab83e43c3/work/artifacts"
2025-12-10 11:50:25.185719 | controller -> localhost | changed: "/var/lib/zuul/builds/b1dbf66fe9ab464d90e0238ab83e43c3/work/docs"
2025-12-10 11:50:25.194495 | 
2025-12-10 11:50:25.194590 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-10 11:50:25.711099 | controller | changed:
2025-12-10 11:50:25.711279 | controller | .d..t...... ./
2025-12-10 11:50:25.711310 | controller | >f+++++++++ README.html
2025-12-10 11:50:25.711333 | controller | >f+++++++++ ansible-execution.log
2025-12-10 11:50:25.711355 | controller | >f+++++++++ ansible.log
2025-12-10 11:50:25.711375 | controller | >f+++++++++ dmesg.log
2025-12-10 11:50:25.711394 | controller | >f+++++++++ installed-pkgs.log
2025-12-10 11:50:25.711412 | controller | >f+++++++++ python.log
2025-12-10 11:50:25.711430 | controller | >f+++++++++ registries.conf
2025-12-10 11:50:25.711448 | controller | >f+++++++++ report.html
2025-12-10 11:50:25.711465 | controller | >f+++++++++ selinux-denials.log
2025-12-10 11:50:25.711482 | controller | >f+++++++++ selinux-listing.log
2025-12-10 11:50:25.711499 | controller | cd+++++++++ ci-framework-data/
2025-12-10 11:50:25.711516 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-12-10 11:50:25.711533 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_000_build_the_nat64_appliance.sh
2025-12-10 11:50:25.711552 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_001_generate_nocloud_iso.sh
2025-12-10 11:50:25.711570 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_002_generate_nocloud_iso.sh
2025-12-10 11:50:25.711587 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-12-10 11:50:25.711604 | controller | cd+++++++++ ci-framework-data/artifacts/cifmw_config_drive/
2025-12-10 11:50:25.711621 | controller | cd+++++++++ ci-framework-data/artifacts/cifmw_config_drive/1ccb1041-4e2a-5df9-ad6c-c5ed4875de88/
2025-12-10 11:50:25.711638 | controller | >f+++++++++ ci-framework-data/artifacts/cifmw_config_drive/1ccb1041-4e2a-5df9-ad6c-c5ed4875de88/meta-data
2025-12-10 11:50:25.711656 | controller | >f+++++++++ ci-framework-data/artifacts/cifmw_config_drive/1ccb1041-4e2a-5df9-ad6c-c5ed4875de88/network-config
2025-12-10 11:50:25.711672 | controller | >f+++++++++ ci-framework-data/artifacts/cifmw_config_drive/1ccb1041-4e2a-5df9-ad6c-c5ed4875de88/user-data
2025-12-10 11:50:25.711689 | controller | cd+++++++++ ci-framework-data/artifacts/cifmw_config_drive/6bb30345-7a13-5c64-88df-79f4df229310/
2025-12-10 11:50:25.711706 | controller | >f+++++++++ ci-framework-data/artifacts/cifmw_config_drive/6bb30345-7a13-5c64-88df-79f4df229310/meta-data
2025-12-10 11:50:25.711728 | controller | >f+++++++++ ci-framework-data/artifacts/cifmw_config_drive/6bb30345-7a13-5c64-88df-79f4df229310/network-config
2025-12-10 11:50:25.711746 | controller | >f+++++++++ ci-framework-data/artifacts/cifmw_config_drive/6bb30345-7a13-5c64-88df-79f4df229310/user-data
2025-12-10 11:50:25.711762 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-12-10 11:50:25.711779 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-12-10 11:50:25.711796 | controller | cd+++++++++ ci-framework-data/artifacts/repositories/
2025-12-10 11:50:25.711813 | controller | >f+++++++++ ci-framework-data/artifacts/repositories/delorean.repo.md5
2025-12-10 11:50:25.711831 | controller | cd+++++++++ ci-framework-data/logs/
2025-12-10 11:50:25.711847 | controller | >f+++++++++ ci-framework-data/logs/ci_script_000_build_the_nat64_appliance.log
2025-12-10 11:50:25.711864 | controller | >f+++++++++ ci-framework-data/logs/ci_script_001_generate_nocloud_iso.log
2025-12-10 11:50:25.711882 | controller | >f+++++++++ ci-framework-data/logs/ci_script_002_generate_nocloud_iso.log
2025-12-10 11:50:25.711899 | controller | >f+++++++++ ci-framework-data/logs/hypervisor_info.log
2025-12-10 11:50:25.711942 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-12-10 11:50:25.711965 | controller | >f+++++++++ ci-framework-data/logs/nat64_appliance_dns64_debug.log
2025-12-10 11:50:25.711984 | controller | >f+++++++++ ci-framework-data/logs/nat64_appliance_journal.log
2025-12-10 11:50:25.712002 | controller | >f+++++++++ ci-framework-data/logs/nat64_appliance_node_info.log
2025-12-10 11:50:25.712019 | controller | >f+++++++++ ci-framework-data/logs/test_node_info.log
2025-12-10 11:50:25.712036 | controller | cd+++++++++ registries.conf.d/
2025-12-10 11:50:25.712053 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-12-10 11:50:25.712079 | controller | cd+++++++++ system-config/
2025-12-10 11:50:25.712098 | controller | cd+++++++++ system-config/libvirt/
2025-12-10 11:50:25.712116 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-12-10 11:50:25.712132 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-12-10 11:50:25.712149 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf
2025-12-10 11:50:25.712166 | controller | >f+++++++++ system-config/libvirt/network.conf
2025-12-10 11:50:25.712183 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf
2025-12-10 11:50:25.712199 | controller | >f+++++++++ system-config/libvirt/qemu.conf
2025-12-10 11:50:25.712215 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf
2025-12-10 11:50:25.712231 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf
2025-12-10 11:50:25.712248 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf
2025-12-10 11:50:25.712264 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf
2025-12-10 11:50:25.712281 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf
2025-12-10 11:50:25.712298 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf
2025-12-10 11:50:25.712315 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf
2025-12-10 11:50:25.712331 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf
2025-12-10 11:50:25.712348 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf
2025-12-10 11:50:25.712364 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf
2025-12-10 11:50:26.043934 | controller | changed: .d..t...... ./
2025-12-10 11:50:26.378209 | controller | changed: .d..t...... ./
2025-12-10 11:50:26.391021 | 
2025-12-10 11:50:26.391135 | TASK [Return artifact to Zuul]
2025-12-10 11:50:26.418748 | controller | ok
2025-12-10 11:50:26.435948 | 
2025-12-10 11:50:26.436009 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-12-10 11:50:26.436112 | 
2025-12-10 11:50:26.436138 | PLAY RECAP
2025-12-10 11:50:26.436172 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-12-10 11:50:26.436197 | 
2025-12-10 11:50:26.509135 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-12-10 11:50:26.509809 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-10 11:50:26.980114 | 
2025-12-10 11:50:26.980207 | PLAY [all]
2025-12-10 11:50:26.997018 | 
2025-12-10 11:50:26.997099 | TASK [include_role : fetch-output]
2025-12-10 11:50:27.024958 | controller | ok
2025-12-10 11:50:27.040144 | 
2025-12-10 11:50:27.040220 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-10 11:50:27.074457 | controller | skipping: Conditional result was False
2025-12-10 11:50:27.079531 | 
2025-12-10 11:50:27.079592 | TASK [fetch-output : Set log path for single node]
2025-12-10 11:50:27.106867 | controller | ok
2025-12-10 11:50:27.111368 | 
2025-12-10 11:50:27.111432 | LOOP [fetch-output : Ensure local output dirs]
2025-12-10 11:50:27.403591 | controller -> localhost | ok: "/var/lib/zuul/builds/b1dbf66fe9ab464d90e0238ab83e43c3/work/logs"
2025-12-10 11:50:27.572474 | controller -> localhost | ok: "/var/lib/zuul/builds/b1dbf66fe9ab464d90e0238ab83e43c3/work/artifacts"
2025-12-10 11:50:27.742527 | controller -> localhost | ok: "/var/lib/zuul/builds/b1dbf66fe9ab464d90e0238ab83e43c3/work/docs"
2025-12-10 11:50:27.758382 | 
2025-12-10 11:50:27.758489 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-10 11:50:28.230827 | controller | ok
2025-12-10 11:50:28.231066 | controller | ok: All items complete
2025-12-10 11:50:28.231109 | 
2025-12-10 11:50:28.593787 | controller | ok
2025-12-10 11:50:28.940865 | controller | ok
2025-12-10 11:50:28.951774 | 
2025-12-10 11:50:28.951871 | TASK [include_role : fetch-output-openshift]
2025-12-10 11:50:28.965218 | controller | skipping: Conditional result was False
2025-12-10 11:50:28.970690 | 
2025-12-10 11:50:28.970755 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-10 11:50:29.283505 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.005828
2025-12-10 11:50:29.456042 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.005293
2025-12-10 11:50:29.483251 | 
2025-12-10 11:50:29.483347 | PLAY [all]
2025-12-10 11:50:29.496643 | 
2025-12-10 11:50:29.496711 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-12-10 11:50:29.860005 | controller | changed
2025-12-10 11:50:29.880746 | 
2025-12-10 11:50:29.880796 | PLAY RECAP
2025-12-10 11:50:29.880837 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-10 11:50:29.880857 | 
2025-12-10 11:50:29.946120 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-10 11:50:29.946789 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-12-10 11:50:30.441893 | 
2025-12-10 11:50:30.442005 | PLAY [localhost]
2025-12-10 11:50:30.457770 | 
2025-12-10 11:50:30.457840 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-10 11:50:30.748770 | localhost | changed
2025-12-10 11:50:30.753362 | 
2025-12-10 11:50:30.753459 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-10 11:50:30.771831 | localhost | ok
2025-12-10 11:50:30.779104 | 
2025-12-10 11:50:30.779173 | TASK [add-fileserver : Create SSH private key tempfile]
2025-12-10 11:50:31.059800 | localhost | changed
2025-12-10 11:50:31.065729 | 
2025-12-10 11:50:31.065809 | TASK [add-fileserver : Create SSH private key from secret]
2025-12-10 11:50:31.579128 | localhost | changed
2025-12-10 11:50:31.583841 | 
2025-12-10 11:50:31.583939 | TASK [add-fileserver : Add fileserver ssh key]
2025-12-10 11:50:31.894710 | localhost | Identity added: /var/lib/zuul/builds/b1dbf66fe9ab464d90e0238ab83e43c3/work/tmp/ansible.kl_zvk90 (/var/lib/zuul/builds/b1dbf66fe9ab464d90e0238ab83e43c3/work/tmp/ansible.kl_zvk90)
2025-12-10 11:50:31.894896 | localhost | ok: Runtime: 0:00:00.006510
2025-12-10 11:50:31.899062 | 
2025-12-10 11:50:31.899136 | TASK [add-fileserver : Remove SSH private key from disk]
2025-12-10 11:50:32.108512 | localhost | ok: Runtime: 0:00:00.004447
2025-12-10 11:50:32.113002 | 
2025-12-10 11:50:32.113069 | TASK [add-fileserver : Add fileserver to inventory]
2025-12-10 11:50:32.160293 | localhost | changed
2025-12-10 11:50:32.164812 | 
2025-12-10 11:50:32.164872 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-12-10 11:50:32.454418 | localhost | changed
2025-12-10 11:50:32.473004 | 
2025-12-10 11:50:32.473081 | PLAY [localhost]
2025-12-10 11:50:32.484232 | 
2025-12-10 11:50:32.484293 | TASK [Generate bulk log download script]
2025-12-10 11:50:32.501987 | localhost | ok
2025-12-10 11:50:32.512424 | 
2025-12-10 11:50:32.512485 | TASK [local-log-download : Check API endpoint is defined]
2025-12-10 11:50:32.539119 | localhost | ok: All assertions passed
2025-12-10 11:50:32.543060 | 
2025-12-10 11:50:32.543130 | TASK [local-log-download : Create download script]
2025-12-10 11:50:32.859149 | localhost -> localhost | changed
2025-12-10 11:50:32.867085 | 
2025-12-10 11:50:32.867155 | TASK [Register quick-download link]
2025-12-10 11:50:32.883985 | localhost | ok
2025-12-10 11:50:32.918164 | 
2025-12-10 11:50:32.918228 | PLAY [logserver.rdoproject.org]
2025-12-10 11:50:32.928021 | 
2025-12-10 11:50:32.928091 | TASK [Set zuul-log-path fact]
2025-12-10 11:50:32.943350 | logserver.rdoproject.org | ok
2025-12-10 11:50:32.952184 | 
2025-12-10 11:50:32.952251 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-10 11:50:32.978028 | logserver.rdoproject.org | ok
2025-12-10 11:50:32.983616 | 
2025-12-10 11:50:32.983680 | TASK [upload-logs : Create log directories]
2025-12-10 11:50:34.525827 | logserver.rdoproject.org | changed
2025-12-10 11:50:34.528849 | 
2025-12-10 11:50:34.528932 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-12-10 11:50:34.744957 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005024
2025-12-10 11:50:34.749388 | 
2025-12-10 11:50:34.749453 | TASK [upload-logs : Upload logs to log server]
2025-12-10 11:50:36.183221 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-12-10 11:50:36.185941 | 
2025-12-10 11:50:36.186004 | LOOP [upload-logs : Compress console log and json output]
2025-12-10 11:50:36.220969 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-10 11:50:36.228421 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-10 11:50:36.232333 | 
2025-12-10 11:50:36.232421 | LOOP [upload-logs : Upload compressed console log and json output]
2025-12-10 11:50:36.264850 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-10 11:50:36.265041 | 
2025-12-10 11:50:36.267666 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-10 11:50:36.278944 | 
2025-12-10 11:50:36.279027 | LOOP [upload-logs : Upload console log and json output]