2025-09-30 07:35:09.545016 | Job console starting... 2025-09-30 07:35:09.559511 | Updating repositories 2025-09-30 07:35:09.602251 | Preparing job workspace 2025-09-30 07:35:16.771108 | Running Ansible setup... 2025-09-30 07:35:22.298702 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-09-30 07:35:22.869614 | 2025-09-30 07:35:22.869743 | PLAY [localhost] 2025-09-30 07:35:22.878361 | 2025-09-30 07:35:22.878429 | TASK [Gathering Facts] 2025-09-30 07:35:23.934146 | localhost | ok 2025-09-30 07:35:23.960797 | 2025-09-30 07:35:23.960901 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-09-30 07:35:24.355960 | localhost -> localhost | changed 2025-09-30 07:35:24.367523 | 2025-09-30 07:35:24.367713 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-09-30 07:35:25.253736 | localhost -> localhost | changed 2025-09-30 07:35:25.262024 | 2025-09-30 07:35:25.262090 | TASK [Setup log path fact] 2025-09-30 07:35:25.279712 | localhost | ok 2025-09-30 07:35:25.290548 | 2025-09-30 07:35:25.290610 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-30 07:35:25.319519 | localhost | ok 2025-09-30 07:35:25.329414 | 2025-09-30 07:35:25.329499 | TASK [emit-job-header : Print job information] 2025-09-30 07:35:25.359044 | # Job Information 2025-09-30 07:35:25.359194 | Ansible Version: 2.15.12 2025-09-30 07:35:25.359229 | Job: cifmw-molecule-ci_multus 2025-09-30 07:35:25.359256 | Pipeline: github-check 2025-09-30 07:35:25.359280 | Executor: ze02.softwarefactory-project.io 2025-09-30 07:35:25.359305 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3352 2025-09-30 07:35:25.359330 | Log URL (when completed): https://logserver.rdoproject.org/b23/rdoproject.org/b2302220a73b484ca6fe7dc378e1df74/ 2025-09-30 07:35:25.359354 | Event ID: e086b100-9dcf-11f0-84e0-23beb7628175 2025-09-30 07:35:25.364100 | 2025-09-30 07:35:25.364180 | LOOP [emit-job-header : Print node information] 2025-09-30 07:35:25.460547 | localhost | ok: 2025-09-30 07:35:25.460848 | localhost | # Node Information 2025-09-30 07:35:25.460908 | localhost | Inventory Hostname: controller 2025-09-30 07:35:25.460958 | localhost | Hostname: np0005461991 2025-09-30 07:35:25.461000 | localhost | Username: zuul 2025-09-30 07:35:25.461043 | localhost | Distro: CentOS 9 2025-09-30 07:35:25.461081 | localhost | Provider: vexxhost-nodepool-tripleo 2025-09-30 07:35:25.461118 | localhost | Region: RegionOne 2025-09-30 07:35:25.461153 | localhost | Label: centos-9-stream-crc-2-48-0-xxl 2025-09-30 07:35:25.461189 | localhost | Product Name: OpenStack Nova 2025-09-30 07:35:25.461225 | localhost | Interface IP: 38.102.83.9 2025-09-30 07:35:25.500912 | 2025-09-30 07:35:25.501044 | PLAY [all] 2025-09-30 07:35:25.514615 | 2025-09-30 07:35:25.514773 | TASK [Gather network facts] 2025-09-30 07:35:26.145693 | controller | ok 2025-09-30 07:35:26.177934 | 2025-09-30 07:35:26.178061 | TASK [include_role : start-zuul-console] 2025-09-30 07:35:26.200127 | controller | ok 2025-09-30 07:35:26.215406 | 2025-09-30 07:35:26.215487 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-09-30 07:35:26.786931 | controller | ok 2025-09-30 07:35:26.812912 | 2025-09-30 07:35:26.813042 | TASK [include_role : add-build-sshkey] 2025-09-30 07:35:26.845231 | controller | ok 2025-09-30 07:35:26.867342 | 2025-09-30 07:35:26.867433 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-09-30 07:35:27.162239 | controller -> localhost | ok 2025-09-30 07:35:27.174243 | 2025-09-30 07:35:27.174380 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-09-30 07:35:27.211814 | controller | ok 2025-09-30 07:35:27.239410 | controller | included: /var/lib/zuul/builds/b2302220a73b484ca6fe7dc378e1df74/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-09-30 07:35:27.247362 | 2025-09-30 07:35:27.247444 | TASK [add-build-sshkey : Create Temp SSH key] 2025-09-30 07:35:27.966143 | controller -> localhost | Generating public/private rsa key pair. 2025-09-30 07:35:27.966518 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/b2302220a73b484ca6fe7dc378e1df74/work/b2302220a73b484ca6fe7dc378e1df74_id_rsa. 2025-09-30 07:35:27.966585 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/b2302220a73b484ca6fe7dc378e1df74/work/b2302220a73b484ca6fe7dc378e1df74_id_rsa.pub. 2025-09-30 07:35:27.966634 | controller -> localhost | The key fingerprint is: 2025-09-30 07:35:27.966724 | controller -> localhost | SHA256:HoXdEmgEQtLtjWTNZNW7Vxah3tHVQ/xZ+HDrOq26fxo zuul-build-sshkey 2025-09-30 07:35:27.966776 | controller -> localhost | The key's randomart image is: 2025-09-30 07:35:27.966818 | controller -> localhost | +---[RSA 3072]----+ 2025-09-30 07:35:27.966858 | controller -> localhost | | .oo..*+oo. o++| 2025-09-30 07:35:27.966899 | controller -> localhost | | ...+.=o o. ++*| 2025-09-30 07:35:27.966940 | controller -> localhost | | + +. + .o =O| 2025-09-30 07:35:27.966980 | controller -> localhost | | o .. .o .o*| 2025-09-30 07:35:27.967019 | controller -> localhost | | S o.+ | 2025-09-30 07:35:27.967058 | controller -> localhost | | . . . .. | 2025-09-30 07:35:27.967096 | controller -> localhost | | . Eo | 2025-09-30 07:35:27.967134 | controller -> localhost | | o.o | 2025-09-30 07:35:27.967172 | controller -> localhost | | o++= | 2025-09-30 07:35:27.967210 | controller -> localhost | +----[SHA256]-----+ 2025-09-30 07:35:27.967295 | controller -> localhost | ok: Runtime: 0:00:00.285413 2025-09-30 07:35:27.986118 | 2025-09-30 07:35:27.986271 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-09-30 07:35:28.013024 | controller | ok 2025-09-30 07:35:28.035053 | controller | included: /var/lib/zuul/builds/b2302220a73b484ca6fe7dc378e1df74/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-09-30 07:35:28.045972 | 2025-09-30 07:35:28.046056 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-09-30 07:35:28.061681 | controller | skipping: Conditional result was False 2025-09-30 07:35:28.068858 | 2025-09-30 07:35:28.068939 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-09-30 07:35:28.692394 | controller | changed 2025-09-30 07:35:28.699430 | 2025-09-30 07:35:28.699491 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-09-30 07:35:29.144478 | controller | ok 2025-09-30 07:35:29.155501 | 2025-09-30 07:35:29.155639 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-09-30 07:35:31.087106 | controller | changed 2025-09-30 07:35:31.091943 | 2025-09-30 07:35:31.092005 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-09-30 07:35:33.126824 | controller | changed 2025-09-30 07:35:33.137968 | 2025-09-30 07:35:33.138103 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-09-30 07:35:33.175234 | controller | skipping: Conditional result was False 2025-09-30 07:35:33.186963 | 2025-09-30 07:35:33.187103 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-09-30 07:35:33.572935 | controller -> localhost | changed 2025-09-30 07:35:33.583264 | 2025-09-30 07:35:33.583329 | TASK [add-build-sshkey : Add back temp key] 2025-09-30 07:35:33.897407 | controller -> localhost | Identity added: /var/lib/zuul/builds/b2302220a73b484ca6fe7dc378e1df74/work/b2302220a73b484ca6fe7dc378e1df74_id_rsa (zuul-build-sshkey) 2025-09-30 07:35:33.897763 | controller -> localhost | ok: Runtime: 0:00:00.009451 2025-09-30 07:35:33.919460 | 2025-09-30 07:35:33.919595 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-09-30 07:35:34.460997 | controller | ok 2025-09-30 07:35:34.478640 | 2025-09-30 07:35:34.478907 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-09-30 07:35:34.567207 | controller | skipping: Conditional result was False 2025-09-30 07:35:34.629210 | 2025-09-30 07:35:34.629344 | TASK [include_role : validate-host] 2025-09-30 07:35:34.661644 | controller | ok 2025-09-30 07:35:34.691280 | 2025-09-30 07:35:34.691435 | TASK [validate-host : Define zuul_info_dir fact] 2025-09-30 07:35:34.733077 | controller | ok 2025-09-30 07:35:34.739245 | 2025-09-30 07:35:34.739325 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-09-30 07:35:35.016952 | controller -> localhost | ok 2025-09-30 07:35:35.024684 | 2025-09-30 07:35:35.024770 | TASK [validate-host : Collect information about the host] 2025-09-30 07:35:36.068737 | controller | ok 2025-09-30 07:35:36.085050 | 2025-09-30 07:35:36.085258 | TASK [validate-host : Sanitize hostname] 2025-09-30 07:35:36.169011 | controller | ok 2025-09-30 07:35:36.176871 | 2025-09-30 07:35:36.176959 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-09-30 07:35:36.663058 | controller -> localhost | changed 2025-09-30 07:35:36.675390 | 2025-09-30 07:35:36.675520 | TASK [validate-host : Collect information about zuul worker] 2025-09-30 07:35:37.254371 | controller | ok 2025-09-30 07:35:37.261081 | 2025-09-30 07:35:37.261172 | TASK [validate-host : Write out all zuul information for each host] 2025-09-30 07:35:37.788527 | controller -> localhost | changed 2025-09-30 07:35:37.815787 | 2025-09-30 07:35:37.815985 | TASK [include_role : prepare-workspace-openshift] 2025-09-30 07:35:37.842447 | controller | skipping: Conditional result was False 2025-09-30 07:35:37.853994 | 2025-09-30 07:35:37.854128 | TASK [include_role : remove-zuul-sshkey] 2025-09-30 07:35:37.881639 | controller | skipping: Conditional result was False 2025-09-30 07:35:37.889024 | 2025-09-30 07:35:37.889108 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-09-30 07:35:38.337086 | controller | ok: "logs" 2025-09-30 07:35:38.337437 | controller | ok: All items complete 2025-09-30 07:35:38.337475 | 2025-09-30 07:35:38.755527 | controller | ok: "artifacts" 2025-09-30 07:35:39.172073 | controller | ok: "docs" 2025-09-30 07:35:39.186844 | 2025-09-30 07:35:39.187011 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-09-30 07:35:39.639615 | controller | changed: "logs" 2025-09-30 07:35:40.028916 | controller | changed: "artifacts" 2025-09-30 07:35:40.415869 | controller | changed: "docs" 2025-09-30 07:35:40.463995 | 2025-09-30 07:35:40.464095 | PLAY RECAP 2025-09-30 07:35:40.464141 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-09-30 07:35:40.464166 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-09-30 07:35:40.464185 | 2025-09-30 07:35:40.562458 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-09-30 07:35:40.563734 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master] 2025-09-30 07:35:41.224925 | 2025-09-30 07:35:41.225033 | PLAY [all] 2025-09-30 07:35:41.249106 | 2025-09-30 07:35:41.249224 | TASK [mirror-info-fork : Set mirror_fqdn if not defined] 2025-09-30 07:35:41.309375 | controller | ok 2025-09-30 07:35:41.314733 | 2025-09-30 07:35:41.314812 | TASK [mirror-info-fork : Create /etc/ci] 2025-09-30 07:35:41.914633 | controller | changed 2025-09-30 07:35:41.920486 | 2025-09-30 07:35:41.920560 | TASK [mirror-info-fork : Install ci_mirror script] 2025-09-30 07:35:43.943965 | controller | changed 2025-09-30 07:35:43.965606 | 2025-09-30 07:35:43.965716 | LOOP [add-authorized-keys : Enable access via build key on all nodes] 2025-09-30 07:35:44.611719 | controller | changed: 2025-09-30 07:35:44.612045 | controller | { 2025-09-30 07:35:44.612110 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com" 2025-09-30 07:35:44.612171 | controller | } 2025-09-30 07:35:45.037296 | controller | changed: 2025-09-30 07:35:45.037422 | controller | { 2025-09-30 07:35:45.037449 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com" 2025-09-30 07:35:45.037468 | controller | } 2025-09-30 07:35:45.473918 | controller | changed: 2025-09-30 07:35:45.474102 | controller | { 2025-09-30 07:35:45.474132 | 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 07:35:45.474153 | controller | } 2025-09-30 07:35:45.923851 | controller | changed: 2025-09-30 07:35:45.923972 | controller | { 2025-09-30 07:35:45.924005 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com" 2025-09-30 07:35:45.924031 | controller | } 2025-09-30 07:35:46.396015 | controller | changed: 2025-09-30 07:35:46.396175 | controller | { 2025-09-30 07:35:46.396230 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com" 2025-09-30 07:35:46.396274 | controller | } 2025-09-30 07:35:46.868708 | controller | changed: 2025-09-30 07:35:46.868873 | controller | { 2025-09-30 07:35:46.868927 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com" 2025-09-30 07:35:46.868970 | controller | } 2025-09-30 07:35:47.306872 | controller | changed: 2025-09-30 07:35:47.307014 | controller | { 2025-09-30 07:35:47.307047 | 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 07:35:47.307073 | controller | } 2025-09-30 07:35:47.754468 | controller | changed: 2025-09-30 07:35:47.754806 | controller | { 2025-09-30 07:35:47.754882 | 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 07:35:47.754929 | controller | } 2025-09-30 07:35:48.217709 | controller | changed: 2025-09-30 07:35:48.217882 | controller | { 2025-09-30 07:35:48.217934 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner" 2025-09-30 07:35:48.217975 | controller | } 2025-09-30 07:35:48.694144 | controller | changed: 2025-09-30 07:35:48.694306 | controller | { 2025-09-30 07:35:48.694359 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com" 2025-09-30 07:35:48.694400 | controller | } 2025-09-30 07:35:49.144788 | controller | changed: 2025-09-30 07:35:49.145035 | controller | { 2025-09-30 07:35:49.145097 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com" 2025-09-30 07:35:49.145144 | controller | } 2025-09-30 07:35:49.581163 | controller | changed: 2025-09-30 07:35:49.581405 | controller | { 2025-09-30 07:35:49.581458 | controller | "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com" 2025-09-30 07:35:49.581500 | controller | } 2025-09-30 07:35:50.039375 | controller | changed: 2025-09-30 07:35:50.039841 | controller | { 2025-09-30 07:35:50.039924 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith" 2025-09-30 07:35:50.039973 | controller | } 2025-09-30 07:35:50.476763 | controller | changed: 2025-09-30 07:35:50.476922 | controller | { 2025-09-30 07:35:50.476947 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel" 2025-09-30 07:35:50.476967 | controller | } 2025-09-30 07:35:50.942599 | controller | changed: 2025-09-30 07:35:50.943054 | controller | { 2025-09-30 07:35:50.943129 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux" 2025-09-30 07:35:50.943173 | controller | } 2025-09-30 07:35:51.377689 | controller | changed: 2025-09-30 07:35:51.377865 | controller | { 2025-09-30 07:35:51.377889 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr" 2025-09-30 07:35:51.377907 | controller | } 2025-09-30 07:35:51.772623 | controller | changed: 2025-09-30 07:35:51.772836 | controller | { 2025-09-30 07:35:51.772860 | 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 07:35:51.772881 | controller | } 2025-09-30 07:35:52.200867 | controller | changed: 2025-09-30 07:35:52.201295 | controller | { 2025-09-30 07:35:52.201556 | 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 07:35:52.201615 | controller | } 2025-09-30 07:35:52.596923 | controller | changed: 2025-09-30 07:35:52.597113 | controller | { 2025-09-30 07:35:52.597137 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9" 2025-09-30 07:35:52.597156 | controller | } 2025-09-30 07:35:53.027217 | controller | changed: 2025-09-30 07:35:53.027445 | controller | { 2025-09-30 07:35:53.027498 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora" 2025-09-30 07:35:53.027540 | controller | } 2025-09-30 07:35:53.491214 | controller | changed: 2025-09-30 07:35:53.491439 | controller | { 2025-09-30 07:35:53.491492 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac" 2025-09-30 07:35:53.491622 | controller | } 2025-09-30 07:35:53.923618 | controller | changed: 2025-09-30 07:35:53.923772 | controller | { 2025-09-30 07:35:53.923806 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop" 2025-09-30 07:35:53.923832 | controller | } 2025-09-30 07:35:54.389345 | controller | changed: 2025-09-30 07:35:54.389505 | controller | { 2025-09-30 07:35:54.389557 | 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 07:35:54.389600 | controller | } 2025-09-30 07:35:54.838451 | controller | changed: 2025-09-30 07:35:54.838617 | controller | { 2025-09-30 07:35:54.838699 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com" 2025-09-30 07:35:54.838750 | controller | } 2025-09-30 07:35:55.290869 | controller | changed: 2025-09-30 07:35:55.290982 | controller | { 2025-09-30 07:35:55.291005 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com" 2025-09-30 07:35:55.291025 | controller | } 2025-09-30 07:35:55.702115 | controller | changed: 2025-09-30 07:35:55.702231 | controller | { 2025-09-30 07:35:55.702255 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono" 2025-09-30 07:35:55.702273 | controller | } 2025-09-30 07:35:55.729628 | 2025-09-30 07:35:55.729762 | TASK [Set timezone to UTC] 2025-09-30 07:35:56.524339 | controller | changed: executed `/bin/timedatectl set-timezone UTC` 2025-09-30 07:35:56.539692 | 2025-09-30 07:35:56.539829 | TASK [Create nodepool directory] 2025-09-30 07:35:57.012738 | controller | changed 2025-09-30 07:35:57.029631 | 2025-09-30 07:35:57.029758 | TASK [Create nodepool sub_nodes file] 2025-09-30 07:35:58.766747 | controller | changed 2025-09-30 07:35:58.774184 | 2025-09-30 07:35:58.774306 | TASK [Create nodepool sub_nodes_private file] 2025-09-30 07:36:00.440015 | controller | changed 2025-09-30 07:36:00.449888 | 2025-09-30 07:36:00.449968 | LOOP [Populate nodepool sub_nodes file] 2025-09-30 07:36:00.482503 | 2025-09-30 07:36:00.482656 | LOOP [Populate nodepool sub_nodes_private file] 2025-09-30 07:36:00.516179 | 2025-09-30 07:36:00.516617 | TASK [Create nodepool primary file] 2025-09-30 07:36:00.543314 | controller | skipping: Conditional result was False 2025-09-30 07:36:00.553522 | 2025-09-30 07:36:00.553641 | TASK [Create nodepool node_private for this node] 2025-09-30 07:36:02.220947 | controller | changed 2025-09-30 07:36:02.227392 | 2025-09-30 07:36:02.227463 | LOOP [Copy ssh keys to nodepool directory] 2025-09-30 07:36:02.808062 | controller | ok: Item: id_rsa Runtime: 0:00:00.011224 2025-09-30 07:36:02.808313 | 2025-09-30 07:36:03.207374 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.008348 2025-09-30 07:36:03.217463 | 2025-09-30 07:36:03.217556 | TASK [Add sudoers role for zuul-sudo-grep.sh] 2025-09-30 07:36:05.056085 | controller | changed 2025-09-30 07:36:05.061521 | 2025-09-30 07:36:05.061586 | TASK [Validate sudoers config after edits] 2025-09-30 07:36:05.541512 | controller | /etc/sudoers: parsed OK 2025-09-30 07:36:05.541764 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK 2025-09-30 07:36:05.541784 | controller | /etc/sudoers.d/zuul: parsed OK 2025-09-30 07:36:05.541800 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK 2025-09-30 07:36:05.640430 | controller | ok: Runtime: 0:00:00.008865 2025-09-30 07:36:05.656459 | 2025-09-30 07:36:05.656622 | TASK [Show the environment passed in to job shell scripts] 2025-09-30 07:36:06.139091 | controller | SHELL=/bin/bash 2025-09-30 07:36:06.139176 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework 2025-09-30 07:36:06.139197 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework 2025-09-30 07:36:06.139212 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/46/3346/eb5b53fb17db92a72d33d052a56c8edd0d10ea78^openstack-k8s-operators/ci-framework:main:refs/changes/52/3352/6442e37e2e901d750c5bf184fc25fe0337bd2e95 2025-09-30 07:36:06.139231 | controller | PWD=/home/zuul 2025-09-30 07:36:06.139245 | controller | ZUUL_PIPELINE=github-check 2025-09-30 07:36:06.139258 | controller | LOGNAME=zuul 2025-09-30 07:36:06.139298 | controller | XDG_SESSION_TYPE=tty 2025-09-30 07:36:06.139317 | controller | _=/usr/bin/env 2025-09-30 07:36:06.139331 | controller | MOTD_SHOWN=pam 2025-09-30 07:36:06.139344 | controller | HOME=/home/zuul 2025-09-30 07:36:06.139414 | controller | LANG=en_US.UTF-8 2025-09-30 07:36:06.139432 | controller | SSH_CONNECTION=38.102.83.114 60478 38.102.83.9 22 2025-09-30 07:36:06.139445 | 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 07:36:06.139459 | controller | ZUUL_CHANGE_IDS=3346,eb5b53fb17db92a72d33d052a56c8edd0d10ea78 3352,6442e37e2e901d750c5bf184fc25fe0337bd2e95 2025-09-30 07:36:06.139472 | controller | WORKSPACE=/home/zuul/workspace 2025-09-30 07:36:06.139486 | controller | XDG_SESSION_CLASS=user 2025-09-30 07:36:06.139500 | controller | SELINUX_ROLE_REQUESTED= 2025-09-30 07:36:06.139513 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s 2025-09-30 07:36:06.139527 | controller | USER=zuul 2025-09-30 07:36:06.139540 | controller | ZUUL_VOTING=True 2025-09-30 07:36:06.139553 | controller | BUILD_TIMEOUT=1800000 2025-09-30 07:36:06.139566 | controller | SELINUX_USE_CURRENT_RANGE= 2025-09-30 07:36:06.139579 | controller | SHLVL=1 2025-09-30 07:36:06.139593 | controller | ZUUL_PATCHSET=6442e37e2e901d750c5bf184fc25fe0337bd2e95 2025-09-30 07:36:06.139606 | controller | XDG_SESSION_ID=1 2025-09-30 07:36:06.139619 | controller | ZUUL_BRANCH=main 2025-09-30 07:36:06.139633 | controller | XDG_RUNTIME_DIR=/run/user/1000 2025-09-30 07:36:06.139646 | controller | SSH_CLIENT=38.102.83.114 60478 22 2025-09-30 07:36:06.139659 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/ 2025-09-30 07:36:06.139672 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima: 2025-09-30 07:36:06.139685 | controller | which_declare=declare -f 2025-09-30 07:36:06.139699 | controller | PATH=/home/zuul/.crc/bin/oc:/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin 2025-09-30 07:36:06.139713 | controller | SELINUX_LEVEL_REQUESTED= 2025-09-30 07:36:06.139726 | controller | ZUUL_CHANGE=3352 2025-09-30 07:36:06.139739 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus 2025-09-30 07:36:06.139752 | controller | ZUUL_UUID=b2302220a73b484ca6fe7dc378e1df74 2025-09-30 07:36:06.139765 | controller | BASH_FUNC_which%%=() { ( alias; 2025-09-30 07:36:06.139782 | controller | eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@ 2025-09-30 07:36:06.139795 | controller | } 2025-09-30 07:36:06.233317 | controller | ok: Runtime: 0:00:00.011148 2025-09-30 07:36:06.250375 | 2025-09-30 07:36:06.250508 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars] 2025-09-30 07:36:06.267067 | controller | skipping: Conditional result was False 2025-09-30 07:36:06.279278 | 2025-09-30 07:36:06.279408 | TASK [Symlink /home/zuul-worker/workspace] 2025-09-30 07:36:06.820602 | controller | skipping: Conditional result was False 2025-09-30 07:36:06.832758 | 2025-09-30 07:36:06.832892 | TASK [Ensure legacy workspace directory] 2025-09-30 07:36:07.284487 | controller | changed 2025-09-30 07:36:07.317318 | 2025-09-30 07:36:07.317383 | PLAY RECAP 2025-09-30 07:36:07.317437 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-09-30 07:36:07.317465 | 2025-09-30 07:36:07.420580 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master] 2025-09-30 07:36:07.422195 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/crc/podman.yaml@master] 2025-09-30 07:36:07.993346 | 2025-09-30 07:36:07.993453 | PLAY [all,!compute] 2025-09-30 07:36:08.012343 | 2025-09-30 07:36:08.012415 | TASK [Enable container-tools rhel-modules for c8/crc node] 2025-09-30 07:36:08.541760 | controller | skipping: Conditional result was False 2025-09-30 07:36:08.553900 | 2025-09-30 07:36:08.554068 | TASK [Install podman] 2025-09-30 07:36:08.612469 | controller | skipping: Conditional result was False 2025-09-30 07:36:08.630299 | 2025-09-30 07:36:08.630420 | TASK [Set var name for quay login zuul secret] 2025-09-30 07:36:08.687772 | controller | skipping: Conditional result was False 2025-09-30 07:36:08.695175 | 2025-09-30 07:36:08.695264 | TASK [Print the username] 2025-09-30 07:36:09.234206 | controller | skipping: Conditional result was False 2025-09-30 07:36:09.254474 | 2025-09-30 07:36:09.254642 | TASK [Fail when user or password is not set] 2025-09-30 07:36:09.291580 | controller | skipping: Conditional result was False 2025-09-30 07:36:09.303967 | 2025-09-30 07:36:09.304113 | TASK [Set vars for quay login] 2025-09-30 07:36:09.381297 | 2025-09-30 07:36:09.381509 | LOOP [Perform container registry login(s) with podman] 2025-09-30 07:36:09.438379 | 2025-09-30 07:36:09.438711 | LOOP [Perform container registry login(s) with buildah] 2025-09-30 07:36:09.495938 | 2025-09-30 07:36:09.496124 | TASK [Set Insecure registry for content provider] 2025-09-30 07:36:09.539722 | controller | skipping: Conditional result was False 2025-09-30 07:36:09.558775 | 2025-09-30 07:36:09.558831 | PLAY RECAP 2025-09-30 07:36:09.558874 | controller | ok: 0 changed: 0 unreachable: 0 failed: 0 skipped: 9 rescued: 0 ignored: 0 2025-09-30 07:36:09.558894 | 2025-09-30 07:36:09.660816 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/crc/podman.yaml@master] 2025-09-30 07:36:09.662397 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/crc/simple-start.yaml@master] 2025-09-30 07:36:10.286609 | 2025-09-30 07:36:10.286739 | PLAY [Prefer ipv4 over ipv6] 2025-09-30 07:36:10.305852 | 2025-09-30 07:36:10.305924 | TASK [Configure /etc/gai.conf to prever ipv4 over ipv6] 2025-09-30 07:36:10.370901 | controller | skipping: Conditional result was False 2025-09-30 07:36:10.399131 | 2025-09-30 07:36:10.399233 | PLAY [controller] 2025-09-30 07:36:10.420142 | 2025-09-30 07:36:10.420259 | TASK [Fail when openshift_pull_sec not provided] 2025-09-30 07:36:10.445222 | controller | skipping: Conditional result was False 2025-09-30 07:36:10.453285 | 2025-09-30 07:36:10.453373 | TASK [Clone repos in the job workspace] 2025-09-30 07:36:10.474250 | controller | ok 2025-09-30 07:36:10.495479 | 2025-09-30 07:36:10.495569 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-09-30 07:36:11.009489 | controller | ok 2025-09-30 07:36:11.023380 | 2025-09-30 07:36:11.023532 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-09-30 07:36:14.103071 | controller | Output suppressed because no_log was given 2025-09-30 07:36:14.116595 | 2025-09-30 07:36:14.116704 | TASK [Create pull-secret.txt file] 2025-09-30 07:36:15.906851 | controller | Output suppressed because no_log was given 2025-09-30 07:36:15.916999 | 2025-09-30 07:36:15.917131 | TASK [Apply CRC features and print image build date] 2025-09-30 07:36:15.947235 | controller | ok 2025-09-30 07:36:15.961184 | controller | included: /var/lib/zuul/builds/b2302220a73b484ca6fe7dc378e1df74/trusted/project_0/review.rdoproject.org/config/playbooks/crc/features.yaml 2025-09-30 07:36:15.973934 | 2025-09-30 07:36:15.974017 | TASK [Set additional parameters for crc - telemetry] 2025-09-30 07:36:16.513349 | controller | skipping: Conditional result was False 2025-09-30 07:36:16.547439 | 2025-09-30 07:36:16.547584 | TASK [Set additional parameters for crc - monitoring] 2025-09-30 07:36:17.085918 | controller | skipping: Conditional result was False 2025-09-30 07:36:17.097342 | 2025-09-30 07:36:17.097478 | TASK [Set minimum required memory to run the CRC when monitoring enabled] 2025-09-30 07:36:17.650464 | controller | skipping: Conditional result was False 2025-09-30 07:36:17.662743 | 2025-09-30 07:36:17.662905 | TASK [Set additional parameters for crc - enable microshift preset] 2025-09-30 07:36:18.218039 | controller | skipping: Conditional result was False 2025-09-30 07:36:18.229506 | 2025-09-30 07:36:18.229644 | TASK [Set additional parameters for crc - enable okd preset] 2025-09-30 07:36:18.787107 | controller | skipping: Conditional result was False 2025-09-30 07:36:18.799490 | 2025-09-30 07:36:18.799631 | TASK [Delete the cluster if there's a non-default bundle URL] 2025-09-30 07:36:19.353543 | controller | skipping: Conditional result was False 2025-09-30 07:36:19.366027 | 2025-09-30 07:36:19.366179 | TASK [Execute crc start command] 2025-09-30 07:41:53.430637 | controller | ok: Runtime: 0:05:33.342543 2025-09-30 07:41:53.442797 | 2025-09-30 07:41:53.442936 | TASK [Verify that OpenShift is up and running] 2025-09-30 07:41:53.472123 | controller | ok 2025-09-30 07:41:53.489853 | controller | included: /var/lib/zuul/builds/b2302220a73b484ca6fe7dc378e1df74/trusted/project_0/review.rdoproject.org/config/playbooks/crc/verify_openshift_start.yaml 2025-09-30 07:41:53.502458 | 2025-09-30 07:41:53.502540 | TASK [Create script to login and verify services] 2025-09-30 07:41:55.009935 | controller | changed 2025-09-30 07:41:55.022916 | 2025-09-30 07:41:55.023050 | TASK [Ensure that user is logged] 2025-09-30 07:41:55.489508 | controller | Checking login to the cluster 1... 2025-09-30 07:41:56.486568 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:41:56.561769 | controller | 2025-09-30 07:41:56.561848 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:41:56.568774 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:42:01.571546 | controller | Checking login to the cluster 2... 2025-09-30 07:42:01.741355 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:42:01.766708 | controller | 2025-09-30 07:42:01.766790 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:42:01.771987 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:42:06.776872 | controller | Checking login to the cluster 3... 2025-09-30 07:42:06.977390 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:42:07.005173 | controller | 2025-09-30 07:42:07.005288 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:42:07.013058 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:42:12.017788 | controller | Checking login to the cluster 4... 2025-09-30 07:42:12.173541 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:42:12.206985 | controller | 2025-09-30 07:42:12.207099 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:42:12.215247 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:42:17.217721 | controller | Checking login to the cluster 5... 2025-09-30 07:42:17.404236 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:42:17.421286 | controller | 2025-09-30 07:42:17.421346 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:42:17.430700 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:42:22.432866 | controller | Checking login to the cluster 6... 2025-09-30 07:42:22.599331 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:42:22.632705 | controller | 2025-09-30 07:42:22.632798 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:42:22.637795 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:42:27.640766 | controller | Checking login to the cluster 7... 2025-09-30 07:42:27.743192 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:42:27.765016 | controller | 2025-09-30 07:42:27.765099 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:42:27.769670 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:42:32.771929 | controller | Checking login to the cluster 8... 2025-09-30 07:42:32.921787 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:42:32.952946 | controller | 2025-09-30 07:42:32.953012 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:42:32.960114 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:42:37.963599 | controller | Checking login to the cluster 9... 2025-09-30 07:42:38.087226 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:42:38.102895 | controller | 2025-09-30 07:42:38.102953 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:42:38.107409 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:42:43.110807 | controller | Checking login to the cluster 10... 2025-09-30 07:42:43.295788 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:42:43.323184 | controller | 2025-09-30 07:42:43.323305 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:42:43.329866 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:42:48.334058 | controller | Checking login to the cluster 11... 2025-09-30 07:42:48.497289 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:42:48.513058 | controller | 2025-09-30 07:42:48.513099 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:42:48.524137 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:42:53.526403 | controller | Checking login to the cluster 12... 2025-09-30 07:42:53.645645 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:42:53.685480 | controller | 2025-09-30 07:42:53.685576 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:42:53.696395 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:42:58.699196 | controller | Checking login to the cluster 13... 2025-09-30 07:42:58.840763 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:42:58.868834 | controller | 2025-09-30 07:42:58.868928 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:42:58.873530 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:43:03.875491 | controller | Checking login to the cluster 14... 2025-09-30 07:43:04.008202 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:43:04.026830 | controller | 2025-09-30 07:43:04.026882 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:43:04.035461 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:43:09.038448 | controller | Checking login to the cluster 15... 2025-09-30 07:43:09.187133 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:43:09.208532 | controller | 2025-09-30 07:43:09.208596 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:43:09.215528 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:43:14.218611 | controller | Checking login to the cluster 16... 2025-09-30 07:43:14.392694 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:43:14.425703 | controller | 2025-09-30 07:43:14.425832 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:43:14.435801 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:43:19.440172 | controller | Checking login to the cluster 17... 2025-09-30 07:43:19.609140 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:43:19.639032 | controller | 2025-09-30 07:43:19.639155 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:43:19.647786 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:43:24.651546 | controller | Checking login to the cluster 18... 2025-09-30 07:43:24.797456 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:43:24.820943 | controller | 2025-09-30 07:43:24.821017 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:43:24.827416 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:43:29.830187 | controller | Checking login to the cluster 19... 2025-09-30 07:43:30.007559 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:43:30.026770 | controller | 2025-09-30 07:43:30.026858 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:43:30.033604 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:43:35.036185 | controller | Checking login to the cluster 20... 2025-09-30 07:43:35.166854 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:43:35.187694 | controller | 2025-09-30 07:43:35.187819 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:43:35.196980 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:43:40.199518 | controller | Checking login to the cluster 21... 2025-09-30 07:43:40.332592 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:43:40.394720 | controller | 2025-09-30 07:43:40.394800 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-09-30 07:43:40.404916 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:43:45.407352 | controller | Checking login to the cluster 22... 2025-09-30 07:43:45.540144 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:43:45.587732 | controller | 2025-09-30 07:43:45.587831 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-09-30 07:43:45.595706 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:43:50.598105 | controller | Checking login to the cluster 23... 2025-09-30 07:43:50.725380 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:43:50.773720 | controller | 2025-09-30 07:43:50.773843 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-09-30 07:43:50.783302 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:43:55.786785 | controller | Checking login to the cluster 24... 2025-09-30 07:43:55.905021 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:43:55.991055 | controller | 2025-09-30 07:43:55.991181 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-09-30 07:43:56.002492 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:44:01.005440 | controller | Checking login to the cluster 25... 2025-09-30 07:44:01.203222 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:44:01.352423 | controller | 2025-09-30 07:44:01.352509 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-09-30 07:44:01.357669 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:44:06.362152 | controller | Checking login to the cluster 26... 2025-09-30 07:44:06.555538 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:44:06.644559 | controller | 2025-09-30 07:44:06.644654 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-09-30 07:44:06.654074 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:44:11.658049 | controller | Checking login to the cluster 27... 2025-09-30 07:44:11.821330 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:44:11.921397 | controller | 2025-09-30 07:44:11.921486 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-09-30 07:44:11.932040 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:44:16.935196 | controller | Checking login to the cluster 28... 2025-09-30 07:44:17.091363 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:44:17.215193 | controller | 2025-09-30 07:44:17.215291 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-09-30 07:44:17.225228 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:44:22.228543 | controller | Checking login to the cluster 29... 2025-09-30 07:44:22.354230 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:44:22.457642 | controller | 2025-09-30 07:44:22.457760 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-09-30 07:44:22.467535 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:44:27.473014 | controller | Checking login to the cluster 30... 2025-09-30 07:44:27.638081 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:44:27.743547 | controller | 2025-09-30 07:44:27.743676 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:44:27.758833 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:44:32.763197 | controller | Checking login to the cluster 31... 2025-09-30 07:44:32.898631 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:44:32.975786 | controller | 2025-09-30 07:44:32.975929 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:44:32.985502 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:44:37.988919 | controller | Checking login to the cluster 32... 2025-09-30 07:44:38.173205 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:44:38.206032 | controller | 2025-09-30 07:44:38.206101 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:44:38.212885 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:44:43.216204 | controller | Checking login to the cluster 33... 2025-09-30 07:44:43.386074 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:44:43.429729 | controller | 2025-09-30 07:44:43.429836 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:44:43.440051 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:44:48.443944 | controller | Checking login to the cluster 34... 2025-09-30 07:44:48.725506 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:44:50.741939 | controller | 2025-09-30 07:44:50.742093 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:44:50.753573 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:44:55.756970 | controller | Checking login to the cluster 35... 2025-09-30 07:44:55.879349 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:44:56.024689 | controller | 2025-09-30 07:44:56.024776 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:44:56.034934 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:45:01.038185 | controller | Checking login to the cluster 36... 2025-09-30 07:45:01.933920 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:45:02.990819 | controller | 2025-09-30 07:45:02.990894 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:45:02.996698 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:45:08.003548 | controller | Checking login to the cluster 37... 2025-09-30 07:45:09.688660 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:45:13.575473 | controller | 2025-09-30 07:45:13.575561 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:45:13.580268 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:45:18.582620 | controller | Checking login to the cluster 38... 2025-09-30 07:45:18.777077 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:45:18.817602 | controller | 2025-09-30 07:45:18.817630 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:45:18.822064 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:45:23.824072 | controller | Checking login to the cluster 39... 2025-09-30 07:45:24.021074 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:45:24.055986 | controller | 2025-09-30 07:45:24.056055 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:45:24.066849 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:45:29.071692 | controller | Checking login to the cluster 40... 2025-09-30 07:45:29.212335 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:45:29.233004 | controller | 2025-09-30 07:45:29.233038 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:45:29.237976 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:45:34.241381 | controller | Checking login to the cluster 41... 2025-09-30 07:45:34.363814 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:45:34.380804 | controller | 2025-09-30 07:45:34.380844 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:45:34.386985 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:45:39.389854 | controller | Checking login to the cluster 42... 2025-09-30 07:45:39.632256 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:45:39.657295 | controller | 2025-09-30 07:45:39.657398 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 07:45:39.664512 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 07:45:44.668043 | controller | Checking login to the cluster 43... 2025-09-30 07:45:44.805827 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 07:45:45.398165 | controller | 2025-09-30 07:45:45.398251 | controller | Login successful. 2025-09-30 07:45:45.442503 | controller | 2025-09-30 07:45:45.442597 | controller | You have access to 65 projects, the list has been suppressed. You can list all projects with 'oc projects' 2025-09-30 07:45:45.465555 | controller | 2025-09-30 07:45:45.465605 | controller | Using project "default". 2025-09-30 07:45:45.849880 | controller | changed 2025-09-30 07:45:45.865787 | 2025-09-30 07:45:45.865929 | TASK [Delete all openshift-marketplace pods] 2025-09-30 07:45:47.379031 | controller | pod "certified-operators-f8szs" deleted 2025-09-30 07:45:47.409935 | controller | pod "certified-operators-px8h4" deleted 2025-09-30 07:45:47.441353 | controller | pod "community-operators-5zsqg" deleted 2025-09-30 07:45:47.474003 | controller | pod "community-operators-b2sz5" deleted 2025-09-30 07:45:47.496238 | controller | pod "marketplace-operator-79b997595-d2lpl" deleted 2025-09-30 07:45:47.525292 | controller | pod "redhat-marketplace-cx2t2" deleted 2025-09-30 07:45:47.555433 | controller | pod "redhat-marketplace-ps6xk" deleted 2025-09-30 07:45:47.609417 | controller | pod "redhat-operators-48cl2" deleted 2025-09-30 07:45:47.672066 | controller | pod "redhat-operators-tqxl9" deleted 2025-09-30 07:46:26.965877 | controller | ok 2025-09-30 07:46:26.977311 | 2025-09-30 07:46:26.977438 | TASK [Copy script ensure_services_up.sh] 2025-09-30 07:46:27.025478 | controller | skipping: Conditional result was False 2025-09-30 07:46:27.037849 | 2025-09-30 07:46:27.037977 | TASK [Ensure all pods are up and running] 2025-09-30 07:46:27.588452 | controller | skipping: Conditional result was False 2025-09-30 07:46:27.600580 | 2025-09-30 07:46:27.600745 | TASK [Check if there is a image build date file] 2025-09-30 07:46:28.299857 | controller | ok 2025-09-30 07:46:28.311114 | 2025-09-30 07:46:28.311238 | TASK [Print image date if available] 2025-09-30 07:46:28.893513 | controller | Tue Apr 1 06:17:46 PM EDT 2025 2025-09-30 07:46:29.357342 | controller | changed 2025-09-30 07:46:29.368860 | 2025-09-30 07:46:29.369010 | TASK [Fix machineconfigpool] 2025-09-30 07:46:29.436001 | controller | skipping: Conditional result was False 2025-09-30 07:46:29.449028 | 2025-09-30 07:46:29.449181 | TASK [Show available nodes] 2025-09-30 07:46:32.389728 | controller | NAME STATUS ROLES AGE VERSION 2025-09-30 07:46:32.392192 | controller | crc Ready control-plane,master,worker 219d v1.31.5 2025-09-30 07:46:32.503589 | controller | ok: Runtime: 0:00:02.541040 2025-09-30 07:46:32.514615 | 2025-09-30 07:46:32.514770 | TASK [Configure insecure registry inside crc vm] 2025-09-30 07:46:32.552795 | controller | skipping: Conditional result was False 2025-09-30 07:46:32.564982 | 2025-09-30 07:46:32.565110 | TASK [Catch CRC IP] 2025-09-30 07:46:33.039539 | controller | 192.168.130.11 2025-09-30 07:46:33.113465 | controller | changed 2025-09-30 07:46:33.164698 | 2025-09-30 07:46:33.164840 | TASK [Check if id_ed25519 key exists] 2025-09-30 07:46:33.567474 | controller | ok 2025-09-30 07:46:33.579233 | 2025-09-30 07:46:33.579362 | TASK [Set fact if new keypair exists] 2025-09-30 07:46:33.627147 | controller | ok 2025-09-30 07:46:33.637545 | 2025-09-30 07:46:33.637712 | TASK [Run crc] 2025-09-30 07:46:37.500765 | controller | 2025-09-30 07:46:48.419480 | controller | PLAY [OpenShift secret copy and CRC securitization] **************************** 2025-09-30 07:46:48.419556 | controller | 2025-09-30 07:46:48.419563 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 07:46:48.419580 | controller | [WARNING]: Platform linux on host 192.168.130.11 is using the discovered Python 2025-09-30 07:46:48.467820 | controller | interpreter at /usr/bin/python3.9, but future installation of another Python 2025-09-30 07:46:48.467893 | controller | interpreter could change the meaning of that path. See 2025-09-30 07:46:48.467910 | controller | https://docs.ansible.com/ansible- 2025-09-30 07:46:48.467918 | controller | core/2.14/reference_appendices/interpreter_discovery.html for more information. 2025-09-30 07:46:48.467935 | controller | ok: [192.168.130.11] 2025-09-30 07:46:50.451724 | controller | 2025-09-30 07:46:50.451787 | controller | TASK [Copy pull-secret] ******************************************************** 2025-09-30 07:46:50.451804 | controller | changed: [192.168.130.11] 2025-09-30 07:46:52.231484 | controller | 2025-09-30 07:46:52.231554 | controller | TASK [Add crio config] ********************************************************* 2025-09-30 07:46:52.231579 | controller | changed: [192.168.130.11] 2025-09-30 07:47:04.128095 | controller | 2025-09-30 07:47:04.128193 | controller | TASK [Restart crio to pickup new configuration] ******************************** 2025-09-30 07:47:04.128226 | controller | changed: [192.168.130.11] 2025-09-30 07:47:04.183962 | controller | 2025-09-30 07:47:04.184013 | controller | PLAY RECAP ********************************************************************* 2025-09-30 07:47:04.184022 | controller | 192.168.130.11 : ok=4 changed=3 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 2025-09-30 07:47:04.184028 | controller | 2025-09-30 07:47:04.223467 | controller | changed 2025-09-30 07:47:04.235199 | 2025-09-30 07:47:04.235333 | TASK [Set slower etcd profile] 2025-09-30 07:47:04.317317 | controller | ok 2025-09-30 07:47:04.358550 | 2025-09-30 07:47:04.358654 | TASK [prepare-crc-cloud : Set slower profile] 2025-09-30 07:47:04.897047 | controller | etcd.operator.openshift.io/cluster patched 2025-09-30 07:47:05.397713 | controller | ok 2025-09-30 07:47:05.410397 | 2025-09-30 07:47:05.410531 | TASK [prepare-crc-cloud : Wait 30 seconds to apply] 2025-09-30 07:47:35.460278 | controller | ok 2025-09-30 07:47:35.471321 | 2025-09-30 07:47:35.471454 | TASK [prepare-crc-cloud : Get pod phase status] 2025-09-30 07:52:49.701510 | controller | ok 2025-09-30 07:52:49.724055 | 2025-09-30 07:52:49.724144 | TASK [Set limit for disk usage - IOPS and Read/Write] 2025-09-30 07:52:49.796363 | controller | ok 2025-09-30 07:52:49.805251 | controller | included: /var/lib/zuul/builds/b2302220a73b484ca6fe7dc378e1df74/trusted/project_0/review.rdoproject.org/config/playbooks/crc/limit-disk-usage.yaml 2025-09-30 07:52:49.817254 | 2025-09-30 07:52:49.817316 | TASK [Set facts for disk limitation] 2025-09-30 07:52:49.847180 | controller | ok 2025-09-30 07:52:49.853738 | 2025-09-30 07:52:49.853796 | TASK [Print limits for the disk] 2025-09-30 07:52:49.893425 | controller | ok: Set limit to crc VM to the vda disk: iops 18000 read/write 262144000 2025-09-30 07:52:49.900010 | 2025-09-30 07:52:49.900071 | TASK [Set limit to crc VM to the vda disk] 2025-09-30 07:52:50.347702 | controller | 2025-09-30 07:52:50.431887 | controller | changed 2025-09-30 07:52:50.444075 | 2025-09-30 07:52:50.444203 | TASK [Pause machineconfigpool] 2025-09-30 07:52:50.530361 | controller | ok 2025-09-30 07:52:50.561455 | 2025-09-30 07:52:50.561527 | LOOP [prepare-crc-cloud : Pause the machineconfig configuration if mcp is not needed] 2025-09-30 07:52:51.171289 | controller | ok 2025-09-30 07:52:51.713487 | controller | ok 2025-09-30 07:52:51.733231 | 2025-09-30 07:52:51.733366 | TASK [prepare-crc-cloud : Print current machineconfigpool] 2025-09-30 07:52:52.240427 | controller | NAME CONFIG UPDATED UPDATING DEGRADED MACHINECOUNT READYMACHINECOUNT UPDATEDMACHINECOUNT DEGRADEDMACHINECOUNT AGE 2025-09-30 07:52:52.246860 | controller | master rendered-master-95020e6e79c40b4dd095817bccfc5060 True False False 1 1 1 0 219d 2025-09-30 07:52:52.246911 | controller | worker rendered-worker-594cc07c9feefb5e37f2530ac457d36c True False False 0 0 0 0 219d 2025-09-30 07:52:52.289942 | controller | ok 2025-09-30 07:52:52.336753 | 2025-09-30 07:52:52.336836 | PLAY [Set IOPS and Read/Write disk limitation excluding controller] 2025-09-30 07:52:52.336964 | 2025-09-30 07:52:52.336999 | PLAY RECAP 2025-09-30 07:52:52.337046 | controller | ok: 25 changed: 10 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 0 2025-09-30 07:52:52.337073 | 2025-09-30 07:52:52.443205 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/crc/simple-start.yaml@master] 2025-09-30 07:52:52.444753 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/read_global_vars.yml@main] 2025-09-30 07:52:53.009037 | 2025-09-30 07:52:53.009144 | PLAY [Load global variables] 2025-09-30 07:52:53.029100 | 2025-09-30 07:52:53.029171 | TASK [Read group_vars all file] 2025-09-30 07:52:53.048475 | controller | ok 2025-09-30 07:52:53.064026 | 2025-09-30 07:52:53.064096 | TASK [cifmw_helpers : Check if file is available] 2025-09-30 07:52:53.479227 | controller | ok 2025-09-30 07:52:53.484436 | 2025-09-30 07:52:53.484504 | TASK [cifmw_helpers : Read vars] 2025-09-30 07:52:53.514377 | 2025-09-30 07:52:53.514493 | LOOP [cifmw_helpers : Set vars as fact] 2025-09-30 07:52:53.592279 | 2025-09-30 07:52:53.592429 | PLAY RECAP 2025-09-30 07:52:53.592472 | controller | ok: 1 changed: 0 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-09-30 07:52:53.592492 | 2025-09-30 07:52:53.673053 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/read_global_vars.yml@main] 2025-09-30 07:52:53.673864 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main] 2025-09-30 07:52:54.191737 | 2025-09-30 07:52:54.191843 | PLAY [Run ci/playbooks/dump_zuul_data.yml] 2025-09-30 07:52:54.212026 | 2025-09-30 07:52:54.212128 | TASK [Create zuul-output directory] 2025-09-30 07:52:54.706392 | controller | changed 2025-09-30 07:52:54.717448 | 2025-09-30 07:52:54.717597 | TASK [Slurp Zuul inventory test] 2025-09-30 07:52:55.101303 | controller -> localhost | ok 2025-09-30 07:52:55.107875 | 2025-09-30 07:52:55.107943 | TASK [Save zuul inventory] 2025-09-30 07:52:56.832319 | controller | changed 2025-09-30 07:52:56.838600 | 2025-09-30 07:52:56.838784 | TASK [Save zuul vars without the change_message] 2025-09-30 07:52:58.247915 | controller | changed 2025-09-30 07:52:58.285223 | 2025-09-30 07:52:58.285303 | PLAY RECAP 2025-09-30 07:52:58.285364 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-09-30 07:52:58.285396 | 2025-09-30 07:52:58.377479 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main] 2025-09-30 07:52:58.378528 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main] 2025-09-30 07:52:59.080081 | 2025-09-30 07:52:59.080200 | PLAY [Run ci/playbooks/molecule-prepare.yml] 2025-09-30 07:52:59.101525 | 2025-09-30 07:52:59.101609 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh] 2025-09-30 07:52:59.121094 | controller | ok 2025-09-30 07:52:59.138348 | 2025-09-30 07:52:59.138437 | TASK [mirror-info-fork : Set mirror_fqdn if not defined] 2025-09-30 07:52:59.182908 | controller | skipping: Conditional result was False 2025-09-30 07:52:59.188823 | 2025-09-30 07:52:59.188893 | TASK [mirror-info-fork : Create /etc/ci] 2025-09-30 07:52:59.719896 | controller | ok 2025-09-30 07:52:59.732407 | 2025-09-30 07:52:59.732554 | TASK [mirror-info-fork : Install ci_mirror script] 2025-09-30 07:53:01.053703 | controller | ok 2025-09-30 07:53:01.083402 | 2025-09-30 07:53:01.083539 | TASK [Prepare workspace] 2025-09-30 07:53:01.105545 | controller | ok 2025-09-30 07:53:01.128878 | 2025-09-30 07:53:01.128968 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-09-30 07:53:01.604144 | controller | ok 2025-09-30 07:53:01.616890 | 2025-09-30 07:53:01.617029 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-09-30 07:53:02.701709 | controller | Output suppressed because no_log was given 2025-09-30 07:53:02.720343 | 2025-09-30 07:53:02.720430 | LOOP [Create zuul-output directory] 2025-09-30 07:53:03.153511 | controller | changed: "/home/zuul/ci-framework-data/logs" 2025-09-30 07:53:03.476952 | controller | ok: "/home/zuul/zuul-output/logs" 2025-09-30 07:53:03.498569 | 2025-09-30 07:53:03.498791 | TASK [Install required packages] 2025-09-30 07:53:05.883833 | controller | ok: Nothing to do 2025-09-30 07:53:05.895027 | 2025-09-30 07:53:05.895157 | TASK [Install venv] 2025-09-30 07:54:08.162419 | controller | changed 2025-09-30 07:54:08.216135 | 2025-09-30 07:54:08.216235 | PLAY RECAP 2025-09-30 07:54:08.216291 | controller | ok: 7 changed: 3 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-09-30 07:54:08.216319 | 2025-09-30 07:54:08.319770 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main] 2025-09-30 07:54:08.321458 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main] 2025-09-30 07:54:08.890404 | 2025-09-30 07:54:08.890513 | PLAY [Run ci/playbooks/molecule-test.yml] 2025-09-30 07:54:08.911393 | 2025-09-30 07:54:08.911467 | TASK [Gather required facts] 2025-09-30 07:54:09.680331 | controller | ok 2025-09-30 07:54:09.700598 | 2025-09-30 07:54:09.700900 | TASK [Load environment var if instructed to] 2025-09-30 07:54:09.732097 | controller | skipping: Conditional result was False 2025-09-30 07:54:09.747576 | 2025-09-30 07:54:09.747726 | TASK [Run molecule] 2025-09-30 07:54:11.051644 | controller | INFO Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml 2025-09-30 07:54:11.298867 | controller | INFO Running default > destroy 2025-09-30 07:54:11.299156 | controller | WARNING Skipping, instances are delegated. 2025-09-30 07:54:11.312508 | controller | INFO Running default > create 2025-09-30 07:54:11.313384 | controller | WARNING Skipping, instances are delegated. 2025-09-30 07:54:11.325201 | controller | INFO Running default > converge 2025-09-30 07:54:12.208878 | controller | 2025-09-30 07:54:12.209062 | controller | PLAY [Converge] **************************************************************** 2025-09-30 07:54:12.209315 | controller | 2025-09-30 07:54:12.209572 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 07:54:12.209794 | controller | Tuesday 30 September 2025 07:54:12 +0000 (0:00:00.011) 0:00:00.011 ***** 2025-09-30 07:54:13.290918 | controller | ok: [instance] 2025-09-30 07:54:13.291142 | controller | 2025-09-30 07:54:13.291750 | controller | TASK [Add crc hostname with it's IP to /etc/hosts] ***************************** 2025-09-30 07:54:13.291773 | controller | Tuesday 30 September 2025 07:54:13 +0000 (0:00:01.082) 0:00:01.094 ***** 2025-09-30 07:54:13.786334 | controller | changed: [instance] 2025-09-30 07:54:13.786621 | controller | 2025-09-30 07:54:13.835010 | controller | TASK [Check if new ssh keypair exists] ***************************************** 2025-09-30 07:54:13.835061 | controller | Tuesday 30 September 2025 07:54:13 +0000 (0:00:00.494) 0:00:01.589 ***** 2025-09-30 07:54:13.835085 | controller | 2025-09-30 07:54:13.835261 | controller | TASK [recognize_ssh_keypair : Check if id_ed25519 key exists] ****************** 2025-09-30 07:54:13.835331 | controller | Tuesday 30 September 2025 07:54:13 +0000 (0:00:00.049) 0:00:01.638 ***** 2025-09-30 07:54:14.229434 | controller | ok: [instance] 2025-09-30 07:54:14.229559 | controller | 2025-09-30 07:54:14.230229 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair exists] ****************** 2025-09-30 07:54:14.230309 | controller | Tuesday 30 September 2025 07:54:14 +0000 (0:00:00.394) 0:00:02.033 ***** 2025-09-30 07:54:14.251845 | controller | ok: [instance] 2025-09-30 07:54:14.251923 | controller | 2025-09-30 07:54:14.252022 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair does not exists] ********* 2025-09-30 07:54:14.252135 | controller | Tuesday 30 September 2025 07:54:14 +0000 (0:00:00.022) 0:00:02.056 ***** 2025-09-30 07:54:14.275571 | controller | skipping: [instance] 2025-09-30 07:54:14.275646 | controller | 2025-09-30 07:54:14.275841 | controller | TASK [Add the crc host dynamically] ******************************************** 2025-09-30 07:54:14.275952 | controller | Tuesday 30 September 2025 07:54:14 +0000 (0:00:00.023) 0:00:02.079 ***** 2025-09-30 07:54:14.296985 | controller | changed: [instance] 2025-09-30 07:54:14.297057 | controller | 2025-09-30 07:54:14.297229 | controller | TASK [Fetch crc network facts] ************************************************* 2025-09-30 07:54:14.297393 | controller | Tuesday 30 September 2025 07:54:14 +0000 (0:00:00.021) 0:00:02.101 ***** 2025-09-30 07:54:19.358947 | controller | ok: [instance -> crc] 2025-09-30 07:54:19.359014 | controller | 2025-09-30 07:54:19.359122 | controller | TASK [Load shared variables] *************************************************** 2025-09-30 07:54:19.359228 | controller | Tuesday 30 September 2025 07:54:19 +0000 (0:00:05.061) 0:00:07.163 ***** 2025-09-30 07:54:19.383850 | controller | ok: [instance] 2025-09-30 07:54:19.383905 | controller | 2025-09-30 07:54:19.384057 | controller | TASK [Call ci_multus role] ***************************************************** 2025-09-30 07:54:19.384174 | controller | Tuesday 30 September 2025 07:54:19 +0000 (0:00:00.025) 0:00:07.188 ***** 2025-09-30 07:54:19.430037 | controller | 2025-09-30 07:54:19.430121 | controller | TASK [ci_multus : Create manifests directory] ********************************** 2025-09-30 07:54:19.430228 | controller | Tuesday 30 September 2025 07:54:19 +0000 (0:00:00.045) 0:00:07.234 ***** 2025-09-30 07:54:19.800399 | controller | changed: [instance] 2025-09-30 07:54:19.800475 | controller | 2025-09-30 07:54:19.800667 | controller | TASK [networking_mapper : Check for Networking Environment Definition file existence] *** 2025-09-30 07:54:19.800827 | controller | Tuesday 30 September 2025 07:54:19 +0000 (0:00:00.369) 0:00:07.603 ***** 2025-09-30 07:54:19.838390 | controller | skipping: [instance] 2025-09-30 07:54:19.838462 | controller | 2025-09-30 07:54:19.838629 | controller | TASK [networking_mapper : Check for Networking Definition file existance] ****** 2025-09-30 07:54:19.838758 | controller | Tuesday 30 September 2025 07:54:19 +0000 (0:00:00.037) 0:00:07.641 ***** 2025-09-30 07:54:19.873685 | controller | skipping: [instance] 2025-09-30 07:54:19.873762 | controller | 2025-09-30 07:54:19.873883 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************ 2025-09-30 07:54:19.874016 | controller | Tuesday 30 September 2025 07:54:19 +0000 (0:00:00.035) 0:00:07.677 ***** 2025-09-30 07:54:19.914013 | controller | skipping: [instance] 2025-09-30 07:54:19.914215 | controller | 2025-09-30 07:54:19.915361 | controller | TASK [networking_mapper : Set cifmw_networking_env_definition is present] ****** 2025-09-30 07:54:19.971825 | controller | Tuesday 30 September 2025 07:54:19 +0000 (0:00:00.040) 0:00:07.717 ***** 2025-09-30 07:54:19.971896 | controller | skipping: [instance] 2025-09-30 07:54:19.971990 | controller | 2025-09-30 07:54:19.972253 | controller | TASK [ci_multus : Gather network layout from OCP host or default networks] ***** 2025-09-30 07:54:19.972505 | controller | Tuesday 30 September 2025 07:54:19 +0000 (0:00:00.057) 0:00:07.775 ***** 2025-09-30 07:54:20.028537 | controller | ok: [instance] 2025-09-30 07:54:20.028702 | controller | 2025-09-30 07:54:20.028960 | controller | TASK [ci_multus : Merge any available multus net info patches] ***************** 2025-09-30 07:54:20.029161 | controller | Tuesday 30 September 2025 07:54:20 +0000 (0:00:00.057) 0:00:07.832 ***** 2025-09-30 07:54:20.247749 | controller | ok: [instance] => (item={'default': {'interface_name': 'eth0', 'network_name': 'default', 'gw_v4': '192.168.122.1', 'network_v4': '192.168.122.0/24', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}], 'multus_type': 'bridge'}}}, 'deny_network': {'gw_v4': '192.168.122.1', 'network_name': 'deny_network', 'network_v4': '192.168.122.0/24', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}], 'multus_type': 'bridge'}}}, 'not_allowed_network': {'gw_v4': '192.168.122.1', 'network_name': 'not_allowed_network', 'network_v4': '192.168.122.0/24', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}], 'multus_type': 'bridge'}}}, 'no_multus_network': {'gw_v4': '192.168.122.1', 'network_name': 'patchnetwork', 'network_v4': '192.168.122.0/24', 'interface_name': 'eth2'}}) 2025-09-30 07:54:20.248100 | controller | ok: [instance] => (item={'patchnetwork': {'gw_v4': '192.168.122.1', 'interface_name': 'eth2', 'network_name': 'patchnetwork', 'network_v4': '192.168.122.0/24', 'tools': {'multus': {'ipv4_ranges': [{'end': '192.168.122.70', 'start': '192.168.122.30'}], 'multus_type': 'macvlan'}}}}) 2025-09-30 07:54:20.248419 | controller | ok: [instance] => (item={'bridge-to-linux-bridge': {'gw_v4': '192.168.122.1', 'interface_name': 'eth1', 'network_name': 'bridge-to-linux-bridge', 'network_v4': '192.168.122.0/24', 'tools': {'multus': {'ipv4_ranges': [{'end': '192.168.122.70', 'start': '192.168.122.30'}], 'multus_attach': 'linux-bridge', 'multus_type': 'bridge'}}}}) 2025-09-30 07:54:20.248758 | controller | 2025-09-30 07:54:20.249037 | controller | TASK [ci_multus : Remove any networks without Multus networking defined] ******* 2025-09-30 07:54:20.249393 | controller | Tuesday 30 September 2025 07:54:20 +0000 (0:00:00.217) 0:00:08.050 ***** 2025-09-30 07:54:20.362594 | controller | ok: [instance] 2025-09-30 07:54:20.362655 | controller | 2025-09-30 07:54:20.362769 | controller | TASK [ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined] *** 2025-09-30 07:54:20.362886 | controller | Tuesday 30 September 2025 07:54:20 +0000 (0:00:00.116) 0:00:08.166 ***** 2025-09-30 07:54:20.453981 | controller | ok: [instance] 2025-09-30 07:54:20.454023 | controller | 2025-09-30 07:54:20.456372 | controller | TASK [ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined] *** 2025-09-30 07:54:20.526881 | controller | Tuesday 30 September 2025 07:54:20 +0000 (0:00:00.091) 0:00:08.258 ***** 2025-09-30 07:54:20.526932 | controller | ok: [instance] 2025-09-30 07:54:20.527026 | controller | 2025-09-30 07:54:20.527038 | controller | TASK [ci_multus : Render NetworkAttachmenktDefinition manifests] *************** 2025-09-30 07:54:20.527136 | controller | Tuesday 30 September 2025 07:54:20 +0000 (0:00:00.072) 0:00:08.331 ***** 2025-09-30 07:54:21.154844 | controller | changed: [instance] 2025-09-30 07:54:21.154994 | controller | 2025-09-30 07:54:21.155385 | controller | TASK [ci_multus : Create the multus namespace] ********************************* 2025-09-30 07:54:21.155844 | controller | Tuesday 30 September 2025 07:54:21 +0000 (0:00:00.626) 0:00:08.957 ***** 2025-09-30 07:54:22.200877 | controller | changed: [instance] 2025-09-30 07:54:22.201400 | controller | 2025-09-30 07:54:22.201427 | controller | TASK [ci_multus : Apply network attachment definition manifests] *************** 2025-09-30 07:54:22.201522 | controller | Tuesday 30 September 2025 07:54:22 +0000 (0:00:01.044) 0:00:10.002 ***** 2025-09-30 07:54:23.043075 | controller | changed: [instance] 2025-09-30 07:54:23.043168 | controller | 2025-09-30 07:54:23.043290 | controller | PLAY RECAP ********************************************************************* 2025-09-30 07:54:23.043533 | controller | instance : ok=16 changed=6 unreachable=0 failed=0 skipped=5 rescued=0 ignored=0 2025-09-30 07:54:23.043887 | controller | 2025-09-30 07:54:23.044056 | controller | Tuesday 30 September 2025 07:54:23 +0000 (0:00:00.844) 0:00:10.847 ***** 2025-09-30 07:54:23.044072 | controller | =============================================================================== 2025-09-30 07:54:23.044206 | controller | Fetch crc network facts ------------------------------------------------- 5.06s 2025-09-30 07:54:23.044363 | controller | Gathering Facts --------------------------------------------------------- 1.08s 2025-09-30 07:54:23.044571 | controller | ci_multus : Create the multus namespace --------------------------------- 1.04s 2025-09-30 07:54:23.044639 | controller | ci_multus : Apply network attachment definition manifests --------------- 0.84s 2025-09-30 07:54:23.044791 | controller | ci_multus : Render NetworkAttachmenktDefinition manifests --------------- 0.63s 2025-09-30 07:54:23.045029 | controller | Add crc hostname with it's IP to /etc/hosts ----------------------------- 0.49s 2025-09-30 07:54:23.045133 | controller | recognize_ssh_keypair : Check if id_ed25519 key exists ------------------ 0.39s 2025-09-30 07:54:23.045301 | controller | ci_multus : Create manifests directory ---------------------------------- 0.37s 2025-09-30 07:54:23.045428 | controller | ci_multus : Merge any available multus net info patches ----------------- 0.22s 2025-09-30 07:54:23.045565 | controller | ci_multus : Remove any networks without Multus networking defined ------- 0.12s 2025-09-30 07:54:23.045697 | controller | ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined --- 0.09s 2025-09-30 07:54:23.045854 | controller | ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined --- 0.07s 2025-09-30 07:54:23.045983 | controller | networking_mapper : Set cifmw_networking_env_definition is present ------ 0.06s 2025-09-30 07:54:23.046167 | controller | ci_multus : Gather network layout from OCP host or default networks ----- 0.06s 2025-09-30 07:54:23.046388 | controller | Check if new ssh keypair exists ----------------------------------------- 0.05s 2025-09-30 07:54:23.046523 | controller | Call ci_multus role ----------------------------------------------------- 0.05s 2025-09-30 07:54:23.046659 | controller | networking_mapper : Load the Networking Definition from file ------------ 0.04s 2025-09-30 07:54:23.046803 | controller | networking_mapper : Check for Networking Environment Definition file existence --- 0.04s 2025-09-30 07:54:23.046955 | controller | networking_mapper : Check for Networking Definition file existance ------ 0.04s 2025-09-30 07:54:23.047090 | controller | Load shared variables --------------------------------------------------- 0.03s 2025-09-30 07:54:23.150458 | controller | INFO Running default > verify 2025-09-30 07:54:23.150880 | controller | INFO Running Ansible Verifier 2025-09-30 07:54:23.641818 | controller | 2025-09-30 07:54:23.642634 | controller | PLAY [Verify] ****************************************************************** 2025-09-30 07:54:23.645201 | controller | 2025-09-30 07:54:24.856497 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 07:54:24.856554 | controller | Tuesday 30 September 2025 07:54:23 +0000 (0:00:00.015) 0:00:00.015 ***** 2025-09-30 07:54:24.856580 | controller | ok: [instance] 2025-09-30 07:54:24.856610 | controller | 2025-09-30 07:54:24.856842 | controller | TASK [Load shared variables] *************************************************** 2025-09-30 07:54:24.857049 | controller | Tuesday 30 September 2025 07:54:24 +0000 (0:00:01.214) 0:00:01.229 ***** 2025-09-30 07:54:24.898173 | controller | ok: [instance] 2025-09-30 07:54:24.898417 | controller | 2025-09-30 07:54:24.898666 | controller | TASK [Fetch files stat results] ************************************************ 2025-09-30 07:54:24.898918 | controller | Tuesday 30 September 2025 07:54:24 +0000 (0:00:00.041) 0:00:01.271 ***** 2025-09-30 07:54:25.296223 | controller | ok: [instance] 2025-09-30 07:54:25.296306 | controller | 2025-09-30 07:54:25.296444 | controller | TASK [Assert that expected file exist] ***************************************** 2025-09-30 07:54:25.296584 | controller | Tuesday 30 September 2025 07:54:25 +0000 (0:00:00.397) 0:00:01.669 ***** 2025-09-30 07:54:25.321326 | controller | ok: [instance] => changed=false 2025-09-30 07:54:25.321450 | controller | msg: All assertions passed 2025-09-30 07:54:25.321576 | controller | 2025-09-30 07:54:25.321714 | controller | TASK [Fetch file content] ****************************************************** 2025-09-30 07:54:25.321875 | controller | Tuesday 30 September 2025 07:54:25 +0000 (0:00:00.026) 0:00:01.695 ***** 2025-09-30 07:54:25.679648 | controller | ok: [instance] 2025-09-30 07:54:25.679795 | controller | 2025-09-30 07:54:25.680007 | controller | TASK [Set _ci_multus_nad variable] ********************************************* 2025-09-30 07:54:25.680225 | controller | Tuesday 30 September 2025 07:54:25 +0000 (0:00:00.357) 0:00:02.053 ***** 2025-09-30 07:54:25.732761 | controller | ok: [instance] 2025-09-30 07:54:25.732953 | controller | 2025-09-30 07:54:25.733207 | controller | TASK [Assert expected number of Network Attachment Definitions are created] **** 2025-09-30 07:54:25.733467 | controller | Tuesday 30 September 2025 07:54:25 +0000 (0:00:00.052) 0:00:02.105 ***** 2025-09-30 07:54:25.821345 | controller | ok: [instance] 2025-09-30 07:54:25.821444 | controller | 2025-09-30 07:54:25.821697 | controller | PLAY RECAP ********************************************************************* 2025-09-30 07:54:25.821946 | controller | instance : ok=7 changed=0 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 2025-09-30 07:54:25.822155 | controller | 2025-09-30 07:54:25.822424 | controller | Tuesday 30 September 2025 07:54:25 +0000 (0:00:00.089) 0:00:02.195 ***** 2025-09-30 07:54:25.822637 | controller | =============================================================================== 2025-09-30 07:54:25.822848 | controller | Gathering Facts --------------------------------------------------------- 1.21s 2025-09-30 07:54:25.823070 | controller | Fetch files stat results ------------------------------------------------ 0.40s 2025-09-30 07:54:25.823325 | controller | Fetch file content ------------------------------------------------------ 0.36s 2025-09-30 07:54:25.823558 | controller | Assert expected number of Network Attachment Definitions are created ---- 0.09s 2025-09-30 07:54:25.823805 | controller | Set _ci_multus_nad variable --------------------------------------------- 0.05s 2025-09-30 07:54:25.824033 | controller | Load shared variables --------------------------------------------------- 0.04s 2025-09-30 07:54:25.824286 | controller | Assert that expected file exist ----------------------------------------- 0.03s 2025-09-30 07:54:25.891177 | controller | INFO Verifier completed successfully. 2025-09-30 07:54:25.922937 | controller | INFO Running default > verify 2025-09-30 07:54:25.923502 | controller | INFO Running Ansible Verifier 2025-09-30 07:54:26.438555 | controller | 2025-09-30 07:54:26.438622 | controller | PLAY [Verify CRC] ************************************************************** 2025-09-30 07:54:26.438760 | controller | 2025-09-30 07:54:26.438982 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 07:54:26.439179 | controller | Tuesday 30 September 2025 07:54:26 +0000 (0:00:00.015) 0:00:00.015 ***** 2025-09-30 07:54:27.555515 | controller | ok: [instance] 2025-09-30 07:54:27.555798 | controller | 2025-09-30 07:54:27.589020 | controller | TASK [Include default vars] **************************************************** 2025-09-30 07:54:27.589065 | controller | Tuesday 30 September 2025 07:54:27 +0000 (0:00:01.117) 0:00:01.133 ***** 2025-09-30 07:54:27.589081 | controller | ok: [instance] 2025-09-30 07:54:28.523914 | controller | 2025-09-30 07:54:28.523958 | controller | TASK [Check if NADs were created] ********************************************** 2025-09-30 07:54:28.523969 | controller | Tuesday 30 September 2025 07:54:27 +0000 (0:00:00.033) 0:00:01.166 ***** 2025-09-30 07:54:28.524005 | controller | ok: [instance] 2025-09-30 07:54:28.524042 | controller | 2025-09-30 07:54:28.524056 | controller | TASK [Store output spec] ******************************************************* 2025-09-30 07:54:28.524162 | controller | Tuesday 30 September 2025 07:54:28 +0000 (0:00:00.935) 0:00:02.101 ***** 2025-09-30 07:54:28.564686 | controller | ok: [instance] 2025-09-30 07:54:28.564764 | controller | 2025-09-30 07:54:28.565001 | controller | TASK [Ensure both lists have the same length] ********************************** 2025-09-30 07:54:28.565022 | controller | Tuesday 30 September 2025 07:54:28 +0000 (0:00:00.040) 0:00:02.142 ***** 2025-09-30 07:54:28.610677 | controller | ok: [instance] => changed=false 2025-09-30 07:54:28.610754 | controller | msg: All assertions passed 2025-09-30 07:54:28.610820 | controller | 2025-09-30 07:54:28.610914 | controller | TASK [Compare each corresponding element in the lists] ************************* 2025-09-30 07:54:28.611019 | controller | Tuesday 30 September 2025 07:54:28 +0000 (0:00:00.043) 0:00:02.186 ***** 2025-09-30 07:54:28.687891 | controller | ok: [instance] => (item=['{\n "cniVersion": "0.3.1",\n "name": "bridge-to-linux-bridge",\n "type": "bridge",\n "bridge": "bridge-to-linux-bridge",\n "ipam": {\n "type": "whereabouts",\n "range": "192.168.122.0/24",\n "range_start": "192.168.122.30",\n "range_end": "192.168.122.70"\n }\n}', '{\n "cniVersion": "0.3.1",\n "name": "bridge-to-linux-bridge",\n "type": "bridge",\n "bridge": "bridge-to-linux-bridge",\n "ipam": {\n "type": "whereabouts",\n "range": "192.168.122.0/24",\n "range_start": "192.168.122.30",\n "range_end": "192.168.122.70"\n }\n}\n']) => changed=false 2025-09-30 07:54:28.687936 | controller | ansible_loop_var: item 2025-09-30 07:54:28.687947 | controller | item: 2025-09-30 07:54:28.687957 | controller | - |- 2025-09-30 07:54:28.688083 | controller | { 2025-09-30 07:54:28.688198 | controller | "cniVersion": "0.3.1", 2025-09-30 07:54:28.688344 | controller | "name": "bridge-to-linux-bridge", 2025-09-30 07:54:28.688475 | controller | "type": "bridge", 2025-09-30 07:54:28.688589 | controller | "bridge": "bridge-to-linux-bridge", 2025-09-30 07:54:28.688703 | controller | "ipam": { 2025-09-30 07:54:28.688829 | controller | "type": "whereabouts", 2025-09-30 07:54:28.688946 | controller | "range": "192.168.122.0/24", 2025-09-30 07:54:28.689082 | controller | "range_start": "192.168.122.30", 2025-09-30 07:54:28.689189 | controller | "range_end": "192.168.122.70" 2025-09-30 07:54:28.689333 | controller | } 2025-09-30 07:54:28.689465 | controller | } 2025-09-30 07:54:28.689600 | controller | - |- 2025-09-30 07:54:28.689730 | controller | { 2025-09-30 07:54:28.689892 | controller | "cniVersion": "0.3.1", 2025-09-30 07:54:28.690016 | controller | "name": "bridge-to-linux-bridge", 2025-09-30 07:54:28.690146 | controller | "type": "bridge", 2025-09-30 07:54:28.690284 | controller | "bridge": "bridge-to-linux-bridge", 2025-09-30 07:54:28.690432 | controller | "ipam": { 2025-09-30 07:54:28.690568 | controller | "type": "whereabouts", 2025-09-30 07:54:28.690707 | controller | "range": "192.168.122.0/24", 2025-09-30 07:54:28.690855 | controller | "range_start": "192.168.122.30", 2025-09-30 07:54:28.690984 | controller | "range_end": "192.168.122.70" 2025-09-30 07:54:28.691081 | controller | } 2025-09-30 07:54:28.691176 | controller | } 2025-09-30 07:54:28.691284 | controller | msg: All assertions passed 2025-09-30 07:54:28.691432 | controller | ok: [instance] => (item=['{\n "cniVersion": "0.3.1",\n "name": "default",\n "type": "bridge",\n "bridge": "eth0",\n "ipam": {\n "type": "whereabouts",\n "range": "192.168.122.0/24",\n "range_start": "192.168.122.30",\n "range_end": "192.168.122.70"\n }\n}\n', '{\n "cniVersion": "0.3.1",\n "name": "default",\n "type": "bridge",\n "bridge": "eth0",\n "ipam": {\n "type": "whereabouts",\n "range": "192.168.122.0/24",\n "range_start": "192.168.122.30",\n "range_end": "192.168.122.70"\n }\n}\n']) => changed=false 2025-09-30 07:54:28.691530 | controller | ansible_loop_var: item 2025-09-30 07:54:28.691645 | controller | item: 2025-09-30 07:54:28.691737 | controller | - |- 2025-09-30 07:54:28.691835 | controller | { 2025-09-30 07:54:28.691946 | controller | "cniVersion": "0.3.1", 2025-09-30 07:54:28.692076 | controller | "name": "default", 2025-09-30 07:54:28.692187 | controller | "type": "bridge", 2025-09-30 07:54:28.692273 | controller | "bridge": "eth0", 2025-09-30 07:54:28.692393 | controller | "ipam": { 2025-09-30 07:54:28.692489 | controller | "type": "whereabouts", 2025-09-30 07:54:28.692591 | controller | "range": "192.168.122.0/24", 2025-09-30 07:54:28.692693 | controller | "range_start": "192.168.122.30", 2025-09-30 07:54:28.692819 | controller | "range_end": "192.168.122.70" 2025-09-30 07:54:28.692881 | controller | } 2025-09-30 07:54:28.692974 | controller | } 2025-09-30 07:54:28.693065 | controller | - |- 2025-09-30 07:54:28.693176 | controller | { 2025-09-30 07:54:28.693329 | controller | "cniVersion": "0.3.1", 2025-09-30 07:54:28.693414 | controller | "name": "default", 2025-09-30 07:54:28.693529 | controller | "type": "bridge", 2025-09-30 07:54:28.693620 | controller | "bridge": "eth0", 2025-09-30 07:54:28.693725 | controller | "ipam": { 2025-09-30 07:54:28.693823 | controller | "type": "whereabouts", 2025-09-30 07:54:28.693915 | controller | "range": "192.168.122.0/24", 2025-09-30 07:54:28.694011 | controller | "range_start": "192.168.122.30", 2025-09-30 07:54:28.694104 | controller | "range_end": "192.168.122.70" 2025-09-30 07:54:28.694199 | controller | } 2025-09-30 07:54:28.694336 | controller | } 2025-09-30 07:54:28.694460 | controller | msg: All assertions passed 2025-09-30 07:54:28.694587 | controller | ok: [instance] => (item=['{\n "cniVersion": "0.3.1",\n "name": "patchnetwork",\n "type": "macvlan",\n "master": "eth2",\n "ipam": {\n "type": "whereabouts",\n "range": "192.168.122.0/24",\n "range_start": "192.168.122.30",\n "range_end": "192.168.122.70"\n }\n}\n', '{\n "cniVersion": "0.3.1",\n "name": "patchnetwork",\n "type": "macvlan",\n "master": "eth2",\n "ipam": {\n "type": "whereabouts",\n "range": "192.168.122.0/24",\n "range_start": "192.168.122.30",\n "range_end": "192.168.122.70"\n }\n}']) => changed=false 2025-09-30 07:54:28.694690 | controller | ansible_loop_var: item 2025-09-30 07:54:28.694786 | controller | item: 2025-09-30 07:54:28.694873 | controller | - |- 2025-09-30 07:54:28.694968 | controller | { 2025-09-30 07:54:28.695062 | controller | "cniVersion": "0.3.1", 2025-09-30 07:54:28.695160 | controller | "name": "patchnetwork", 2025-09-30 07:54:28.695260 | controller | "type": "macvlan", 2025-09-30 07:54:28.695384 | controller | "master": "eth2", 2025-09-30 07:54:28.695522 | controller | "ipam": { 2025-09-30 07:54:28.695648 | controller | "type": "whereabouts", 2025-09-30 07:54:28.695761 | controller | "range": "192.168.122.0/24", 2025-09-30 07:54:28.695851 | controller | "range_start": "192.168.122.30", 2025-09-30 07:54:28.695940 | controller | "range_end": "192.168.122.70" 2025-09-30 07:54:28.696028 | controller | } 2025-09-30 07:54:28.696118 | controller | } 2025-09-30 07:54:28.696200 | controller | - |- 2025-09-30 07:54:28.696325 | controller | { 2025-09-30 07:54:28.696432 | controller | "cniVersion": "0.3.1", 2025-09-30 07:54:28.696542 | controller | "name": "patchnetwork", 2025-09-30 07:54:28.696671 | controller | "type": "macvlan", 2025-09-30 07:54:28.696771 | controller | "master": "eth2", 2025-09-30 07:54:28.696858 | controller | "ipam": { 2025-09-30 07:54:28.696950 | controller | "type": "whereabouts", 2025-09-30 07:54:28.697045 | controller | "range": "192.168.122.0/24", 2025-09-30 07:54:28.697134 | controller | "range_start": "192.168.122.30", 2025-09-30 07:54:28.697252 | controller | "range_end": "192.168.122.70" 2025-09-30 07:54:28.697367 | controller | } 2025-09-30 07:54:28.697468 | controller | } 2025-09-30 07:54:28.697567 | controller | msg: All assertions passed 2025-09-30 07:54:28.697658 | controller | 2025-09-30 07:54:28.697803 | controller | TASK [Create a test pod to attach a network] *********************************** 2025-09-30 07:54:28.697903 | controller | Tuesday 30 September 2025 07:54:28 +0000 (0:00:00.079) 0:00:02.265 ***** 2025-09-30 07:56:02.754067 | controller | [WARNING]: unknown field "api_version" 2025-09-30 07:56:02.764716 | controller | FAILED - RETRYING: [instance]: Create a test pod to attach a network (30 retries left). 2025-09-30 07:56:02.764866 | controller | FAILED - RETRYING: [instance]: Create a test pod to attach a network (29 retries left). 2025-09-30 07:56:02.765085 | controller | FAILED - RETRYING: [instance]: Create a test pod to attach a network (28 retries left). 2025-09-30 07:56:02.765255 | controller | FAILED - RETRYING: [instance]: Create a test pod to attach a network (27 retries left). 2025-09-30 07:56:02.765467 | controller | changed: [instance] 2025-09-30 07:56:02.765592 | controller | 2025-09-30 07:56:02.766259 | controller | TASK [Assert that test pod has the additional network] ************************* 2025-09-30 07:56:02.766517 | controller | Tuesday 30 September 2025 07:56:02 +0000 (0:01:34.076) 0:01:36.342 ***** 2025-09-30 07:56:02.813365 | controller | ok: [instance] => changed=false 2025-09-30 07:56:02.813529 | controller | msg: All assertions passed 2025-09-30 07:56:02.813638 | controller | 2025-09-30 07:56:02.813802 | controller | TASK [Delete test pod] ********************************************************* 2025-09-30 07:56:02.813973 | controller | Tuesday 30 September 2025 07:56:02 +0000 (0:00:00.048) 0:01:36.391 ***** 2025-09-30 07:56:03.632410 | controller | changed: [instance] 2025-09-30 07:56:03.632478 | controller | 2025-09-30 07:56:03.632612 | controller | PLAY RECAP ********************************************************************* 2025-09-30 07:56:03.632761 | controller | instance : ok=9 changed=2 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 2025-09-30 07:56:03.632939 | controller | 2025-09-30 07:56:03.634751 | controller | Tuesday 30 September 2025 07:56:03 +0000 (0:00:00.819) 0:01:37.210 ***** 2025-09-30 07:56:03.726435 | controller | =============================================================================== 2025-09-30 07:56:03.726534 | controller | Create a test pod to attach a network ---------------------------------- 94.08s 2025-09-30 07:56:03.726545 | controller | Gathering Facts --------------------------------------------------------- 1.12s 2025-09-30 07:56:03.726553 | controller | Check if NADs were created ---------------------------------------------- 0.94s 2025-09-30 07:56:03.726561 | controller | Delete test pod --------------------------------------------------------- 0.82s 2025-09-30 07:56:03.726570 | controller | Compare each corresponding element in the lists ------------------------- 0.08s 2025-09-30 07:56:03.726578 | controller | Assert that test pod has the additional network ------------------------- 0.05s 2025-09-30 07:56:03.726586 | controller | Ensure both lists have the same length ---------------------------------- 0.04s 2025-09-30 07:56:03.726594 | controller | Store output spec ------------------------------------------------------- 0.04s 2025-09-30 07:56:03.726602 | controller | Include default vars ---------------------------------------------------- 0.03s 2025-09-30 07:56:03.726622 | controller | INFO Verifier completed successfully. 2025-09-30 07:56:03.747460 | controller | INFO Running default > side_effect 2025-09-30 07:56:04.243053 | controller | 2025-09-30 07:56:04.243130 | controller | PLAY [Clean] ******************************************************************* 2025-09-30 07:56:04.243315 | controller | 2025-09-30 07:56:04.243477 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 07:56:04.245076 | controller | Tuesday 30 September 2025 07:56:04 +0000 (0:00:00.016) 0:00:00.016 ***** 2025-09-30 07:56:05.330449 | controller | ok: [instance] 2025-09-30 07:56:05.330600 | controller | 2025-09-30 07:56:05.330895 | controller | TASK [Backup NAD before cleanup so they can be inspected in CI] **************** 2025-09-30 07:56:05.331155 | controller | Tuesday 30 September 2025 07:56:05 +0000 (0:00:01.087) 0:00:01.103 ***** 2025-09-30 07:56:05.774881 | controller | changed: [instance] 2025-09-30 07:56:05.774963 | controller | 2025-09-30 07:56:05.775053 | controller | TASK [ci_multus : Cleanup - Fetch NADs in namespace: openstack] **************** 2025-09-30 07:56:05.775117 | controller | Tuesday 30 September 2025 07:56:05 +0000 (0:00:00.444) 0:00:01.548 ***** 2025-09-30 07:56:06.598144 | controller | ok: [instance] 2025-09-30 07:56:06.598415 | controller | 2025-09-30 07:56:06.598589 | controller | TASK [ci_multus : Cleanup - Delete NADs] *************************************** 2025-09-30 07:56:06.598634 | controller | Tuesday 30 September 2025 07:56:06 +0000 (0:00:00.823) 0:00:02.371 ***** 2025-09-30 07:56:08.895417 | controller | changed: [instance] => (item=bridge-to-linux-bridge) 2025-09-30 07:56:09.305858 | controller | changed: [instance] => (item=default) 2025-09-30 07:56:09.305891 | controller | changed: [instance] => (item=patchnetwork) 2025-09-30 07:56:09.305898 | controller | 2025-09-30 07:56:09.305905 | controller | TASK [ci_multus : Cleanup - Remove if artifact directory exists] *************** 2025-09-30 07:56:09.305912 | controller | Tuesday 30 September 2025 07:56:08 +0000 (0:00:02.296) 0:00:04.668 ***** 2025-09-30 07:56:09.305932 | controller | changed: [instance] 2025-09-30 07:56:09.419974 | controller | 2025-09-30 07:56:09.420038 | controller | PLAY RECAP ********************************************************************* 2025-09-30 07:56:09.420052 | controller | instance : ok=5 changed=3 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 2025-09-30 07:56:09.420061 | controller | 2025-09-30 07:56:09.420070 | controller | Tuesday 30 September 2025 07:56:09 +0000 (0:00:00.410) 0:00:05.079 ***** 2025-09-30 07:56:09.420078 | controller | =============================================================================== 2025-09-30 07:56:09.420087 | controller | ci_multus : Cleanup - Delete NADs --------------------------------------- 2.30s 2025-09-30 07:56:09.420096 | controller | Gathering Facts --------------------------------------------------------- 1.09s 2025-09-30 07:56:09.420104 | controller | ci_multus : Cleanup - Fetch NADs in namespace: openstack ---------------- 0.82s 2025-09-30 07:56:09.420113 | controller | Backup NAD before cleanup so they can be inspected in CI ---------------- 0.44s 2025-09-30 07:56:09.420122 | controller | ci_multus : Cleanup - Remove if artifact directory exists --------------- 0.41s 2025-09-30 07:56:09.420139 | controller | INFO Running default > verify 2025-09-30 07:56:09.420644 | controller | INFO Running Ansible Verifier 2025-09-30 07:56:09.900173 | controller | 2025-09-30 07:56:09.900511 | controller | PLAY [Verify Clean] ************************************************************ 2025-09-30 07:56:09.900688 | controller | 2025-09-30 07:56:09.900848 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 07:56:09.901001 | controller | Tuesday 30 September 2025 07:56:09 +0000 (0:00:00.016) 0:00:00.016 ***** 2025-09-30 07:56:11.028008 | controller | ok: [instance] 2025-09-30 07:56:11.054594 | controller | 2025-09-30 07:56:11.054630 | controller | TASK [Include default vars] **************************************************** 2025-09-30 07:56:11.054638 | controller | Tuesday 30 September 2025 07:56:11 +0000 (0:00:01.124) 0:00:01.141 ***** 2025-09-30 07:56:11.054649 | controller | ok: [instance] 2025-09-30 07:56:11.483285 | controller | 2025-09-30 07:56:11.483344 | controller | TASK [Fetch file stat results] ************************************************* 2025-09-30 07:56:11.483355 | controller | Tuesday 30 September 2025 07:56:11 +0000 (0:00:00.029) 0:00:01.171 ***** 2025-09-30 07:56:11.483373 | controller | ok: [instance] 2025-09-30 07:56:11.543608 | controller | 2025-09-30 07:56:11.543686 | controller | TASK [Assert that created file are removed by cleanup] ************************* 2025-09-30 07:56:11.543695 | controller | Tuesday 30 September 2025 07:56:11 +0000 (0:00:00.427) 0:00:01.599 ***** 2025-09-30 07:56:11.543715 | controller | ok: [instance] => changed=false 2025-09-30 07:56:11.617190 | controller | msg: All assertions passed 2025-09-30 07:56:11.617248 | controller | 2025-09-30 07:56:11.617292 | controller | PLAY RECAP ********************************************************************* 2025-09-30 07:56:11.617312 | controller | instance : ok=4 changed=0 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 2025-09-30 07:56:11.617326 | controller | 2025-09-30 07:56:11.617339 | controller | Tuesday 30 September 2025 07:56:11 +0000 (0:00:00.061) 0:00:01.660 ***** 2025-09-30 07:56:11.617352 | controller | =============================================================================== 2025-09-30 07:56:11.617366 | controller | Gathering Facts --------------------------------------------------------- 1.12s 2025-09-30 07:56:11.617378 | controller | Fetch file stat results ------------------------------------------------- 0.43s 2025-09-30 07:56:11.617392 | controller | Assert that created file are removed by cleanup ------------------------- 0.06s 2025-09-30 07:56:11.617423 | controller | Include default vars ---------------------------------------------------- 0.03s 2025-09-30 07:56:11.617447 | controller | INFO Verifier completed successfully. 2025-09-30 07:56:11.646395 | controller | INFO Running default > verify 2025-09-30 07:56:11.647097 | controller | INFO Running Ansible Verifier 2025-09-30 07:56:12.128256 | controller | 2025-09-30 07:56:12.129322 | controller | PLAY [Verify Clean CRC] ******************************************************** 2025-09-30 07:56:13.256517 | controller | 2025-09-30 07:56:13.256616 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 07:56:13.256645 | controller | Tuesday 30 September 2025 07:56:12 +0000 (0:00:00.015) 0:00:00.015 ***** 2025-09-30 07:56:13.256669 | controller | ok: [instance] 2025-09-30 07:56:13.257045 | controller | 2025-09-30 07:56:13.257122 | controller | TASK [Include default vars] **************************************************** 2025-09-30 07:56:13.310774 | controller | Tuesday 30 September 2025 07:56:13 +0000 (0:00:01.127) 0:00:01.143 ***** 2025-09-30 07:56:13.310825 | controller | ok: [instance] 2025-09-30 07:56:13.310975 | controller | 2025-09-30 07:56:13.310992 | controller | TASK [Check if NADs were deleted] ********************************************** 2025-09-30 07:56:13.311191 | controller | Tuesday 30 September 2025 07:56:13 +0000 (0:00:00.054) 0:00:01.198 ***** 2025-09-30 07:56:14.269899 | controller | ok: [instance] 2025-09-30 07:56:14.270067 | controller | 2025-09-30 07:56:14.270085 | controller | PLAY RECAP ********************************************************************* 2025-09-30 07:56:14.270355 | controller | instance : ok=3 changed=0 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 2025-09-30 07:56:14.270378 | controller | 2025-09-30 07:56:14.270414 | controller | Tuesday 30 September 2025 07:56:14 +0000 (0:00:00.960) 0:00:02.158 ***** 2025-09-30 07:56:14.270618 | controller | =============================================================================== 2025-09-30 07:56:14.271097 | controller | Gathering Facts --------------------------------------------------------- 1.13s 2025-09-30 07:56:14.330789 | controller | Check if NADs were deleted ---------------------------------------------- 0.96s 2025-09-30 07:56:14.330845 | controller | Include default vars ---------------------------------------------------- 0.06s 2025-09-30 07:56:14.330873 | controller | INFO Verifier completed successfully. 2025-09-30 07:56:14.331946 | controller | INFO Pruning extra files from scenario ephemeral directory 2025-09-30 07:56:14.359675 | controller | INFO Running local > destroy 2025-09-30 07:56:14.360263 | controller | WARNING Skipping, instances are delegated. 2025-09-30 07:56:14.379357 | controller | INFO Running local > create 2025-09-30 07:56:14.381632 | controller | WARNING Skipping, instances are delegated. 2025-09-30 07:56:14.395421 | controller | INFO Running local > converge 2025-09-30 07:56:14.952319 | controller | 2025-09-30 07:56:16.046504 | controller | PLAY [Converge] **************************************************************** 2025-09-30 07:56:16.046584 | controller | 2025-09-30 07:56:16.046600 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 07:56:16.046614 | controller | Tuesday 30 September 2025 07:56:14 +0000 (0:00:00.016) 0:00:00.016 ***** 2025-09-30 07:56:16.046636 | controller | ok: [instance] 2025-09-30 07:56:16.046698 | controller | 2025-09-30 07:56:16.046733 | controller | TASK [Load shared variables] *************************************************** 2025-09-30 07:56:16.046755 | controller | Tuesday 30 September 2025 07:56:16 +0000 (0:00:01.095) 0:00:01.111 ***** 2025-09-30 07:56:16.082447 | controller | ok: [instance] 2025-09-30 07:56:16.082850 | controller | 2025-09-30 07:56:16.083063 | controller | TASK [Call ci_multus role] ***************************************************** 2025-09-30 07:56:16.083124 | controller | Tuesday 30 September 2025 07:56:16 +0000 (0:00:00.036) 0:00:01.147 ***** 2025-09-30 07:56:16.158491 | controller | 2025-09-30 07:56:16.158554 | controller | TASK [ci_multus : Create manifests directory] ********************************** 2025-09-30 07:56:16.158787 | controller | Tuesday 30 September 2025 07:56:16 +0000 (0:00:00.076) 0:00:01.223 ***** 2025-09-30 07:56:16.574938 | controller | changed: [instance] 2025-09-30 07:56:16.575097 | controller | 2025-09-30 07:56:16.575346 | controller | TASK [networking_mapper : Check for Networking Environment Definition file existence] *** 2025-09-30 07:56:16.575548 | controller | Tuesday 30 September 2025 07:56:16 +0000 (0:00:00.417) 0:00:01.640 ***** 2025-09-30 07:56:16.613878 | controller | skipping: [instance] 2025-09-30 07:56:16.613976 | controller | 2025-09-30 07:56:16.614130 | controller | TASK [networking_mapper : Check for Networking Definition file existance] ****** 2025-09-30 07:56:16.614290 | controller | Tuesday 30 September 2025 07:56:16 +0000 (0:00:00.039) 0:00:01.679 ***** 2025-09-30 07:56:16.654710 | controller | skipping: [instance] 2025-09-30 07:56:16.654881 | controller | 2025-09-30 07:56:16.655138 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************ 2025-09-30 07:56:16.655401 | controller | Tuesday 30 September 2025 07:56:16 +0000 (0:00:00.040) 0:00:01.720 ***** 2025-09-30 07:56:16.690598 | controller | skipping: [instance] 2025-09-30 07:56:16.690710 | controller | 2025-09-30 07:56:16.690951 | controller | TASK [networking_mapper : Set cifmw_networking_env_definition is present] ****** 2025-09-30 07:56:16.691204 | controller | Tuesday 30 September 2025 07:56:16 +0000 (0:00:00.036) 0:00:01.756 ***** 2025-09-30 07:56:16.748134 | controller | skipping: [instance] 2025-09-30 07:56:16.748313 | controller | 2025-09-30 07:56:16.748584 | controller | TASK [ci_multus : Gather network layout from OCP host or default networks] ***** 2025-09-30 07:56:16.748815 | controller | Tuesday 30 September 2025 07:56:16 +0000 (0:00:00.056) 0:00:01.813 ***** 2025-09-30 07:56:16.814989 | controller | ok: [instance] 2025-09-30 07:56:16.815136 | controller | 2025-09-30 07:56:16.815423 | controller | TASK [ci_multus : Merge any available multus net info patches] ***************** 2025-09-30 07:56:16.815672 | controller | Tuesday 30 September 2025 07:56:16 +0000 (0:00:00.067) 0:00:01.880 ***** 2025-09-30 07:56:16.984951 | controller | ok: [instance] => (item={'default': {'interface_name': 'eth0', 'network_name': 'default', 'gw_v4': '192.168.122.1', 'network_v4': '192.168.122.0/24', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}], 'multus_type': 'bridge'}}}, 'deny_network': {'gw_v4': '192.168.122.1', 'network_name': 'deny_network', 'network_v4': '192.168.122.0/24', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}], 'multus_type': 'bridge'}}}, 'not_allowed_network': {'gw_v4': '192.168.122.1', 'network_name': 'not_allowed_network', 'network_v4': '192.168.122.0/24', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}], 'multus_type': 'bridge'}}}, 'no_multus_network': {'gw_v4': '192.168.122.1', 'network_name': 'patchnetwork', 'network_v4': '192.168.122.0/24', 'interface_name': 'eth2'}}) 2025-09-30 07:56:16.985234 | controller | ok: [instance] => (item={'patchnetwork': {'gw_v4': '192.168.122.1', 'interface_name': 'eth2', 'network_name': 'patchnetwork', 'network_v4': '192.168.122.0/24', 'tools': {'multus': {'ipv4_ranges': [{'end': '192.168.122.70', 'start': '192.168.122.30'}]}}}}) 2025-09-30 07:56:16.985580 | controller | 2025-09-30 07:56:16.985878 | controller | TASK [ci_multus : Remove any networks without Multus networking defined] ******* 2025-09-30 07:56:16.986189 | controller | Tuesday 30 September 2025 07:56:16 +0000 (0:00:00.169) 0:00:02.049 ***** 2025-09-30 07:56:17.101356 | controller | ok: [instance] 2025-09-30 07:56:17.101494 | controller | 2025-09-30 07:56:17.101754 | controller | TASK [ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined] *** 2025-09-30 07:56:17.101956 | controller | Tuesday 30 September 2025 07:56:17 +0000 (0:00:00.117) 0:00:02.166 ***** 2025-09-30 07:56:17.202621 | controller | ok: [instance] 2025-09-30 07:56:17.202743 | controller | 2025-09-30 07:56:17.202983 | controller | TASK [ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined] *** 2025-09-30 07:56:17.203215 | controller | Tuesday 30 September 2025 07:56:17 +0000 (0:00:00.101) 0:00:02.268 ***** 2025-09-30 07:56:17.319560 | controller | ok: [instance] 2025-09-30 07:56:17.319710 | controller | 2025-09-30 07:56:17.319725 | controller | TASK [ci_multus : Render NetworkAttachmenktDefinition manifests] *************** 2025-09-30 07:56:17.319949 | controller | Tuesday 30 September 2025 07:56:17 +0000 (0:00:00.115) 0:00:02.383 ***** 2025-09-30 07:56:18.114495 | controller | changed: [instance] 2025-09-30 07:56:18.114555 | controller | 2025-09-30 07:56:18.114692 | controller | TASK [ci_multus : Create the multus namespace] ********************************* 2025-09-30 07:56:18.114895 | controller | Tuesday 30 September 2025 07:56:18 +0000 (0:00:00.796) 0:00:03.180 ***** 2025-09-30 07:56:18.139651 | controller | skipping: [instance] 2025-09-30 07:56:18.139748 | controller | 2025-09-30 07:56:18.140054 | controller | TASK [ci_multus : Apply network attachment definition manifests] *************** 2025-09-30 07:56:18.140226 | controller | Tuesday 30 September 2025 07:56:18 +0000 (0:00:00.025) 0:00:03.205 ***** 2025-09-30 07:56:18.186433 | controller | skipping: [instance] 2025-09-30 07:56:18.186508 | controller | 2025-09-30 07:56:18.186651 | controller | PLAY RECAP ********************************************************************* 2025-09-30 07:56:18.186822 | controller | instance : ok=9 changed=2 unreachable=0 failed=0 skipped=6 rescued=0 ignored=0 2025-09-30 07:56:18.186938 | controller | 2025-09-30 07:56:18.187075 | controller | Tuesday 30 September 2025 07:56:18 +0000 (0:00:00.046) 0:00:03.252 ***** 2025-09-30 07:56:18.187200 | controller | =============================================================================== 2025-09-30 07:56:18.187363 | controller | Gathering Facts --------------------------------------------------------- 1.10s 2025-09-30 07:56:18.187496 | controller | ci_multus : Render NetworkAttachmenktDefinition manifests --------------- 0.80s 2025-09-30 07:56:18.187633 | controller | ci_multus : Create manifests directory ---------------------------------- 0.42s 2025-09-30 07:56:18.187761 | controller | ci_multus : Merge any available multus net info patches ----------------- 0.17s 2025-09-30 07:56:18.187913 | controller | ci_multus : Remove any networks without Multus networking defined ------- 0.12s 2025-09-30 07:56:18.188062 | controller | ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined --- 0.12s 2025-09-30 07:56:18.188198 | controller | ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined --- 0.10s 2025-09-30 07:56:18.188365 | controller | Call ci_multus role ----------------------------------------------------- 0.08s 2025-09-30 07:56:18.188515 | controller | ci_multus : Gather network layout from OCP host or default networks ----- 0.07s 2025-09-30 07:56:18.188645 | controller | networking_mapper : Set cifmw_networking_env_definition is present ------ 0.06s 2025-09-30 07:56:18.188779 | controller | ci_multus : Apply network attachment definition manifests --------------- 0.05s 2025-09-30 07:56:18.188916 | controller | networking_mapper : Check for Networking Definition file existance ------ 0.04s 2025-09-30 07:56:18.189066 | controller | networking_mapper : Check for Networking Environment Definition file existence --- 0.04s 2025-09-30 07:56:18.189212 | controller | networking_mapper : Load the Networking Definition from file ------------ 0.04s 2025-09-30 07:56:18.189384 | controller | Load shared variables --------------------------------------------------- 0.04s 2025-09-30 07:56:18.189517 | controller | ci_multus : Create the multus namespace --------------------------------- 0.03s 2025-09-30 07:56:18.267910 | controller | INFO Running local > verify 2025-09-30 07:56:18.268289 | controller | INFO Running Ansible Verifier 2025-09-30 07:56:18.799137 | controller | 2025-09-30 07:56:18.799328 | controller | PLAY [Verify] ****************************************************************** 2025-09-30 07:56:18.799543 | controller | 2025-09-30 07:56:18.799735 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 07:56:18.800337 | controller | Tuesday 30 September 2025 07:56:18 +0000 (0:00:00.018) 0:00:00.018 ***** 2025-09-30 07:56:20.021826 | controller | ok: [instance] 2025-09-30 07:56:20.021922 | controller | 2025-09-30 07:56:20.022003 | controller | TASK [Load shared variables] *************************************************** 2025-09-30 07:56:20.022213 | controller | Tuesday 30 September 2025 07:56:20 +0000 (0:00:01.222) 0:00:01.241 ***** 2025-09-30 07:56:20.054856 | controller | ok: [instance] 2025-09-30 07:56:20.055040 | controller | 2025-09-30 07:56:20.055217 | controller | TASK [Fetch files stat results] ************************************************ 2025-09-30 07:56:20.055426 | controller | Tuesday 30 September 2025 07:56:20 +0000 (0:00:00.033) 0:00:01.274 ***** 2025-09-30 07:56:20.444503 | controller | ok: [instance] 2025-09-30 07:56:20.444572 | controller | 2025-09-30 07:56:20.444695 | controller | TASK [Assert that expected file exist] ***************************************** 2025-09-30 07:56:20.444852 | controller | Tuesday 30 September 2025 07:56:20 +0000 (0:00:00.389) 0:00:01.663 ***** 2025-09-30 07:56:20.482372 | controller | ok: [instance] => changed=false 2025-09-30 07:56:20.482591 | controller | msg: All assertions passed 2025-09-30 07:56:20.482845 | controller | 2025-09-30 07:56:20.483115 | controller | TASK [Fetch file content] ****************************************************** 2025-09-30 07:56:20.483399 | controller | Tuesday 30 September 2025 07:56:20 +0000 (0:00:00.038) 0:00:01.701 ***** 2025-09-30 07:56:20.855964 | controller | ok: [instance] 2025-09-30 07:56:20.856037 | controller | 2025-09-30 07:56:20.856159 | controller | TASK [Set _ci_multus_nad variable] ********************************************* 2025-09-30 07:56:20.856329 | controller | Tuesday 30 September 2025 07:56:20 +0000 (0:00:00.373) 0:00:02.075 ***** 2025-09-30 07:56:20.895423 | controller | ok: [instance] 2025-09-30 07:56:20.895535 | controller | 2025-09-30 07:56:20.895689 | controller | TASK [Assert expected number of Network Attachment Definitions are created] **** 2025-09-30 07:56:20.895829 | controller | Tuesday 30 September 2025 07:56:20 +0000 (0:00:00.039) 0:00:02.115 ***** 2025-09-30 07:56:20.947370 | controller | ok: [instance] 2025-09-30 07:56:20.947433 | controller | 2025-09-30 07:56:20.947544 | controller | PLAY RECAP ********************************************************************* 2025-09-30 07:56:20.947640 | controller | instance : ok=7 changed=0 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 2025-09-30 07:56:20.947732 | controller | 2025-09-30 07:56:20.947856 | controller | Tuesday 30 September 2025 07:56:20 +0000 (0:00:00.052) 0:00:02.167 ***** 2025-09-30 07:56:20.948001 | controller | =============================================================================== 2025-09-30 07:56:20.948030 | controller | Gathering Facts --------------------------------------------------------- 1.22s 2025-09-30 07:56:20.948122 | controller | Fetch files stat results ------------------------------------------------ 0.39s 2025-09-30 07:56:20.948214 | controller | Fetch file content ------------------------------------------------------ 0.37s 2025-09-30 07:56:20.948350 | controller | Assert expected number of Network Attachment Definitions are created ---- 0.05s 2025-09-30 07:56:20.948439 | controller | Set _ci_multus_nad variable --------------------------------------------- 0.04s 2025-09-30 07:56:20.948666 | controller | Assert that expected file exist ----------------------------------------- 0.04s 2025-09-30 07:56:21.014219 | controller | Load shared variables --------------------------------------------------- 0.03s 2025-09-30 07:56:21.014286 | controller | INFO Verifier completed successfully. 2025-09-30 07:56:21.024741 | controller | INFO Running local > side_effect 2025-09-30 07:56:21.542932 | controller | 2025-09-30 07:56:21.543098 | controller | PLAY [Clean] ******************************************************************* 2025-09-30 07:56:21.543528 | controller | 2025-09-30 07:56:21.543685 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 07:56:21.544027 | controller | Tuesday 30 September 2025 07:56:21 +0000 (0:00:00.015) 0:00:00.015 ***** 2025-09-30 07:56:22.706922 | controller | ok: [instance] 2025-09-30 07:56:22.707033 | controller | 2025-09-30 07:56:22.707265 | controller | TASK [Backup NAD before cleanup so they can be inspected in CI] **************** 2025-09-30 07:56:22.707565 | controller | Tuesday 30 September 2025 07:56:22 +0000 (0:00:01.164) 0:00:01.179 ***** 2025-09-30 07:56:23.125953 | controller | changed: [instance] 2025-09-30 07:56:23.126022 | controller | 2025-09-30 07:56:23.126136 | controller | TASK [ci_multus : Cleanup - Fetch NADs in namespace: openstack] **************** 2025-09-30 07:56:23.126307 | controller | Tuesday 30 September 2025 07:56:23 +0000 (0:00:00.419) 0:00:01.599 ***** 2025-09-30 07:56:23.158410 | controller | skipping: [instance] 2025-09-30 07:56:23.158479 | controller | 2025-09-30 07:56:23.158672 | controller | TASK [ci_multus : Cleanup - Delete NADs] *************************************** 2025-09-30 07:56:23.158809 | controller | Tuesday 30 September 2025 07:56:23 +0000 (0:00:00.032) 0:00:01.631 ***** 2025-09-30 07:56:23.222042 | controller | skipping: [instance] 2025-09-30 07:56:23.222109 | controller | 2025-09-30 07:56:23.222315 | controller | TASK [ci_multus : Cleanup - Remove if artifact directory exists] *************** 2025-09-30 07:56:23.222470 | controller | Tuesday 30 September 2025 07:56:23 +0000 (0:00:00.062) 0:00:01.694 ***** 2025-09-30 07:56:23.672543 | controller | changed: [instance] 2025-09-30 07:56:23.672731 | controller | 2025-09-30 07:56:23.672960 | controller | PLAY RECAP ********************************************************************* 2025-09-30 07:56:23.673232 | controller | instance : ok=3 changed=2 unreachable=0 failed=0 skipped=2 rescued=0 ignored=0 2025-09-30 07:56:23.673465 | controller | 2025-09-30 07:56:23.673696 | controller | Tuesday 30 September 2025 07:56:23 +0000 (0:00:00.451) 0:00:02.146 ***** 2025-09-30 07:56:23.673920 | controller | =============================================================================== 2025-09-30 07:56:23.674138 | controller | Gathering Facts --------------------------------------------------------- 1.16s 2025-09-30 07:56:23.674407 | controller | ci_multus : Cleanup - Remove if artifact directory exists --------------- 0.45s 2025-09-30 07:56:23.674706 | controller | Backup NAD before cleanup so they can be inspected in CI ---------------- 0.42s 2025-09-30 07:56:23.674957 | controller | ci_multus : Cleanup - Delete NADs --------------------------------------- 0.06s 2025-09-30 07:56:23.675211 | controller | ci_multus : Cleanup - Fetch NADs in namespace: openstack ---------------- 0.03s 2025-09-30 07:56:23.760562 | controller | INFO Running local > verify 2025-09-30 07:56:23.761141 | controller | INFO Running Ansible Verifier 2025-09-30 07:56:24.238843 | controller | 2025-09-30 07:56:24.239862 | controller | PLAY [Verify Clean] ************************************************************ 2025-09-30 07:56:26.407502 | controller | 2025-09-30 07:56:26.407551 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 07:56:26.407559 | controller | Tuesday 30 September 2025 07:56:24 +0000 (0:00:00.015) 0:00:00.015 ***** 2025-09-30 07:56:26.407572 | controller | ok: [instance] 2025-09-30 07:56:26.447447 | controller | 2025-09-30 07:56:26.447524 | controller | TASK [Include default vars] **************************************************** 2025-09-30 07:56:26.447536 | controller | Tuesday 30 September 2025 07:56:26 +0000 (0:00:02.169) 0:00:02.185 ***** 2025-09-30 07:56:26.447554 | controller | ok: [instance] 2025-09-30 07:56:26.447725 | controller | 2025-09-30 07:56:26.447778 | controller | TASK [Fetch file stat results] ************************************************* 2025-09-30 07:56:26.812771 | controller | Tuesday 30 September 2025 07:56:26 +0000 (0:00:00.039) 0:00:02.225 ***** 2025-09-30 07:56:26.812847 | controller | ok: [instance] 2025-09-30 07:56:26.867234 | controller | 2025-09-30 07:56:26.867345 | controller | TASK [Assert that created file are removed by cleanup] ************************* 2025-09-30 07:56:26.867358 | controller | Tuesday 30 September 2025 07:56:26 +0000 (0:00:00.364) 0:00:02.589 ***** 2025-09-30 07:56:26.867381 | controller | ok: [instance] => changed=false 2025-09-30 07:56:26.867533 | controller | msg: All assertions passed 2025-09-30 07:56:26.867557 | controller | 2025-09-30 07:56:26.867566 | controller | PLAY RECAP ********************************************************************* 2025-09-30 07:56:26.867575 | controller | instance : ok=4 changed=0 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 2025-09-30 07:56:26.867583 | controller | 2025-09-30 07:56:26.867597 | controller | Tuesday 30 September 2025 07:56:26 +0000 (0:00:00.055) 0:00:02.645 ***** 2025-09-30 07:56:26.867662 | controller | =============================================================================== 2025-09-30 07:56:26.867818 | controller | Gathering Facts --------------------------------------------------------- 2.17s 2025-09-30 07:56:26.867935 | controller | Fetch file stat results ------------------------------------------------- 0.36s 2025-09-30 07:56:26.868079 | controller | Assert that created file are removed by cleanup ------------------------- 0.06s 2025-09-30 07:56:26.868201 | controller | Include default vars ---------------------------------------------------- 0.04s 2025-09-30 07:56:26.934647 | controller | INFO Verifier completed successfully. 2025-09-30 07:56:26.935503 | controller | INFO Pruning extra files from scenario ephemeral directory 2025-09-30 07:56:26.960534 | controller | INFO Running local_ipv6 > destroy 2025-09-30 07:56:26.961493 | controller | WARNING Skipping, instances are delegated. 2025-09-30 07:56:26.985658 | controller | INFO Running local_ipv6 > create 2025-09-30 07:56:26.988796 | controller | WARNING Skipping, instances are delegated. 2025-09-30 07:56:27.009020 | controller | INFO Running local_ipv6 > converge 2025-09-30 07:56:27.532878 | controller | 2025-09-30 07:56:27.533007 | controller | PLAY [Converge] **************************************************************** 2025-09-30 07:56:27.533123 | controller | 2025-09-30 07:56:27.533346 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 07:56:27.533931 | controller | Tuesday 30 September 2025 07:56:27 +0000 (0:00:00.015) 0:00:00.015 ***** 2025-09-30 07:56:28.678596 | controller | ok: [instance] 2025-09-30 07:56:28.678905 | controller | 2025-09-30 07:56:28.679107 | controller | TASK [Load shared variables] *************************************************** 2025-09-30 07:56:28.679169 | controller | Tuesday 30 September 2025 07:56:28 +0000 (0:00:01.145) 0:00:01.161 ***** 2025-09-30 07:56:28.710643 | controller | ok: [instance] 2025-09-30 07:56:28.710805 | controller | 2025-09-30 07:56:28.711012 | controller | TASK [Call ci_multus role] ***************************************************** 2025-09-30 07:56:28.711817 | controller | Tuesday 30 September 2025 07:56:28 +0000 (0:00:00.032) 0:00:01.193 ***** 2025-09-30 07:56:28.755093 | controller | 2025-09-30 07:56:29.178400 | controller | TASK [ci_multus : Create manifests directory] ********************************** 2025-09-30 07:56:29.178490 | controller | Tuesday 30 September 2025 07:56:28 +0000 (0:00:00.044) 0:00:01.237 ***** 2025-09-30 07:56:29.178517 | controller | changed: [instance] 2025-09-30 07:56:29.217575 | controller | 2025-09-30 07:56:29.217644 | controller | TASK [networking_mapper : Check for Networking Environment Definition file existence] *** 2025-09-30 07:56:29.217661 | controller | Tuesday 30 September 2025 07:56:29 +0000 (0:00:00.421) 0:00:01.659 ***** 2025-09-30 07:56:29.217685 | controller | skipping: [instance] 2025-09-30 07:56:29.217829 | controller | 2025-09-30 07:56:29.218034 | controller | TASK [networking_mapper : Check for Networking Definition file existance] ****** 2025-09-30 07:56:29.218220 | controller | Tuesday 30 September 2025 07:56:29 +0000 (0:00:00.040) 0:00:01.700 ***** 2025-09-30 07:56:29.249171 | controller | skipping: [instance] 2025-09-30 07:56:29.249333 | controller | 2025-09-30 07:56:29.249592 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************ 2025-09-30 07:56:29.249826 | controller | Tuesday 30 September 2025 07:56:29 +0000 (0:00:00.031) 0:00:01.732 ***** 2025-09-30 07:56:29.301603 | controller | skipping: [instance] 2025-09-30 07:56:29.301730 | controller | 2025-09-30 07:56:29.301997 | controller | TASK [networking_mapper : Set cifmw_networking_env_definition is present] ****** 2025-09-30 07:56:29.302210 | controller | Tuesday 30 September 2025 07:56:29 +0000 (0:00:00.051) 0:00:01.783 ***** 2025-09-30 07:56:29.370086 | controller | skipping: [instance] 2025-09-30 07:56:29.370468 | controller | 2025-09-30 07:56:29.370518 | controller | TASK [ci_multus : Gather network layout from OCP host or default networks] ***** 2025-09-30 07:56:29.370870 | controller | Tuesday 30 September 2025 07:56:29 +0000 (0:00:00.068) 0:00:01.851 ***** 2025-09-30 07:56:29.443982 | controller | ok: [instance] 2025-09-30 07:56:29.444149 | controller | 2025-09-30 07:56:29.444402 | controller | TASK [ci_multus : Merge any available multus net info patches] ***************** 2025-09-30 07:56:29.444621 | controller | Tuesday 30 September 2025 07:56:29 +0000 (0:00:00.074) 0:00:01.926 ***** 2025-09-30 07:56:29.571325 | controller | skipping: [instance] => (item={'default': {'interface_name': 'eth1', 'network_name': 'default', 'gw_v6': 'fdc0:8b54:108a:c949:0000:0000:0000:0001', 'network_v6': 'fdc0:8b54:108a:c949::/64', 'tools': {'multus': {'ipv6_ranges': [{'start': 'fdc0:8b54:108a:c949:0000:0000:0000:001e', 'end': 'fdc0:8b54:108a:c949:0000:0000:0000:0027'}]}}}}) 2025-09-30 07:56:29.571374 | controller | skipping: [instance] 2025-09-30 07:56:29.571540 | controller | 2025-09-30 07:56:29.571673 | controller | TASK [ci_multus : Remove any networks without Multus networking defined] ******* 2025-09-30 07:56:29.571810 | controller | Tuesday 30 September 2025 07:56:29 +0000 (0:00:00.128) 0:00:02.054 ***** 2025-09-30 07:56:29.655772 | controller | ok: [instance] 2025-09-30 07:56:29.655824 | controller | 2025-09-30 07:56:29.655979 | controller | TASK [ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined] *** 2025-09-30 07:56:29.656114 | controller | Tuesday 30 September 2025 07:56:29 +0000 (0:00:00.084) 0:00:02.139 ***** 2025-09-30 07:56:29.750072 | controller | ok: [instance] 2025-09-30 07:56:29.750204 | controller | 2025-09-30 07:56:29.750501 | controller | TASK [ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined] *** 2025-09-30 07:56:29.750750 | controller | Tuesday 30 September 2025 07:56:29 +0000 (0:00:00.093) 0:00:02.232 ***** 2025-09-30 07:56:29.825820 | controller | ok: [instance] 2025-09-30 07:56:29.826119 | controller | 2025-09-30 07:56:29.826205 | controller | TASK [ci_multus : Render NetworkAttachmenktDefinition manifests] *************** 2025-09-30 07:56:29.826460 | controller | Tuesday 30 September 2025 07:56:29 +0000 (0:00:00.076) 0:00:02.308 ***** 2025-09-30 07:56:30.595216 | controller | changed: [instance] 2025-09-30 07:56:30.595386 | controller | 2025-09-30 07:56:30.595417 | controller | TASK [ci_multus : Create the multus namespace] ********************************* 2025-09-30 07:56:30.595533 | controller | Tuesday 30 September 2025 07:56:30 +0000 (0:00:00.768) 0:00:03.077 ***** 2025-09-30 07:56:30.625009 | controller | skipping: [instance] 2025-09-30 07:56:30.625067 | controller | 2025-09-30 07:56:30.625304 | controller | TASK [ci_multus : Apply network attachment definition manifests] *************** 2025-09-30 07:56:30.625505 | controller | Tuesday 30 September 2025 07:56:30 +0000 (0:00:00.030) 0:00:03.107 ***** 2025-09-30 07:56:30.689120 | controller | skipping: [instance] 2025-09-30 07:56:30.689300 | controller | 2025-09-30 07:56:30.689330 | controller | PLAY RECAP ********************************************************************* 2025-09-30 07:56:30.689472 | controller | instance : ok=8 changed=2 unreachable=0 failed=0 skipped=7 rescued=0 ignored=0 2025-09-30 07:56:30.691912 | controller | 2025-09-30 07:56:30.691956 | controller | Tuesday 30 September 2025 07:56:30 +0000 (0:00:00.064) 0:00:03.172 ***** 2025-09-30 07:56:30.691971 | controller | =============================================================================== 2025-09-30 07:56:30.691985 | controller | Gathering Facts --------------------------------------------------------- 1.15s 2025-09-30 07:56:30.691998 | controller | ci_multus : Render NetworkAttachmenktDefinition manifests --------------- 0.77s 2025-09-30 07:56:30.692011 | controller | ci_multus : Create manifests directory ---------------------------------- 0.42s 2025-09-30 07:56:30.692024 | controller | ci_multus : Merge any available multus net info patches ----------------- 0.13s 2025-09-30 07:56:30.692037 | controller | ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined --- 0.09s 2025-09-30 07:56:30.692050 | controller | ci_multus : Remove any networks without Multus networking defined ------- 0.08s 2025-09-30 07:56:30.692063 | controller | ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined --- 0.08s 2025-09-30 07:56:30.692076 | controller | ci_multus : Gather network layout from OCP host or default networks ----- 0.07s 2025-09-30 07:56:30.692089 | controller | networking_mapper : Set cifmw_networking_env_definition is present ------ 0.07s 2025-09-30 07:56:30.692102 | controller | ci_multus : Apply network attachment definition manifests --------------- 0.06s 2025-09-30 07:56:30.692115 | controller | networking_mapper : Load the Networking Definition from file ------------ 0.05s 2025-09-30 07:56:30.692128 | controller | Call ci_multus role ----------------------------------------------------- 0.04s 2025-09-30 07:56:30.692146 | controller | networking_mapper : Check for Networking Environment Definition file existence --- 0.04s 2025-09-30 07:56:30.692800 | controller | Load shared variables --------------------------------------------------- 0.03s 2025-09-30 07:56:30.692845 | controller | networking_mapper : Check for Networking Definition file existance ------ 0.03s 2025-09-30 07:56:30.768753 | controller | ci_multus : Create the multus namespace --------------------------------- 0.03s 2025-09-30 07:56:30.768873 | controller | INFO Running local_ipv6 > verify 2025-09-30 07:56:30.769006 | controller | INFO Running Ansible Verifier 2025-09-30 07:56:31.302908 | controller | 2025-09-30 07:56:31.303149 | controller | PLAY [Verify] ****************************************************************** 2025-09-30 07:56:31.304427 | controller | 2025-09-30 07:56:32.460253 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 07:56:32.460350 | controller | Tuesday 30 September 2025 07:56:31 +0000 (0:00:00.017) 0:00:00.017 ***** 2025-09-30 07:56:32.460371 | controller | ok: [instance] 2025-09-30 07:56:32.460425 | controller | 2025-09-30 07:56:32.460438 | controller | TASK [Load shared variables] *************************************************** 2025-09-30 07:56:32.460530 | controller | Tuesday 30 September 2025 07:56:32 +0000 (0:00:01.158) 0:00:01.175 ***** 2025-09-30 07:56:32.487389 | controller | ok: [instance] 2025-09-30 07:56:32.487449 | controller | 2025-09-30 07:56:32.487603 | controller | TASK [Fetch files stat results] ************************************************ 2025-09-30 07:56:32.487752 | controller | Tuesday 30 September 2025 07:56:32 +0000 (0:00:00.026) 0:00:01.202 ***** 2025-09-30 07:56:32.881604 | controller | ok: [instance] 2025-09-30 07:56:32.881906 | controller | 2025-09-30 07:56:32.882159 | controller | TASK [Assert that expected file exist] ***************************************** 2025-09-30 07:56:32.882546 | controller | Tuesday 30 September 2025 07:56:32 +0000 (0:00:00.392) 0:00:01.595 ***** 2025-09-30 07:56:32.920345 | controller | ok: [instance] => changed=false 2025-09-30 07:56:32.920569 | controller | msg: All assertions passed 2025-09-30 07:56:32.920783 | controller | 2025-09-30 07:56:32.921066 | controller | TASK [Fetch file content] ****************************************************** 2025-09-30 07:56:32.921427 | controller | Tuesday 30 September 2025 07:56:32 +0000 (0:00:00.040) 0:00:01.635 ***** 2025-09-30 07:56:33.260290 | controller | ok: [instance] 2025-09-30 07:56:33.260605 | controller | 2025-09-30 07:56:33.260875 | controller | TASK [Set _ci_multus_nad variable] ********************************************* 2025-09-30 07:56:33.261160 | controller | Tuesday 30 September 2025 07:56:33 +0000 (0:00:00.339) 0:00:01.975 ***** 2025-09-30 07:56:33.322196 | controller | ok: [instance] 2025-09-30 07:56:33.322542 | controller | 2025-09-30 07:56:33.322802 | controller | TASK [Assert expected number of Network Attachment Definitions are created] **** 2025-09-30 07:56:33.323116 | controller | Tuesday 30 September 2025 07:56:33 +0000 (0:00:00.061) 0:00:02.036 ***** 2025-09-30 07:56:33.411058 | controller | ok: [instance] 2025-09-30 07:56:33.411221 | controller | 2025-09-30 07:56:33.411583 | controller | PLAY RECAP ********************************************************************* 2025-09-30 07:56:33.411943 | controller | instance : ok=7 changed=0 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 2025-09-30 07:56:33.412191 | controller | 2025-09-30 07:56:33.412539 | controller | Tuesday 30 September 2025 07:56:33 +0000 (0:00:00.089) 0:00:02.126 ***** 2025-09-30 07:56:33.412823 | controller | =============================================================================== 2025-09-30 07:56:33.413123 | controller | Gathering Facts --------------------------------------------------------- 1.16s 2025-09-30 07:56:33.413399 | controller | Fetch files stat results ------------------------------------------------ 0.39s 2025-09-30 07:56:33.413621 | controller | Fetch file content ------------------------------------------------------ 0.34s 2025-09-30 07:56:33.413929 | controller | Assert expected number of Network Attachment Definitions are created ---- 0.09s 2025-09-30 07:56:33.414370 | controller | Set _ci_multus_nad variable --------------------------------------------- 0.06s 2025-09-30 07:56:33.414708 | controller | Assert that expected file exist ----------------------------------------- 0.04s 2025-09-30 07:56:33.414966 | controller | Load shared variables --------------------------------------------------- 0.03s 2025-09-30 07:56:33.484092 | controller | INFO Verifier completed successfully. 2025-09-30 07:56:33.505372 | controller | INFO Running local_ipv6 > side_effect 2025-09-30 07:56:34.042393 | controller | 2025-09-30 07:56:34.042505 | controller | PLAY [Clean] ******************************************************************* 2025-09-30 07:56:34.042640 | controller | 2025-09-30 07:56:34.042787 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 07:56:34.042931 | controller | Tuesday 30 September 2025 07:56:34 +0000 (0:00:00.015) 0:00:00.015 ***** 2025-09-30 07:56:35.134522 | controller | ok: [instance] 2025-09-30 07:56:35.134787 | controller | 2025-09-30 07:56:35.134885 | controller | TASK [Backup NAD before cleanup so they can be inspected in CI] **************** 2025-09-30 07:56:35.135203 | controller | Tuesday 30 September 2025 07:56:35 +0000 (0:00:01.092) 0:00:01.107 ***** 2025-09-30 07:56:35.543606 | controller | changed: [instance] 2025-09-30 07:56:35.589202 | controller | 2025-09-30 07:56:35.589245 | controller | TASK [ci_multus : Cleanup - Fetch NADs in namespace: openstack] **************** 2025-09-30 07:56:35.589255 | controller | Tuesday 30 September 2025 07:56:35 +0000 (0:00:00.408) 0:00:01.515 ***** 2025-09-30 07:56:35.589291 | controller | skipping: [instance] 2025-09-30 07:56:35.638755 | controller | 2025-09-30 07:56:35.638801 | controller | TASK [ci_multus : Cleanup - Delete NADs] *************************************** 2025-09-30 07:56:35.638815 | controller | Tuesday 30 September 2025 07:56:35 +0000 (0:00:00.045) 0:00:01.561 ***** 2025-09-30 07:56:35.638833 | controller | skipping: [instance] 2025-09-30 07:56:36.048580 | controller | 2025-09-30 07:56:36.048631 | controller | TASK [ci_multus : Cleanup - Remove if artifact directory exists] *************** 2025-09-30 07:56:36.048644 | controller | Tuesday 30 September 2025 07:56:35 +0000 (0:00:00.049) 0:00:01.610 ***** 2025-09-30 07:56:36.048677 | controller | changed: [instance] 2025-09-30 07:56:36.122380 | controller | 2025-09-30 07:56:36.122418 | controller | PLAY RECAP ********************************************************************* 2025-09-30 07:56:36.122427 | controller | instance : ok=3 changed=2 unreachable=0 failed=0 skipped=2 rescued=0 ignored=0 2025-09-30 07:56:36.122433 | controller | 2025-09-30 07:56:36.122439 | controller | Tuesday 30 September 2025 07:56:36 +0000 (0:00:00.409) 0:00:02.020 ***** 2025-09-30 07:56:36.122446 | controller | =============================================================================== 2025-09-30 07:56:36.122456 | controller | Gathering Facts --------------------------------------------------------- 1.09s 2025-09-30 07:56:36.122462 | controller | ci_multus : Cleanup - Remove if artifact directory exists --------------- 0.41s 2025-09-30 07:56:36.122468 | controller | Backup NAD before cleanup so they can be inspected in CI ---------------- 0.41s 2025-09-30 07:56:36.122473 | controller | ci_multus : Cleanup - Delete NADs --------------------------------------- 0.05s 2025-09-30 07:56:36.122479 | controller | ci_multus : Cleanup - Fetch NADs in namespace: openstack ---------------- 0.05s 2025-09-30 07:56:36.122490 | controller | INFO Running local_ipv6 > verify 2025-09-30 07:56:36.122861 | controller | INFO Running Ansible Verifier 2025-09-30 07:56:36.632253 | controller | 2025-09-30 07:56:36.632484 | controller | PLAY [Verify Clean] ************************************************************ 2025-09-30 07:56:36.632628 | controller | 2025-09-30 07:56:36.632777 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 07:56:36.632949 | controller | Tuesday 30 September 2025 07:56:36 +0000 (0:00:00.015) 0:00:00.015 ***** 2025-09-30 07:56:37.732831 | controller | ok: [instance] 2025-09-30 07:56:37.732883 | controller | 2025-09-30 07:56:37.732895 | controller | TASK [Include default vars] **************************************************** 2025-09-30 07:56:37.732998 | controller | Tuesday 30 September 2025 07:56:37 +0000 (0:00:01.100) 0:00:01.115 ***** 2025-09-30 07:56:37.760426 | controller | ok: [instance] 2025-09-30 07:56:37.760592 | controller | 2025-09-30 07:56:37.760625 | controller | TASK [Fetch file stat results] ************************************************* 2025-09-30 07:56:38.096075 | controller | Tuesday 30 September 2025 07:56:37 +0000 (0:00:00.027) 0:00:01.143 ***** 2025-09-30 07:56:38.096112 | controller | ok: [instance] 2025-09-30 07:56:38.146388 | controller | 2025-09-30 07:56:38.146424 | controller | TASK [Assert that created file are removed by cleanup] ************************* 2025-09-30 07:56:38.146432 | controller | Tuesday 30 September 2025 07:56:38 +0000 (0:00:00.335) 0:00:01.478 ***** 2025-09-30 07:56:38.146443 | controller | ok: [instance] => changed=false 2025-09-30 07:56:38.146464 | controller | msg: All assertions passed 2025-09-30 07:56:38.146472 | controller | 2025-09-30 07:56:38.146478 | controller | PLAY RECAP ********************************************************************* 2025-09-30 07:56:38.146490 | controller | instance : ok=4 changed=0 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 2025-09-30 07:56:38.146498 | controller | 2025-09-30 07:56:38.146517 | controller | Tuesday 30 September 2025 07:56:38 +0000 (0:00:00.050) 0:00:01.529 ***** 2025-09-30 07:56:38.146626 | controller | =============================================================================== 2025-09-30 07:56:38.146714 | controller | Gathering Facts --------------------------------------------------------- 1.10s 2025-09-30 07:56:38.146831 | controller | Fetch file stat results ------------------------------------------------- 0.34s 2025-09-30 07:56:38.146923 | controller | Assert that created file are removed by cleanup ------------------------- 0.05s 2025-09-30 07:56:38.147019 | controller | Include default vars ---------------------------------------------------- 0.03s 2025-09-30 07:56:38.207398 | controller | INFO Verifier completed successfully. 2025-09-30 07:56:38.207772 | controller | INFO Pruning extra files from scenario ephemeral directory 2025-09-30 07:56:38.209477 | controller | INFO Writing /tmp/report.html report. 2025-09-30 07:56:38.531414 | controller | changed 2025-09-30 07:56:38.583461 | 2025-09-30 07:56:38.583544 | PLAY RECAP 2025-09-30 07:56:38.583599 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-09-30 07:56:38.583626 | 2025-09-30 07:56:38.683805 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main] 2025-09-30 07:56:38.684689 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main] 2025-09-30 07:56:39.282124 | 2025-09-30 07:56:39.282293 | PLAY [Run ci/playbooks/collect-logs.yml] 2025-09-30 07:56:39.303280 | 2025-09-30 07:56:39.303355 | TASK [Filter out host if needed] 2025-09-30 07:56:39.311987 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller 2025-09-30 07:56:39.316477 | 2025-09-30 07:56:39.316540 | TASK [Ensure file is present] 2025-09-30 07:56:39.790886 | controller | ok 2025-09-30 07:56:39.806562 | 2025-09-30 07:56:39.806756 | TASK [Manage molecule report file] 2025-09-30 07:56:40.353949 | controller | changed 2025-09-30 07:56:40.365269 | 2025-09-30 07:56:40.365409 | TASK [Check if we get ci-framework-data basedir] 2025-09-30 07:56:40.691558 | controller | ok 2025-09-30 07:56:40.696881 | 2025-09-30 07:56:40.696948 | TASK [Create ci-framework-data log directory for zuul] 2025-09-30 07:56:41.223629 | controller | changed 2025-09-30 07:56:41.229499 | 2025-09-30 07:56:41.229565 | TASK [Copy ci-framework interesting files] 2025-09-30 07:56:41.594345 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory 2025-09-30 07:56:41.758738 | controller | changed 2025-09-30 07:56:41.770766 | 2025-09-30 07:56:41.770909 | TASK [Get SELinux listing] 2025-09-30 07:56:42.324928 | controller | changed 2025-09-30 07:56:42.336653 | 2025-09-30 07:56:42.336838 | TASK [Generate log index] 2025-09-30 07:56:44.277078 | controller | changed 2025-09-30 07:56:44.288201 | 2025-09-30 07:56:44.288333 | TASK [Get some env related data] 2025-09-30 07:56:45.055085 | controller | /home/zuul/.local/bin/ansible 2025-09-30 07:56:45.840086 | controller | changed 2025-09-30 07:56:45.850713 | 2025-09-30 07:56:45.850839 | TASK [Generate list of logs to collect in home directory] 2025-09-30 07:56:46.388089 | controller | ok: All paths examined 2025-09-30 07:56:46.400183 | 2025-09-30 07:56:46.400311 | LOOP [Copy logs from home directory] 2025-09-30 07:56:47.272126 | controller | changed: 2025-09-30 07:56:47.272607 | controller | { 2025-09-30 07:56:47.272709 | controller | "atime": 1743544925.4788878, 2025-09-30 07:56:47.272756 | controller | "ctime": 1743545329.1409318, 2025-09-30 07:56:47.272792 | controller | "dev": 64513, 2025-09-30 07:56:47.272827 | controller | "gid": 1000, 2025-09-30 07:56:47.272861 | controller | "gr_name": "zuul", 2025-09-30 07:56:47.272898 | controller | "inode": 4518807, 2025-09-30 07:56:47.272933 | controller | "isblk": false, 2025-09-30 07:56:47.272967 | controller | "ischr": false, 2025-09-30 07:56:47.273000 | controller | "isdir": false, 2025-09-30 07:56:47.273033 | controller | "isfifo": false, 2025-09-30 07:56:47.273066 | controller | "isgid": false, 2025-09-30 07:56:47.273098 | controller | "islnk": false, 2025-09-30 07:56:47.273131 | controller | "isreg": true, 2025-09-30 07:56:47.273163 | controller | "issock": false, 2025-09-30 07:56:47.273194 | controller | "isuid": false, 2025-09-30 07:56:47.273225 | controller | "mode": "0644", 2025-09-30 07:56:47.273268 | controller | "mtime": 1743545329.1409318, 2025-09-30 07:56:47.273314 | controller | "nlink": 1, 2025-09-30 07:56:47.273349 | controller | "path": "/home/zuul/crc-setup.log", 2025-09-30 07:56:47.273389 | controller | "pw_name": "zuul", 2025-09-30 07:56:47.273424 | controller | "rgrp": true, 2025-09-30 07:56:47.273457 | controller | "roth": true, 2025-09-30 07:56:47.273492 | controller | "rusr": true, 2025-09-30 07:56:47.273525 | controller | "size": 4108, 2025-09-30 07:56:47.273558 | controller | "uid": 1000, 2025-09-30 07:56:47.273591 | controller | "wgrp": false, 2025-09-30 07:56:47.273623 | controller | "woth": false, 2025-09-30 07:56:47.273690 | controller | "wusr": true, 2025-09-30 07:56:47.273739 | controller | "xgrp": false, 2025-09-30 07:56:47.273775 | controller | "xoth": false, 2025-09-30 07:56:47.273808 | controller | "xusr": false 2025-09-30 07:56:47.273841 | controller | } 2025-09-30 07:56:48.053797 | controller | changed: 2025-09-30 07:56:48.053923 | controller | { 2025-09-30 07:56:48.053946 | controller | "atime": 1759218115.4799237, 2025-09-30 07:56:48.053964 | controller | "ctime": 1759218113.183857, 2025-09-30 07:56:48.053980 | controller | "dev": 64513, 2025-09-30 07:56:48.053996 | controller | "gid": 1000, 2025-09-30 07:56:48.054012 | controller | "gr_name": "zuul", 2025-09-30 07:56:48.054027 | controller | "inode": 4194437, 2025-09-30 07:56:48.054042 | controller | "isblk": false, 2025-09-30 07:56:48.054056 | controller | "ischr": false, 2025-09-30 07:56:48.054072 | controller | "isdir": false, 2025-09-30 07:56:48.054086 | controller | "isfifo": false, 2025-09-30 07:56:48.054101 | controller | "isgid": false, 2025-09-30 07:56:48.054115 | controller | "islnk": false, 2025-09-30 07:56:48.054129 | controller | "isreg": true, 2025-09-30 07:56:48.054151 | controller | "issock": false, 2025-09-30 07:56:48.054167 | controller | "isuid": false, 2025-09-30 07:56:48.054181 | controller | "mode": "0644", 2025-09-30 07:56:48.054195 | controller | "mtime": 1759218113.183857, 2025-09-30 07:56:48.054210 | controller | "nlink": 1, 2025-09-30 07:56:48.054225 | controller | "path": "/home/zuul/crc-start.log", 2025-09-30 07:56:48.054240 | controller | "pw_name": "zuul", 2025-09-30 07:56:48.054255 | controller | "rgrp": true, 2025-09-30 07:56:48.054270 | controller | "roth": true, 2025-09-30 07:56:48.054285 | controller | "rusr": true, 2025-09-30 07:56:48.054300 | controller | "size": 3404, 2025-09-30 07:56:48.054315 | controller | "uid": 1000, 2025-09-30 07:56:48.054329 | controller | "wgrp": false, 2025-09-30 07:56:48.054344 | controller | "woth": false, 2025-09-30 07:56:48.054359 | controller | "wusr": true, 2025-09-30 07:56:48.054373 | controller | "xgrp": false, 2025-09-30 07:56:48.054388 | controller | "xoth": false, 2025-09-30 07:56:48.054402 | controller | "xusr": false 2025-09-30 07:56:48.054417 | controller | } 2025-09-30 07:56:48.849075 | controller | changed: 2025-09-30 07:56:48.849197 | controller | { 2025-09-30 07:56:48.849219 | controller | "atime": 1759218830.9049726, 2025-09-30 07:56:48.849237 | controller | "ctime": 1759218847.559457, 2025-09-30 07:56:48.849253 | controller | "dev": 64513, 2025-09-30 07:56:48.849269 | controller | "gid": 1000, 2025-09-30 07:56:48.849285 | controller | "gr_name": "zuul", 2025-09-30 07:56:48.849300 | controller | "inode": 4340273, 2025-09-30 07:56:48.849316 | controller | "isblk": false, 2025-09-30 07:56:48.849331 | controller | "ischr": false, 2025-09-30 07:56:48.849346 | controller | "isdir": false, 2025-09-30 07:56:48.849361 | controller | "isfifo": false, 2025-09-30 07:56:48.849375 | controller | "isgid": false, 2025-09-30 07:56:48.849390 | controller | "islnk": false, 2025-09-30 07:56:48.849405 | controller | "isreg": true, 2025-09-30 07:56:48.849421 | controller | "issock": false, 2025-09-30 07:56:48.849436 | controller | "isuid": false, 2025-09-30 07:56:48.849451 | controller | "mode": "0644", 2025-09-30 07:56:48.849466 | controller | "mtime": 1759218847.559457, 2025-09-30 07:56:48.849481 | controller | "nlink": 1, 2025-09-30 07:56:48.849496 | controller | "path": "/home/zuul/ansible.log", 2025-09-30 07:56:48.849511 | controller | "pw_name": "zuul", 2025-09-30 07:56:48.849526 | controller | "rgrp": true, 2025-09-30 07:56:48.849541 | controller | "roth": true, 2025-09-30 07:56:48.849559 | controller | "rusr": true, 2025-09-30 07:56:48.849575 | controller | "size": 6749, 2025-09-30 07:56:48.849591 | controller | "uid": 1000, 2025-09-30 07:56:48.849606 | controller | "wgrp": false, 2025-09-30 07:56:48.849621 | controller | "woth": false, 2025-09-30 07:56:48.849635 | controller | "wusr": true, 2025-09-30 07:56:48.849650 | controller | "xgrp": false, 2025-09-30 07:56:48.849682 | controller | "xoth": false, 2025-09-30 07:56:48.849702 | controller | "xusr": false 2025-09-30 07:56:48.849717 | controller | } 2025-09-30 07:56:48.866562 | 2025-09-30 07:56:48.866784 | TASK [Copy crio stats log file] 2025-09-30 07:56:48.893996 | controller | skipping: Conditional result was False 2025-09-30 07:56:48.905810 | 2025-09-30 07:56:48.905945 | TASK [Get SELinux related data] 2025-09-30 07:56:49.285345 | controller | 2025-09-30 07:56:49.452827 | controller | ERROR 2025-09-30 07:56:49.453095 | controller | { 2025-09-30 07:56:49.453154 | controller | "delta": "0:00:00.011562", 2025-09-30 07:56:49.453198 | controller | "end": "2025-09-30 07:56:49.286411", 2025-09-30 07:56:49.453236 | controller | "msg": "non-zero return code", 2025-09-30 07:56:49.453272 | controller | "rc": 1, 2025-09-30 07:56:49.453306 | controller | "start": "2025-09-30 07:56:49.274849" 2025-09-30 07:56:49.453341 | controller | } 2025-09-30 07:56:49.453388 | controller | ERROR: Ignoring Errors 2025-09-30 07:56:49.464030 | 2025-09-30 07:56:49.464157 | TASK [Create system configuration directory] 2025-09-30 07:56:49.827504 | controller | changed 2025-09-30 07:56:49.838446 | 2025-09-30 07:56:49.838577 | TASK [Get some of the system configurations] 2025-09-30 07:56:50.389880 | controller | changed 2025-09-30 07:56:50.400623 | 2025-09-30 07:56:50.400792 | TASK [Copy generated documentation if available] 2025-09-30 07:56:50.427294 | controller | skipping: Conditional result was False 2025-09-30 07:56:50.439435 | 2025-09-30 07:56:50.439567 | TASK [Copy generated AsciiDoc documentation if available] 2025-09-30 07:56:50.466263 | controller | skipping: Conditional result was False 2025-09-30 07:56:50.478274 | 2025-09-30 07:56:50.478401 | TASK [Compress logs bigger than 2MB] 2025-09-30 07:56:51.033768 | controller | changed 2025-09-30 07:56:51.044508 | 2025-09-30 07:56:51.044635 | TASK [Copy files from workspace on node] 2025-09-30 07:56:51.072145 | controller | ok 2025-09-30 07:56:51.113593 | 2025-09-30 07:56:51.113701 | TASK [fetch-output : Set log path for multiple nodes] 2025-09-30 07:56:51.138429 | controller | skipping: Conditional result was False 2025-09-30 07:56:51.146563 | 2025-09-30 07:56:51.146655 | TASK [fetch-output : Set log path for single node] 2025-09-30 07:56:51.192071 | controller | ok 2025-09-30 07:56:51.204273 | 2025-09-30 07:56:51.204395 | LOOP [fetch-output : Ensure local output dirs] 2025-09-30 07:56:51.500599 | controller -> localhost | ok: "/var/lib/zuul/builds/b2302220a73b484ca6fe7dc378e1df74/work/logs" 2025-09-30 07:56:51.501104 | controller -> localhost | changed: All items complete 2025-09-30 07:56:51.501166 | 2025-09-30 07:56:51.716573 | controller -> localhost | changed: "/var/lib/zuul/builds/b2302220a73b484ca6fe7dc378e1df74/work/artifacts" 2025-09-30 07:56:51.931989 | controller -> localhost | changed: "/var/lib/zuul/builds/b2302220a73b484ca6fe7dc378e1df74/work/docs" 2025-09-30 07:56:51.958174 | 2025-09-30 07:56:51.958343 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-09-30 07:56:52.796729 | controller | changed: 2025-09-30 07:56:52.797130 | controller | .d..t...... ./ 2025-09-30 07:56:52.797190 | controller | >f+++++++++ README.html 2025-09-30 07:56:52.797235 | controller | >f+++++++++ ansible-execution.log 2025-09-30 07:56:52.797277 | controller | >f+++++++++ ansible.log 2025-09-30 07:56:52.797315 | controller | >f+++++++++ crc-setup.log 2025-09-30 07:56:52.797353 | controller | >f+++++++++ crc-start.log 2025-09-30 07:56:52.797390 | controller | >f+++++++++ dmesg.log 2025-09-30 07:56:52.797433 | controller | >f+++++++++ installed-pkgs.log 2025-09-30 07:56:52.797471 | controller | >f+++++++++ python.log 2025-09-30 07:56:52.797507 | controller | >f+++++++++ registries.conf 2025-09-30 07:56:52.797542 | controller | >f+++++++++ report.html 2025-09-30 07:56:52.797578 | controller | >f+++++++++ selinux-denials.log 2025-09-30 07:56:52.797613 | controller | >f+++++++++ selinux-listing.log 2025-09-30 07:56:52.797648 | controller | cd+++++++++ ci-framework-data/ 2025-09-30 07:56:52.797730 | controller | cd+++++++++ ci-framework-data/artifacts/ 2025-09-30 07:56:52.797770 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml 2025-09-30 07:56:52.797805 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/ 2025-09-30 07:56:52.797846 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/ci_multus.backup/ 2025-09-30 07:56:52.797896 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/ci_multus.backup/ci_multus/ 2025-09-30 07:56:52.797944 | controller | >f+++++++++ ci-framework-data/artifacts/manifests/ci_multus.backup/ci_multus/ci_multus_nads.yml 2025-09-30 07:56:52.797991 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/ 2025-09-30 07:56:52.798036 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml 2025-09-30 07:56:52.798080 | controller | cd+++++++++ ci-framework-data/logs/ 2025-09-30 07:56:52.798125 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log 2025-09-30 07:56:52.798170 | controller | cd+++++++++ registries.conf.d/ 2025-09-30 07:56:52.798227 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf 2025-09-30 07:56:52.798273 | controller | cd+++++++++ system-config/ 2025-09-30 07:56:52.798318 | controller | cd+++++++++ system-config/libvirt/ 2025-09-30 07:56:52.798363 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf 2025-09-30 07:56:52.798429 | controller | >f+++++++++ system-config/libvirt/libvirt.conf 2025-09-30 07:56:52.798474 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf 2025-09-30 07:56:52.798518 | controller | >f+++++++++ system-config/libvirt/network.conf 2025-09-30 07:56:52.798562 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf 2025-09-30 07:56:52.798610 | controller | >f+++++++++ system-config/libvirt/qemu.conf 2025-09-30 07:56:52.798689 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf 2025-09-30 07:56:52.798753 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf 2025-09-30 07:56:52.798806 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf 2025-09-30 07:56:52.798854 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf 2025-09-30 07:56:52.798898 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf 2025-09-30 07:56:52.798941 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf 2025-09-30 07:56:52.798985 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf 2025-09-30 07:56:52.799029 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf 2025-09-30 07:56:52.799072 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf 2025-09-30 07:56:52.799116 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf 2025-09-30 07:56:53.414563 | controller | changed: .d..t...... ./ 2025-09-30 07:56:54.035981 | controller | changed: .d..t...... ./ 2025-09-30 07:56:54.068311 | 2025-09-30 07:56:54.068504 | TASK [Return artifact to Zuul] 2025-09-30 07:56:54.125268 | controller | ok 2025-09-30 07:56:54.164333 | 2025-09-30 07:56:54.164409 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host] 2025-09-30 07:56:54.164552 | 2025-09-30 07:56:54.164586 | PLAY RECAP 2025-09-30 07:56:54.164636 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1 2025-09-30 07:56:54.164687 | 2025-09-30 07:56:54.275046 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main] 2025-09-30 07:56:54.276602 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/dlrn/dlrn-report.yaml@master] 2025-09-30 07:56:54.830231 | 2025-09-30 07:56:54.830343 | PLAY [Report DLRN results after job run] 2025-09-30 07:56:54.850528 | 2025-09-30 07:56:54.850623 | TASK [Report job status to DLRN] 2025-09-30 07:56:54.870830 | controller | ok 2025-09-30 07:56:54.893245 | 2025-09-30 07:56:54.893322 | TASK [dlrn_report : Warning if DLRN is not running] 2025-09-30 07:56:54.957966 | controller | skipping: Conditional result was False 2025-09-30 07:56:54.965928 | 2025-09-30 07:56:54.966022 | TASK [dlrn_report : Install dlrnapi-client shyaml package] 2025-09-30 07:56:55.022065 | controller | skipping: Conditional result was False 2025-09-30 07:56:55.036692 | 2025-09-30 07:56:55.036862 | TASK [dlrn_report : Install kinit related package] 2025-09-30 07:56:55.094483 | controller | skipping: Conditional result was False 2025-09-30 07:56:55.106850 | 2025-09-30 07:56:55.106983 | TASK [dlrn_report : Install dlrn kerberos related packages] 2025-09-30 07:56:55.164313 | controller | skipping: Conditional result was False 2025-09-30 07:56:55.178354 | 2025-09-30 07:56:55.178482 | TASK [Set zuul-log-path fact] 2025-09-30 07:56:55.235950 | controller | skipping: Conditional result was False 2025-09-30 07:56:55.248198 | 2025-09-30 07:56:55.248343 | TASK [dlrn_report : Set the the value of cifmw_repo_setup_promotion when multiple dlrn tags are used] 2025-09-30 07:56:55.316901 | controller | skipping: Conditional result was False 2025-09-30 07:56:55.329767 | 2025-09-30 07:56:55.329917 | TASK [Get hash related data from repo_setup role] 2025-09-30 07:56:55.397308 | controller | skipping: Conditional result was False 2025-09-30 07:56:55.410480 | 2025-09-30 07:56:55.410619 | TASK [dlrn_report : Perform kinit for DLRN kerberos authentication] 2025-09-30 07:56:55.964396 | controller | skipping: Conditional result was False 2025-09-30 07:56:55.978116 | 2025-09-30 07:56:55.978312 | TASK [dlrn_report : Set empty value for dlrnapi password] 2025-09-30 07:56:56.056506 | controller | skipping: Conditional result was False 2025-09-30 07:56:56.069185 | 2025-09-30 07:56:56.069330 | TASK [dlrn_report : Report results to dlrn for the tested hash] 2025-09-30 07:56:56.619790 | controller | skipping: Conditional result was False 2025-09-30 07:56:56.671576 | 2025-09-30 07:56:56.671654 | PLAY RECAP 2025-09-30 07:56:56.671737 | controller | ok: 0 changed: 0 unreachable: 0 failed: 0 skipped: 10 rescued: 0 ignored: 0 2025-09-30 07:56:56.671766 | 2025-09-30 07:56:56.771303 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/dlrn/dlrn-report.yaml@master] 2025-09-30 07:56:56.772938 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-09-30 07:56:57.347928 | 2025-09-30 07:56:57.348041 | PLAY [all] 2025-09-30 07:56:57.366903 | 2025-09-30 07:56:57.366983 | TASK [include_role : fetch-output] 2025-09-30 07:56:57.406428 | controller | ok 2025-09-30 07:56:57.423093 | 2025-09-30 07:56:57.423175 | TASK [fetch-output : Set log path for multiple nodes] 2025-09-30 07:56:57.487080 | controller | skipping: Conditional result was False 2025-09-30 07:56:57.492753 | 2025-09-30 07:56:57.492820 | TASK [fetch-output : Set log path for single node] 2025-09-30 07:56:57.530974 | controller | ok 2025-09-30 07:56:57.535807 | 2025-09-30 07:56:57.535870 | LOOP [fetch-output : Ensure local output dirs] 2025-09-30 07:56:57.930908 | controller -> localhost | ok: "/var/lib/zuul/builds/b2302220a73b484ca6fe7dc378e1df74/work/logs" 2025-09-30 07:56:58.191784 | controller -> localhost | ok: "/var/lib/zuul/builds/b2302220a73b484ca6fe7dc378e1df74/work/artifacts" 2025-09-30 07:56:58.405643 | controller -> localhost | ok: "/var/lib/zuul/builds/b2302220a73b484ca6fe7dc378e1df74/work/docs" 2025-09-30 07:56:58.419382 | 2025-09-30 07:56:58.419450 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-09-30 07:56:59.299818 | controller | ok 2025-09-30 07:56:59.300153 | controller | ok: All items complete 2025-09-30 07:56:59.300210 | 2025-09-30 07:56:59.944305 | controller | ok 2025-09-30 07:57:00.520154 | controller | ok 2025-09-30 07:57:00.540147 | 2025-09-30 07:57:00.540378 | TASK [include_role : fetch-output-openshift] 2025-09-30 07:57:00.565268 | controller | skipping: Conditional result was False 2025-09-30 07:57:00.573363 | 2025-09-30 07:57:00.573452 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-09-30 07:57:01.056954 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013053 2025-09-30 07:57:01.338284 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.012837 2025-09-30 07:57:01.397035 | 2025-09-30 07:57:01.397221 | PLAY [all] 2025-09-30 07:57:01.418063 | 2025-09-30 07:57:01.418157 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-09-30 07:57:02.007821 | controller | changed 2025-09-30 07:57:02.056029 | 2025-09-30 07:57:02.056180 | PLAY RECAP 2025-09-30 07:57:02.056240 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-09-30 07:57:02.056268 | 2025-09-30 07:57:02.218603 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-09-30 07:57:02.220601 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-09-30 07:57:02.796870 | 2025-09-30 07:57:02.797076 | PLAY [localhost] 2025-09-30 07:57:02.814785 | 2025-09-30 07:57:02.814860 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-09-30 07:57:03.239399 | localhost | changed 2025-09-30 07:57:03.244435 | 2025-09-30 07:57:03.244515 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-09-30 07:57:03.273931 | localhost | ok 2025-09-30 07:57:03.281928 | 2025-09-30 07:57:03.281997 | TASK [add-fileserver : Create SSH private key tempfile] 2025-09-30 07:57:03.699069 | localhost | changed 2025-09-30 07:57:03.704339 | 2025-09-30 07:57:03.704411 | TASK [add-fileserver : Create SSH private key from secret] 2025-09-30 07:57:04.389529 | localhost | changed 2025-09-30 07:57:04.401103 | 2025-09-30 07:57:04.401254 | TASK [add-fileserver : Add fileserver ssh key] 2025-09-30 07:57:04.866502 | localhost | Identity added: /var/lib/zuul/builds/b2302220a73b484ca6fe7dc378e1df74/work/tmp/ansible.66oaw456 (/var/lib/zuul/builds/b2302220a73b484ca6fe7dc378e1df74/work/tmp/ansible.66oaw456) 2025-09-30 07:57:04.866934 | localhost | ok: Runtime: 0:00:00.012795 2025-09-30 07:57:04.877619 | 2025-09-30 07:57:04.877813 | TASK [add-fileserver : Remove SSH private key from disk] 2025-09-30 07:57:05.190493 | localhost | ok: Runtime: 0:00:00.009716 2025-09-30 07:57:05.202639 | 2025-09-30 07:57:05.202850 | TASK [add-fileserver : Add fileserver to inventory] 2025-09-30 07:57:05.279650 | localhost | changed 2025-09-30 07:57:05.289473 | 2025-09-30 07:57:05.289618 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-09-30 07:57:05.733539 | localhost | changed 2025-09-30 07:57:05.774606 | 2025-09-30 07:57:05.774715 | PLAY [localhost] 2025-09-30 07:57:05.792855 | 2025-09-30 07:57:05.792946 | TASK [Generate bulk log download script] 2025-09-30 07:57:05.813718 | localhost | ok 2025-09-30 07:57:05.830463 | 2025-09-30 07:57:05.830557 | TASK [local-log-download : Check API endpoint is defined] 2025-09-30 07:57:05.860699 | localhost | ok: All assertions passed 2025-09-30 07:57:05.867336 | 2025-09-30 07:57:05.867427 | TASK [local-log-download : Create download script] 2025-09-30 07:57:06.329040 | localhost -> localhost | changed 2025-09-30 07:57:06.338335 | 2025-09-30 07:57:06.338401 | TASK [Register quick-download link] 2025-09-30 07:57:06.367429 | localhost | ok 2025-09-30 07:57:06.411610 | 2025-09-30 07:57:06.411753 | PLAY [logserver.rdoproject.org] 2025-09-30 07:57:06.421143 | 2025-09-30 07:57:06.421204 | TASK [Set zuul-log-path fact] 2025-09-30 07:57:06.438389 | logserver.rdoproject.org | ok 2025-09-30 07:57:06.447291 | 2025-09-30 07:57:06.447357 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-30 07:57:06.483821 | logserver.rdoproject.org | ok 2025-09-30 07:57:06.491344 | 2025-09-30 07:57:06.491429 | TASK [upload-logs : Create log directories] 2025-09-30 07:57:07.388075 | logserver.rdoproject.org | changed 2025-09-30 07:57:07.394815 | 2025-09-30 07:57:07.394951 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-09-30 07:57:07.686402 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005857 2025-09-30 07:57:07.696556 | 2025-09-30 07:57:07.696748 | TASK [upload-logs : Upload logs to log server] 2025-09-30 07:57:08.553227 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-09-30 07:57:08.559491 | 2025-09-30 07:57:08.559626 | LOOP [upload-logs : Compress console log and json output] 2025-09-30 07:57:08.629328 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 07:57:08.640649 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 07:57:08.654650 | 2025-09-30 07:57:08.654893 | LOOP [upload-logs : Upload compressed console log and json output] 2025-09-30 07:57:08.704462 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 07:57:08.704942 | 2025-09-30 07:57:08.707925 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 07:57:08.718987 | 2025-09-30 07:57:08.719151 | LOOP [upload-logs : Upload console log and json output]