2025-09-30 05:05:56.957996 | Job console starting... 2025-09-30 05:05:57.198091 | Updating repositories 2025-09-30 05:05:57.969165 | Preparing job workspace 2025-09-30 05:06:06.673811 | Running Ansible setup... 2025-09-30 05:06:10.915703 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-09-30 05:06:11.822398 | 2025-09-30 05:06:11.822506 | PLAY [localhost] 2025-09-30 05:06:11.831603 | 2025-09-30 05:06:11.831684 | TASK [Gathering Facts] 2025-09-30 05:06:13.158228 | localhost | ok 2025-09-30 05:06:13.183707 | 2025-09-30 05:06:13.183835 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-09-30 05:06:13.664346 | localhost -> localhost | changed 2025-09-30 05:06:13.669940 | 2025-09-30 05:06:13.670027 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-09-30 05:06:14.615221 | localhost -> localhost | changed 2025-09-30 05:06:14.623416 | 2025-09-30 05:06:14.623489 | TASK [Setup log path fact] 2025-09-30 05:06:14.655552 | localhost | ok 2025-09-30 05:06:14.678599 | 2025-09-30 05:06:14.678692 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-30 05:06:14.706264 | localhost | ok 2025-09-30 05:06:14.715815 | 2025-09-30 05:06:14.715982 | TASK [emit-job-header : Print job information] 2025-09-30 05:06:14.801110 | # Job Information 2025-09-30 05:06:14.801239 | Ansible Version: 2.15.12 2025-09-30 05:06:14.801283 | Job: cifmw-molecule-adoption_osp_deploy 2025-09-30 05:06:14.801309 | Pipeline: github-check 2025-09-30 05:06:14.801331 | Executor: ibm-bm4-ze.softwarefactory-project.io 2025-09-30 05:06:14.801352 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3333 2025-09-30 05:06:14.801373 | Log URL (when completed): https://logserver.rdoproject.org/8cf/rdoproject.org/8cfd2b4bc50f44aa8f625093a3a93c64/ 2025-09-30 05:06:14.801393 | Event ID: 3089cae0-9dba-11f0-9d66-59f03df1d747 2025-09-30 05:06:14.805355 | 2025-09-30 05:06:14.805423 | LOOP [emit-job-header : Print node information] 2025-09-30 05:06:14.954984 | localhost | ok: 2025-09-30 05:06:14.955166 | localhost | # Node Information 2025-09-30 05:06:14.955200 | localhost | Inventory Hostname: controller 2025-09-30 05:06:14.955230 | localhost | Hostname: np0005461649 2025-09-30 05:06:14.955253 | localhost | Username: zuul 2025-09-30 05:06:14.955288 | localhost | Distro: CentOS 9 2025-09-30 05:06:14.955405 | localhost | Provider: ibm-bm4-nodepool 2025-09-30 05:06:14.955437 | localhost | Region: regionOne 2025-09-30 05:06:14.955459 | localhost | Label: cloud-centos-9-stream-tripleo-ibm 2025-09-30 05:06:14.955478 | localhost | Product Name: OpenStack Compute 2025-09-30 05:06:14.955495 | localhost | Interface IP: 192.168.26.62 2025-09-30 05:06:15.011552 | 2025-09-30 05:06:15.011661 | PLAY [all] 2025-09-30 05:06:15.025573 | 2025-09-30 05:06:15.025645 | TASK [Gather network facts] 2025-09-30 05:06:15.440239 | controller | ok 2025-09-30 05:06:15.467449 | 2025-09-30 05:06:15.467528 | TASK [include_role : start-zuul-console] 2025-09-30 05:06:15.508531 | controller | ok 2025-09-30 05:06:15.527493 | 2025-09-30 05:06:15.527574 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-09-30 05:06:15.862511 | controller | ok 2025-09-30 05:06:15.875486 | 2025-09-30 05:06:15.875568 | TASK [include_role : add-build-sshkey] 2025-09-30 05:06:15.893149 | controller | ok 2025-09-30 05:06:15.914151 | 2025-09-30 05:06:15.914458 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-09-30 05:06:16.305305 | controller -> localhost | ok 2025-09-30 05:06:16.314585 | 2025-09-30 05:06:16.314656 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-09-30 05:06:16.363649 | controller | ok 2025-09-30 05:06:16.381808 | controller | included: /var/lib/zuul/builds/8cfd2b4bc50f44aa8f625093a3a93c64/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-09-30 05:06:16.387746 | 2025-09-30 05:06:16.387817 | TASK [add-build-sshkey : Create Temp SSH key] 2025-09-30 05:06:16.875304 | controller -> localhost | Generating public/private rsa key pair. 2025-09-30 05:06:16.875500 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/8cfd2b4bc50f44aa8f625093a3a93c64/work/8cfd2b4bc50f44aa8f625093a3a93c64_id_rsa. 2025-09-30 05:06:16.875539 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/8cfd2b4bc50f44aa8f625093a3a93c64/work/8cfd2b4bc50f44aa8f625093a3a93c64_id_rsa.pub. 2025-09-30 05:06:16.875565 | controller -> localhost | The key fingerprint is: 2025-09-30 05:06:16.875591 | controller -> localhost | SHA256:L5OT1Y/LMKm0nERrRCArqjmrpLaahDYVeOLg0Mzsc/w zuul-build-sshkey 2025-09-30 05:06:16.875614 | controller -> localhost | The key's randomart image is: 2025-09-30 05:06:16.875634 | controller -> localhost | +---[RSA 3072]----+ 2025-09-30 05:06:16.875654 | controller -> localhost | | . . | 2025-09-30 05:06:16.875674 | controller -> localhost | | =. o . | 2025-09-30 05:06:16.875713 | controller -> localhost | |oo*o. . | 2025-09-30 05:06:16.875737 | controller -> localhost | |=ooo. . . | 2025-09-30 05:06:16.875757 | controller -> localhost | |.oo.o S . . | 2025-09-30 05:06:16.875775 | controller -> localhost | |o..o . o * . o | 2025-09-30 05:06:16.875793 | controller -> localhost | |== E @ = . . | 2025-09-30 05:06:16.875813 | controller -> localhost | |==. = B + . | 2025-09-30 05:06:16.875831 | controller -> localhost | |X.. = o | 2025-09-30 05:06:16.875850 | controller -> localhost | +----[SHA256]-----+ 2025-09-30 05:06:16.875925 | controller -> localhost | ok: Runtime: 0:00:00.066215 2025-09-30 05:06:16.882069 | 2025-09-30 05:06:16.882137 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-09-30 05:06:16.915106 | controller | ok 2025-09-30 05:06:16.934157 | controller | included: /var/lib/zuul/builds/8cfd2b4bc50f44aa8f625093a3a93c64/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-09-30 05:06:16.957442 | 2025-09-30 05:06:16.957520 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-09-30 05:06:17.007718 | controller | skipping: Conditional result was False 2025-09-30 05:06:17.018504 | 2025-09-30 05:06:17.018578 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-09-30 05:06:17.431898 | controller | changed 2025-09-30 05:06:17.436867 | 2025-09-30 05:06:17.436956 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-09-30 05:06:17.669364 | controller | ok 2025-09-30 05:06:17.674391 | 2025-09-30 05:06:17.674478 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-09-30 05:06:18.301680 | controller | changed 2025-09-30 05:06:18.309254 | 2025-09-30 05:06:18.309364 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-09-30 05:06:18.989245 | controller | changed 2025-09-30 05:06:18.999868 | 2025-09-30 05:06:18.999953 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-09-30 05:06:19.043242 | controller | skipping: Conditional result was False 2025-09-30 05:06:19.049362 | 2025-09-30 05:06:19.049438 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-09-30 05:06:19.570547 | controller -> localhost | changed 2025-09-30 05:06:19.581155 | 2025-09-30 05:06:19.581239 | TASK [add-build-sshkey : Add back temp key] 2025-09-30 05:06:20.208240 | controller -> localhost | Identity added: /var/lib/zuul/builds/8cfd2b4bc50f44aa8f625093a3a93c64/work/8cfd2b4bc50f44aa8f625093a3a93c64_id_rsa (zuul-build-sshkey) 2025-09-30 05:06:20.208429 | controller -> localhost | ok: Runtime: 0:00:00.093665 2025-09-30 05:06:20.214885 | 2025-09-30 05:06:20.214988 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-09-30 05:06:20.596524 | controller | ok 2025-09-30 05:06:20.603373 | 2025-09-30 05:06:20.603482 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-09-30 05:06:20.678436 | controller | skipping: Conditional result was False 2025-09-30 05:06:20.688074 | 2025-09-30 05:06:20.688155 | TASK [include_role : validate-host] 2025-09-30 05:06:20.734821 | controller | ok 2025-09-30 05:06:20.756133 | 2025-09-30 05:06:20.756223 | TASK [validate-host : Define zuul_info_dir fact] 2025-09-30 05:06:20.810116 | controller | ok 2025-09-30 05:06:20.817165 | 2025-09-30 05:06:20.817258 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-09-30 05:06:21.325674 | controller -> localhost | ok 2025-09-30 05:06:21.330838 | 2025-09-30 05:06:21.331282 | TASK [validate-host : Collect information about the host] 2025-09-30 05:06:21.955038 | controller | ok 2025-09-30 05:06:21.968096 | 2025-09-30 05:06:21.968172 | TASK [validate-host : Sanitize hostname] 2025-09-30 05:06:22.083244 | controller | ok 2025-09-30 05:06:22.090368 | 2025-09-30 05:06:22.090454 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-09-30 05:06:22.622232 | controller -> localhost | changed 2025-09-30 05:06:22.630329 | 2025-09-30 05:06:22.630430 | TASK [validate-host : Collect information about zuul worker] 2025-09-30 05:06:22.987113 | controller | ok 2025-09-30 05:06:22.991825 | 2025-09-30 05:06:22.991894 | TASK [validate-host : Write out all zuul information for each host] 2025-09-30 05:06:23.421493 | controller -> localhost | changed 2025-09-30 05:06:23.430967 | 2025-09-30 05:06:23.431034 | TASK [include_role : prepare-workspace-openshift] 2025-09-30 05:06:23.469068 | controller | skipping: Conditional result was False 2025-09-30 05:06:23.475103 | 2025-09-30 05:06:23.475173 | TASK [include_role : remove-zuul-sshkey] 2025-09-30 05:06:23.498820 | controller | skipping: Conditional result was False 2025-09-30 05:06:23.504509 | 2025-09-30 05:06:23.504582 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-09-30 05:06:23.714834 | controller | ok: "logs" 2025-09-30 05:06:23.715044 | controller | ok: All items complete 2025-09-30 05:06:23.715074 | 2025-09-30 05:06:23.879745 | controller | ok: "artifacts" 2025-09-30 05:06:24.052805 | controller | ok: "docs" 2025-09-30 05:06:24.060242 | 2025-09-30 05:06:24.060367 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-09-30 05:06:24.269477 | controller | changed: "logs" 2025-09-30 05:06:24.440293 | controller | changed: "artifacts" 2025-09-30 05:06:24.620693 | controller | changed: "docs" 2025-09-30 05:06:24.654826 | 2025-09-30 05:06:24.655014 | PLAY RECAP 2025-09-30 05:06:24.655070 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-09-30 05:06:24.655101 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-09-30 05:06:24.655121 | 2025-09-30 05:06:24.838309 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-09-30 05:06:24.839063 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master] 2025-09-30 05:06:25.712667 | 2025-09-30 05:06:25.712809 | PLAY [all] 2025-09-30 05:06:25.770159 | 2025-09-30 05:06:25.770289 | TASK [mirror-info-fork : Set mirror_fqdn if not defined] 2025-09-30 05:06:25.931042 | controller | ok 2025-09-30 05:06:25.938063 | 2025-09-30 05:06:25.938165 | TASK [mirror-info-fork : Create /etc/ci] 2025-09-30 05:06:26.421284 | controller | changed 2025-09-30 05:06:26.431103 | 2025-09-30 05:06:26.431197 | TASK [mirror-info-fork : Install ci_mirror script] 2025-09-30 05:06:27.531755 | controller | changed 2025-09-30 05:06:27.556116 | 2025-09-30 05:06:27.556222 | LOOP [add-authorized-keys : Enable access via build key on all nodes] 2025-09-30 05:06:28.059723 | controller | changed: 2025-09-30 05:06:28.059891 | controller | { 2025-09-30 05:06:28.059962 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com" 2025-09-30 05:06:28.059996 | controller | } 2025-09-30 05:06:28.293112 | controller | changed: 2025-09-30 05:06:28.293203 | controller | { 2025-09-30 05:06:28.293236 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com" 2025-09-30 05:06:28.293261 | controller | } 2025-09-30 05:06:28.506844 | controller | changed: 2025-09-30 05:06:28.512247 | controller | { 2025-09-30 05:06:28.512323 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com" 2025-09-30 05:06:28.512353 | controller | } 2025-09-30 05:06:28.708665 | controller | changed: 2025-09-30 05:06:28.708760 | controller | { 2025-09-30 05:06:28.708801 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com" 2025-09-30 05:06:28.708823 | controller | } 2025-09-30 05:06:28.915040 | controller | changed: 2025-09-30 05:06:28.915129 | controller | { 2025-09-30 05:06:28.915158 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com" 2025-09-30 05:06:28.915179 | controller | } 2025-09-30 05:06:29.139175 | controller | changed: 2025-09-30 05:06:29.139262 | controller | { 2025-09-30 05:06:29.139306 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com" 2025-09-30 05:06:29.139330 | controller | } 2025-09-30 05:06:29.349041 | controller | changed: 2025-09-30 05:06:29.349133 | controller | { 2025-09-30 05:06:29.349164 | 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-09-30 05:06:29.349188 | controller | } 2025-09-30 05:06:29.564664 | controller | changed: 2025-09-30 05:06:29.564746 | controller | { 2025-09-30 05:06:29.564775 | 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-09-30 05:06:29.564799 | controller | } 2025-09-30 05:06:29.790427 | controller | changed: 2025-09-30 05:06:29.790513 | controller | { 2025-09-30 05:06:29.790542 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner" 2025-09-30 05:06:29.790564 | controller | } 2025-09-30 05:06:30.020355 | controller | changed: 2025-09-30 05:06:30.020533 | controller | { 2025-09-30 05:06:30.020580 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com" 2025-09-30 05:06:30.020605 | controller | } 2025-09-30 05:06:30.285300 | controller | changed: 2025-09-30 05:06:30.285402 | controller | { 2025-09-30 05:06:30.285432 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com" 2025-09-30 05:06:30.285452 | controller | } 2025-09-30 05:06:30.450168 | controller | changed: 2025-09-30 05:06:30.450254 | controller | { 2025-09-30 05:06:30.450295 | controller | "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com" 2025-09-30 05:06:30.450319 | controller | } 2025-09-30 05:06:30.675485 | controller | changed: 2025-09-30 05:06:30.675563 | controller | { 2025-09-30 05:06:30.675591 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith" 2025-09-30 05:06:30.675613 | controller | } 2025-09-30 05:06:30.898523 | controller | changed: 2025-09-30 05:06:30.898699 | controller | { 2025-09-30 05:06:30.898735 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel" 2025-09-30 05:06:30.898760 | controller | } 2025-09-30 05:06:31.127801 | controller | changed: 2025-09-30 05:06:31.127886 | controller | { 2025-09-30 05:06:31.127941 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux" 2025-09-30 05:06:31.127968 | controller | } 2025-09-30 05:06:31.351063 | controller | changed: 2025-09-30 05:06:31.351137 | controller | { 2025-09-30 05:06:31.351167 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr" 2025-09-30 05:06:31.351190 | controller | } 2025-09-30 05:06:31.584719 | controller | changed: 2025-09-30 05:06:31.584799 | controller | { 2025-09-30 05:06:31.584829 | 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-09-30 05:06:31.584852 | controller | } 2025-09-30 05:06:31.816596 | controller | changed: 2025-09-30 05:06:31.817076 | controller | { 2025-09-30 05:06:31.817126 | 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-09-30 05:06:31.817161 | controller | } 2025-09-30 05:06:32.068519 | controller | changed: 2025-09-30 05:06:32.068598 | controller | { 2025-09-30 05:06:32.068626 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9" 2025-09-30 05:06:32.068649 | controller | } 2025-09-30 05:06:32.320813 | controller | changed: 2025-09-30 05:06:32.320897 | controller | { 2025-09-30 05:06:32.320962 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora" 2025-09-30 05:06:32.320988 | controller | } 2025-09-30 05:06:32.573593 | controller | changed: 2025-09-30 05:06:32.573676 | controller | { 2025-09-30 05:06:32.573704 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac" 2025-09-30 05:06:32.573727 | controller | } 2025-09-30 05:06:32.788748 | controller | changed: 2025-09-30 05:06:32.788830 | controller | { 2025-09-30 05:06:32.788861 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop" 2025-09-30 05:06:32.788883 | controller | } 2025-09-30 05:06:32.999150 | controller | changed: 2025-09-30 05:06:32.999240 | controller | { 2025-09-30 05:06:32.999268 | 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-09-30 05:06:32.999308 | controller | } 2025-09-30 05:06:33.205543 | controller | changed: 2025-09-30 05:06:33.205624 | controller | { 2025-09-30 05:06:33.205651 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com" 2025-09-30 05:06:33.205671 | controller | } 2025-09-30 05:06:33.412177 | controller | changed: 2025-09-30 05:06:33.412260 | controller | { 2025-09-30 05:06:33.412310 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com" 2025-09-30 05:06:33.412333 | controller | } 2025-09-30 05:06:33.629228 | controller | changed: 2025-09-30 05:06:33.629335 | controller | { 2025-09-30 05:06:33.629364 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono" 2025-09-30 05:06:33.629385 | controller | } 2025-09-30 05:06:33.668253 | 2025-09-30 05:06:33.668364 | TASK [Set timezone to UTC] 2025-09-30 05:06:34.171040 | controller | changed: executed `/bin/timedatectl set-timezone UTC` 2025-09-30 05:06:34.177889 | 2025-09-30 05:06:34.178099 | TASK [Create nodepool directory] 2025-09-30 05:06:34.385606 | controller | changed 2025-09-30 05:06:34.391252 | 2025-09-30 05:06:34.391348 | TASK [Create nodepool sub_nodes file] 2025-09-30 05:06:34.993070 | controller | changed 2025-09-30 05:06:34.998720 | 2025-09-30 05:06:34.998814 | TASK [Create nodepool sub_nodes_private file] 2025-09-30 05:06:35.575368 | controller | changed 2025-09-30 05:06:35.580789 | 2025-09-30 05:06:35.580872 | LOOP [Populate nodepool sub_nodes file] 2025-09-30 05:06:35.624576 | 2025-09-30 05:06:35.624762 | LOOP [Populate nodepool sub_nodes_private file] 2025-09-30 05:06:35.666590 | 2025-09-30 05:06:35.666756 | TASK [Create nodepool primary file] 2025-09-30 05:06:35.694566 | controller | skipping: Conditional result was False 2025-09-30 05:06:35.700113 | 2025-09-30 05:06:35.700189 | TASK [Create nodepool node_private for this node] 2025-09-30 05:06:36.337316 | controller | changed 2025-09-30 05:06:36.345166 | 2025-09-30 05:06:36.345234 | LOOP [Copy ssh keys to nodepool directory] 2025-09-30 05:06:36.797376 | controller | ok: Item: id_rsa Runtime: 0:00:00.005404 2025-09-30 05:06:36.797557 | 2025-09-30 05:06:36.975169 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.004373 2025-09-30 05:06:36.989325 | 2025-09-30 05:06:36.989414 | TASK [Add sudoers role for zuul-sudo-grep.sh] 2025-09-30 05:06:37.570124 | controller | changed 2025-09-30 05:06:37.575167 | 2025-09-30 05:06:37.575240 | TASK [Validate sudoers config after edits] 2025-09-30 05:06:37.878657 | controller | /etc/sudoers: parsed OK 2025-09-30 05:06:37.878764 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK 2025-09-30 05:06:37.878776 | controller | /etc/sudoers.d/zuul: parsed OK 2025-09-30 05:06:37.878785 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK 2025-09-30 05:06:38.131388 | controller | ok: Runtime: 0:00:00.004962 2025-09-30 05:06:38.136950 | 2025-09-30 05:06:38.137028 | TASK [Show the environment passed in to job shell scripts] 2025-09-30 05:06:38.364525 | controller | SHELL=/bin/bash 2025-09-30 05:06:38.364584 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework 2025-09-30 05:06:38.364595 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework 2025-09-30 05:06:38.364602 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/46/3346/eb5b53fb17db92a72d33d052a56c8edd0d10ea78^openstack-k8s-operators/ci-framework:main:refs/changes/33/3333/b461fc761ffaeed72eedc04b84a1fb92d251fe5d 2025-09-30 05:06:38.364652 | controller | PWD=/home/zuul 2025-09-30 05:06:38.364675 | controller | ZUUL_PIPELINE=github-check 2025-09-30 05:06:38.364681 | controller | LOGNAME=zuul 2025-09-30 05:06:38.364686 | controller | XDG_SESSION_TYPE=tty 2025-09-30 05:06:38.364692 | controller | _=/usr/bin/env 2025-09-30 05:06:38.364697 | controller | MOTD_SHOWN=pam 2025-09-30 05:06:38.364703 | controller | HOME=/home/zuul 2025-09-30 05:06:38.364708 | controller | LANG=en_US.UTF-8 2025-09-30 05:06:38.364713 | controller | SSH_CONNECTION=192.168.26.12 40414 192.168.26.62 22 2025-09-30 05:06:38.364719 | 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-09-30 05:06:38.364725 | controller | ZUUL_CHANGE_IDS=3346,eb5b53fb17db92a72d33d052a56c8edd0d10ea78 3333,b461fc761ffaeed72eedc04b84a1fb92d251fe5d 2025-09-30 05:06:38.364730 | controller | WORKSPACE=/home/zuul/workspace 2025-09-30 05:06:38.364736 | controller | XDG_SESSION_CLASS=user 2025-09-30 05:06:38.364741 | controller | SELINUX_ROLE_REQUESTED= 2025-09-30 05:06:38.364747 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s 2025-09-30 05:06:38.364752 | controller | USER=zuul 2025-09-30 05:06:38.364757 | controller | ZUUL_VOTING=True 2025-09-30 05:06:38.364763 | controller | BUILD_TIMEOUT=1800000 2025-09-30 05:06:38.364768 | controller | SELINUX_USE_CURRENT_RANGE= 2025-09-30 05:06:38.364773 | controller | SHLVL=1 2025-09-30 05:06:38.364779 | controller | ZUUL_PATCHSET=b461fc761ffaeed72eedc04b84a1fb92d251fe5d 2025-09-30 05:06:38.364784 | controller | XDG_SESSION_ID=1 2025-09-30 05:06:38.364789 | controller | ZUUL_BRANCH=main 2025-09-30 05:06:38.364795 | controller | XDG_RUNTIME_DIR=/run/user/1000 2025-09-30 05:06:38.364800 | controller | SSH_CLIENT=192.168.26.12 40414 22 2025-09-30 05:06:38.364806 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/ 2025-09-30 05:06:38.364811 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima: 2025-09-30 05:06:38.364817 | controller | which_declare=declare -f 2025-09-30 05:06:38.364823 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin 2025-09-30 05:06:38.364829 | controller | SELINUX_LEVEL_REQUESTED= 2025-09-30 05:06:38.364834 | controller | ZUUL_CHANGE=3333 2025-09-30 05:06:38.364839 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus 2025-09-30 05:06:38.364845 | controller | ZUUL_UUID=8cfd2b4bc50f44aa8f625093a3a93c64 2025-09-30 05:06:38.364850 | controller | BASH_FUNC_which%%=() { ( alias; 2025-09-30 05:06:38.364856 | controller | eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@ 2025-09-30 05:06:38.364861 | controller | } 2025-09-30 05:06:38.671121 | controller | ok: Runtime: 0:00:00.005426 2025-09-30 05:06:38.676745 | 2025-09-30 05:06:38.676811 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars] 2025-09-30 05:06:38.690740 | controller | skipping: Conditional result was False 2025-09-30 05:06:38.696938 | 2025-09-30 05:06:38.697016 | TASK [Symlink /home/zuul-worker/workspace] 2025-09-30 05:06:39.224321 | controller | skipping: Conditional result was False 2025-09-30 05:06:39.229967 | 2025-09-30 05:06:39.230040 | TASK [Ensure legacy workspace directory] 2025-09-30 05:06:39.421241 | controller | changed 2025-09-30 05:06:39.461513 | 2025-09-30 05:06:39.461600 | PLAY RECAP 2025-09-30 05:06:39.461647 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-09-30 05:06:39.461671 | 2025-09-30 05:06:39.606309 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master] 2025-09-30 05:06:39.607082 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/read_global_vars.yml@main] 2025-09-30 05:06:40.677545 | 2025-09-30 05:06:40.677646 | PLAY [Load global variables] 2025-09-30 05:06:40.705449 | 2025-09-30 05:06:40.707117 | TASK [Read group_vars all file] 2025-09-30 05:06:40.752229 | controller | ok 2025-09-30 05:06:40.772570 | 2025-09-30 05:06:40.772675 | TASK [cifmw_helpers : Check if file is available] 2025-09-30 05:06:41.070330 | controller | ok 2025-09-30 05:06:41.078429 | 2025-09-30 05:06:41.078511 | TASK [cifmw_helpers : Read vars] 2025-09-30 05:06:41.099194 | 2025-09-30 05:06:41.099358 | LOOP [cifmw_helpers : Set vars as fact] 2025-09-30 05:06:41.177077 | 2025-09-30 05:06:41.177196 | PLAY RECAP 2025-09-30 05:06:41.177239 | controller | ok: 1 changed: 0 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-09-30 05:06:41.177262 | 2025-09-30 05:06:41.262933 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/read_global_vars.yml@main] 2025-09-30 05:06:41.263703 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main] 2025-09-30 05:06:41.869243 | 2025-09-30 05:06:41.869359 | PLAY [Run ci/playbooks/dump_zuul_data.yml] 2025-09-30 05:06:41.900527 | 2025-09-30 05:06:41.900629 | TASK [Create zuul-output directory] 2025-09-30 05:06:42.257661 | controller | changed 2025-09-30 05:06:42.262819 | 2025-09-30 05:06:42.262895 | TASK [Slurp Zuul inventory test] 2025-09-30 05:06:42.553444 | controller -> localhost | ok 2025-09-30 05:06:42.561118 | 2025-09-30 05:06:42.561211 | TASK [Save zuul inventory] 2025-09-30 05:06:43.311445 | controller | changed 2025-09-30 05:06:43.318711 | 2025-09-30 05:06:43.318811 | TASK [Save zuul vars without the change_message] 2025-09-30 05:06:43.924200 | controller | changed 2025-09-30 05:06:43.948268 | 2025-09-30 05:06:43.948355 | PLAY RECAP 2025-09-30 05:06:43.948401 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-09-30 05:06:43.948425 | 2025-09-30 05:06:44.029310 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main] 2025-09-30 05:06:44.030153 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main] 2025-09-30 05:06:44.626347 | 2025-09-30 05:06:44.626448 | PLAY [Run ci/playbooks/molecule-prepare.yml] 2025-09-30 05:06:44.647066 | 2025-09-30 05:06:44.647141 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh] 2025-09-30 05:06:44.665488 | controller | ok 2025-09-30 05:06:44.682793 | 2025-09-30 05:06:44.682874 | TASK [mirror-info-fork : Set mirror_fqdn if not defined] 2025-09-30 05:06:44.706605 | controller | skipping: Conditional result was False 2025-09-30 05:06:44.712175 | 2025-09-30 05:06:44.712242 | TASK [mirror-info-fork : Create /etc/ci] 2025-09-30 05:06:45.076504 | controller | ok 2025-09-30 05:06:45.082800 | 2025-09-30 05:06:45.082886 | TASK [mirror-info-fork : Install ci_mirror script] 2025-09-30 05:06:45.725542 | controller | ok 2025-09-30 05:06:45.736518 | 2025-09-30 05:06:45.736613 | TASK [Prepare workspace] 2025-09-30 05:06:45.754812 | controller | ok 2025-09-30 05:06:45.782732 | 2025-09-30 05:06:45.782844 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-09-30 05:06:46.095976 | controller | ok 2025-09-30 05:06:46.102548 | 2025-09-30 05:06:46.102618 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-09-30 05:06:48.236065 | controller | Output suppressed because no_log was given 2025-09-30 05:06:48.246340 | 2025-09-30 05:06:48.246426 | LOOP [Create zuul-output directory] 2025-09-30 05:06:48.434735 | controller | changed: "/home/zuul/ci-framework-data/logs" 2025-09-30 05:06:48.603215 | controller | ok: "/home/zuul/zuul-output/logs" 2025-09-30 05:06:48.610486 | 2025-09-30 05:06:48.610809 | TASK [Install required packages] 2025-09-30 05:07:42.031295 | controller | changed 2025-09-30 05:07:42.038786 | 2025-09-30 05:07:42.038860 | TASK [Install venv] 2025-09-30 05:08:46.072193 | controller | changed 2025-09-30 05:08:46.099670 | 2025-09-30 05:08:46.099763 | PLAY RECAP 2025-09-30 05:08:46.099810 | controller | ok: 7 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-09-30 05:08:46.099834 | 2025-09-30 05:08:46.191989 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main] 2025-09-30 05:08:46.192813 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main] 2025-09-30 05:08:46.736058 | 2025-09-30 05:08:46.736171 | PLAY [Run ci/playbooks/molecule-test.yml] 2025-09-30 05:08:46.756576 | 2025-09-30 05:08:46.756680 | TASK [Gather required facts] 2025-09-30 05:08:47.287100 | controller | ok 2025-09-30 05:08:47.292397 | 2025-09-30 05:08:47.292475 | TASK [Load environment var if instructed to] 2025-09-30 05:08:47.316814 | controller | skipping: Conditional result was False 2025-09-30 05:08:47.322567 | 2025-09-30 05:08:47.322645 | TASK [Run molecule] 2025-09-30 05:08:48.281027 | controller | INFO Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml 2025-09-30 05:08:48.353737 | controller | WARNING Driver podman does not provide a schema. 2025-09-30 05:08:48.356603 | controller | INFO Performing prerun with role_name_check=0... 2025-09-30 05:09:04.937967 | controller | WARNING Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/82d78a/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections). 2025-09-30 05:09:04.938413 | controller | WARNING Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/82d78a/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-09-30 05:09:04.938894 | controller | WARNING Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/82d78a/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections). 2025-09-30 05:09:04.939378 | controller | WARNING Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/82d78a/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections). 2025-09-30 05:09:04.939846 | controller | WARNING Another version of 'cifmw.general' 1.0.0+e2f9c552 was found installed in /home/zuul/.cache/ansible-compat/82d78a/collections/ansible_collections, only the first one will be used, 1.0.0+e2f9c552 (/home/zuul/.ansible/collections/ansible_collections). 2025-09-30 05:09:04.940320 | controller | WARNING Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/82d78a/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections). 2025-09-30 05:09:04.940758 | controller | WARNING Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/82d78a/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections). 2025-09-30 05:09:04.941239 | controller | WARNING Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/82d78a/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections). 2025-09-30 05:09:04.941681 | controller | WARNING Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/82d78a/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-09-30 05:09:04.942204 | controller | WARNING Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/82d78a/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-09-30 05:09:04.942654 | controller | WARNING Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/82d78a/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections). 2025-09-30 05:09:04.943137 | controller | WARNING Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/82d78a/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-09-30 05:09:04.943573 | controller | WARNING Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/82d78a/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-09-30 05:09:04.944021 | controller | WARNING Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/82d78a/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-09-30 05:09:04.944485 | controller | WARNING Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/82d78a/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections). 2025-09-30 05:09:04.954678 | controller | INFO Running default > destroy 2025-09-30 05:09:05.185628 | controller | INFO Sanity checks: 'podman' 2025-09-30 05:09:06.072067 | controller | 2025-09-30 05:09:06.072193 | controller | PLAY [Destroy] ***************************************************************** 2025-09-30 05:09:06.072298 | controller | 2025-09-30 05:09:06.072409 | controller | TASK [Get passwd entries for USER env] ***************************************** 2025-09-30 05:09:06.072523 | controller | Tuesday 30 September 2025 05:09:06 +0000 (0:00:00.014) 0:00:00.014 ***** 2025-09-30 05:09:06.360352 | controller | ok: [localhost] 2025-09-30 05:09:06.360415 | controller | 2025-09-30 05:09:06.360532 | controller | TASK [Get shell async_dir] ***************************************************** 2025-09-30 05:09:06.360640 | controller | Tuesday 30 September 2025 05:09:06 +0000 (0:00:00.289) 0:00:00.303 ***** 2025-09-30 05:09:06.402980 | controller | ok: [localhost] 2025-09-30 05:09:06.403048 | controller | 2025-09-30 05:09:06.403224 | controller | TASK [Set async_dir for HOME env] ********************************************** 2025-09-30 05:09:06.403351 | controller | Tuesday 30 September 2025 05:09:06 +0000 (0:00:00.042) 0:00:00.346 ***** 2025-09-30 05:09:06.436969 | controller | skipping: [localhost] 2025-09-30 05:09:06.437095 | controller | 2025-09-30 05:09:06.437261 | controller | TASK [Destroy molecule instance(s)] ******************************************** 2025-09-30 05:09:06.437390 | controller | Tuesday 30 September 2025 05:09:06 +0000 (0:00:00.033) 0:00:00.380 ***** 2025-09-30 05:09:06.829798 | controller | changed: [localhost] => (item={'command': '/sbin/init', 'dockerfile': 'containerfile', 'image': 'registry.access.redhat.com/ubi9/ubi-init', 'name': 'instance', 'pre_build_image': True}) 2025-09-30 05:09:06.829856 | controller | 2025-09-30 05:09:06.830003 | controller | TASK [Wait for instance(s) deletion to complete] ******************************* 2025-09-30 05:09:06.830133 | controller | Tuesday 30 September 2025 05:09:06 +0000 (0:00:00.391) 0:00:00.771 ***** 2025-09-30 05:09:12.317008 | controller | FAILED - RETRYING: [localhost]: Wait for instance(s) deletion to complete (300 retries left). 2025-09-30 05:09:12.317157 | controller | changed: [localhost] => (item={'failed': 0, 'started': 1, 'finished': 0, 'ansible_job_id': 'j746164660870.26122', 'results_file': '/home/zuul/.ansible_async/j746164660870.26122', 'changed': True, 'item': {'command': '/sbin/init', 'dockerfile': 'containerfile', 'image': 'registry.access.redhat.com/ubi9/ubi-init', 'name': 'instance', 'pre_build_image': True}, 'ansible_loop_var': 'item'}) 2025-09-30 05:09:12.317258 | controller | 2025-09-30 05:09:12.317369 | controller | TASK [Delete podman network dedicated to this scenario] ************************ 2025-09-30 05:09:12.317482 | controller | Tuesday 30 September 2025 05:09:12 +0000 (0:00:05.488) 0:00:06.260 ***** 2025-09-30 05:09:12.369719 | controller | skipping: [localhost] => (item=instance: None specified) 2025-09-30 05:09:12.369825 | controller | skipping: [localhost] 2025-09-30 05:09:12.369968 | controller | 2025-09-30 05:09:12.370074 | controller | PLAY RECAP ********************************************************************* 2025-09-30 05:09:12.370222 | controller | localhost : ok=4 changed=2 unreachable=0 failed=0 skipped=2 rescued=0 ignored=0 2025-09-30 05:09:12.370317 | controller | 2025-09-30 05:09:12.370423 | controller | Tuesday 30 September 2025 05:09:12 +0000 (0:00:00.053) 0:00:06.313 ***** 2025-09-30 05:09:12.370519 | controller | =============================================================================== 2025-09-30 05:09:12.370620 | controller | Wait for instance(s) deletion to complete ------------------------------- 5.49s 2025-09-30 05:09:12.370719 | controller | Destroy molecule instance(s) -------------------------------------------- 0.39s 2025-09-30 05:09:12.370816 | controller | Get passwd entries for USER env ----------------------------------------- 0.29s 2025-09-30 05:09:12.370916 | controller | Delete podman network dedicated to this scenario ------------------------ 0.05s 2025-09-30 05:09:12.371036 | controller | Get shell async_dir ----------------------------------------------------- 0.04s 2025-09-30 05:09:12.371152 | controller | Set async_dir for HOME env ---------------------------------------------- 0.03s 2025-09-30 05:09:12.431179 | controller | INFO Running default > create 2025-09-30 05:09:12.889688 | controller | 2025-09-30 05:09:12.889784 | controller | PLAY [Create] ****************************************************************** 2025-09-30 05:09:12.889893 | controller | 2025-09-30 05:09:12.890031 | controller | TASK [Get podman executable path] ********************************************** 2025-09-30 05:09:12.890153 | controller | Tuesday 30 September 2025 05:09:12 +0000 (0:00:00.015) 0:00:00.015 ***** 2025-09-30 05:09:13.192548 | controller | ok: [localhost] 2025-09-30 05:09:13.192600 | controller | 2025-09-30 05:09:13.192716 | controller | TASK [Register podman executable path] ***************************************** 2025-09-30 05:09:13.192820 | controller | Tuesday 30 September 2025 05:09:13 +0000 (0:00:00.303) 0:00:00.319 ***** 2025-09-30 05:09:13.232468 | controller | ok: [localhost] 2025-09-30 05:09:13.232533 | controller | 2025-09-30 05:09:13.232642 | controller | TASK [Get passwd entries for USER env] ***************************************** 2025-09-30 05:09:13.232749 | controller | Tuesday 30 September 2025 05:09:13 +0000 (0:00:00.040) 0:00:00.359 ***** 2025-09-30 05:09:13.524093 | controller | ok: [localhost] 2025-09-30 05:09:13.524161 | controller | 2025-09-30 05:09:13.524258 | controller | TASK [Get shell async_dir] ***************************************************** 2025-09-30 05:09:13.524363 | controller | Tuesday 30 September 2025 05:09:13 +0000 (0:00:00.291) 0:00:00.650 ***** 2025-09-30 05:09:13.566184 | controller | ok: [localhost] 2025-09-30 05:09:13.566264 | controller | 2025-09-30 05:09:13.566393 | controller | TASK [Set async_dir for HOME env] ********************************************** 2025-09-30 05:09:13.566524 | controller | Tuesday 30 September 2025 05:09:13 +0000 (0:00:00.042) 0:00:00.692 ***** 2025-09-30 05:09:13.600990 | controller | skipping: [localhost] 2025-09-30 05:09:13.601079 | controller | 2025-09-30 05:09:13.601205 | controller | TASK [Log into a container registry] ******************************************* 2025-09-30 05:09:13.601320 | controller | Tuesday 30 September 2025 05:09:13 +0000 (0:00:00.034) 0:00:00.727 ***** 2025-09-30 05:09:13.646653 | controller | skipping: [localhost] => (item="instance registry username: None specified") 2025-09-30 05:09:13.646709 | controller | skipping: [localhost] 2025-09-30 05:09:13.646814 | controller | 2025-09-30 05:09:13.646915 | controller | TASK [Check presence of custom Dockerfiles] ************************************ 2025-09-30 05:09:13.647038 | controller | Tuesday 30 September 2025 05:09:13 +0000 (0:00:00.045) 0:00:00.773 ***** 2025-09-30 05:09:13.967781 | controller | ok: [localhost] => (item=Dockerfile: containerfile) 2025-09-30 05:09:13.967829 | controller | 2025-09-30 05:09:13.967962 | controller | TASK [Create Dockerfiles from image names] ************************************* 2025-09-30 05:09:13.968065 | controller | Tuesday 30 September 2025 05:09:13 +0000 (0:00:00.320) 0:00:01.094 ***** 2025-09-30 05:09:14.010324 | controller | skipping: [localhost] => (item="Dockerfile: containerfile; Image: registry.access.redhat.com/ubi9/ubi-init") 2025-09-30 05:09:14.010444 | controller | skipping: [localhost] 2025-09-30 05:09:14.010573 | controller | 2025-09-30 05:09:14.010705 | controller | TASK [Discover local Podman images] ******************************************** 2025-09-30 05:09:14.010837 | controller | Tuesday 30 September 2025 05:09:14 +0000 (0:00:00.042) 0:00:01.136 ***** 2025-09-30 05:09:14.361536 | controller | ok: [localhost] => (item=instance) 2025-09-30 05:09:14.361603 | controller | 2025-09-30 05:09:14.361717 | controller | TASK [Build an Ansible compatible image] *************************************** 2025-09-30 05:09:14.361818 | controller | Tuesday 30 September 2025 05:09:14 +0000 (0:00:00.351) 0:00:01.488 ***** 2025-09-30 05:09:14.405540 | controller | skipping: [localhost] => (item=registry.access.redhat.com/ubi9/ubi-init) 2025-09-30 05:09:14.405640 | controller | skipping: [localhost] 2025-09-30 05:09:14.405757 | controller | 2025-09-30 05:09:14.405863 | controller | TASK [Determine the CMD directives] ******************************************** 2025-09-30 05:09:14.405984 | controller | Tuesday 30 September 2025 05:09:14 +0000 (0:00:00.043) 0:00:01.532 ***** 2025-09-30 05:09:14.457099 | controller | ok: [localhost] => (item="instance command: /sbin/init") 2025-09-30 05:09:14.457213 | controller | 2025-09-30 05:09:14.457341 | controller | TASK [Remove possible pre-existing containers] ********************************* 2025-09-30 05:09:14.457465 | controller | Tuesday 30 September 2025 05:09:14 +0000 (0:00:00.051) 0:00:01.583 ***** 2025-09-30 05:09:14.705591 | controller | changed: [localhost] 2025-09-30 05:09:14.705921 | controller | 2025-09-30 05:09:14.751517 | controller | TASK [Discover local podman networks] ****************************************** 2025-09-30 05:09:14.751538 | controller | Tuesday 30 September 2025 05:09:14 +0000 (0:00:00.248) 0:00:01.832 ***** 2025-09-30 05:09:14.751549 | controller | skipping: [localhost] => (item=instance: None specified) 2025-09-30 05:09:14.788617 | controller | skipping: [localhost] 2025-09-30 05:09:14.788642 | controller | 2025-09-30 05:09:14.788650 | controller | TASK [Create podman network dedicated to this scenario] ************************ 2025-09-30 05:09:14.788656 | controller | Tuesday 30 September 2025 05:09:14 +0000 (0:00:00.045) 0:00:01.877 ***** 2025-09-30 05:09:14.788666 | controller | skipping: [localhost] 2025-09-30 05:09:15.115541 | controller | 2025-09-30 05:09:15.115570 | controller | TASK [Create molecule instance(s)] ********************************************* 2025-09-30 05:09:15.115578 | controller | Tuesday 30 September 2025 05:09:14 +0000 (0:00:00.037) 0:00:01.914 ***** 2025-09-30 05:09:15.115588 | controller | changed: [localhost] => (item=instance) 2025-09-30 05:09:20.587237 | controller | 2025-09-30 05:09:20.587270 | controller | TASK [Wait for instance(s) creation to complete] ******************************* 2025-09-30 05:09:20.587280 | controller | Tuesday 30 September 2025 05:09:15 +0000 (0:00:00.325) 0:00:02.239 ***** 2025-09-30 05:09:20.587292 | controller | FAILED - RETRYING: [localhost]: Wait for instance(s) creation to complete (300 retries left). 2025-09-30 05:09:20.587321 | controller | changed: [localhost] => (item=instance) 2025-09-30 05:09:20.587330 | controller | 2025-09-30 05:09:20.587337 | controller | PLAY RECAP ********************************************************************* 2025-09-30 05:09:20.587343 | controller | localhost : ok=10 changed=3 unreachable=0 failed=0 skipped=6 rescued=0 ignored=0 2025-09-30 05:09:20.587351 | controller | 2025-09-30 05:09:20.587357 | controller | Tuesday 30 September 2025 05:09:20 +0000 (0:00:05.473) 0:00:07.713 ***** 2025-09-30 05:09:20.587364 | controller | =============================================================================== 2025-09-30 05:09:20.587371 | controller | Wait for instance(s) creation to complete ------------------------------- 5.47s 2025-09-30 05:09:20.587380 | controller | Discover local Podman images -------------------------------------------- 0.35s 2025-09-30 05:09:20.587406 | controller | Create molecule instance(s) --------------------------------------------- 0.33s 2025-09-30 05:09:20.588621 | controller | Check presence of custom Dockerfiles ------------------------------------ 0.32s 2025-09-30 05:09:20.642017 | controller | Get podman executable path ---------------------------------------------- 0.30s 2025-09-30 05:09:20.642049 | controller | Get passwd entries for USER env ----------------------------------------- 0.29s 2025-09-30 05:09:20.642056 | controller | Remove possible pre-existing containers --------------------------------- 0.25s 2025-09-30 05:09:20.642062 | controller | Determine the CMD directives -------------------------------------------- 0.05s 2025-09-30 05:09:20.642067 | controller | Discover local podman networks ------------------------------------------ 0.05s 2025-09-30 05:09:20.642073 | controller | Log into a container registry ------------------------------------------- 0.05s 2025-09-30 05:09:20.642079 | controller | Build an Ansible compatible image --------------------------------------- 0.04s 2025-09-30 05:09:20.642084 | controller | Create Dockerfiles from image names ------------------------------------- 0.04s 2025-09-30 05:09:20.642090 | controller | Get shell async_dir ----------------------------------------------------- 0.04s 2025-09-30 05:09:20.642101 | controller | Register podman executable path ----------------------------------------- 0.04s 2025-09-30 05:09:20.642106 | controller | Create podman network dedicated to this scenario ------------------------ 0.04s 2025-09-30 05:09:20.642112 | controller | Set async_dir for HOME env ---------------------------------------------- 0.03s 2025-09-30 05:09:20.642140 | controller | INFO Running default > prepare 2025-09-30 05:09:20.642596 | controller | WARNING Skipping, prepare playbook not configured. 2025-09-30 05:09:20.650311 | controller | INFO Running default > converge 2025-09-30 05:09:21.090201 | controller | 2025-09-30 05:09:21.121493 | controller | PLAY [Converge] **************************************************************** 2025-09-30 05:09:21.121522 | controller | 2025-09-30 05:09:21.121530 | controller | TASK [Gather stack nodes and facts] ******************************************** 2025-09-30 05:09:21.121537 | controller | Tuesday 30 September 2025 05:09:21 +0000 (0:00:00.019) 0:00:00.019 ***** 2025-09-30 05:09:21.121550 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/adoption_osp_deploy/tasks/gather_stack_nodes.yml for instance => (item={'stackname': 'overcloud', 'network_data_file': 'network_data.yaml.j2', 'vips_data_file': 'vips_data_overcloud.yaml', 'stack_nodes': ['osp-controllers']}) 2025-09-30 05:09:21.155305 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/adoption_osp_deploy/tasks/gather_stack_nodes.yml for instance => (item={'stackname': 'cell1', 'network_data_file': 'network_data.yaml.j2', 'vips_data_file': 'vips_data_cell1.yaml', 'stack_nodes': ['cell1-osp-computes', 'cell1-osp-controllers']}) 2025-09-30 05:09:21.155334 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/adoption_osp_deploy/tasks/gather_stack_nodes.yml for instance => (item={'stackname': 'cell2', 'network_data_file': 'network_data.yaml.j2', 'vips_data_file': 'vips_data_cell2.yaml', 'stack_nodes': ['cell2-osp-computes', 'cell2-osp-controllers']}) 2025-09-30 05:09:21.155343 | controller | 2025-09-30 05:09:21.155349 | controller | TASK [Get main facts for the overcloud stack] ********************************** 2025-09-30 05:09:21.155355 | controller | Tuesday 30 September 2025 05:09:21 +0000 (0:00:00.031) 0:00:00.051 ***** 2025-09-30 05:09:21.155365 | controller | ok: [instance] 2025-09-30 05:09:21.239726 | controller | 2025-09-30 05:09:21.239754 | controller | TASK [Gather other facts for stack overcloud"] ********************************* 2025-09-30 05:09:21.239762 | controller | Tuesday 30 September 2025 05:09:21 +0000 (0:00:00.034) 0:00:00.085 ***** 2025-09-30 05:09:21.239772 | controller | ok: [instance] 2025-09-30 05:09:21.299852 | controller | 2025-09-30 05:09:21.299882 | controller | TASK [Gather nodes for stack overcloud] **************************************** 2025-09-30 05:09:21.299890 | controller | Tuesday 30 September 2025 05:09:21 +0000 (0:00:00.084) 0:00:00.169 ***** 2025-09-30 05:09:21.299900 | controller | skipping: [instance] => (item=cell1-osp-computes) 2025-09-30 05:09:21.329006 | controller | skipping: [instance] => (item=cell1-osp-controllers) 2025-09-30 05:09:21.329033 | controller | skipping: [instance] => (item=cell2-osp-computes) 2025-09-30 05:09:21.329041 | controller | skipping: [instance] => (item=cell2-osp-controllers) 2025-09-30 05:09:21.329047 | controller | skipping: [instance] => (item=controllers) 2025-09-30 05:09:21.329053 | controller | skipping: [instance] => (item=ocps) 2025-09-30 05:09:21.329058 | controller | ok: [instance] => (item=osp-controllers) 2025-09-30 05:09:21.329064 | controller | skipping: [instance] => (item=osp-underclouds) 2025-09-30 05:09:21.329069 | controller | 2025-09-30 05:09:21.329075 | controller | TASK [Get main facts for the overcloud stack] ********************************** 2025-09-30 05:09:21.329081 | controller | Tuesday 30 September 2025 05:09:21 +0000 (0:00:00.059) 0:00:00.229 ***** 2025-09-30 05:09:21.329091 | controller | ok: [instance] 2025-09-30 05:09:21.397176 | controller | 2025-09-30 05:09:21.397204 | controller | TASK [Gather other facts for stack cell1"] ************************************* 2025-09-30 05:09:21.397213 | controller | Tuesday 30 September 2025 05:09:21 +0000 (0:00:00.029) 0:00:00.259 ***** 2025-09-30 05:09:21.397223 | controller | ok: [instance] 2025-09-30 05:09:21.397250 | controller | 2025-09-30 05:09:21.397466 | controller | TASK [Gather nodes for stack cell1] ******************************************** 2025-09-30 05:09:21.463214 | controller | Tuesday 30 September 2025 05:09:21 +0000 (0:00:00.068) 0:00:00.327 ***** 2025-09-30 05:09:21.463252 | controller | ok: [instance] => (item=cell1-osp-computes) 2025-09-30 05:09:21.463282 | controller | ok: [instance] => (item=cell1-osp-controllers) 2025-09-30 05:09:21.463292 | controller | skipping: [instance] => (item=cell2-osp-computes) 2025-09-30 05:09:21.464036 | controller | skipping: [instance] => (item=cell2-osp-controllers) 2025-09-30 05:09:21.493855 | controller | skipping: [instance] => (item=controllers) 2025-09-30 05:09:21.493885 | controller | skipping: [instance] => (item=ocps) 2025-09-30 05:09:21.493893 | controller | skipping: [instance] => (item=osp-controllers) 2025-09-30 05:09:21.493898 | controller | skipping: [instance] => (item=osp-underclouds) 2025-09-30 05:09:21.493904 | controller | 2025-09-30 05:09:21.493910 | controller | TASK [Get main facts for the overcloud stack] ********************************** 2025-09-30 05:09:21.493916 | controller | Tuesday 30 September 2025 05:09:21 +0000 (0:00:00.065) 0:00:00.393 ***** 2025-09-30 05:09:21.493925 | controller | ok: [instance] 2025-09-30 05:09:21.562729 | controller | 2025-09-30 05:09:21.562758 | controller | TASK [Gather other facts for stack cell2"] ************************************* 2025-09-30 05:09:21.562765 | controller | Tuesday 30 September 2025 05:09:21 +0000 (0:00:00.030) 0:00:00.423 ***** 2025-09-30 05:09:21.562775 | controller | ok: [instance] 2025-09-30 05:09:21.628855 | controller | 2025-09-30 05:09:21.628884 | controller | TASK [Gather nodes for stack cell2] ******************************************** 2025-09-30 05:09:21.628892 | controller | Tuesday 30 September 2025 05:09:21 +0000 (0:00:00.068) 0:00:00.492 ***** 2025-09-30 05:09:21.628902 | controller | skipping: [instance] => (item=cell1-osp-computes) 2025-09-30 05:09:21.659206 | controller | skipping: [instance] => (item=cell1-osp-controllers) 2025-09-30 05:09:21.659235 | controller | ok: [instance] => (item=cell2-osp-computes) 2025-09-30 05:09:21.659243 | controller | ok: [instance] => (item=cell2-osp-controllers) 2025-09-30 05:09:21.659249 | controller | skipping: [instance] => (item=controllers) 2025-09-30 05:09:21.659254 | controller | skipping: [instance] => (item=ocps) 2025-09-30 05:09:21.659260 | controller | skipping: [instance] => (item=osp-controllers) 2025-09-30 05:09:21.659265 | controller | skipping: [instance] => (item=osp-underclouds) 2025-09-30 05:09:21.659271 | controller | 2025-09-30 05:09:21.659276 | controller | TASK [Store result for verification as persistent fact] ************************ 2025-09-30 05:09:21.659282 | controller | Tuesday 30 September 2025 05:09:21 +0000 (0:00:00.065) 0:00:00.557 ***** 2025-09-30 05:09:21.659293 | controller | ok: [instance] 2025-09-30 05:09:21.659315 | controller | 2025-09-30 05:09:21.659322 | controller | PLAY RECAP ********************************************************************* 2025-09-30 05:09:21.659327 | controller | instance : ok=13 changed=0 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 2025-09-30 05:09:21.659333 | controller | 2025-09-30 05:09:21.659339 | controller | Tuesday 30 September 2025 05:09:21 +0000 (0:00:00.030) 0:00:00.588 ***** 2025-09-30 05:09:21.659344 | controller | =============================================================================== 2025-09-30 05:09:21.659350 | controller | Gather other facts for stack overcloud" --------------------------------- 0.08s 2025-09-30 05:09:21.659355 | controller | Gather other facts for stack cell2" ------------------------------------- 0.07s 2025-09-30 05:09:21.659366 | controller | Gather other facts for stack cell1" ------------------------------------- 0.07s 2025-09-30 05:09:21.659372 | controller | Gather nodes for stack cell1 -------------------------------------------- 0.07s 2025-09-30 05:09:21.659377 | controller | Gather nodes for stack cell2 -------------------------------------------- 0.07s 2025-09-30 05:09:21.659383 | controller | Gather nodes for stack overcloud ---------------------------------------- 0.06s 2025-09-30 05:09:21.659388 | controller | Get main facts for the overcloud stack ---------------------------------- 0.03s 2025-09-30 05:09:21.659395 | controller | Gather stack nodes and facts -------------------------------------------- 0.03s 2025-09-30 05:09:21.659416 | controller | Store result for verification as persistent fact ------------------------ 0.03s 2025-09-30 05:09:21.659600 | controller | Get main facts for the overcloud stack ---------------------------------- 0.03s 2025-09-30 05:09:21.711521 | controller | Get main facts for the overcloud stack ---------------------------------- 0.03s 2025-09-30 05:09:21.711556 | controller | INFO Running default > verify 2025-09-30 05:09:21.711900 | controller | INFO Running Ansible Verifier 2025-09-30 05:09:22.154443 | controller | 2025-09-30 05:09:22.177044 | controller | PLAY [Verify] ****************************************************************** 2025-09-30 05:09:22.177077 | controller | 2025-09-30 05:09:22.177100 | controller | TASK [Set _tripleo_nodes_stack from persistent fact] *************************** 2025-09-30 05:09:22.177108 | controller | Tuesday 30 September 2025 05:09:22 +0000 (0:00:00.020) 0:00:00.020 ***** 2025-09-30 05:09:22.177139 | controller | skipping: [instance] 2025-09-30 05:09:22.247224 | controller | 2025-09-30 05:09:22.247259 | controller | TASK [Assert gathered nodes for stacks] **************************************** 2025-09-30 05:09:22.247269 | controller | Tuesday 30 September 2025 05:09:22 +0000 (0:00:00.022) 0:00:00.043 ***** 2025-09-30 05:09:22.247281 | controller | ok: [instance] => (item={'stackname': 'overcloud', 'network_data_file': 'network_data.yaml.j2', 'vips_data_file': 'vips_data_overcloud.yaml', 'stack_nodes': ['osp-controllers']}) => changed=false 2025-09-30 05:09:22.247307 | controller | _stack: 2025-09-30 05:09:22.247318 | controller | network_data_file: network_data.yaml.j2 2025-09-30 05:09:22.247343 | controller | stack_nodes: 2025-09-30 05:09:22.250519 | controller | - osp-controllers 2025-09-30 05:09:22.294532 | controller | stackname: overcloud 2025-09-30 05:09:22.294560 | controller | vips_data_file: vips_data_overcloud.yaml 2025-09-30 05:09:22.294568 | controller | ansible_loop_var: _stack 2025-09-30 05:09:22.294574 | controller | msg: Successfully verified gathered nodes for stack overcloud 2025-09-30 05:09:22.294580 | controller | ok: [instance] => (item={'stackname': 'cell1', 'network_data_file': 'network_data.yaml.j2', 'vips_data_file': 'vips_data_cell1.yaml', 'stack_nodes': ['cell1-osp-computes', 'cell1-osp-controllers']}) => changed=false 2025-09-30 05:09:22.294591 | controller | _stack: 2025-09-30 05:09:22.294598 | controller | network_data_file: network_data.yaml.j2 2025-09-30 05:09:22.294603 | controller | stack_nodes: 2025-09-30 05:09:22.294609 | controller | - cell1-osp-computes 2025-09-30 05:09:22.294615 | controller | - cell1-osp-controllers 2025-09-30 05:09:22.294620 | controller | stackname: cell1 2025-09-30 05:09:22.294625 | controller | vips_data_file: vips_data_cell1.yaml 2025-09-30 05:09:22.294631 | controller | ansible_loop_var: _stack 2025-09-30 05:09:22.294638 | controller | msg: Successfully verified gathered nodes for stack cell1 2025-09-30 05:09:22.294643 | controller | ok: [instance] => (item={'stackname': 'cell2', 'network_data_file': 'network_data.yaml.j2', 'vips_data_file': 'vips_data_cell2.yaml', 'stack_nodes': ['cell2-osp-computes', 'cell2-osp-controllers']}) => changed=false 2025-09-30 05:09:22.294649 | controller | _stack: 2025-09-30 05:09:22.294654 | controller | network_data_file: network_data.yaml.j2 2025-09-30 05:09:22.294660 | controller | stack_nodes: 2025-09-30 05:09:22.294665 | controller | - cell2-osp-computes 2025-09-30 05:09:22.294671 | controller | - cell2-osp-controllers 2025-09-30 05:09:22.294676 | controller | stackname: cell2 2025-09-30 05:09:22.294681 | controller | vips_data_file: vips_data_cell2.yaml 2025-09-30 05:09:22.294687 | controller | ansible_loop_var: _stack 2025-09-30 05:09:22.294692 | controller | msg: Successfully verified gathered nodes for stack cell2 2025-09-30 05:09:22.294697 | controller | 2025-09-30 05:09:22.294704 | controller | PLAY RECAP ********************************************************************* 2025-09-30 05:09:22.294710 | controller | instance : ok=1 changed=0 unreachable=0 failed=0 skipped=1 rescued=0 ignored=0 2025-09-30 05:09:22.294715 | controller | 2025-09-30 05:09:22.294721 | controller | Tuesday 30 September 2025 05:09:22 +0000 (0:00:00.070) 0:00:00.114 ***** 2025-09-30 05:09:22.294726 | controller | =============================================================================== 2025-09-30 05:09:22.294731 | controller | Assert gathered nodes for stacks ---------------------------------------- 0.07s 2025-09-30 05:09:22.294737 | controller | Set _tripleo_nodes_stack from persistent fact --------------------------- 0.02s 2025-09-30 05:09:22.294746 | controller | INFO Verifier completed successfully. 2025-09-30 05:09:22.303498 | controller | INFO Running default > destroy 2025-09-30 05:09:22.724595 | controller | 2025-09-30 05:09:23.025630 | controller | PLAY [Destroy] ***************************************************************** 2025-09-30 05:09:23.025662 | controller | 2025-09-30 05:09:23.025669 | controller | TASK [Get passwd entries for USER env] ***************************************** 2025-09-30 05:09:23.025676 | controller | Tuesday 30 September 2025 05:09:22 +0000 (0:00:00.015) 0:00:00.015 ***** 2025-09-30 05:09:23.025685 | controller | ok: [localhost] 2025-09-30 05:09:23.067155 | controller | 2025-09-30 05:09:23.067186 | controller | TASK [Get shell async_dir] ***************************************************** 2025-09-30 05:09:23.067193 | controller | Tuesday 30 September 2025 05:09:23 +0000 (0:00:00.301) 0:00:00.316 ***** 2025-09-30 05:09:23.067203 | controller | ok: [localhost] 2025-09-30 05:09:23.100572 | controller | 2025-09-30 05:09:23.100600 | controller | TASK [Set async_dir for HOME env] ********************************************** 2025-09-30 05:09:23.100607 | controller | Tuesday 30 September 2025 05:09:23 +0000 (0:00:00.041) 0:00:00.358 ***** 2025-09-30 05:09:23.100617 | controller | skipping: [localhost] 2025-09-30 05:09:23.476192 | controller | 2025-09-30 05:09:23.476222 | controller | TASK [Destroy molecule instance(s)] ******************************************** 2025-09-30 05:09:23.476231 | controller | Tuesday 30 September 2025 05:09:23 +0000 (0:00:00.033) 0:00:00.391 ***** 2025-09-30 05:09:23.476240 | controller | changed: [localhost] => (item={'command': '/sbin/init', 'dockerfile': 'containerfile', 'image': 'registry.access.redhat.com/ubi9/ubi-init', 'name': 'instance', 'pre_build_image': True}) 2025-09-30 05:09:23.476503 | controller | 2025-09-30 05:09:23.476518 | controller | TASK [Wait for instance(s) deletion to complete] ******************************* 2025-09-30 05:09:28.951908 | controller | Tuesday 30 September 2025 05:09:23 +0000 (0:00:00.375) 0:00:00.767 ***** 2025-09-30 05:09:28.951946 | controller | FAILED - RETRYING: [localhost]: Wait for instance(s) deletion to complete (300 retries left). 2025-09-30 05:09:29.004214 | controller | changed: [localhost] => (item={'failed': 0, 'started': 1, 'finished': 0, 'ansible_job_id': 'j417044479171.26572', 'results_file': '/home/zuul/.ansible_async/j417044479171.26572', 'changed': True, 'item': {'command': '/sbin/init', 'dockerfile': 'containerfile', 'image': 'registry.access.redhat.com/ubi9/ubi-init', 'name': 'instance', 'pre_build_image': True}, 'ansible_loop_var': 'item'}) 2025-09-30 05:09:29.004246 | controller | 2025-09-30 05:09:29.004254 | controller | TASK [Delete podman network dedicated to this scenario] ************************ 2025-09-30 05:09:29.004261 | controller | Tuesday 30 September 2025 05:09:28 +0000 (0:00:05.475) 0:00:06.242 ***** 2025-09-30 05:09:29.004271 | controller | skipping: [localhost] => (item=instance: None specified) 2025-09-30 05:09:29.004295 | controller | skipping: [localhost] 2025-09-30 05:09:29.004301 | controller | 2025-09-30 05:09:29.004307 | controller | PLAY RECAP ********************************************************************* 2025-09-30 05:09:29.004313 | controller | localhost : ok=4 changed=2 unreachable=0 failed=0 skipped=2 rescued=0 ignored=0 2025-09-30 05:09:29.004320 | controller | 2025-09-30 05:09:29.005101 | controller | Tuesday 30 September 2025 05:09:29 +0000 (0:00:00.052) 0:00:06.295 ***** 2025-09-30 05:09:29.054208 | controller | =============================================================================== 2025-09-30 05:09:29.054241 | controller | Wait for instance(s) deletion to complete ------------------------------- 5.48s 2025-09-30 05:09:29.054249 | controller | Destroy molecule instance(s) -------------------------------------------- 0.38s 2025-09-30 05:09:29.054255 | controller | Get passwd entries for USER env ----------------------------------------- 0.30s 2025-09-30 05:09:29.054261 | controller | Delete podman network dedicated to this scenario ------------------------ 0.05s 2025-09-30 05:09:29.054266 | controller | Get shell async_dir ----------------------------------------------------- 0.04s 2025-09-30 05:09:29.054272 | controller | Set async_dir for HOME env ---------------------------------------------- 0.03s 2025-09-30 05:09:29.054282 | controller | INFO Pruning extra files from scenario ephemeral directory 2025-09-30 05:09:29.056254 | controller | INFO Writing /tmp/report.html report. 2025-09-30 05:09:29.399352 | controller | changed 2025-09-30 05:09:29.419457 | 2025-09-30 05:09:29.419531 | PLAY RECAP 2025-09-30 05:09:29.419573 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-09-30 05:09:29.419596 | 2025-09-30 05:09:29.492266 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main] 2025-09-30 05:09:29.493095 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main] 2025-09-30 05:09:30.063113 | 2025-09-30 05:09:30.063254 | PLAY [Run ci/playbooks/collect-logs.yml] 2025-09-30 05:09:30.086012 | 2025-09-30 05:09:30.086106 | TASK [Filter out host if needed] 2025-09-30 05:09:30.095451 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller 2025-09-30 05:09:30.100008 | 2025-09-30 05:09:30.100078 | TASK [Ensure file is present] 2025-09-30 05:09:30.444452 | controller | ok 2025-09-30 05:09:30.451741 | 2025-09-30 05:09:30.451849 | TASK [Manage molecule report file] 2025-09-30 05:09:30.980594 | controller | changed 2025-09-30 05:09:30.987173 | 2025-09-30 05:09:30.987252 | TASK [Check if we get ci-framework-data basedir] 2025-09-30 05:09:31.169831 | controller | ok 2025-09-30 05:09:31.176002 | 2025-09-30 05:09:31.176097 | TASK [Create ci-framework-data log directory for zuul] 2025-09-30 05:09:31.510961 | controller | changed 2025-09-30 05:09:31.517443 | 2025-09-30 05:09:31.517530 | TASK [Copy ci-framework interesting files] 2025-09-30 05:09:31.720483 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory 2025-09-30 05:09:32.046801 | controller | changed 2025-09-30 05:09:32.052453 | 2025-09-30 05:09:32.052543 | TASK [Get SELinux listing] 2025-09-30 05:09:32.580816 | controller | changed 2025-09-30 05:09:32.586487 | 2025-09-30 05:09:32.586565 | TASK [Generate log index] 2025-09-30 05:09:33.193896 | controller | changed 2025-09-30 05:09:33.199448 | 2025-09-30 05:09:33.199521 | TASK [Get some env related data] 2025-09-30 05:09:33.739929 | controller | /home/zuul/.local/bin/ansible 2025-09-30 05:09:34.733390 | controller | changed 2025-09-30 05:09:34.738601 | 2025-09-30 05:09:34.738665 | TASK [Generate list of logs to collect in home directory] 2025-09-30 05:09:35.040312 | controller | ok: All paths examined 2025-09-30 05:09:35.045424 | 2025-09-30 05:09:35.045490 | LOOP [Copy logs from home directory] 2025-09-30 05:09:35.359448 | controller | changed: 2025-09-30 05:09:35.359564 | controller | { 2025-09-30 05:09:35.359591 | controller | "atime": 1759208907.4019282, 2025-09-30 05:09:35.359611 | controller | "ctime": 1759208925.6471586, 2025-09-30 05:09:35.359629 | controller | "dev": 64513, 2025-09-30 05:09:35.359645 | controller | "gid": 1000, 2025-09-30 05:09:35.359660 | controller | "gr_name": "zuul", 2025-09-30 05:09:35.359675 | controller | "inode": 4411387, 2025-09-30 05:09:35.359690 | controller | "isblk": false, 2025-09-30 05:09:35.359704 | controller | "ischr": false, 2025-09-30 05:09:35.359718 | controller | "isdir": false, 2025-09-30 05:09:35.359731 | controller | "isfifo": false, 2025-09-30 05:09:35.359747 | controller | "isgid": false, 2025-09-30 05:09:35.359761 | controller | "islnk": false, 2025-09-30 05:09:35.359775 | controller | "isreg": true, 2025-09-30 05:09:35.359788 | controller | "issock": false, 2025-09-30 05:09:35.359801 | controller | "isuid": false, 2025-09-30 05:09:35.359813 | controller | "mode": "0644", 2025-09-30 05:09:35.359828 | controller | "mtime": 1759208925.6471586, 2025-09-30 05:09:35.359842 | controller | "nlink": 1, 2025-09-30 05:09:35.359856 | controller | "path": "/home/zuul/ansible.log", 2025-09-30 05:09:35.359871 | controller | "pw_name": "zuul", 2025-09-30 05:09:35.359886 | controller | "rgrp": true, 2025-09-30 05:09:35.359900 | controller | "roth": true, 2025-09-30 05:09:35.359942 | controller | "rusr": true, 2025-09-30 05:09:35.359962 | controller | "size": 6749, 2025-09-30 05:09:35.359977 | controller | "uid": 1000, 2025-09-30 05:09:35.359992 | controller | "wgrp": false, 2025-09-30 05:09:35.360006 | controller | "woth": false, 2025-09-30 05:09:35.360023 | controller | "wusr": true, 2025-09-30 05:09:35.360038 | controller | "xgrp": false, 2025-09-30 05:09:35.360052 | controller | "xoth": false, 2025-09-30 05:09:35.360065 | controller | "xusr": false 2025-09-30 05:09:35.360079 | controller | } 2025-09-30 05:09:35.374100 | 2025-09-30 05:09:35.374211 | TASK [Copy crio stats log file] 2025-09-30 05:09:35.398028 | controller | skipping: Conditional result was False 2025-09-30 05:09:35.403658 | 2025-09-30 05:09:35.403729 | TASK [Get SELinux related data] 2025-09-30 05:09:35.621690 | controller | 2025-09-30 05:09:35.930689 | controller | ERROR 2025-09-30 05:09:35.930870 | controller | { 2025-09-30 05:09:35.930902 | controller | "delta": "0:00:00.009086", 2025-09-30 05:09:35.930955 | controller | "end": "2025-09-30 05:09:35.622541", 2025-09-30 05:09:35.930976 | controller | "msg": "non-zero return code", 2025-09-30 05:09:35.930993 | controller | "rc": 1, 2025-09-30 05:09:35.931010 | controller | "start": "2025-09-30 05:09:35.613455" 2025-09-30 05:09:35.931027 | controller | } 2025-09-30 05:09:35.931050 | controller | ERROR: Ignoring Errors 2025-09-30 05:09:35.936468 | 2025-09-30 05:09:35.936536 | TASK [Create system configuration directory] 2025-09-30 05:09:36.126988 | controller | changed 2025-09-30 05:09:36.132678 | 2025-09-30 05:09:36.132780 | TASK [Get some of the system configurations] 2025-09-30 05:09:36.656574 | controller | changed 2025-09-30 05:09:36.662016 | 2025-09-30 05:09:36.662096 | TASK [Copy generated documentation if available] 2025-09-30 05:09:36.685452 | controller | skipping: Conditional result was False 2025-09-30 05:09:36.690769 | 2025-09-30 05:09:36.690841 | TASK [Copy generated AsciiDoc documentation if available] 2025-09-30 05:09:36.705010 | controller | skipping: Conditional result was False 2025-09-30 05:09:36.713749 | 2025-09-30 05:09:36.713868 | TASK [Compress logs bigger than 2MB] 2025-09-30 05:09:37.241110 | controller | changed 2025-09-30 05:09:37.246576 | 2025-09-30 05:09:37.246646 | TASK [Copy files from workspace on node] 2025-09-30 05:09:37.264895 | controller | ok 2025-09-30 05:09:37.286864 | 2025-09-30 05:09:37.286972 | TASK [fetch-output : Set log path for multiple nodes] 2025-09-30 05:09:37.310929 | controller | skipping: Conditional result was False 2025-09-30 05:09:37.316447 | 2025-09-30 05:09:37.316537 | TASK [fetch-output : Set log path for single node] 2025-09-30 05:09:37.345507 | controller | ok 2025-09-30 05:09:37.351716 | 2025-09-30 05:09:37.351795 | LOOP [fetch-output : Ensure local output dirs] 2025-09-30 05:09:37.562174 | controller -> localhost | ok: "/var/lib/zuul/builds/8cfd2b4bc50f44aa8f625093a3a93c64/work/logs" 2025-09-30 05:09:37.562449 | controller -> localhost | changed: All items complete 2025-09-30 05:09:37.562481 | 2025-09-30 05:09:37.749662 | controller -> localhost | changed: "/var/lib/zuul/builds/8cfd2b4bc50f44aa8f625093a3a93c64/work/artifacts" 2025-09-30 05:09:37.939041 | controller -> localhost | changed: "/var/lib/zuul/builds/8cfd2b4bc50f44aa8f625093a3a93c64/work/docs" 2025-09-30 05:09:37.952838 | 2025-09-30 05:09:37.952987 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-09-30 05:09:38.507497 | controller | changed: 2025-09-30 05:09:38.507676 | controller | .d..t...... ./ 2025-09-30 05:09:38.507710 | controller | >f+++++++++ README.html 2025-09-30 05:09:38.507732 | controller | >f+++++++++ ansible-execution.log 2025-09-30 05:09:38.507753 | controller | >f+++++++++ ansible.log 2025-09-30 05:09:38.507772 | controller | >f+++++++++ dmesg.log 2025-09-30 05:09:38.507791 | controller | >f+++++++++ installed-pkgs.log 2025-09-30 05:09:38.507814 | controller | >f+++++++++ python.log 2025-09-30 05:09:38.507834 | controller | >f+++++++++ registries.conf 2025-09-30 05:09:38.507852 | controller | >f+++++++++ report.html 2025-09-30 05:09:38.507872 | controller | >f+++++++++ selinux-denials.log 2025-09-30 05:09:38.507891 | controller | >f+++++++++ selinux-listing.log 2025-09-30 05:09:38.507925 | controller | cd+++++++++ ci-framework-data/ 2025-09-30 05:09:38.507952 | controller | cd+++++++++ ci-framework-data/artifacts/ 2025-09-30 05:09:38.507973 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml 2025-09-30 05:09:38.507992 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/ 2025-09-30 05:09:38.508010 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml 2025-09-30 05:09:38.508027 | controller | cd+++++++++ ci-framework-data/logs/ 2025-09-30 05:09:38.508044 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log 2025-09-30 05:09:38.508060 | controller | cd+++++++++ registries.conf.d/ 2025-09-30 05:09:38.508077 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf 2025-09-30 05:09:38.508094 | controller | cd+++++++++ system-config/ 2025-09-30 05:09:38.508111 | controller | cd+++++++++ system-config/libvirt/ 2025-09-30 05:09:38.508129 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf 2025-09-30 05:09:38.508146 | controller | >f+++++++++ system-config/libvirt/libvirt.conf 2025-09-30 05:09:38.903765 | controller | changed: .d..t...... ./ 2025-09-30 05:09:39.288573 | controller | changed: .d..t...... ./ 2025-09-30 05:09:39.317284 | 2025-09-30 05:09:39.317412 | TASK [Return artifact to Zuul] 2025-09-30 05:09:39.347920 | controller | ok 2025-09-30 05:09:39.372305 | 2025-09-30 05:09:39.372391 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host] 2025-09-30 05:09:39.372490 | 2025-09-30 05:09:39.372518 | PLAY RECAP 2025-09-30 05:09:39.372557 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1 2025-09-30 05:09:39.372577 | 2025-09-30 05:09:39.455203 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main] 2025-09-30 05:09:39.455981 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-09-30 05:09:40.010864 | 2025-09-30 05:09:40.010994 | PLAY [all] 2025-09-30 05:09:40.030302 | 2025-09-30 05:09:40.030404 | TASK [include_role : fetch-output] 2025-09-30 05:09:40.069149 | controller | ok 2025-09-30 05:09:40.085621 | 2025-09-30 05:09:40.085737 | TASK [fetch-output : Set log path for multiple nodes] 2025-09-30 05:09:40.149886 | controller | skipping: Conditional result was False 2025-09-30 05:09:40.155552 | 2025-09-30 05:09:40.155646 | TASK [fetch-output : Set log path for single node] 2025-09-30 05:09:40.194540 | controller | ok 2025-09-30 05:09:40.199617 | 2025-09-30 05:09:40.199710 | LOOP [fetch-output : Ensure local output dirs] 2025-09-30 05:09:40.569206 | controller -> localhost | ok: "/var/lib/zuul/builds/8cfd2b4bc50f44aa8f625093a3a93c64/work/logs" 2025-09-30 05:09:40.762433 | controller -> localhost | ok: "/var/lib/zuul/builds/8cfd2b4bc50f44aa8f625093a3a93c64/work/artifacts" 2025-09-30 05:09:40.952568 | controller -> localhost | ok: "/var/lib/zuul/builds/8cfd2b4bc50f44aa8f625093a3a93c64/work/docs" 2025-09-30 05:09:40.964295 | 2025-09-30 05:09:40.964397 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-09-30 05:09:41.493934 | controller | ok 2025-09-30 05:09:41.494134 | controller | ok: All items complete 2025-09-30 05:09:41.494165 | 2025-09-30 05:09:41.895044 | controller | ok 2025-09-30 05:09:42.310054 | controller | ok 2025-09-30 05:09:42.329200 | 2025-09-30 05:09:42.329304 | TASK [include_role : fetch-output-openshift] 2025-09-30 05:09:42.363411 | controller | skipping: Conditional result was False 2025-09-30 05:09:42.369684 | 2025-09-30 05:09:42.369782 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-09-30 05:09:42.791047 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007190 2025-09-30 05:09:43.020193 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.015113 2025-09-30 05:09:43.074080 | 2025-09-30 05:09:43.074174 | PLAY [all] 2025-09-30 05:09:43.091940 | 2025-09-30 05:09:43.092047 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-09-30 05:09:43.509837 | controller | changed 2025-09-30 05:09:43.534285 | 2025-09-30 05:09:43.534395 | PLAY RECAP 2025-09-30 05:09:43.534443 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-09-30 05:09:43.534467 | 2025-09-30 05:09:43.650119 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-09-30 05:09:43.650886 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-09-30 05:09:44.397648 | 2025-09-30 05:09:44.397769 | PLAY [localhost] 2025-09-30 05:09:44.416030 | 2025-09-30 05:09:44.416125 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-09-30 05:09:44.811241 | localhost | changed 2025-09-30 05:09:44.815835 | 2025-09-30 05:09:44.815940 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-09-30 05:09:44.844670 | localhost | ok 2025-09-30 05:09:44.852640 | 2025-09-30 05:09:44.852718 | TASK [add-fileserver : Create SSH private key tempfile] 2025-09-30 05:09:45.209062 | localhost | changed 2025-09-30 05:09:45.215280 | 2025-09-30 05:09:45.215369 | TASK [add-fileserver : Create SSH private key from secret] 2025-09-30 05:09:45.832290 | localhost | changed 2025-09-30 05:09:45.840247 | 2025-09-30 05:09:45.840487 | TASK [add-fileserver : Add fileserver ssh key] 2025-09-30 05:09:46.204249 | localhost | Identity added: /var/lib/zuul/builds/8cfd2b4bc50f44aa8f625093a3a93c64/work/tmp/ansible.4hpqz83p (/var/lib/zuul/builds/8cfd2b4bc50f44aa8f625093a3a93c64/work/tmp/ansible.4hpqz83p) 2025-09-30 05:09:46.204450 | localhost | ok: Runtime: 0:00:00.006990 2025-09-30 05:09:46.214038 | 2025-09-30 05:09:46.214110 | TASK [add-fileserver : Remove SSH private key from disk] 2025-09-30 05:09:46.445229 | localhost | ok: Runtime: 0:00:00.004638 2025-09-30 05:09:46.450070 | 2025-09-30 05:09:46.450152 | TASK [add-fileserver : Add fileserver to inventory] 2025-09-30 05:09:46.504676 | localhost | changed 2025-09-30 05:09:46.509837 | 2025-09-30 05:09:46.509922 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-09-30 05:09:46.838519 | localhost | changed 2025-09-30 05:09:46.859611 | 2025-09-30 05:09:46.859743 | PLAY [localhost] 2025-09-30 05:09:46.871846 | 2025-09-30 05:09:46.871947 | TASK [Generate bulk log download script] 2025-09-30 05:09:46.889436 | localhost | ok 2025-09-30 05:09:46.901406 | 2025-09-30 05:09:46.901491 | TASK [local-log-download : Check API endpoint is defined] 2025-09-30 05:09:46.929503 | localhost | ok: All assertions passed 2025-09-30 05:09:46.934189 | 2025-09-30 05:09:46.934258 | TASK [local-log-download : Create download script] 2025-09-30 05:09:47.365640 | localhost -> localhost | changed 2025-09-30 05:09:47.375475 | 2025-09-30 05:09:47.375570 | TASK [Register quick-download link] 2025-09-30 05:09:47.403317 | localhost | ok 2025-09-30 05:09:47.448881 | 2025-09-30 05:09:47.449005 | PLAY [logserver.rdoproject.org] 2025-09-30 05:09:47.459245 | 2025-09-30 05:09:47.459323 | TASK [Set zuul-log-path fact] 2025-09-30 05:09:47.474991 | logserver.rdoproject.org | ok 2025-09-30 05:09:47.485015 | 2025-09-30 05:09:47.485119 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-30 05:09:47.512228 | logserver.rdoproject.org | ok 2025-09-30 05:09:47.518944 | 2025-09-30 05:09:47.519040 | TASK [upload-logs : Create log directories] 2025-09-30 05:09:50.282710 | logserver.rdoproject.org | changed 2025-09-30 05:09:50.286223 | 2025-09-30 05:09:50.286318 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-09-30 05:09:50.759399 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009480 2025-09-30 05:09:50.764498 | 2025-09-30 05:09:50.764574 | TASK [upload-logs : Upload logs to log server] 2025-09-30 05:09:52.469623 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-09-30 05:09:52.472615 | 2025-09-30 05:09:52.472686 | LOOP [upload-logs : Compress console log and json output] 2025-09-30 05:09:52.518214 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 05:09:52.527668 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 05:09:52.541477 | 2025-09-30 05:09:52.541573 | LOOP [upload-logs : Upload compressed console log and json output] 2025-09-30 05:09:52.583379 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 05:09:52.583625 | 2025-09-30 05:09:52.589150 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 05:09:52.600294 | 2025-09-30 05:09:52.600371 | LOOP [upload-logs : Upload console log and json output]