2025-10-13 10:10:05.778814 | Job console starting... 2025-10-13 10:10:06.081696 | Updating repositories 2025-10-13 10:10:06.873088 | Preparing job workspace 2025-10-13 10:10:18.992333 | Running Ansible setup... 2025-10-13 10:10:23.598647 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 10:10:24.879844 | 2025-10-13 10:10:24.879999 | PLAY [localhost] 2025-10-13 10:10:24.912706 | 2025-10-13 10:10:24.912837 | TASK [Gathering Facts] 2025-10-13 10:10:26.264864 | localhost | ok 2025-10-13 10:10:26.282983 | 2025-10-13 10:10:26.283094 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-13 10:10:26.812557 | localhost -> localhost | changed 2025-10-13 10:10:26.818334 | 2025-10-13 10:10:26.818415 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-13 10:10:27.845841 | localhost -> localhost | changed 2025-10-13 10:10:27.854731 | 2025-10-13 10:10:27.854804 | TASK [Setup log path fact] 2025-10-13 10:10:27.894199 | localhost | ok 2025-10-13 10:10:27.906124 | 2025-10-13 10:10:27.906215 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 10:10:27.974564 | localhost | ok 2025-10-13 10:10:27.982217 | 2025-10-13 10:10:27.982299 | TASK [emit-job-header : Print job information] 2025-10-13 10:10:28.070404 | # Job Information 2025-10-13 10:10:28.070554 | Ansible Version: 2.15.12 2025-10-13 10:10:28.070606 | Job: cifmw-molecule-deploy_bmh 2025-10-13 10:10:28.070634 | Pipeline: github-check 2025-10-13 10:10:28.070655 | Executor: ibm-bm4-ze.softwarefactory-project.io 2025-10-13 10:10:28.070675 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3402 2025-10-13 10:10:28.070695 | Log URL (when completed): https://logserver.rdoproject.org/007/rdoproject.org/0073926b47414081ad902a855609181a/ 2025-10-13 10:10:28.070714 | Event ID: d1a3c640-a81b-11f0-8130-c9720bfa03f3 2025-10-13 10:10:28.074285 | 2025-10-13 10:10:28.074352 | LOOP [emit-job-header : Print node information] 2025-10-13 10:10:28.197920 | localhost | ok: 2025-10-13 10:10:28.198074 | localhost | # Node Information 2025-10-13 10:10:28.198108 | localhost | Inventory Hostname: controller 2025-10-13 10:10:28.198135 | localhost | Hostname: np0005483342 2025-10-13 10:10:28.198156 | localhost | Username: zuul 2025-10-13 10:10:28.198177 | localhost | Distro: CentOS 9 2025-10-13 10:10:28.198195 | localhost | Provider: ibm-bm4-nodepool 2025-10-13 10:10:28.198213 | localhost | Region: regionOne 2025-10-13 10:10:28.198229 | localhost | Label: cloud-centos-9-stream-tripleo-ibm 2025-10-13 10:10:28.198246 | localhost | Product Name: OpenStack Compute 2025-10-13 10:10:28.198263 | localhost | Interface IP: 192.168.26.214 2025-10-13 10:10:28.244647 | 2025-10-13 10:10:28.244747 | PLAY [all] 2025-10-13 10:10:28.258536 | 2025-10-13 10:10:28.258653 | TASK [Gather network facts] 2025-10-13 10:10:28.607321 | controller | ok 2025-10-13 10:10:28.624537 | 2025-10-13 10:10:28.624617 | TASK [include_role : start-zuul-console] 2025-10-13 10:10:28.656170 | controller | ok 2025-10-13 10:10:28.668488 | 2025-10-13 10:10:28.668554 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-13 10:10:29.017280 | controller | ok 2025-10-13 10:10:29.036009 | 2025-10-13 10:10:29.036104 | TASK [include_role : add-build-sshkey] 2025-10-13 10:10:29.059511 | controller | ok 2025-10-13 10:10:29.075822 | 2025-10-13 10:10:29.075899 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-13 10:10:29.326217 | controller -> localhost | ok 2025-10-13 10:10:29.333046 | 2025-10-13 10:10:29.333113 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-13 10:10:29.376496 | controller | ok 2025-10-13 10:10:29.400352 | controller | included: /var/lib/zuul/builds/0073926b47414081ad902a855609181a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-13 10:10:29.407105 | 2025-10-13 10:10:29.407175 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-13 10:10:30.075705 | controller -> localhost | Generating public/private rsa key pair. 2025-10-13 10:10:30.075905 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/0073926b47414081ad902a855609181a/work/0073926b47414081ad902a855609181a_id_rsa. 2025-10-13 10:10:30.075960 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/0073926b47414081ad902a855609181a/work/0073926b47414081ad902a855609181a_id_rsa.pub. 2025-10-13 10:10:30.075988 | controller -> localhost | The key fingerprint is: 2025-10-13 10:10:30.076012 | controller -> localhost | SHA256:5Zcjou7NjXvn+9LC29dM4ym2BVcP7iW9wkYffNviGdU zuul-build-sshkey 2025-10-13 10:10:30.076034 | controller -> localhost | The key's randomart image is: 2025-10-13 10:10:30.076055 | controller -> localhost | +---[RSA 3072]----+ 2025-10-13 10:10:30.076075 | controller -> localhost | | | 2025-10-13 10:10:30.076095 | controller -> localhost | | | 2025-10-13 10:10:30.076113 | controller -> localhost | | . . .| 2025-10-13 10:10:30.076132 | controller -> localhost | | o o.o+| 2025-10-13 10:10:30.076150 | controller -> localhost | | S o +oo+E| 2025-10-13 10:10:30.076183 | controller -> localhost | | . . ooo+=B| 2025-10-13 10:10:30.076210 | controller -> localhost | | . . ==B=| 2025-10-13 10:10:30.076232 | controller -> localhost | | . o o. *=+*+| 2025-10-13 10:10:30.076253 | controller -> localhost | | .o =o.o=BB. | 2025-10-13 10:10:30.076272 | controller -> localhost | +----[SHA256]-----+ 2025-10-13 10:10:30.076318 | controller -> localhost | ok: Runtime: 0:00:00.136366 2025-10-13 10:10:30.082400 | 2025-10-13 10:10:30.082466 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-13 10:10:30.110641 | controller | ok 2025-10-13 10:10:30.121081 | controller | included: /var/lib/zuul/builds/0073926b47414081ad902a855609181a/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-13 10:10:30.128726 | 2025-10-13 10:10:30.128790 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-13 10:10:30.152433 | controller | skipping: Conditional result was False 2025-10-13 10:10:30.157929 | 2025-10-13 10:10:30.158010 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-13 10:10:30.529453 | controller | changed 2025-10-13 10:10:30.535937 | 2025-10-13 10:10:30.536023 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-13 10:10:30.728890 | controller | ok 2025-10-13 10:10:30.734215 | 2025-10-13 10:10:30.734288 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-13 10:10:31.355697 | controller | changed 2025-10-13 10:10:31.362158 | 2025-10-13 10:10:31.362221 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-13 10:10:31.942887 | controller | changed 2025-10-13 10:10:31.948028 | 2025-10-13 10:10:31.948094 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-13 10:10:31.972327 | controller | skipping: Conditional result was False 2025-10-13 10:10:31.982235 | 2025-10-13 10:10:31.982301 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-13 10:10:32.564475 | controller -> localhost | changed 2025-10-13 10:10:32.574066 | 2025-10-13 10:10:32.574139 | TASK [add-build-sshkey : Add back temp key] 2025-10-13 10:10:32.810746 | controller -> localhost | Identity added: /var/lib/zuul/builds/0073926b47414081ad902a855609181a/work/0073926b47414081ad902a855609181a_id_rsa (zuul-build-sshkey) 2025-10-13 10:10:32.810981 | controller -> localhost | ok: Runtime: 0:00:00.006968 2025-10-13 10:10:32.816486 | 2025-10-13 10:10:32.816545 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-13 10:10:33.099138 | controller | ok 2025-10-13 10:10:33.103678 | 2025-10-13 10:10:33.103740 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-13 10:10:33.127233 | controller | skipping: Conditional result was False 2025-10-13 10:10:33.136631 | 2025-10-13 10:10:33.136699 | TASK [include_role : validate-host] 2025-10-13 10:10:33.155679 | controller | ok 2025-10-13 10:10:33.175160 | 2025-10-13 10:10:33.175231 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-13 10:10:33.203263 | controller | ok 2025-10-13 10:10:33.207999 | 2025-10-13 10:10:33.208065 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-13 10:10:33.413611 | controller -> localhost | ok 2025-10-13 10:10:33.419132 | 2025-10-13 10:10:33.419197 | TASK [validate-host : Collect information about the host] 2025-10-13 10:10:34.046526 | controller | ok 2025-10-13 10:10:34.059973 | 2025-10-13 10:10:34.060061 | TASK [validate-host : Sanitize hostname] 2025-10-13 10:10:34.132256 | controller | ok 2025-10-13 10:10:34.137412 | 2025-10-13 10:10:34.137478 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-13 10:10:34.608259 | controller -> localhost | changed 2025-10-13 10:10:34.615091 | 2025-10-13 10:10:34.615197 | TASK [validate-host : Collect information about zuul worker] 2025-10-13 10:10:34.951127 | controller | ok 2025-10-13 10:10:34.956876 | 2025-10-13 10:10:34.956971 | TASK [validate-host : Write out all zuul information for each host] 2025-10-13 10:10:35.399853 | controller -> localhost | changed 2025-10-13 10:10:35.409552 | 2025-10-13 10:10:35.409745 | TASK [include_role : prepare-workspace-openshift] 2025-10-13 10:10:35.423061 | controller | skipping: Conditional result was False 2025-10-13 10:10:35.428080 | 2025-10-13 10:10:35.428147 | TASK [include_role : remove-zuul-sshkey] 2025-10-13 10:10:35.451755 | controller | skipping: Conditional result was False 2025-10-13 10:10:35.457214 | 2025-10-13 10:10:35.457305 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-13 10:10:35.660097 | controller | ok: "logs" 2025-10-13 10:10:35.660313 | controller | ok: All items complete 2025-10-13 10:10:35.660342 | 2025-10-13 10:10:35.818541 | controller | ok: "artifacts" 2025-10-13 10:10:35.978604 | controller | ok: "docs" 2025-10-13 10:10:35.985562 | 2025-10-13 10:10:35.985643 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-13 10:10:36.174760 | controller | changed: "logs" 2025-10-13 10:10:36.343716 | controller | changed: "artifacts" 2025-10-13 10:10:36.514462 | controller | changed: "docs" 2025-10-13 10:10:36.545734 | 2025-10-13 10:10:36.545852 | PLAY RECAP 2025-10-13 10:10:36.545900 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-13 10:10:36.545976 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 10:10:36.545999 | 2025-10-13 10:10:36.665276 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-13 10:10:36.666121 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master] 2025-10-13 10:10:37.284604 | 2025-10-13 10:10:37.284721 | PLAY [all] 2025-10-13 10:10:37.304329 | 2025-10-13 10:10:37.304428 | TASK [mirror-info-fork : Set mirror_fqdn if not defined] 2025-10-13 10:10:37.363276 | controller | ok 2025-10-13 10:10:37.369521 | 2025-10-13 10:10:37.369617 | TASK [mirror-info-fork : Create /etc/ci] 2025-10-13 10:10:37.735026 | controller | changed 2025-10-13 10:10:37.741891 | 2025-10-13 10:10:37.741982 | TASK [mirror-info-fork : Install ci_mirror script] 2025-10-13 10:10:38.593940 | controller | changed 2025-10-13 10:10:38.605475 | 2025-10-13 10:10:38.605607 | LOOP [add-authorized-keys : Enable access via build key on all nodes] 2025-10-13 10:10:38.987609 | controller | changed: 2025-10-13 10:10:38.987879 | controller | { 2025-10-13 10:10:38.987937 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com" 2025-10-13 10:10:38.987974 | controller | } 2025-10-13 10:10:39.193336 | controller | changed: 2025-10-13 10:10:39.193430 | controller | { 2025-10-13 10:10:39.193459 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com" 2025-10-13 10:10:39.193482 | controller | } 2025-10-13 10:10:39.395263 | controller | changed: 2025-10-13 10:10:39.395358 | controller | { 2025-10-13 10:10:39.395385 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com" 2025-10-13 10:10:39.395407 | controller | } 2025-10-13 10:10:39.606319 | controller | changed: 2025-10-13 10:10:39.606418 | controller | { 2025-10-13 10:10:39.606472 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com" 2025-10-13 10:10:39.606497 | controller | } 2025-10-13 10:10:39.811196 | controller | changed: 2025-10-13 10:10:39.811378 | controller | { 2025-10-13 10:10:39.811417 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com" 2025-10-13 10:10:39.811442 | controller | } 2025-10-13 10:10:40.021116 | controller | changed: 2025-10-13 10:10:40.021203 | controller | { 2025-10-13 10:10:40.021231 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com" 2025-10-13 10:10:40.021254 | controller | } 2025-10-13 10:10:40.237174 | controller | changed: 2025-10-13 10:10:40.237257 | controller | { 2025-10-13 10:10:40.237285 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDLOQd4ZLtkZXQGY6UwAr/06ppWQK4fDO3HaqxPk98csyOCBXsliSKK39Bso828+5srIXiW7aI6aC9P5mwi4mUZlGPfJlQbfrcGvY+b/SocuvaGK+1RrHLoJCT52LBhwgrzlXio2jeksZeein8iaTrhsPrOAs7KggIL/rB9hEiB3NaOPWhhoCP4vlW6MEMExGcqB/1FVxXFBPnLkEyW0Lk7ycVflZl2ocRxbfjZi0+tI1Wlinp8PvSQSc/WVrAcDgKjc/mB4ODPOyYy3G8FHgfMsrXSDEyjBKgLKMsdCrAUcqJQWjkqXleXSYOV4q3pzL+9umK+q/e3P/bIoSFQzmJKTU1eDfuvPXmow9F5H54fii/Da7ezlMJ+wPGHJrRAkmzvMbALy7xwswLhZMkOGNtRcPqaKYRmIBKpw3o6bCTtcNUHOtOQnzwY8JzrM2eBWJBXAANYw+9/ho80JIiwhg29CFNpVBuHbql2YxJQNrnl90guN65rYNpDxdIluweyUf8= anbanerj@kaermorhen" 2025-10-13 10:10:40.237308 | controller | } 2025-10-13 10:10:40.443883 | controller | changed: 2025-10-13 10:10:40.443990 | controller | { 2025-10-13 10:10:40.444019 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC3VwV8Im9kRm49lt3tM36hj4Zv27FxGo4C1Q/0jqhzFmHY7RHbmeRr8ObhwWoHjXSozKWg8FL5ER0z3hTwL0W6lez3sL7hUaCmSuZmG5Hnl3x4vTSxDI9JZ/Y65rtYiiWQo2fC5xJhU/4+0e5e/pseCm8cKRSu+SaxhO+sd6FDojA2x1BzOzKiQRDy/1zWGp/cZkxcEuB1wHI5LMzN03c67vmbu+fhZRAUO4dQkvcnj2LrhQtpa+ytvnSjr8icMDosf1OsbSffwZFyHB/hfWGAfe0eIeSA2XPraxiPknXxiPKx2MJsaUTYbsZcm3EjFdHBBMumw5rBI74zLrMRvCO9GwBEmGT4rFng1nP+yw5DB8sn2zqpOsPg1LYRwCPOUveC13P6pgsZZPh812e8v5EKnETct+5XI3dVpdw6CnNiLwAyVAF15DJvBGT/u1k0Myg/bQn+Gv9k2MSj6LvQmf6WbZu2Wgjm30z3FyCneBqTL7mLF19YXzeC0ufHz5pnO1E= dasm@fedora" 2025-10-13 10:10:40.444041 | controller | } 2025-10-13 10:10:40.643851 | controller | changed: 2025-10-13 10:10:40.643961 | controller | { 2025-10-13 10:10:40.644002 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner" 2025-10-13 10:10:40.644028 | controller | } 2025-10-13 10:10:40.847231 | controller | changed: 2025-10-13 10:10:40.847307 | controller | { 2025-10-13 10:10:40.847335 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com" 2025-10-13 10:10:40.847356 | controller | } 2025-10-13 10:10:41.058009 | controller | changed: 2025-10-13 10:10:41.058081 | controller | { 2025-10-13 10:10:41.058109 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com" 2025-10-13 10:10:41.058130 | controller | } 2025-10-13 10:10:41.292977 | controller | changed: 2025-10-13 10:10:41.293046 | controller | { 2025-10-13 10:10:41.293074 | controller | "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com" 2025-10-13 10:10:41.293096 | controller | } 2025-10-13 10:10:41.487828 | controller | changed: 2025-10-13 10:10:41.488995 | controller | { 2025-10-13 10:10:41.489041 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith" 2025-10-13 10:10:41.489067 | controller | } 2025-10-13 10:10:41.696668 | controller | changed: 2025-10-13 10:10:41.696753 | controller | { 2025-10-13 10:10:41.696779 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel" 2025-10-13 10:10:41.696802 | controller | } 2025-10-13 10:10:41.903741 | controller | changed: 2025-10-13 10:10:41.903823 | controller | { 2025-10-13 10:10:41.903850 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux" 2025-10-13 10:10:41.903870 | controller | } 2025-10-13 10:10:42.098542 | controller | changed: 2025-10-13 10:10:42.098646 | controller | { 2025-10-13 10:10:42.098675 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr" 2025-10-13 10:10:42.098697 | controller | } 2025-10-13 10:10:42.299184 | controller | changed: 2025-10-13 10:10:42.299269 | controller | { 2025-10-13 10:10:42.299297 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQCfNtF7NvKl915TGsGGoseUb06Hj8L/S4toWf0hExeY+F00woL6NvBlJD0nDct+P5a22I4EhvoQCRQ8reaPCm1lybR3uiRIJsj+8zkVvLwby9LXzfZorlNG9ofjd00FEmB09uW/YvTl6Q9XwwwX6tInzIOv3TMqTHHGOL74ibbj8J/FJR0cFEyj0z4WQRvtkh32xAHl83gbuINryMt0sqRI+clj2381NKL55DRLQrVw0gsfqqxiHAnXg21qWmc4J+b9e9kiuAFQjcjwTVkwJCcg3xbPwC/qokYRby/Y5S40UUd7/jEARGXT7RZgpzTuDd1oZiCVrnrqJNPaMNdVv5MLeFdf1B7iIe5aa/fGouX7AO4SdKhZUdnJmCFAGvjC6S3JMZ2wAcUl+OHnssfmdj7XL50cLo27vjuzMtLAgSqi6N99m92WCF2s8J9aVzszX7Xz9OKZCeGsiVJp3/NdABKzSEAyM9xBD/5Vho894Sav+otpySHe3p6RUTgbB5Zu8VyZRZ/UtB3ueXxyo764yrc6qWIDqrehm84Xm9g+/jpIBzGPl07NUNJpdt/6Sgf9RIKXw/7XypO5yZfUcuFNGTxLfqjTNrtgLZNcjfav6sSdVXVcMPL//XNuRdKmVFaO76eV/oGMQGr1fGcCD+N+CpI7+Q+fCNB6VFWG4nZFuI/Iuw== averdagu@redhat.com" 2025-10-13 10:10:42.299319 | controller | } 2025-10-13 10:10:42.499573 | controller | changed: 2025-10-13 10:10:42.499710 | controller | { 2025-10-13 10:10:42.499738 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDq8l27xI+QlQVdS4djp9ogSoyrNE2+Ox6vKPdhSNL1J3PE5w+WCSvMz9A5gnNuH810zwbekEApbxTze/gLQJwBHA52CChfURpXrFaxY7ePXRElwKAL3mJfzBWY/c5jnNL9TCVmFJTGZkFZP3Nh+BMgZvL6xBkt3WKm6Uq18qzd9XeKcZusrA+O+uLv1fVeQnadY9RIqOCyeFYCzLWrUfTyE8x/XG0hAWIM7qpnF2cALQS2h9n4hW5ybiUN790H08wf9hFwEf5nxY9Z9dVkPFQiTSGKNBzmnCXU9skxS/xhpFjJ5duGSZdtAHe9O+nGZm9c67hxgtf8e5PDuqAdXEv2cf6e3VBAt+Bz8EKI3yosTj0oZHfwr42Yzb1l/SKy14Rggsrc9KAQlrGXan6+u2jcQqqx7l+SWmnpFiWTV9u5cWj2IgOhApOitmRBPYqk9rE2usfO0hLn/Pj/R/Nau4803e1/EikdLE7Ps95s9mX5jRDjAoUa2JwFF5RsVFyL910= ashigupt@ashigupt.remote.csb" 2025-10-13 10:10:42.499768 | controller | } 2025-10-13 10:10:42.700636 | controller | changed: 2025-10-13 10:10:42.700723 | controller | { 2025-10-13 10:10:42.700750 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9" 2025-10-13 10:10:42.700770 | controller | } 2025-10-13 10:10:42.903436 | controller | changed: 2025-10-13 10:10:42.903577 | controller | { 2025-10-13 10:10:42.903622 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora" 2025-10-13 10:10:42.903645 | controller | } 2025-10-13 10:10:43.110937 | controller | changed: 2025-10-13 10:10:43.111030 | controller | { 2025-10-13 10:10:43.111057 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac" 2025-10-13 10:10:43.111078 | controller | } 2025-10-13 10:10:43.313808 | controller | changed: 2025-10-13 10:10:43.313896 | controller | { 2025-10-13 10:10:43.313943 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop" 2025-10-13 10:10:43.313967 | controller | } 2025-10-13 10:10:43.525920 | controller | changed: 2025-10-13 10:10:43.526058 | controller | { 2025-10-13 10:10:43.526089 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQDZdI7t1cxYx65heVI24HTV4F7oQLW1zyfxHreL2TIJKxjyrUUKIFEUmTutcBlJRLNT2Eoix6x1sOw9YrchloCLcn//SGfTElr9mSc5jbjb7QXEU+zJMhtxyEJ1Po3CUGnj7ckiIXw7wcawZtrEOAQ9pH3ExYCJcEMiyNjRQZCxT3tPK+S4B95EWh5Fsrz9CkwpjNRPPH7LigCeQTM3Wc7r97utAslBUUvYceDSLA7rMgkitJE38b7rZBeYzsGQ8YYUBjTCtehqQXxCRjizbHWaaZkBU+N3zkKB6n/iCNGIO690NK7A/qb6msTijiz1PeuM8ThOsi9qXnbX5v0PoTpcFSojV7NHAQ71f0XXuS43FhZctT+Dcx44dT8Fb5vJu2cJGrk+qF8ZgJYNpRS7gPg0EG2EqjK7JMf9ULdjSu0r+KlqIAyLvtzT4eOnQipoKlb/WG5D/0ohKv7OMQ352ggfkBFIQsRXyyTCT98Ft9juqPuahi3CAQmP4H9dyE+7+Kz437PEtsxLmfm6naNmWi7Ee1DqWPwS8rEajsm4sNM4wW9gdBboJQtc0uZw0DfLj1I9r3Mc8Ol0jYtz0yNQDSzVLrGCaJlC311trU70tZ+ZkAVV6Mn8lOhSbj1cK0lvSr6ZK4dgqGl3I1eTZJJhbLNdg7UOVaiRx9543+C/p/As7w== brjackma@redhat.com" 2025-10-13 10:10:43.526113 | controller | } 2025-10-13 10:10:43.740478 | controller | changed: 2025-10-13 10:10:43.740570 | controller | { 2025-10-13 10:10:43.740613 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com" 2025-10-13 10:10:43.740636 | controller | } 2025-10-13 10:10:43.943489 | controller | changed: 2025-10-13 10:10:43.943577 | controller | { 2025-10-13 10:10:43.943620 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com" 2025-10-13 10:10:43.943642 | controller | } 2025-10-13 10:10:44.152374 | controller | changed: 2025-10-13 10:10:44.152528 | controller | { 2025-10-13 10:10:44.152562 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono" 2025-10-13 10:10:44.152585 | controller | } 2025-10-13 10:10:44.170514 | 2025-10-13 10:10:44.170635 | TASK [Set timezone to UTC] 2025-10-13 10:10:44.575143 | controller | changed: executed `/bin/timedatectl set-timezone UTC` 2025-10-13 10:10:44.579872 | 2025-10-13 10:10:44.585090 | TASK [Create nodepool directory] 2025-10-13 10:10:44.828432 | controller | changed 2025-10-13 10:10:44.836891 | 2025-10-13 10:10:44.837007 | TASK [Create nodepool sub_nodes file] 2025-10-13 10:10:45.360833 | controller | changed 2025-10-13 10:10:45.367034 | 2025-10-13 10:10:45.367124 | TASK [Create nodepool sub_nodes_private file] 2025-10-13 10:10:45.906817 | controller | changed 2025-10-13 10:10:45.912147 | 2025-10-13 10:10:45.912212 | LOOP [Populate nodepool sub_nodes file] 2025-10-13 10:10:45.945884 | 2025-10-13 10:10:45.946036 | LOOP [Populate nodepool sub_nodes_private file] 2025-10-13 10:10:45.995888 | 2025-10-13 10:10:45.996118 | TASK [Create nodepool primary file] 2025-10-13 10:10:46.019293 | controller | skipping: Conditional result was False 2025-10-13 10:10:46.024860 | 2025-10-13 10:10:46.025098 | TASK [Create nodepool node_private for this node] 2025-10-13 10:10:46.570773 | controller | changed 2025-10-13 10:10:46.578443 | 2025-10-13 10:10:46.578542 | LOOP [Copy ssh keys to nodepool directory] 2025-10-13 10:10:46.929421 | controller | ok: Item: id_rsa Runtime: 0:00:00.005445 2025-10-13 10:10:46.929585 | 2025-10-13 10:10:47.102711 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.004496 2025-10-13 10:10:47.117122 | 2025-10-13 10:10:47.117228 | TASK [Add sudoers role for zuul-sudo-grep.sh] 2025-10-13 10:10:47.647276 | controller | changed 2025-10-13 10:10:47.653581 | 2025-10-13 10:10:47.653668 | TASK [Validate sudoers config after edits] 2025-10-13 10:10:47.895950 | controller | /etc/sudoers: parsed OK 2025-10-13 10:10:47.896036 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK 2025-10-13 10:10:47.896046 | controller | /etc/sudoers.d/zuul: parsed OK 2025-10-13 10:10:47.896054 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK 2025-10-13 10:10:48.194193 | controller | ok: Runtime: 0:00:00.005741 2025-10-13 10:10:48.199962 | 2025-10-13 10:10:48.200026 | TASK [Show the environment passed in to job shell scripts] 2025-10-13 10:10:48.436005 | controller | SHELL=/bin/bash 2025-10-13 10:10:48.436053 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework 2025-10-13 10:10:48.436063 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework 2025-10-13 10:10:48.436070 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/02/3402/0029ba8cf646fb53936389652feaf095d4937d80 2025-10-13 10:10:48.436076 | controller | PWD=/home/zuul 2025-10-13 10:10:48.436082 | controller | ZUUL_PIPELINE=github-check 2025-10-13 10:10:48.436087 | controller | LOGNAME=zuul 2025-10-13 10:10:48.436093 | controller | XDG_SESSION_TYPE=tty 2025-10-13 10:10:48.436098 | controller | _=/usr/bin/env 2025-10-13 10:10:48.436103 | controller | MOTD_SHOWN=pam 2025-10-13 10:10:48.436157 | controller | HOME=/home/zuul 2025-10-13 10:10:48.436165 | controller | LANG=en_US.UTF-8 2025-10-13 10:10:48.436171 | controller | SSH_CONNECTION=192.168.26.12 40566 192.168.26.214 22 2025-10-13 10:10:48.436177 | controller | TOX_TESTENV_PASSENV=ZUUL_UUID ZUUL_PROJECT ZUUL_SHORT_PROJECT_NAME ZUUL_PIPELINE ZUUL_VOTING WORKSPACE BUILD_TIMEOUT ZUUL_BRANCH ZUUL_CHANGES ZUUL_CHANGE_IDS ZUUL_CHANGE ZUUL_PATCHSET 2025-10-13 10:10:48.436185 | controller | ZUUL_CHANGE_IDS=3402,0029ba8cf646fb53936389652feaf095d4937d80 2025-10-13 10:10:48.436191 | controller | WORKSPACE=/home/zuul/workspace 2025-10-13 10:10:48.436197 | controller | XDG_SESSION_CLASS=user 2025-10-13 10:10:48.436202 | controller | SELINUX_ROLE_REQUESTED= 2025-10-13 10:10:48.436207 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s 2025-10-13 10:10:48.436213 | controller | USER=zuul 2025-10-13 10:10:48.436218 | controller | ZUUL_VOTING=True 2025-10-13 10:10:48.436224 | controller | BUILD_TIMEOUT=1800000 2025-10-13 10:10:48.436229 | controller | SELINUX_USE_CURRENT_RANGE= 2025-10-13 10:10:48.436234 | controller | SHLVL=1 2025-10-13 10:10:48.436240 | controller | ZUUL_PATCHSET=0029ba8cf646fb53936389652feaf095d4937d80 2025-10-13 10:10:48.436245 | controller | XDG_SESSION_ID=1 2025-10-13 10:10:48.436250 | controller | ZUUL_BRANCH=main 2025-10-13 10:10:48.436256 | controller | XDG_RUNTIME_DIR=/run/user/1000 2025-10-13 10:10:48.436261 | controller | SSH_CLIENT=192.168.26.12 40566 22 2025-10-13 10:10:48.436266 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/ 2025-10-13 10:10:48.436272 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima: 2025-10-13 10:10:48.436279 | controller | which_declare=declare -f 2025-10-13 10:10:48.436285 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin 2025-10-13 10:10:48.436290 | controller | SELINUX_LEVEL_REQUESTED= 2025-10-13 10:10:48.436296 | controller | ZUUL_CHANGE=3402 2025-10-13 10:10:48.436301 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus 2025-10-13 10:10:48.436307 | controller | ZUUL_UUID=0073926b47414081ad902a855609181a 2025-10-13 10:10:48.436312 | controller | BASH_FUNC_which%%=() { ( alias; 2025-10-13 10:10:48.436318 | controller | eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@ 2025-10-13 10:10:48.436323 | controller | } 2025-10-13 10:10:48.739638 | controller | ok: Runtime: 0:00:00.005754 2025-10-13 10:10:48.745207 | 2025-10-13 10:10:48.745271 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars] 2025-10-13 10:10:48.759095 | controller | skipping: Conditional result was False 2025-10-13 10:10:48.764518 | 2025-10-13 10:10:48.764600 | TASK [Symlink /home/zuul-worker/workspace] 2025-10-13 10:10:49.291120 | controller | skipping: Conditional result was False 2025-10-13 10:10:49.297120 | 2025-10-13 10:10:49.297188 | TASK [Ensure legacy workspace directory] 2025-10-13 10:10:49.487989 | controller | changed 2025-10-13 10:10:49.506765 | 2025-10-13 10:10:49.506848 | PLAY RECAP 2025-10-13 10:10:49.506896 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-13 10:10:49.506948 | 2025-10-13 10:10:49.591692 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master] 2025-10-13 10:10:49.592467 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main] 2025-10-13 10:10:50.139661 | 2025-10-13 10:10:50.139799 | PLAY [Run ci/playbooks/dump_zuul_data.yml] 2025-10-13 10:10:50.174018 | 2025-10-13 10:10:50.174096 | TASK [Create zuul-output directory] 2025-10-13 10:10:50.488550 | controller | changed 2025-10-13 10:10:50.493883 | 2025-10-13 10:10:50.493985 | TASK [Slurp Zuul inventory test] 2025-10-13 10:10:50.765801 | controller -> localhost | ok 2025-10-13 10:10:50.772996 | 2025-10-13 10:10:50.773091 | TASK [Save zuul inventory] 2025-10-13 10:10:51.553857 | controller | changed 2025-10-13 10:10:51.559962 | 2025-10-13 10:10:51.560039 | TASK [Save zuul vars without the change_message] 2025-10-13 10:10:52.118096 | controller | changed 2025-10-13 10:10:52.140465 | 2025-10-13 10:10:52.140540 | PLAY RECAP 2025-10-13 10:10:52.140582 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-13 10:10:52.140631 | 2025-10-13 10:10:52.227351 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main] 2025-10-13 10:10:52.228197 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main] 2025-10-13 10:10:52.806708 | 2025-10-13 10:10:52.806811 | PLAY [Run ci/playbooks/molecule-prepare.yml] 2025-10-13 10:10:52.826963 | 2025-10-13 10:10:52.827040 | TASK [Read group_vars] 2025-10-13 10:10:52.865671 | controller | ok 2025-10-13 10:10:52.882737 | 2025-10-13 10:10:52.882833 | TASK [cifmw_helpers : Check directory is available] 2025-10-13 10:10:53.165882 | controller | ok 2025-10-13 10:10:53.171009 | 2025-10-13 10:10:53.171076 | TASK [cifmw_helpers : Print var] 2025-10-13 10:10:53.190062 | controller | ok: 2025-10-13 10:10:53.190173 | controller | provide_var is /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/group_vars 2025-10-13 10:10:53.190204 | controller | and registered one is {'changed': False, 'stat': {'exists': False}, 'failed': False} 2025-10-13 10:10:53.195067 | 2025-10-13 10:10:53.195132 | TASK [cifmw_helpers : List dir in ansible user home] 2025-10-13 10:10:53.488975 | controller | ls: cannot access '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/group_vars': No such file or directory 2025-10-13 10:10:53.490269 | controller | ls: cannot access '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/group_vars': No such file or directory 2025-10-13 10:10:53.491547 | controller | ls: cannot access '/root/src/github.com/openstack-k8s-operators/ci-framework/group_vars': Permission denied 2025-10-13 10:10:53.492714 | controller | ls: cannot access '/workspace/src/github.com/openstack-k8s-operators/ci-framework/group_vars': No such file or directory 2025-10-13 10:10:53.721347 | controller | ERROR 2025-10-13 10:10:53.721465 | controller | { 2025-10-13 10:10:53.721495 | controller | "delta": "0:00:00.008324", 2025-10-13 10:10:53.721522 | controller | "end": "2025-10-13 10:10:53.492988", 2025-10-13 10:10:53.721541 | controller | "msg": "non-zero return code", 2025-10-13 10:10:53.721558 | controller | "rc": 2, 2025-10-13 10:10:53.721576 | controller | "start": "2025-10-13 10:10:53.484664" 2025-10-13 10:10:53.721610 | controller | } 2025-10-13 10:10:53.721638 | controller | ERROR: Ignoring Errors 2025-10-13 10:10:53.727567 | 2025-10-13 10:10:53.727652 | TASK [cifmw_helpers : List available files] 2025-10-13 10:10:54.253642 | controller | skipping: Conditional result was False 2025-10-13 10:10:54.260362 | 2025-10-13 10:10:54.260481 | LOOP [cifmw_helpers : Read vars] 2025-10-13 10:10:54.279683 | 2025-10-13 10:10:54.279868 | LOOP [cifmw_helpers : Call task to parse all files as fact] 2025-10-13 10:10:54.303607 | 2025-10-13 10:10:54.303759 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh] 2025-10-13 10:10:54.349184 | controller | ok 2025-10-13 10:10:54.372979 | 2025-10-13 10:10:54.373091 | TASK [mirror-info-fork : Set mirror_fqdn if not defined] 2025-10-13 10:10:54.397208 | controller | skipping: Conditional result was False 2025-10-13 10:10:54.403315 | 2025-10-13 10:10:54.403405 | TASK [mirror-info-fork : Create /etc/ci] 2025-10-13 10:10:54.684802 | controller | ok 2025-10-13 10:10:54.691046 | 2025-10-13 10:10:54.691165 | TASK [mirror-info-fork : Install ci_mirror script] 2025-10-13 10:10:55.189074 | controller | ok 2025-10-13 10:10:55.198785 | 2025-10-13 10:10:55.198851 | TASK [Prepare workspace] 2025-10-13 10:10:55.216228 | controller | ok 2025-10-13 10:10:55.236875 | 2025-10-13 10:10:55.236960 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-13 10:10:55.501356 | controller | ok 2025-10-13 10:10:55.507483 | 2025-10-13 10:10:55.507565 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-13 10:10:57.879136 | controller | Output suppressed because no_log was given 2025-10-13 10:10:57.889373 | 2025-10-13 10:10:57.889457 | LOOP [Create zuul-output directory] 2025-10-13 10:10:58.088259 | controller | changed: "/home/zuul/ci-framework-data/logs" 2025-10-13 10:10:58.088467 | 2025-10-13 10:10:58.243572 | controller | ok: "/home/zuul/zuul-output/logs" 2025-10-13 10:10:58.252974 | 2025-10-13 10:10:58.253049 | TASK [Install required packages] 2025-10-13 10:11:48.723047 | controller | changed 2025-10-13 10:11:48.729823 | 2025-10-13 10:11:48.729926 | TASK [Install venv] 2025-10-13 10:12:50.694714 | controller | changed 2025-10-13 10:12:50.723689 | 2025-10-13 10:12:50.723789 | PLAY RECAP 2025-10-13 10:12:50.723834 | controller | ok: 10 changed: 5 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1 2025-10-13 10:12:50.723858 | 2025-10-13 10:12:50.804360 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main] 2025-10-13 10:12:50.805197 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main] 2025-10-13 10:12:51.502286 | 2025-10-13 10:12:51.502403 | PLAY [Run ci/playbooks/molecule-test.yml] 2025-10-13 10:12:51.525693 | 2025-10-13 10:12:51.525812 | TASK [Gather required facts] 2025-10-13 10:12:52.155655 | controller | ok 2025-10-13 10:12:52.163172 | 2025-10-13 10:12:52.163270 | TASK [Load environment var if instructed to] 2025-10-13 10:12:52.186890 | controller | skipping: Conditional result was False 2025-10-13 10:12:52.194305 | 2025-10-13 10:12:52.194375 | TASK [Ensure group_vars dir exists] 2025-10-13 10:12:52.509056 | controller | ok 2025-10-13 10:12:52.515452 | 2025-10-13 10:12:52.515532 | TASK [Run molecule] 2025-10-13 10:12:53.483264 | controller | INFO Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml 2025-10-13 10:12:53.553991 | controller | INFO Performing prerun with role_name_check=0... 2025-10-13 10:13:11.682182 | controller | WARNING Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/e43bbd/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-13 10:13:11.682776 | controller | WARNING Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/e43bbd/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-13 10:13:11.683317 | controller | WARNING Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/e43bbd/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-13 10:13:11.683843 | controller | WARNING Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/e43bbd/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-13 10:13:11.684390 | controller | WARNING Another version of 'cifmw.general' 1.0.0+0029ba8c was found installed in /home/zuul/.cache/ansible-compat/e43bbd/collections/ansible_collections, only the first one will be used, 1.0.0+0029ba8c (/home/zuul/.ansible/collections/ansible_collections). 2025-10-13 10:13:11.684879 | controller | WARNING Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/e43bbd/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-13 10:13:11.685378 | controller | WARNING Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/e43bbd/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-13 10:13:11.685910 | controller | WARNING Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/e43bbd/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-13 10:13:11.686393 | controller | WARNING Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/e43bbd/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-13 10:13:11.686877 | controller | WARNING Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/e43bbd/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-13 10:13:11.687350 | controller | WARNING Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/e43bbd/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-13 10:13:11.687821 | controller | WARNING Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/e43bbd/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-13 10:13:11.688307 | controller | WARNING Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/e43bbd/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-13 10:13:11.688783 | controller | WARNING Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/e43bbd/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-13 10:13:11.689265 | controller | WARNING Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/e43bbd/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-13 10:13:11.699614 | controller | INFO Running default > prepare 2025-10-13 10:13:12.366094 | controller | 2025-10-13 10:13:12.366212 | controller | PLAY [Prepare] ***************************************************************** 2025-10-13 10:13:12.366316 | controller | 2025-10-13 10:13:12.366433 | controller | TASK [Gathering Facts] ********************************************************* 2025-10-13 10:13:12.366551 | controller | Monday 13 October 2025 10:13:12 +0000 (0:00:00.010) 0:00:00.010 ******** 2025-10-13 10:13:13.193146 | controller | ok: [instance] 2025-10-13 10:13:13.193212 | controller | 2025-10-13 10:13:13.193329 | controller | TASK [Create temp file] ******************************************************** 2025-10-13 10:13:13.193435 | controller | Monday 13 October 2025 10:13:13 +0000 (0:00:00.827) 0:00:00.837 ******** 2025-10-13 10:13:13.722574 | controller | changed: [instance] 2025-10-13 10:13:13.722620 | controller | 2025-10-13 10:13:13.722739 | controller | PLAY RECAP ********************************************************************* 2025-10-13 10:13:13.722856 | controller | instance : ok=2 changed=1 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 2025-10-13 10:13:13.722952 | controller | 2025-10-13 10:13:13.723048 | controller | Monday 13 October 2025 10:13:13 +0000 (0:00:00.529) 0:00:01.367 ******** 2025-10-13 10:13:13.723164 | controller | =============================================================================== 2025-10-13 10:13:13.723272 | controller | Gathering Facts --------------------------------------------------------- 0.83s 2025-10-13 10:13:13.723359 | controller | Create temp file -------------------------------------------------------- 0.53s 2025-10-13 10:13:13.776725 | controller | INFO Running default > converge 2025-10-13 10:13:14.204704 | controller | 2025-10-13 10:13:14.204954 | controller | PLAY [Converge] **************************************************************** 2025-10-13 10:13:14.205102 | controller | 2025-10-13 10:13:14.205265 | controller | TASK [Gathering Facts] ********************************************************* 2025-10-13 10:13:14.205428 | controller | Monday 13 October 2025 10:13:14 +0000 (0:00:00.036) 0:00:00.036 ******** 2025-10-13 10:13:14.996968 | controller | ok: [instance] 2025-10-13 10:13:15.024352 | controller | 2025-10-13 10:13:15.024382 | controller | TASK [Include deploy_bmh role] ************************************************* 2025-10-13 10:13:15.024390 | controller | Monday 13 October 2025 10:13:14 +0000 (0:00:00.792) 0:00:00.828 ******** 2025-10-13 10:13:15.024418 | controller | 2025-10-13 10:13:15.051918 | controller | TASK [deploy_bmh : Load baremetal hosts information from file] ***************** 2025-10-13 10:13:15.051947 | controller | Monday 13 October 2025 10:13:15 +0000 (0:00:00.027) 0:00:00.856 ******** 2025-10-13 10:13:15.051959 | controller | ok: [instance] 2025-10-13 10:13:15.090083 | controller | 2025-10-13 10:13:15.090112 | controller | TASK [deploy_bmh : Set baremetal hosts facts] ********************************** 2025-10-13 10:13:15.090120 | controller | Monday 13 October 2025 10:13:15 +0000 (0:00:00.027) 0:00:00.883 ******** 2025-10-13 10:13:15.090131 | controller | ok: [instance] 2025-10-13 10:13:15.396267 | controller | 2025-10-13 10:13:15.396297 | controller | TASK [deploy_bmh : Create destination directory] ******************************* 2025-10-13 10:13:15.396305 | controller | Monday 13 October 2025 10:13:15 +0000 (0:00:00.038) 0:00:00.921 ******** 2025-10-13 10:13:15.396315 | controller | changed: [instance] 2025-10-13 10:13:15.456664 | controller | 2025-10-13 10:13:15.456694 | controller | TASK [deploy_bmh : Build and create Secret CRs] ******************************** 2025-10-13 10:13:15.456706 | controller | Monday 13 October 2025 10:13:15 +0000 (0:00:00.306) 0:00:01.228 ******** 2025-10-13 10:13:15.456716 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/deploy_bmh/tasks/create_templated_resource.yml for instance => (item=compute-0) 2025-10-13 10:13:16.073484 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/deploy_bmh/tasks/create_templated_resource.yml for instance => (item=compute-1) 2025-10-13 10:13:16.073515 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/deploy_bmh/tasks/create_templated_resource.yml for instance => (item=controller-0) 2025-10-13 10:13:16.073538 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/deploy_bmh/tasks/create_templated_resource.yml for instance => (item=crc-0) 2025-10-13 10:13:16.073545 | controller | 2025-10-13 10:13:16.073550 | controller | TASK [deploy_bmh : Create the templates CR files] ****************************** 2025-10-13 10:13:16.073556 | controller | Monday 13 October 2025 10:13:15 +0000 (0:00:00.060) 0:00:01.288 ******** 2025-10-13 10:13:16.073566 | controller | changed: [instance] 2025-10-13 10:13:16.104234 | controller | 2025-10-13 10:13:16.104266 | controller | TASK [deploy_bmh : Ensure cifmw_deploy_bmh_namespace namespace exists] ********* 2025-10-13 10:13:16.104273 | controller | Monday 13 October 2025 10:13:16 +0000 (0:00:00.617) 0:00:01.905 ******** 2025-10-13 10:13:16.104283 | controller | skipping: [instance] 2025-10-13 10:13:16.134539 | controller | 2025-10-13 10:13:16.134568 | controller | TASK [deploy_bmh : Apply the generated CRs] ************************************ 2025-10-13 10:13:16.134576 | controller | Monday 13 October 2025 10:13:16 +0000 (0:00:00.030) 0:00:01.936 ******** 2025-10-13 10:13:16.134586 | controller | skipping: [instance] 2025-10-13 10:13:16.513148 | controller | 2025-10-13 10:13:16.513196 | controller | TASK [deploy_bmh : Create the templates CR files] ****************************** 2025-10-13 10:13:16.513205 | controller | Monday 13 October 2025 10:13:16 +0000 (0:00:00.030) 0:00:01.966 ******** 2025-10-13 10:13:16.513215 | controller | changed: [instance] 2025-10-13 10:13:16.542628 | controller | 2025-10-13 10:13:16.542656 | controller | TASK [deploy_bmh : Ensure cifmw_deploy_bmh_namespace namespace exists] ********* 2025-10-13 10:13:16.542664 | controller | Monday 13 October 2025 10:13:16 +0000 (0:00:00.378) 0:00:02.345 ******** 2025-10-13 10:13:16.542674 | controller | skipping: [instance] 2025-10-13 10:13:16.572696 | controller | 2025-10-13 10:13:16.572720 | controller | TASK [deploy_bmh : Apply the generated CRs] ************************************ 2025-10-13 10:13:16.572728 | controller | Monday 13 October 2025 10:13:16 +0000 (0:00:00.029) 0:00:02.374 ******** 2025-10-13 10:13:16.572737 | controller | skipping: [instance] 2025-10-13 10:13:16.942150 | controller | 2025-10-13 10:13:16.942193 | controller | TASK [deploy_bmh : Create the templates CR files] ****************************** 2025-10-13 10:13:16.942201 | controller | Monday 13 October 2025 10:13:16 +0000 (0:00:00.030) 0:00:02.404 ******** 2025-10-13 10:13:16.942211 | controller | changed: [instance] 2025-10-13 10:13:16.970986 | controller | 2025-10-13 10:13:16.971005 | controller | TASK [deploy_bmh : Ensure cifmw_deploy_bmh_namespace namespace exists] ********* 2025-10-13 10:13:16.971011 | controller | Monday 13 October 2025 10:13:16 +0000 (0:00:00.369) 0:00:02.774 ******** 2025-10-13 10:13:16.971020 | controller | skipping: [instance] 2025-10-13 10:13:17.000426 | controller | 2025-10-13 10:13:17.000450 | controller | TASK [deploy_bmh : Apply the generated CRs] ************************************ 2025-10-13 10:13:17.000458 | controller | Monday 13 October 2025 10:13:16 +0000 (0:00:00.029) 0:00:02.803 ******** 2025-10-13 10:13:17.000469 | controller | skipping: [instance] 2025-10-13 10:13:17.376851 | controller | 2025-10-13 10:13:17.376881 | controller | TASK [deploy_bmh : Create the templates CR files] ****************************** 2025-10-13 10:13:17.376889 | controller | Monday 13 October 2025 10:13:16 +0000 (0:00:00.029) 0:00:02.832 ******** 2025-10-13 10:13:17.376898 | controller | changed: [instance] 2025-10-13 10:13:17.407029 | controller | 2025-10-13 10:13:17.407058 | controller | TASK [deploy_bmh : Ensure cifmw_deploy_bmh_namespace namespace exists] ********* 2025-10-13 10:13:17.407066 | controller | Monday 13 October 2025 10:13:17 +0000 (0:00:00.376) 0:00:03.208 ******** 2025-10-13 10:13:17.407079 | controller | skipping: [instance] 2025-10-13 10:13:17.437651 | controller | 2025-10-13 10:13:17.437681 | controller | TASK [deploy_bmh : Apply the generated CRs] ************************************ 2025-10-13 10:13:17.437691 | controller | Monday 13 October 2025 10:13:17 +0000 (0:00:00.030) 0:00:03.238 ******** 2025-10-13 10:13:17.437702 | controller | skipping: [instance] 2025-10-13 10:13:17.485499 | controller | 2025-10-13 10:13:17.485529 | controller | TASK [deploy_bmh : Build and create BMH Netconfig Secrets] ********************* 2025-10-13 10:13:17.485538 | controller | Monday 13 October 2025 10:13:17 +0000 (0:00:00.030) 0:00:03.269 ******** 2025-10-13 10:13:17.485560 | controller | skipping: [instance] => (item=compute-0) 2025-10-13 10:13:17.485579 | controller | skipping: [instance] => (item=compute-1) 2025-10-13 10:13:17.485586 | controller | skipping: [instance] => (item=controller-0) 2025-10-13 10:13:17.485591 | controller | skipping: [instance] => (item=crc-0) 2025-10-13 10:13:17.485596 | controller | skipping: [instance] 2025-10-13 10:13:17.485602 | controller | 2025-10-13 10:13:17.485610 | controller | TASK [deploy_bmh : Build and create BMH CRs] *********************************** 2025-10-13 10:13:17.485676 | controller | Monday 13 October 2025 10:13:17 +0000 (0:00:00.047) 0:00:03.317 ******** 2025-10-13 10:13:17.545514 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/deploy_bmh/tasks/create_templated_resource.yml for instance => (item=compute-0) 2025-10-13 10:13:17.545716 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/deploy_bmh/tasks/create_templated_resource.yml for instance => (item=compute-1) 2025-10-13 10:13:17.545729 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/deploy_bmh/tasks/create_templated_resource.yml for instance => (item=controller-0) 2025-10-13 10:13:17.545736 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/deploy_bmh/tasks/create_templated_resource.yml for instance => (item=crc-0) 2025-10-13 10:13:17.545744 | controller | 2025-10-13 10:13:17.545755 | controller | TASK [deploy_bmh : Create the templates CR files] ****************************** 2025-10-13 10:13:17.921221 | controller | Monday 13 October 2025 10:13:17 +0000 (0:00:00.060) 0:00:03.377 ******** 2025-10-13 10:13:17.921264 | controller | changed: [instance] 2025-10-13 10:13:17.950871 | controller | 2025-10-13 10:13:17.950899 | controller | TASK [deploy_bmh : Ensure cifmw_deploy_bmh_namespace namespace exists] ********* 2025-10-13 10:13:17.950908 | controller | Monday 13 October 2025 10:13:17 +0000 (0:00:00.375) 0:00:03.753 ******** 2025-10-13 10:13:17.950920 | controller | skipping: [instance] 2025-10-13 10:13:17.980349 | controller | 2025-10-13 10:13:17.980370 | controller | TASK [deploy_bmh : Apply the generated CRs] ************************************ 2025-10-13 10:13:17.980377 | controller | Monday 13 October 2025 10:13:17 +0000 (0:00:00.029) 0:00:03.782 ******** 2025-10-13 10:13:17.980386 | controller | skipping: [instance] 2025-10-13 10:13:18.339849 | controller | 2025-10-13 10:13:18.339883 | controller | TASK [deploy_bmh : Create the templates CR files] ****************************** 2025-10-13 10:13:18.339891 | controller | Monday 13 October 2025 10:13:17 +0000 (0:00:00.029) 0:00:03.812 ******** 2025-10-13 10:13:18.339902 | controller | changed: [instance] 2025-10-13 10:13:18.369968 | controller | 2025-10-13 10:13:18.370002 | controller | TASK [deploy_bmh : Ensure cifmw_deploy_bmh_namespace namespace exists] ********* 2025-10-13 10:13:18.370011 | controller | Monday 13 October 2025 10:13:18 +0000 (0:00:00.359) 0:00:04.171 ******** 2025-10-13 10:13:18.370022 | controller | skipping: [instance] 2025-10-13 10:13:18.400099 | controller | 2025-10-13 10:13:18.400127 | controller | TASK [deploy_bmh : Apply the generated CRs] ************************************ 2025-10-13 10:13:18.400135 | controller | Monday 13 October 2025 10:13:18 +0000 (0:00:00.030) 0:00:04.201 ******** 2025-10-13 10:13:18.400145 | controller | skipping: [instance] 2025-10-13 10:13:18.760218 | controller | 2025-10-13 10:13:18.760249 | controller | TASK [deploy_bmh : Create the templates CR files] ****************************** 2025-10-13 10:13:18.760257 | controller | Monday 13 October 2025 10:13:18 +0000 (0:00:00.030) 0:00:04.232 ******** 2025-10-13 10:13:18.760268 | controller | changed: [instance] 2025-10-13 10:13:18.789731 | controller | 2025-10-13 10:13:18.789758 | controller | TASK [deploy_bmh : Ensure cifmw_deploy_bmh_namespace namespace exists] ********* 2025-10-13 10:13:18.789765 | controller | Monday 13 October 2025 10:13:18 +0000 (0:00:00.360) 0:00:04.592 ******** 2025-10-13 10:13:18.789776 | controller | skipping: [instance] 2025-10-13 10:13:18.818472 | controller | 2025-10-13 10:13:18.818499 | controller | TASK [deploy_bmh : Apply the generated CRs] ************************************ 2025-10-13 10:13:18.818508 | controller | Monday 13 October 2025 10:13:18 +0000 (0:00:00.029) 0:00:04.621 ******** 2025-10-13 10:13:18.818517 | controller | skipping: [instance] 2025-10-13 10:13:19.192158 | controller | 2025-10-13 10:13:19.192193 | controller | TASK [deploy_bmh : Create the templates CR files] ****************************** 2025-10-13 10:13:19.192201 | controller | Monday 13 October 2025 10:13:18 +0000 (0:00:00.028) 0:00:04.650 ******** 2025-10-13 10:13:19.192227 | controller | changed: [instance] 2025-10-13 10:13:19.219868 | controller | 2025-10-13 10:13:19.219891 | controller | TASK [deploy_bmh : Ensure cifmw_deploy_bmh_namespace namespace exists] ********* 2025-10-13 10:13:19.219899 | controller | Monday 13 October 2025 10:13:19 +0000 (0:00:00.373) 0:00:05.024 ******** 2025-10-13 10:13:19.219914 | controller | skipping: [instance] 2025-10-13 10:13:19.266022 | controller | 2025-10-13 10:13:19.266072 | controller | TASK [deploy_bmh : Apply the generated CRs] ************************************ 2025-10-13 10:13:19.266080 | controller | Monday 13 October 2025 10:13:19 +0000 (0:00:00.027) 0:00:05.052 ******** 2025-10-13 10:13:19.266092 | controller | skipping: [instance] 2025-10-13 10:13:19.320444 | controller | 2025-10-13 10:13:19.320481 | controller | PLAY RECAP ********************************************************************* 2025-10-13 10:13:19.320490 | controller | instance : ok=20 changed=9 unreachable=0 failed=0 skipped=17 rescued=0 ignored=0 2025-10-13 10:13:19.320496 | controller | 2025-10-13 10:13:19.320502 | controller | Monday 13 October 2025 10:13:19 +0000 (0:00:00.043) 0:00:05.095 ******** 2025-10-13 10:13:19.320507 | controller | =============================================================================== 2025-10-13 10:13:19.320512 | controller | Gathering Facts --------------------------------------------------------- 0.79s 2025-10-13 10:13:19.320518 | controller | deploy_bmh : Create the templates CR files ------------------------------ 0.62s 2025-10-13 10:13:19.320523 | controller | deploy_bmh : Create the templates CR files ------------------------------ 0.38s 2025-10-13 10:13:19.320528 | controller | deploy_bmh : Create the templates CR files ------------------------------ 0.38s 2025-10-13 10:13:19.320534 | controller | deploy_bmh : Create the templates CR files ------------------------------ 0.38s 2025-10-13 10:13:19.320539 | controller | deploy_bmh : Create the templates CR files ------------------------------ 0.37s 2025-10-13 10:13:19.320544 | controller | deploy_bmh : Create the templates CR files ------------------------------ 0.37s 2025-10-13 10:13:19.320549 | controller | deploy_bmh : Create the templates CR files ------------------------------ 0.36s 2025-10-13 10:13:19.320555 | controller | deploy_bmh : Create the templates CR files ------------------------------ 0.36s 2025-10-13 10:13:19.320560 | controller | deploy_bmh : Create destination directory ------------------------------- 0.31s 2025-10-13 10:13:19.320565 | controller | deploy_bmh : Build and create BMH CRs ----------------------------------- 0.06s 2025-10-13 10:13:19.320570 | controller | deploy_bmh : Build and create Secret CRs -------------------------------- 0.06s 2025-10-13 10:13:19.320576 | controller | deploy_bmh : Build and create BMH Netconfig Secrets --------------------- 0.05s 2025-10-13 10:13:19.320581 | controller | deploy_bmh : Apply the generated CRs ------------------------------------ 0.04s 2025-10-13 10:13:19.320587 | controller | deploy_bmh : Set baremetal hosts facts ---------------------------------- 0.04s 2025-10-13 10:13:19.320592 | controller | deploy_bmh : Ensure cifmw_deploy_bmh_namespace namespace exists --------- 0.03s 2025-10-13 10:13:19.320597 | controller | deploy_bmh : Apply the generated CRs ------------------------------------ 0.03s 2025-10-13 10:13:19.320602 | controller | deploy_bmh : Apply the generated CRs ------------------------------------ 0.03s 2025-10-13 10:13:19.320608 | controller | deploy_bmh : Apply the generated CRs ------------------------------------ 0.03s 2025-10-13 10:13:19.320614 | controller | deploy_bmh : Ensure cifmw_deploy_bmh_namespace namespace exists --------- 0.03s 2025-10-13 10:13:19.320624 | controller | INFO Running default > cleanup 2025-10-13 10:13:19.734994 | controller | 2025-10-13 10:13:20.515191 | controller | PLAY [Cleanup] ***************************************************************** 2025-10-13 10:13:20.515222 | controller | 2025-10-13 10:13:20.515248 | controller | TASK [Gathering Facts] ********************************************************* 2025-10-13 10:13:20.515255 | controller | Monday 13 October 2025 10:13:19 +0000 (0:00:00.035) 0:00:00.035 ******** 2025-10-13 10:13:20.515264 | controller | ok: [instance] 2025-10-13 10:13:20.540529 | controller | 2025-10-13 10:13:20.540576 | controller | TASK [Include deploy_bmh role] ************************************************* 2025-10-13 10:13:20.540586 | controller | Monday 13 October 2025 10:13:20 +0000 (0:00:00.780) 0:00:00.816 ******** 2025-10-13 10:13:20.540599 | controller | 2025-10-13 10:13:20.540631 | controller | TASK [deploy_bmh : Get the BM manifests] *************************************** 2025-10-13 10:13:20.540722 | controller | Monday 13 October 2025 10:13:20 +0000 (0:00:00.025) 0:00:00.841 ******** 2025-10-13 10:13:20.829976 | controller | ok: [instance] 2025-10-13 10:13:20.883508 | controller | 2025-10-13 10:13:20.883538 | controller | TASK [deploy_bmh : Removing resources if deployed] ***************************** 2025-10-13 10:13:20.883546 | controller | Monday 13 October 2025 10:13:20 +0000 (0:00:00.288) 0:00:01.130 ******** 2025-10-13 10:13:20.883557 | controller | skipping: [instance] => (item={'path': '/home/zuul/ci-framework-data/artifacts/deploy_bmh/bmh-secret-compute-0.yml', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 174, 'inode': 29397798, 'dev': 64513, 'nlink': 1, 'atime': 1760350396.0263848, 'mtime': 1760350395.7553782, 'ctime': 1760350396.0323849, 'gr_name': 'zuul', 'pw_name': 'zuul', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False}) 2025-10-13 10:13:20.883582 | controller | skipping: [instance] => (item={'path': '/home/zuul/ci-framework-data/artifacts/deploy_bmh/bmh-secret-compute-1.yml', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 174, 'inode': 46170230, 'dev': 64513, 'nlink': 1, 'atime': 1760350396.4793956, 'mtime': 1760350396.3393922, 'ctime': 1760350396.4823956, 'gr_name': 'zuul', 'pw_name': 'zuul', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False}) 2025-10-13 10:13:20.883589 | controller | skipping: [instance] => (item={'path': '/home/zuul/ci-framework-data/artifacts/deploy_bmh/bmh-secret-controller-0.yml', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 177, 'inode': 58746702, 'dev': 64513, 'nlink': 1, 'atime': 1760350396.9084058, 'mtime': 1760350396.7654026, 'ctime': 1760350396.911406, 'gr_name': 'zuul', 'pw_name': 'zuul', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False}) 2025-10-13 10:13:20.883600 | controller | skipping: [instance] => (item={'path': '/home/zuul/ci-framework-data/artifacts/deploy_bmh/bmh-secret-crc-0.yml', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 170, 'inode': 71351064, 'dev': 64513, 'nlink': 1, 'atime': 1760350397.3394163, 'mtime': 1760350397.200413, 'ctime': 1760350397.3424163, 'gr_name': 'zuul', 'pw_name': 'zuul', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False}) 2025-10-13 10:13:20.883606 | controller | skipping: [instance] => (item={'path': '/home/zuul/ci-framework-data/artifacts/deploy_bmh/bmh-compute-0.yml', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 416, 'inode': 83929366, 'dev': 64513, 'nlink': 1, 'atime': 1760350397.8884294, 'mtime': 1760350397.7554262, 'ctime': 1760350397.8914294, 'gr_name': 'zuul', 'pw_name': 'zuul', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False}) 2025-10-13 10:13:20.883611 | controller | skipping: [instance] => (item={'path': '/home/zuul/ci-framework-data/artifacts/deploy_bmh/bmh-compute-1.yml', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 416, 'inode': 96487897, 'dev': 64513, 'nlink': 1, 'atime': 1760350398.3064394, 'mtime': 1760350398.174436, 'ctime': 1760350398.3094394, 'gr_name': 'zuul', 'pw_name': 'zuul', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False}) 2025-10-13 10:13:20.883622 | controller | skipping: [instance] => (item={'path': '/home/zuul/ci-framework-data/artifacts/deploy_bmh/bmh-controller-0.yml', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 425, 'inode': 109074847, 'dev': 64513, 'nlink': 1, 'atime': 1760350398.7274494, 'mtime': 1760350398.5914462, 'ctime': 1760350398.7304494, 'gr_name': 'zuul', 'pw_name': 'zuul', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False}) 2025-10-13 10:13:20.883644 | controller | skipping: [instance] => (item={'path': '/home/zuul/ci-framework-data/artifacts/deploy_bmh/bmh-crc-0.yml', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 404, 'inode': 121653929, 'dev': 64513, 'nlink': 1, 'atime': 1760350399.1574597, 'mtime': 1760350399.0144563, 'ctime': 1760350399.1604598, 'gr_name': 'zuul', 'pw_name': 'zuul', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False}) 2025-10-13 10:13:20.884054 | controller | skipping: [instance] 2025-10-13 10:13:22.360502 | controller | 2025-10-13 10:13:22.360536 | controller | TASK [deploy_bmh : Delete CR files] ******************************************** 2025-10-13 10:13:22.360544 | controller | Monday 13 October 2025 10:13:20 +0000 (0:00:00.052) 0:00:01.183 ******** 2025-10-13 10:13:22.360561 | controller | changed: [instance] => (item={'path': '/home/zuul/ci-framework-data/artifacts/deploy_bmh/bmh-secret-compute-0.yml', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 174, 'inode': 29397798, 'dev': 64513, 'nlink': 1, 'atime': 1760350396.0263848, 'mtime': 1760350395.7553782, 'ctime': 1760350396.0323849, 'gr_name': 'zuul', 'pw_name': 'zuul', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False}) 2025-10-13 10:13:22.362061 | controller | changed: [instance] => (item={'path': '/home/zuul/ci-framework-data/artifacts/deploy_bmh/bmh-secret-compute-1.yml', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 174, 'inode': 46170230, 'dev': 64513, 'nlink': 1, 'atime': 1760350396.4793956, 'mtime': 1760350396.3393922, 'ctime': 1760350396.4823956, 'gr_name': 'zuul', 'pw_name': 'zuul', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False}) 2025-10-13 10:13:22.362078 | controller | changed: [instance] => (item={'path': '/home/zuul/ci-framework-data/artifacts/deploy_bmh/bmh-secret-controller-0.yml', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 177, 'inode': 58746702, 'dev': 64513, 'nlink': 1, 'atime': 1760350396.9084058, 'mtime': 1760350396.7654026, 'ctime': 1760350396.911406, 'gr_name': 'zuul', 'pw_name': 'zuul', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False}) 2025-10-13 10:13:22.362085 | controller | changed: [instance] => (item={'path': '/home/zuul/ci-framework-data/artifacts/deploy_bmh/bmh-secret-crc-0.yml', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 170, 'inode': 71351064, 'dev': 64513, 'nlink': 1, 'atime': 1760350397.3394163, 'mtime': 1760350397.200413, 'ctime': 1760350397.3424163, 'gr_name': 'zuul', 'pw_name': 'zuul', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False}) 2025-10-13 10:13:22.362095 | controller | changed: [instance] => (item={'path': '/home/zuul/ci-framework-data/artifacts/deploy_bmh/bmh-compute-0.yml', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 416, 'inode': 83929366, 'dev': 64513, 'nlink': 1, 'atime': 1760350397.8884294, 'mtime': 1760350397.7554262, 'ctime': 1760350397.8914294, 'gr_name': 'zuul', 'pw_name': 'zuul', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False}) 2025-10-13 10:13:22.362107 | controller | changed: [instance] => (item={'path': '/home/zuul/ci-framework-data/artifacts/deploy_bmh/bmh-compute-1.yml', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 416, 'inode': 96487897, 'dev': 64513, 'nlink': 1, 'atime': 1760350398.3064394, 'mtime': 1760350398.174436, 'ctime': 1760350398.3094394, 'gr_name': 'zuul', 'pw_name': 'zuul', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False}) 2025-10-13 10:13:22.408902 | controller | changed: [instance] => (item={'path': '/home/zuul/ci-framework-data/artifacts/deploy_bmh/bmh-controller-0.yml', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 425, 'inode': 109074847, 'dev': 64513, 'nlink': 1, 'atime': 1760350398.7274494, 'mtime': 1760350398.5914462, 'ctime': 1760350398.7304494, 'gr_name': 'zuul', 'pw_name': 'zuul', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False}) 2025-10-13 10:13:22.408936 | controller | changed: [instance] => (item={'path': '/home/zuul/ci-framework-data/artifacts/deploy_bmh/bmh-crc-0.yml', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 404, 'inode': 121653929, 'dev': 64513, 'nlink': 1, 'atime': 1760350399.1574597, 'mtime': 1760350399.0144563, 'ctime': 1760350399.1604598, 'gr_name': 'zuul', 'pw_name': 'zuul', 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False}) 2025-10-13 10:13:22.408944 | controller | 2025-10-13 10:13:22.408950 | controller | PLAY RECAP ********************************************************************* 2025-10-13 10:13:22.408956 | controller | instance : ok=3 changed=1 unreachable=0 failed=0 skipped=1 rescued=0 ignored=0 2025-10-13 10:13:22.408962 | controller | 2025-10-13 10:13:22.408967 | controller | Monday 13 October 2025 10:13:22 +0000 (0:00:01.477) 0:00:02.661 ******** 2025-10-13 10:13:22.408973 | controller | =============================================================================== 2025-10-13 10:13:22.408978 | controller | deploy_bmh : Delete CR files -------------------------------------------- 1.48s 2025-10-13 10:13:22.408983 | controller | Gathering Facts --------------------------------------------------------- 0.78s 2025-10-13 10:13:22.408989 | controller | deploy_bmh : Get the BM manifests --------------------------------------- 0.29s 2025-10-13 10:13:22.408994 | controller | deploy_bmh : Removing resources if deployed ----------------------------- 0.05s 2025-10-13 10:13:22.409006 | controller | Include deploy_bmh role ------------------------------------------------- 0.03s 2025-10-13 10:13:22.409017 | controller | INFO Writing /tmp/report.html report. 2025-10-13 10:13:22.578658 | controller | changed 2025-10-13 10:13:22.605177 | 2025-10-13 10:13:22.605351 | PLAY RECAP 2025-10-13 10:13:22.605402 | controller | ok: 3 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-13 10:13:22.605426 | 2025-10-13 10:13:22.712933 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main] 2025-10-13 10:13:22.713780 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main] 2025-10-13 10:13:23.288018 | 2025-10-13 10:13:23.288132 | PLAY [Run ci/playbooks/collect-logs.yml] 2025-10-13 10:13:23.311700 | 2025-10-13 10:13:23.311822 | TASK [Filter out host if needed] 2025-10-13 10:13:23.320971 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller 2025-10-13 10:13:23.325714 | 2025-10-13 10:13:23.325797 | TASK [Ensure file is present] 2025-10-13 10:13:23.639479 | controller | ok 2025-10-13 10:13:23.648302 | 2025-10-13 10:13:23.648378 | TASK [Manage molecule report file] 2025-10-13 10:13:24.180318 | controller | changed 2025-10-13 10:13:24.186458 | 2025-10-13 10:13:24.186535 | TASK [Check if we get ci-framework-data basedir] 2025-10-13 10:13:24.368100 | controller | ok 2025-10-13 10:13:24.373268 | 2025-10-13 10:13:24.373329 | TASK [Create ci-framework-data log directory for zuul] 2025-10-13 10:13:24.705320 | controller | changed 2025-10-13 10:13:24.710702 | 2025-10-13 10:13:24.710770 | TASK [Copy ci-framework interesting files] 2025-10-13 10:13:24.917069 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory 2025-10-13 10:13:25.243315 | controller | changed 2025-10-13 10:13:25.248995 | 2025-10-13 10:13:25.249065 | TASK [Get SELinux listing] 2025-10-13 10:13:25.777501 | controller | changed 2025-10-13 10:13:25.783257 | 2025-10-13 10:13:25.783339 | TASK [Generate log index] 2025-10-13 10:13:26.450101 | controller | changed 2025-10-13 10:13:26.454981 | 2025-10-13 10:13:26.455053 | TASK [Get some env related data] 2025-10-13 10:13:26.991493 | controller | /home/zuul/.local/bin/ansible 2025-10-13 10:13:27.998231 | controller | changed 2025-10-13 10:13:28.003884 | 2025-10-13 10:13:28.003966 | TASK [Generate list of logs to collect in home directory] 2025-10-13 10:13:28.297148 | controller | ok: All paths examined 2025-10-13 10:13:28.302422 | 2025-10-13 10:13:28.302488 | LOOP [Copy logs from home directory] 2025-10-13 10:13:28.618737 | controller | changed: 2025-10-13 10:13:28.618863 | controller | { 2025-10-13 10:13:28.618892 | controller | "atime": 1760350353.3580942, 2025-10-13 10:13:28.618937 | controller | "ctime": 1760350370.2701187, 2025-10-13 10:13:28.618961 | controller | "dev": 64513, 2025-10-13 10:13:28.618980 | controller | "gid": 1000, 2025-10-13 10:13:28.619008 | controller | "gr_name": "zuul", 2025-10-13 10:13:28.619025 | controller | "inode": 4488323, 2025-10-13 10:13:28.619042 | controller | "isblk": false, 2025-10-13 10:13:28.619058 | controller | "ischr": false, 2025-10-13 10:13:28.619073 | controller | "isdir": false, 2025-10-13 10:13:28.619088 | controller | "isfifo": false, 2025-10-13 10:13:28.619103 | controller | "isgid": false, 2025-10-13 10:13:28.619119 | controller | "islnk": false, 2025-10-13 10:13:28.619134 | controller | "isreg": true, 2025-10-13 10:13:28.619150 | controller | "issock": false, 2025-10-13 10:13:28.619165 | controller | "isuid": false, 2025-10-13 10:13:28.619180 | controller | "mode": "0644", 2025-10-13 10:13:28.619195 | controller | "mtime": 1760350370.2701187, 2025-10-13 10:13:28.619210 | controller | "nlink": 1, 2025-10-13 10:13:28.619226 | controller | "path": "/home/zuul/ansible.log", 2025-10-13 10:13:28.619244 | controller | "pw_name": "zuul", 2025-10-13 10:13:28.619260 | controller | "rgrp": true, 2025-10-13 10:13:28.619276 | controller | "roth": true, 2025-10-13 10:13:28.619292 | controller | "rusr": true, 2025-10-13 10:13:28.619307 | controller | "size": 6749, 2025-10-13 10:13:28.619323 | controller | "uid": 1000, 2025-10-13 10:13:28.619337 | controller | "wgrp": false, 2025-10-13 10:13:28.619352 | controller | "woth": false, 2025-10-13 10:13:28.619370 | controller | "wusr": true, 2025-10-13 10:13:28.619386 | controller | "xgrp": false, 2025-10-13 10:13:28.619402 | controller | "xoth": false, 2025-10-13 10:13:28.619417 | controller | "xusr": false 2025-10-13 10:13:28.619432 | controller | } 2025-10-13 10:13:28.633851 | 2025-10-13 10:13:28.634981 | TASK [Copy crio stats log file] 2025-10-13 10:13:28.650216 | controller | skipping: Conditional result was False 2025-10-13 10:13:28.658579 | 2025-10-13 10:13:28.658680 | TASK [Get SELinux related data] 2025-10-13 10:13:28.878661 | controller | 2025-10-13 10:13:29.197789 | controller | ERROR 2025-10-13 10:13:29.197900 | controller | { 2025-10-13 10:13:29.197954 | controller | "delta": "0:00:00.008688", 2025-10-13 10:13:29.197983 | controller | "end": "2025-10-13 10:13:28.879230", 2025-10-13 10:13:29.198003 | controller | "msg": "non-zero return code", 2025-10-13 10:13:29.198019 | controller | "rc": 1, 2025-10-13 10:13:29.198035 | controller | "start": "2025-10-13 10:13:28.870542" 2025-10-13 10:13:29.198050 | controller | } 2025-10-13 10:13:29.198073 | controller | ERROR: Ignoring Errors 2025-10-13 10:13:29.203295 | 2025-10-13 10:13:29.203360 | TASK [Create system configuration directory] 2025-10-13 10:13:29.395394 | controller | changed 2025-10-13 10:13:29.401365 | 2025-10-13 10:13:29.401447 | TASK [Get some of the system configurations] 2025-10-13 10:13:29.931208 | controller | changed 2025-10-13 10:13:29.936493 | 2025-10-13 10:13:29.936560 | TASK [Copy generated documentation if available] 2025-10-13 10:13:29.950953 | controller | skipping: Conditional result was False 2025-10-13 10:13:29.960202 | 2025-10-13 10:13:29.960290 | TASK [Copy generated AsciiDoc documentation if available] 2025-10-13 10:13:29.983116 | controller | skipping: Conditional result was False 2025-10-13 10:13:29.989068 | 2025-10-13 10:13:29.989139 | TASK [Compress logs bigger than 2MB] 2025-10-13 10:13:30.513731 | controller | changed 2025-10-13 10:13:30.519788 | 2025-10-13 10:13:30.519879 | TASK [Copy files from workspace on node] 2025-10-13 10:13:30.537962 | controller | ok 2025-10-13 10:13:30.564631 | 2025-10-13 10:13:30.564728 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-13 10:13:30.588777 | controller | skipping: Conditional result was False 2025-10-13 10:13:30.595664 | 2025-10-13 10:13:30.595746 | TASK [fetch-output : Set log path for single node] 2025-10-13 10:13:30.627255 | controller | ok 2025-10-13 10:13:30.632165 | 2025-10-13 10:13:30.632232 | LOOP [fetch-output : Ensure local output dirs] 2025-10-13 10:13:30.852803 | controller -> localhost | ok: "/var/lib/zuul/builds/0073926b47414081ad902a855609181a/work/logs" 2025-10-13 10:13:30.853062 | controller -> localhost | changed: All items complete 2025-10-13 10:13:30.853100 | 2025-10-13 10:13:31.067626 | controller -> localhost | changed: "/var/lib/zuul/builds/0073926b47414081ad902a855609181a/work/artifacts" 2025-10-13 10:13:31.253856 | controller -> localhost | changed: "/var/lib/zuul/builds/0073926b47414081ad902a855609181a/work/docs" 2025-10-13 10:13:31.270742 | 2025-10-13 10:13:31.270838 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-13 10:13:31.896701 | controller | changed: 2025-10-13 10:13:31.896888 | controller | .d..t...... ./ 2025-10-13 10:13:31.896938 | controller | >f+++++++++ README.html 2025-10-13 10:13:31.896964 | controller | >f+++++++++ ansible-execution.log 2025-10-13 10:13:31.896986 | controller | >f+++++++++ ansible.log 2025-10-13 10:13:31.897011 | controller | >f+++++++++ dmesg.log 2025-10-13 10:13:31.897036 | controller | >f+++++++++ installed-pkgs.log 2025-10-13 10:13:31.897058 | controller | >f+++++++++ python.log 2025-10-13 10:13:31.897078 | controller | >f+++++++++ registries.conf 2025-10-13 10:13:31.897101 | controller | >f+++++++++ report.html 2025-10-13 10:13:31.897122 | controller | >f+++++++++ selinux-denials.log 2025-10-13 10:13:31.897141 | controller | >f+++++++++ selinux-listing.log 2025-10-13 10:13:31.897158 | controller | cd+++++++++ ci-framework-data/ 2025-10-13 10:13:31.897175 | controller | cd+++++++++ ci-framework-data/artifacts/ 2025-10-13 10:13:31.897193 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml 2025-10-13 10:13:31.897210 | controller | cd+++++++++ ci-framework-data/artifacts/deploy_bmh/ 2025-10-13 10:13:31.897227 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/ 2025-10-13 10:13:31.897244 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml 2025-10-13 10:13:31.897260 | controller | cd+++++++++ ci-framework-data/logs/ 2025-10-13 10:13:31.897278 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log 2025-10-13 10:13:31.897295 | controller | cd+++++++++ registries.conf.d/ 2025-10-13 10:13:31.897324 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf 2025-10-13 10:13:31.897342 | controller | cd+++++++++ system-config/ 2025-10-13 10:13:31.897360 | controller | cd+++++++++ system-config/libvirt/ 2025-10-13 10:13:31.897377 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf 2025-10-13 10:13:31.897394 | controller | >f+++++++++ system-config/libvirt/libvirt.conf 2025-10-13 10:13:32.372848 | controller | changed: .d..t...... ./ 2025-10-13 10:13:32.738313 | controller | changed: .d..t...... ./ 2025-10-13 10:13:32.758708 | 2025-10-13 10:13:32.758813 | TASK [Return artifact to Zuul] 2025-10-13 10:13:32.788055 | controller | ok 2025-10-13 10:13:32.807077 | 2025-10-13 10:13:32.807151 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host] 2025-10-13 10:13:32.807251 | 2025-10-13 10:13:32.807277 | PLAY RECAP 2025-10-13 10:13:32.807325 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1 2025-10-13 10:13:32.807346 | 2025-10-13 10:13:32.899447 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main] 2025-10-13 10:13:32.900225 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 10:13:33.460048 | 2025-10-13 10:13:33.460174 | PLAY [all] 2025-10-13 10:13:33.479715 | 2025-10-13 10:13:33.479823 | TASK [include_role : fetch-output] 2025-10-13 10:13:33.518896 | controller | ok 2025-10-13 10:13:33.541002 | 2025-10-13 10:13:33.541107 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-13 10:13:33.585211 | controller | skipping: Conditional result was False 2025-10-13 10:13:33.590809 | 2025-10-13 10:13:33.590885 | TASK [fetch-output : Set log path for single node] 2025-10-13 10:13:33.619057 | controller | ok 2025-10-13 10:13:33.624181 | 2025-10-13 10:13:33.624258 | LOOP [fetch-output : Ensure local output dirs] 2025-10-13 10:13:33.985227 | controller -> localhost | ok: "/var/lib/zuul/builds/0073926b47414081ad902a855609181a/work/logs" 2025-10-13 10:13:34.186128 | controller -> localhost | ok: "/var/lib/zuul/builds/0073926b47414081ad902a855609181a/work/artifacts" 2025-10-13 10:13:34.412262 | controller -> localhost | ok: "/var/lib/zuul/builds/0073926b47414081ad902a855609181a/work/docs" 2025-10-13 10:13:34.427411 | 2025-10-13 10:13:34.427498 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-13 10:13:34.947111 | controller | ok 2025-10-13 10:13:34.947303 | controller | ok: All items complete 2025-10-13 10:13:34.947334 | 2025-10-13 10:13:35.315768 | controller | ok 2025-10-13 10:13:35.718065 | controller | ok 2025-10-13 10:13:35.741753 | 2025-10-13 10:13:35.741850 | TASK [include_role : fetch-output-openshift] 2025-10-13 10:13:35.766381 | controller | skipping: Conditional result was False 2025-10-13 10:13:35.774058 | 2025-10-13 10:13:35.774137 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-13 10:13:36.137441 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006569 2025-10-13 10:13:36.339155 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006759 2025-10-13 10:13:36.369492 | 2025-10-13 10:13:36.369833 | PLAY [all] 2025-10-13 10:13:36.385177 | 2025-10-13 10:13:36.385302 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-13 10:13:36.770111 | controller | changed 2025-10-13 10:13:36.792174 | 2025-10-13 10:13:36.792245 | PLAY RECAP 2025-10-13 10:13:36.792289 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-13 10:13:36.792312 | 2025-10-13 10:13:36.868668 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-13 10:13:36.869474 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-13 10:13:37.430167 | 2025-10-13 10:13:37.430277 | PLAY [localhost] 2025-10-13 10:13:37.448152 | 2025-10-13 10:13:37.448249 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-13 10:13:37.791097 | localhost | changed 2025-10-13 10:13:37.795721 | 2025-10-13 10:13:37.795805 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-13 10:13:37.817563 | localhost | ok 2025-10-13 10:13:37.825781 | 2025-10-13 10:13:37.825865 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-13 10:13:38.139748 | localhost | changed 2025-10-13 10:13:38.145362 | 2025-10-13 10:13:38.145439 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-13 10:13:38.789360 | localhost | changed 2025-10-13 10:13:38.794695 | 2025-10-13 10:13:38.794767 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-13 10:13:39.190876 | localhost | Identity added: /var/lib/zuul/builds/0073926b47414081ad902a855609181a/work/tmp/ansible.pd_tih07 (/var/lib/zuul/builds/0073926b47414081ad902a855609181a/work/tmp/ansible.pd_tih07) 2025-10-13 10:13:39.191063 | localhost | ok: Runtime: 0:00:00.030711 2025-10-13 10:13:39.195415 | 2025-10-13 10:13:39.195482 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-13 10:13:39.437946 | localhost | ok: Runtime: 0:00:00.004483 2025-10-13 10:13:39.442583 | 2025-10-13 10:13:39.442678 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-13 10:13:39.491455 | localhost | changed 2025-10-13 10:13:39.495686 | 2025-10-13 10:13:39.495759 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-13 10:13:39.849813 | localhost | changed 2025-10-13 10:13:39.869522 | 2025-10-13 10:13:39.869641 | PLAY [localhost] 2025-10-13 10:13:39.881903 | 2025-10-13 10:13:39.882313 | TASK [Generate bulk log download script] 2025-10-13 10:13:39.910902 | localhost | ok 2025-10-13 10:13:39.927268 | 2025-10-13 10:13:39.927370 | TASK [local-log-download : Check API endpoint is defined] 2025-10-13 10:13:39.954886 | localhost | ok: All assertions passed 2025-10-13 10:13:39.959334 | 2025-10-13 10:13:39.959400 | TASK [local-log-download : Create download script] 2025-10-13 10:13:40.360362 | localhost -> localhost | changed 2025-10-13 10:13:40.370066 | 2025-10-13 10:13:40.370153 | TASK [Register quick-download link] 2025-10-13 10:13:40.387941 | localhost | ok 2025-10-13 10:13:40.425634 | 2025-10-13 10:13:40.425717 | PLAY [logserver.rdoproject.org] 2025-10-13 10:13:40.435478 | 2025-10-13 10:13:40.435544 | TASK [Set zuul-log-path fact] 2025-10-13 10:13:40.452143 | logserver.rdoproject.org | ok 2025-10-13 10:13:40.462364 | 2025-10-13 10:13:40.462454 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-13 10:13:40.489195 | logserver.rdoproject.org | ok 2025-10-13 10:13:40.495402 | 2025-10-13 10:13:40.495486 | TASK [upload-logs : Create log directories] 2025-10-13 10:13:42.286179 | logserver.rdoproject.org | changed 2025-10-13 10:13:42.289475 | 2025-10-13 10:13:42.289570 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-13 10:13:42.532142 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004376 2025-10-13 10:13:42.536902 | 2025-10-13 10:13:42.536985 | TASK [upload-logs : Upload logs to log server] 2025-10-13 10:13:44.126429 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-13 10:13:44.129658 | 2025-10-13 10:13:44.129726 | LOOP [upload-logs : Compress console log and json output] 2025-10-13 10:13:44.179713 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 10:13:44.180734 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 10:13:44.187505 | 2025-10-13 10:13:44.187624 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-13 10:13:44.222616 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 10:13:44.222946 | 2025-10-13 10:13:44.227513 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-13 10:13:44.236648 | 2025-10-13 10:13:44.236765 | LOOP [upload-logs : Upload console log and json output]