2025-09-30 05:00:27.501277 | Job console starting... 2025-09-30 05:00:27.517356 | Updating repositories 2025-09-30 05:00:27.551207 | Preparing job workspace 2025-09-30 05:00:34.179802 | Running Ansible setup... 2025-09-30 05:00:39.308940 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-09-30 05:00:39.890127 | 2025-09-30 05:00:39.890274 | PLAY [localhost] 2025-09-30 05:00:39.899906 | 2025-09-30 05:00:39.899975 | TASK [Gathering Facts] 2025-09-30 05:00:40.858645 | localhost | ok 2025-09-30 05:00:40.875628 | 2025-09-30 05:00:40.875748 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-09-30 05:00:41.278995 | localhost -> localhost | changed 2025-09-30 05:00:41.284375 | 2025-09-30 05:00:41.284445 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-09-30 05:00:42.288321 | localhost -> localhost | changed 2025-09-30 05:00:42.296431 | 2025-09-30 05:00:42.296497 | TASK [Setup log path fact] 2025-09-30 05:00:42.313949 | localhost | ok 2025-09-30 05:00:42.325363 | 2025-09-30 05:00:42.325426 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-30 05:00:42.352417 | localhost | ok 2025-09-30 05:00:42.360106 | 2025-09-30 05:00:42.360169 | TASK [emit-job-header : Print job information] 2025-09-30 05:00:42.386697 | # Job Information 2025-09-30 05:00:42.386841 | Ansible Version: 2.15.12 2025-09-30 05:00:42.386867 | Job: cifmw-molecule-ci_multus 2025-09-30 05:00:42.386887 | Pipeline: github-check 2025-09-30 05:00:42.386905 | Executor: ze02.softwarefactory-project.io 2025-09-30 05:00:42.386923 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3333 2025-09-30 05:00:42.386941 | Log URL (when completed): https://logserver.rdoproject.org/c5b/rdoproject.org/c5b76151df2e4b4cb0e4218aced4e6ae/ 2025-09-30 05:00:42.386958 | Event ID: 3089cae0-9dba-11f0-9d66-59f03df1d747 2025-09-30 05:00:42.394429 | 2025-09-30 05:00:42.394568 | LOOP [emit-job-header : Print node information] 2025-09-30 05:00:42.484810 | localhost | ok: 2025-09-30 05:00:42.484968 | localhost | # Node Information 2025-09-30 05:00:42.484994 | localhost | Inventory Hostname: controller 2025-09-30 05:00:42.485017 | localhost | Hostname: np0005461545 2025-09-30 05:00:42.485036 | localhost | Username: zuul 2025-09-30 05:00:42.485087 | localhost | Distro: CentOS 9 2025-09-30 05:00:42.485110 | localhost | Provider: vexxhost-nodepool-tripleo 2025-09-30 05:00:42.485127 | localhost | Region: RegionOne 2025-09-30 05:00:42.485144 | localhost | Label: centos-9-stream-crc-2-48-0-xxl 2025-09-30 05:00:42.485160 | localhost | Product Name: OpenStack Nova 2025-09-30 05:00:42.485175 | localhost | Interface IP: 38.102.83.36 2025-09-30 05:00:42.508017 | 2025-09-30 05:00:42.508155 | PLAY [all] 2025-09-30 05:00:42.514398 | 2025-09-30 05:00:42.514458 | TASK [Gather network facts] 2025-09-30 05:00:43.130301 | controller | ok 2025-09-30 05:00:43.144896 | 2025-09-30 05:00:43.144954 | TASK [include_role : start-zuul-console] 2025-09-30 05:00:43.162889 | controller | ok 2025-09-30 05:00:43.173873 | 2025-09-30 05:00:43.173932 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-09-30 05:00:43.690208 | controller | ok 2025-09-30 05:00:43.702859 | 2025-09-30 05:00:43.702940 | TASK [include_role : add-build-sshkey] 2025-09-30 05:00:43.724008 | controller | ok 2025-09-30 05:00:43.750486 | 2025-09-30 05:00:43.750598 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-09-30 05:00:44.083819 | controller -> localhost | ok 2025-09-30 05:00:44.089333 | 2025-09-30 05:00:44.089402 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-09-30 05:00:44.124236 | controller | ok 2025-09-30 05:00:44.142537 | controller | included: /var/lib/zuul/builds/c5b76151df2e4b4cb0e4218aced4e6ae/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-09-30 05:00:44.150270 | 2025-09-30 05:00:44.150345 | TASK [add-build-sshkey : Create Temp SSH key] 2025-09-30 05:00:44.651764 | controller -> localhost | Generating public/private rsa key pair. 2025-09-30 05:00:44.651974 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/c5b76151df2e4b4cb0e4218aced4e6ae/work/c5b76151df2e4b4cb0e4218aced4e6ae_id_rsa. 2025-09-30 05:00:44.652005 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/c5b76151df2e4b4cb0e4218aced4e6ae/work/c5b76151df2e4b4cb0e4218aced4e6ae_id_rsa.pub. 2025-09-30 05:00:44.652027 | controller -> localhost | The key fingerprint is: 2025-09-30 05:00:44.652047 | controller -> localhost | SHA256:v9w9TU2Fs1/NIfCeZm2YzHFZ9EAQeoFVF96evy5T7GM zuul-build-sshkey 2025-09-30 05:00:44.652066 | controller -> localhost | The key's randomart image is: 2025-09-30 05:00:44.652084 | controller -> localhost | +---[RSA 3072]----+ 2025-09-30 05:00:44.652102 | controller -> localhost | | +*=++=| 2025-09-30 05:00:44.652119 | controller -> localhost | | ...o++*| 2025-09-30 05:00:44.652137 | controller -> localhost | | . .o.B*| 2025-09-30 05:00:44.652154 | controller -> localhost | | .+ O.*| 2025-09-30 05:00:44.652172 | controller -> localhost | | S X.*+| 2025-09-30 05:00:44.652188 | controller -> localhost | | . o .o=| 2025-09-30 05:00:44.652205 | controller -> localhost | | . oo.| 2025-09-30 05:00:44.652222 | controller -> localhost | | . o +.Eo| 2025-09-30 05:00:44.652253 | controller -> localhost | | o . *+.| 2025-09-30 05:00:44.652271 | controller -> localhost | +----[SHA256]-----+ 2025-09-30 05:00:44.652319 | controller -> localhost | ok: Runtime: 0:00:00.083605 2025-09-30 05:00:44.658454 | 2025-09-30 05:00:44.658531 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-09-30 05:00:44.696200 | controller | ok 2025-09-30 05:00:44.707362 | controller | included: /var/lib/zuul/builds/c5b76151df2e4b4cb0e4218aced4e6ae/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-09-30 05:00:44.715323 | 2025-09-30 05:00:44.715386 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-09-30 05:00:44.729241 | controller | skipping: Conditional result was False 2025-09-30 05:00:44.737466 | 2025-09-30 05:00:44.737626 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-09-30 05:00:45.405376 | controller | changed 2025-09-30 05:00:45.419548 | 2025-09-30 05:00:45.419685 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-09-30 05:00:45.856233 | controller | ok 2025-09-30 05:00:45.864462 | 2025-09-30 05:00:45.864528 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-09-30 05:00:47.716381 | controller | changed 2025-09-30 05:00:47.722527 | 2025-09-30 05:00:47.722591 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-09-30 05:00:49.579325 | controller | changed 2025-09-30 05:00:49.584618 | 2025-09-30 05:00:49.584714 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-09-30 05:00:49.599200 | controller | skipping: Conditional result was False 2025-09-30 05:00:49.609497 | 2025-09-30 05:00:49.609566 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-09-30 05:00:50.069941 | controller -> localhost | changed 2025-09-30 05:00:50.079820 | 2025-09-30 05:00:50.079887 | TASK [add-build-sshkey : Add back temp key] 2025-09-30 05:00:50.379225 | controller -> localhost | Identity added: /var/lib/zuul/builds/c5b76151df2e4b4cb0e4218aced4e6ae/work/c5b76151df2e4b4cb0e4218aced4e6ae_id_rsa (zuul-build-sshkey) 2025-09-30 05:00:50.379433 | controller -> localhost | ok: Runtime: 0:00:00.011915 2025-09-30 05:00:50.385496 | 2025-09-30 05:00:50.385558 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-09-30 05:00:50.838712 | controller | ok 2025-09-30 05:00:50.846025 | 2025-09-30 05:00:50.846111 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-09-30 05:00:50.871252 | controller | skipping: Conditional result was False 2025-09-30 05:00:50.910776 | 2025-09-30 05:00:50.910898 | TASK [include_role : validate-host] 2025-09-30 05:00:50.940238 | controller | ok 2025-09-30 05:00:50.962097 | 2025-09-30 05:00:50.962203 | TASK [validate-host : Define zuul_info_dir fact] 2025-09-30 05:00:50.991698 | controller | ok 2025-09-30 05:00:50.996647 | 2025-09-30 05:00:50.996730 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-09-30 05:00:51.255599 | controller -> localhost | ok 2025-09-30 05:00:51.263300 | 2025-09-30 05:00:51.263371 | TASK [validate-host : Collect information about the host] 2025-09-30 05:00:52.170790 | controller | ok 2025-09-30 05:00:52.181770 | 2025-09-30 05:00:52.181833 | TASK [validate-host : Sanitize hostname] 2025-09-30 05:00:52.242728 | controller | ok 2025-09-30 05:00:52.248352 | 2025-09-30 05:00:52.248415 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-09-30 05:00:52.752231 | controller -> localhost | changed 2025-09-30 05:00:52.760030 | 2025-09-30 05:00:52.760115 | TASK [validate-host : Collect information about zuul worker] 2025-09-30 05:00:53.292389 | controller | ok 2025-09-30 05:00:53.307971 | 2025-09-30 05:00:53.308122 | TASK [validate-host : Write out all zuul information for each host] 2025-09-30 05:00:53.829038 | controller -> localhost | changed 2025-09-30 05:00:53.838576 | 2025-09-30 05:00:53.838698 | TASK [include_role : prepare-workspace-openshift] 2025-09-30 05:00:53.857649 | controller | skipping: Conditional result was False 2025-09-30 05:00:53.863893 | 2025-09-30 05:00:53.863970 | TASK [include_role : remove-zuul-sshkey] 2025-09-30 05:00:53.879941 | controller | skipping: Conditional result was False 2025-09-30 05:00:53.885762 | 2025-09-30 05:00:53.885829 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-09-30 05:00:54.276617 | controller | ok: "logs" 2025-09-30 05:00:54.277050 | controller | ok: All items complete 2025-09-30 05:00:54.277118 | 2025-09-30 05:00:54.641364 | controller | ok: "artifacts" 2025-09-30 05:00:54.970894 | controller | ok: "docs" 2025-09-30 05:00:54.986603 | 2025-09-30 05:00:54.986788 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-09-30 05:00:55.374308 | controller | changed: "logs" 2025-09-30 05:00:55.713174 | controller | changed: "artifacts" 2025-09-30 05:00:56.031657 | controller | changed: "docs" 2025-09-30 05:00:56.062512 | 2025-09-30 05:00:56.062632 | PLAY RECAP 2025-09-30 05:00:56.062697 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-09-30 05:00:56.062727 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-09-30 05:00:56.062744 | 2025-09-30 05:00:56.178555 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-09-30 05:00:56.180313 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master] 2025-09-30 05:00:56.940041 | 2025-09-30 05:00:56.940263 | PLAY [all] 2025-09-30 05:00:56.969592 | 2025-09-30 05:00:56.969781 | TASK [mirror-info-fork : Set mirror_fqdn if not defined] 2025-09-30 05:00:57.052281 | controller | ok 2025-09-30 05:00:57.057951 | 2025-09-30 05:00:57.058090 | TASK [mirror-info-fork : Create /etc/ci] 2025-09-30 05:00:57.643934 | controller | changed 2025-09-30 05:00:57.660746 | 2025-09-30 05:00:57.660835 | TASK [mirror-info-fork : Install ci_mirror script] 2025-09-30 05:00:59.661176 | controller | changed 2025-09-30 05:00:59.687891 | 2025-09-30 05:00:59.688328 | LOOP [add-authorized-keys : Enable access via build key on all nodes] 2025-09-30 05:01:00.376931 | controller | changed: 2025-09-30 05:01:00.377115 | controller | { 2025-09-30 05:01:00.377145 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com" 2025-09-30 05:01:00.377172 | controller | } 2025-09-30 05:01:00.793181 | controller | changed: 2025-09-30 05:01:00.793370 | controller | { 2025-09-30 05:01:00.793401 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com" 2025-09-30 05:01:00.793422 | controller | } 2025-09-30 05:01:01.259686 | controller | changed: 2025-09-30 05:01:01.259773 | controller | { 2025-09-30 05:01:01.259797 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com" 2025-09-30 05:01:01.259815 | controller | } 2025-09-30 05:01:01.661347 | controller | changed: 2025-09-30 05:01:01.661450 | controller | { 2025-09-30 05:01:01.661474 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com" 2025-09-30 05:01:01.661492 | controller | } 2025-09-30 05:01:02.117843 | controller | changed: 2025-09-30 05:01:02.118012 | controller | { 2025-09-30 05:01:02.118044 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com" 2025-09-30 05:01:02.118070 | controller | } 2025-09-30 05:01:02.517410 | controller | changed: 2025-09-30 05:01:02.517546 | controller | { 2025-09-30 05:01:02.517573 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com" 2025-09-30 05:01:02.517592 | controller | } 2025-09-30 05:01:02.947318 | controller | changed: 2025-09-30 05:01:02.947474 | controller | { 2025-09-30 05:01:02.947499 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDLOQd4ZLtkZXQGY6UwAr/06ppWQK4fDO3HaqxPk98csyOCBXsliSKK39Bso828+5srIXiW7aI6aC9P5mwi4mUZlGPfJlQbfrcGvY+b/SocuvaGK+1RrHLoJCT52LBhwgrzlXio2jeksZeein8iaTrhsPrOAs7KggIL/rB9hEiB3NaOPWhhoCP4vlW6MEMExGcqB/1FVxXFBPnLkEyW0Lk7ycVflZl2ocRxbfjZi0+tI1Wlinp8PvSQSc/WVrAcDgKjc/mB4ODPOyYy3G8FHgfMsrXSDEyjBKgLKMsdCrAUcqJQWjkqXleXSYOV4q3pzL+9umK+q/e3P/bIoSFQzmJKTU1eDfuvPXmow9F5H54fii/Da7ezlMJ+wPGHJrRAkmzvMbALy7xwswLhZMkOGNtRcPqaKYRmIBKpw3o6bCTtcNUHOtOQnzwY8JzrM2eBWJBXAANYw+9/ho80JIiwhg29CFNpVBuHbql2YxJQNrnl90guN65rYNpDxdIluweyUf8= anbanerj@kaermorhen" 2025-09-30 05:01:02.947519 | controller | } 2025-09-30 05:01:03.370872 | controller | changed: 2025-09-30 05:01:03.371060 | controller | { 2025-09-30 05:01:03.371085 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC3VwV8Im9kRm49lt3tM36hj4Zv27FxGo4C1Q/0jqhzFmHY7RHbmeRr8ObhwWoHjXSozKWg8FL5ER0z3hTwL0W6lez3sL7hUaCmSuZmG5Hnl3x4vTSxDI9JZ/Y65rtYiiWQo2fC5xJhU/4+0e5e/pseCm8cKRSu+SaxhO+sd6FDojA2x1BzOzKiQRDy/1zWGp/cZkxcEuB1wHI5LMzN03c67vmbu+fhZRAUO4dQkvcnj2LrhQtpa+ytvnSjr8icMDosf1OsbSffwZFyHB/hfWGAfe0eIeSA2XPraxiPknXxiPKx2MJsaUTYbsZcm3EjFdHBBMumw5rBI74zLrMRvCO9GwBEmGT4rFng1nP+yw5DB8sn2zqpOsPg1LYRwCPOUveC13P6pgsZZPh812e8v5EKnETct+5XI3dVpdw6CnNiLwAyVAF15DJvBGT/u1k0Myg/bQn+Gv9k2MSj6LvQmf6WbZu2Wgjm30z3FyCneBqTL7mLF19YXzeC0ufHz5pnO1E= dasm@fedora" 2025-09-30 05:01:03.371106 | controller | } 2025-09-30 05:01:03.820207 | controller | changed: 2025-09-30 05:01:03.820387 | controller | { 2025-09-30 05:01:03.820412 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner" 2025-09-30 05:01:03.820432 | controller | } 2025-09-30 05:01:04.229951 | controller | changed: 2025-09-30 05:01:04.230135 | controller | { 2025-09-30 05:01:04.230167 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com" 2025-09-30 05:01:04.230192 | controller | } 2025-09-30 05:01:04.583446 | controller | changed: 2025-09-30 05:01:04.583582 | controller | { 2025-09-30 05:01:04.583605 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com" 2025-09-30 05:01:04.583623 | controller | } 2025-09-30 05:01:04.974726 | controller | changed: 2025-09-30 05:01:04.974906 | controller | { 2025-09-30 05:01:04.974929 | controller | "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com" 2025-09-30 05:01:04.974949 | controller | } 2025-09-30 05:01:05.459314 | controller | changed: 2025-09-30 05:01:05.459502 | controller | { 2025-09-30 05:01:05.459525 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith" 2025-09-30 05:01:05.459544 | controller | } 2025-09-30 05:01:05.850370 | controller | changed: 2025-09-30 05:01:05.850557 | controller | { 2025-09-30 05:01:05.850581 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel" 2025-09-30 05:01:05.850599 | controller | } 2025-09-30 05:01:06.249352 | controller | changed: 2025-09-30 05:01:06.249613 | controller | { 2025-09-30 05:01:06.249707 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux" 2025-09-30 05:01:06.249759 | controller | } 2025-09-30 05:01:06.700204 | controller | changed: 2025-09-30 05:01:06.700344 | controller | { 2025-09-30 05:01:06.700368 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr" 2025-09-30 05:01:06.700386 | controller | } 2025-09-30 05:01:07.095970 | controller | changed: 2025-09-30 05:01:07.096127 | controller | { 2025-09-30 05:01:07.096151 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQCfNtF7NvKl915TGsGGoseUb06Hj8L/S4toWf0hExeY+F00woL6NvBlJD0nDct+P5a22I4EhvoQCRQ8reaPCm1lybR3uiRIJsj+8zkVvLwby9LXzfZorlNG9ofjd00FEmB09uW/YvTl6Q9XwwwX6tInzIOv3TMqTHHGOL74ibbj8J/FJR0cFEyj0z4WQRvtkh32xAHl83gbuINryMt0sqRI+clj2381NKL55DRLQrVw0gsfqqxiHAnXg21qWmc4J+b9e9kiuAFQjcjwTVkwJCcg3xbPwC/qokYRby/Y5S40UUd7/jEARGXT7RZgpzTuDd1oZiCVrnrqJNPaMNdVv5MLeFdf1B7iIe5aa/fGouX7AO4SdKhZUdnJmCFAGvjC6S3JMZ2wAcUl+OHnssfmdj7XL50cLo27vjuzMtLAgSqi6N99m92WCF2s8J9aVzszX7Xz9OKZCeGsiVJp3/NdABKzSEAyM9xBD/5Vho894Sav+otpySHe3p6RUTgbB5Zu8VyZRZ/UtB3ueXxyo764yrc6qWIDqrehm84Xm9g+/jpIBzGPl07NUNJpdt/6Sgf9RIKXw/7XypO5yZfUcuFNGTxLfqjTNrtgLZNcjfav6sSdVXVcMPL//XNuRdKmVFaO76eV/oGMQGr1fGcCD+N+CpI7+Q+fCNB6VFWG4nZFuI/Iuw== averdagu@redhat.com" 2025-09-30 05:01:07.096172 | controller | } 2025-09-30 05:01:07.559063 | controller | changed: 2025-09-30 05:01:07.559609 | controller | { 2025-09-30 05:01:07.559766 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDq8l27xI+QlQVdS4djp9ogSoyrNE2+Ox6vKPdhSNL1J3PE5w+WCSvMz9A5gnNuH810zwbekEApbxTze/gLQJwBHA52CChfURpXrFaxY7ePXRElwKAL3mJfzBWY/c5jnNL9TCVmFJTGZkFZP3Nh+BMgZvL6xBkt3WKm6Uq18qzd9XeKcZusrA+O+uLv1fVeQnadY9RIqOCyeFYCzLWrUfTyE8x/XG0hAWIM7qpnF2cALQS2h9n4hW5ybiUN790H08wf9hFwEf5nxY9Z9dVkPFQiTSGKNBzmnCXU9skxS/xhpFjJ5duGSZdtAHe9O+nGZm9c67hxgtf8e5PDuqAdXEv2cf6e3VBAt+Bz8EKI3yosTj0oZHfwr42Yzb1l/SKy14Rggsrc9KAQlrGXan6+u2jcQqqx7l+SWmnpFiWTV9u5cWj2IgOhApOitmRBPYqk9rE2usfO0hLn/Pj/R/Nau4803e1/EikdLE7Ps95s9mX5jRDjAoUa2JwFF5RsVFyL910= ashigupt@ashigupt.remote.csb" 2025-09-30 05:01:07.559835 | controller | } 2025-09-30 05:01:07.940077 | controller | changed: 2025-09-30 05:01:07.940244 | controller | { 2025-09-30 05:01:07.940267 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9" 2025-09-30 05:01:07.940285 | controller | } 2025-09-30 05:01:08.336967 | controller | changed: 2025-09-30 05:01:08.337143 | controller | { 2025-09-30 05:01:08.337167 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora" 2025-09-30 05:01:08.337186 | controller | } 2025-09-30 05:01:08.745267 | controller | changed: 2025-09-30 05:01:08.745429 | controller | { 2025-09-30 05:01:08.745452 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac" 2025-09-30 05:01:08.745470 | controller | } 2025-09-30 05:01:09.147579 | controller | changed: 2025-09-30 05:01:09.147727 | controller | { 2025-09-30 05:01:09.147751 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop" 2025-09-30 05:01:09.147769 | controller | } 2025-09-30 05:01:09.541718 | controller | changed: 2025-09-30 05:01:09.541892 | controller | { 2025-09-30 05:01:09.541915 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQDZdI7t1cxYx65heVI24HTV4F7oQLW1zyfxHreL2TIJKxjyrUUKIFEUmTutcBlJRLNT2Eoix6x1sOw9YrchloCLcn//SGfTElr9mSc5jbjb7QXEU+zJMhtxyEJ1Po3CUGnj7ckiIXw7wcawZtrEOAQ9pH3ExYCJcEMiyNjRQZCxT3tPK+S4B95EWh5Fsrz9CkwpjNRPPH7LigCeQTM3Wc7r97utAslBUUvYceDSLA7rMgkitJE38b7rZBeYzsGQ8YYUBjTCtehqQXxCRjizbHWaaZkBU+N3zkKB6n/iCNGIO690NK7A/qb6msTijiz1PeuM8ThOsi9qXnbX5v0PoTpcFSojV7NHAQ71f0XXuS43FhZctT+Dcx44dT8Fb5vJu2cJGrk+qF8ZgJYNpRS7gPg0EG2EqjK7JMf9ULdjSu0r+KlqIAyLvtzT4eOnQipoKlb/WG5D/0ohKv7OMQ352ggfkBFIQsRXyyTCT98Ft9juqPuahi3CAQmP4H9dyE+7+Kz437PEtsxLmfm6naNmWi7Ee1DqWPwS8rEajsm4sNM4wW9gdBboJQtc0uZw0DfLj1I9r3Mc8Ol0jYtz0yNQDSzVLrGCaJlC311trU70tZ+ZkAVV6Mn8lOhSbj1cK0lvSr6ZK4dgqGl3I1eTZJJhbLNdg7UOVaiRx9543+C/p/As7w== brjackma@redhat.com" 2025-09-30 05:01:09.541935 | controller | } 2025-09-30 05:01:09.900547 | controller | changed: 2025-09-30 05:01:09.900752 | controller | { 2025-09-30 05:01:09.900778 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com" 2025-09-30 05:01:09.900795 | controller | } 2025-09-30 05:01:10.311012 | controller | changed: 2025-09-30 05:01:10.311135 | controller | { 2025-09-30 05:01:10.311158 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com" 2025-09-30 05:01:10.311177 | controller | } 2025-09-30 05:01:10.693870 | controller | changed: 2025-09-30 05:01:10.694034 | controller | { 2025-09-30 05:01:10.694057 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono" 2025-09-30 05:01:10.694075 | controller | } 2025-09-30 05:01:10.730269 | 2025-09-30 05:01:10.730392 | TASK [Set timezone to UTC] 2025-09-30 05:01:12.527912 | controller | changed: executed `/bin/timedatectl set-timezone UTC` 2025-09-30 05:01:12.545074 | 2025-09-30 05:01:12.545245 | TASK [Create nodepool directory] 2025-09-30 05:01:12.906422 | controller | changed 2025-09-30 05:01:12.913455 | 2025-09-30 05:01:12.913530 | TASK [Create nodepool sub_nodes file] 2025-09-30 05:01:14.447486 | controller | changed 2025-09-30 05:01:14.452745 | 2025-09-30 05:01:14.452838 | TASK [Create nodepool sub_nodes_private file] 2025-09-30 05:01:16.077946 | controller | changed 2025-09-30 05:01:16.092452 | 2025-09-30 05:01:16.092736 | LOOP [Populate nodepool sub_nodes file] 2025-09-30 05:01:16.143824 | 2025-09-30 05:01:16.144053 | LOOP [Populate nodepool sub_nodes_private file] 2025-09-30 05:01:16.188742 | 2025-09-30 05:01:16.188950 | TASK [Create nodepool primary file] 2025-09-30 05:01:16.233700 | controller | skipping: Conditional result was False 2025-09-30 05:01:16.243088 | 2025-09-30 05:01:16.243167 | TASK [Create nodepool node_private for this node] 2025-09-30 05:01:18.058439 | controller | changed 2025-09-30 05:01:18.078322 | 2025-09-30 05:01:18.078457 | LOOP [Copy ssh keys to nodepool directory] 2025-09-30 05:01:18.730941 | controller | ok: Item: id_rsa Runtime: 0:00:00.009364 2025-09-30 05:01:18.731192 | 2025-09-30 05:01:19.053149 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.006708 2025-09-30 05:01:19.074116 | 2025-09-30 05:01:19.074274 | TASK [Add sudoers role for zuul-sudo-grep.sh] 2025-09-30 05:01:20.589516 | controller | changed 2025-09-30 05:01:20.597434 | 2025-09-30 05:01:20.597513 | TASK [Validate sudoers config after edits] 2025-09-30 05:01:21.055120 | controller | /etc/sudoers: parsed OK 2025-09-30 05:01:21.055204 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK 2025-09-30 05:01:21.055216 | controller | /etc/sudoers.d/zuul: parsed OK 2025-09-30 05:01:21.055225 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK 2025-09-30 05:01:21.131344 | controller | ok: Runtime: 0:00:00.007618 2025-09-30 05:01:21.137905 | 2025-09-30 05:01:21.137968 | TASK [Show the environment passed in to job shell scripts] 2025-09-30 05:01:21.633705 | controller | SHELL=/bin/bash 2025-09-30 05:01:21.633903 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework 2025-09-30 05:01:21.633927 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework 2025-09-30 05:01:21.633942 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/46/3346/eb5b53fb17db92a72d33d052a56c8edd0d10ea78^openstack-k8s-operators/ci-framework:main:refs/changes/33/3333/b461fc761ffaeed72eedc04b84a1fb92d251fe5d 2025-09-30 05:01:21.633962 | controller | PWD=/home/zuul 2025-09-30 05:01:21.633976 | controller | ZUUL_PIPELINE=github-check 2025-09-30 05:01:21.633989 | controller | LOGNAME=zuul 2025-09-30 05:01:21.634003 | controller | XDG_SESSION_TYPE=tty 2025-09-30 05:01:21.634017 | controller | _=/usr/bin/env 2025-09-30 05:01:21.634030 | controller | MOTD_SHOWN=pam 2025-09-30 05:01:21.634044 | controller | HOME=/home/zuul 2025-09-30 05:01:21.634057 | controller | LANG=en_US.UTF-8 2025-09-30 05:01:21.634070 | controller | SSH_CONNECTION=38.102.83.114 34690 38.102.83.36 22 2025-09-30 05:01:21.634084 | controller | TOX_TESTENV_PASSENV=ZUUL_UUID ZUUL_PROJECT ZUUL_SHORT_PROJECT_NAME ZUUL_PIPELINE ZUUL_VOTING WORKSPACE BUILD_TIMEOUT ZUUL_BRANCH ZUUL_CHANGES ZUUL_CHANGE_IDS ZUUL_CHANGE ZUUL_PATCHSET 2025-09-30 05:01:21.634098 | controller | ZUUL_CHANGE_IDS=3346,eb5b53fb17db92a72d33d052a56c8edd0d10ea78 3333,b461fc761ffaeed72eedc04b84a1fb92d251fe5d 2025-09-30 05:01:21.634112 | controller | WORKSPACE=/home/zuul/workspace 2025-09-30 05:01:21.634126 | controller | XDG_SESSION_CLASS=user 2025-09-30 05:01:21.634140 | controller | SELINUX_ROLE_REQUESTED= 2025-09-30 05:01:21.634154 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s 2025-09-30 05:01:21.634171 | controller | USER=zuul 2025-09-30 05:01:21.634184 | controller | ZUUL_VOTING=True 2025-09-30 05:01:21.634198 | controller | BUILD_TIMEOUT=1800000 2025-09-30 05:01:21.634211 | controller | SELINUX_USE_CURRENT_RANGE= 2025-09-30 05:01:21.634225 | controller | SHLVL=1 2025-09-30 05:01:21.634238 | controller | ZUUL_PATCHSET=b461fc761ffaeed72eedc04b84a1fb92d251fe5d 2025-09-30 05:01:21.634252 | controller | XDG_SESSION_ID=1 2025-09-30 05:01:21.634266 | controller | ZUUL_BRANCH=main 2025-09-30 05:01:21.634279 | controller | XDG_RUNTIME_DIR=/run/user/1000 2025-09-30 05:01:21.634293 | controller | SSH_CLIENT=38.102.83.114 34690 22 2025-09-30 05:01:21.634307 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/ 2025-09-30 05:01:21.634320 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima: 2025-09-30 05:01:21.634333 | controller | which_declare=declare -f 2025-09-30 05:01:21.634348 | 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 05:01:21.634362 | controller | SELINUX_LEVEL_REQUESTED= 2025-09-30 05:01:21.634375 | controller | ZUUL_CHANGE=3333 2025-09-30 05:01:21.634388 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus 2025-09-30 05:01:21.634401 | controller | ZUUL_UUID=c5b76151df2e4b4cb0e4218aced4e6ae 2025-09-30 05:01:21.634415 | controller | BASH_FUNC_which%%=() { ( alias; 2025-09-30 05:01:21.634429 | controller | eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@ 2025-09-30 05:01:21.634442 | controller | } 2025-09-30 05:01:21.740109 | controller | ok: Runtime: 0:00:00.008205 2025-09-30 05:01:21.746917 | 2025-09-30 05:01:21.747027 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars] 2025-09-30 05:01:21.772529 | controller | skipping: Conditional result was False 2025-09-30 05:01:21.780274 | 2025-09-30 05:01:21.780347 | TASK [Symlink /home/zuul-worker/workspace] 2025-09-30 05:01:22.317419 | controller | skipping: Conditional result was False 2025-09-30 05:01:22.348872 | 2025-09-30 05:01:22.349186 | TASK [Ensure legacy workspace directory] 2025-09-30 05:01:22.724417 | controller | changed 2025-09-30 05:01:22.751518 | 2025-09-30 05:01:22.751681 | PLAY RECAP 2025-09-30 05:01:22.751735 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-09-30 05:01:22.751756 | 2025-09-30 05:01:22.991106 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master] 2025-09-30 05:01:22.991906 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/crc/podman.yaml@master] 2025-09-30 05:01:23.565656 | 2025-09-30 05:01:23.565790 | PLAY [all,!compute] 2025-09-30 05:01:23.584860 | 2025-09-30 05:01:23.584931 | TASK [Enable container-tools rhel-modules for c8/crc node] 2025-09-30 05:01:24.115292 | controller | skipping: Conditional result was False 2025-09-30 05:01:24.121263 | 2025-09-30 05:01:24.121339 | TASK [Install podman] 2025-09-30 05:01:24.162647 | controller | skipping: Conditional result was False 2025-09-30 05:01:24.168365 | 2025-09-30 05:01:24.168430 | TASK [Set var name for quay login zuul secret] 2025-09-30 05:01:24.212676 | controller | skipping: Conditional result was False 2025-09-30 05:01:24.220032 | 2025-09-30 05:01:24.220123 | TASK [Print the username] 2025-09-30 05:01:24.750865 | controller | skipping: Conditional result was False 2025-09-30 05:01:24.757347 | 2025-09-30 05:01:24.757412 | TASK [Fail when user or password is not set] 2025-09-30 05:01:24.793956 | controller | skipping: Conditional result was False 2025-09-30 05:01:24.800234 | 2025-09-30 05:01:24.800306 | TASK [Set vars for quay login] 2025-09-30 05:01:24.844171 | 2025-09-30 05:01:24.844406 | LOOP [Perform container registry login(s) with podman] 2025-09-30 05:01:24.896947 | 2025-09-30 05:01:24.897099 | LOOP [Perform container registry login(s) with buildah] 2025-09-30 05:01:24.947572 | 2025-09-30 05:01:24.947747 | TASK [Set Insecure registry for content provider] 2025-09-30 05:01:24.993616 | controller | skipping: Conditional result was False 2025-09-30 05:01:25.013406 | 2025-09-30 05:01:25.013528 | PLAY RECAP 2025-09-30 05:01:25.013576 | controller | ok: 0 changed: 0 unreachable: 0 failed: 0 skipped: 9 rescued: 0 ignored: 0 2025-09-30 05:01:25.013596 | 2025-09-30 05:01:25.127948 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/crc/podman.yaml@master] 2025-09-30 05:01:25.128732 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/crc/simple-start.yaml@master] 2025-09-30 05:01:25.761130 | 2025-09-30 05:01:25.761243 | PLAY [Prefer ipv4 over ipv6] 2025-09-30 05:01:25.780477 | 2025-09-30 05:01:25.780549 | TASK [Configure /etc/gai.conf to prever ipv4 over ipv6] 2025-09-30 05:01:25.825573 | controller | skipping: Conditional result was False 2025-09-30 05:01:25.859694 | 2025-09-30 05:01:25.859846 | PLAY [controller] 2025-09-30 05:01:25.874133 | 2025-09-30 05:01:25.874220 | TASK [Fail when openshift_pull_sec not provided] 2025-09-30 05:01:25.924853 | controller | skipping: Conditional result was False 2025-09-30 05:01:25.932618 | 2025-09-30 05:01:25.932711 | TASK [Clone repos in the job workspace] 2025-09-30 05:01:25.973997 | controller | ok 2025-09-30 05:01:26.016431 | 2025-09-30 05:01:26.016561 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-09-30 05:01:26.629978 | controller | ok 2025-09-30 05:01:26.642632 | 2025-09-30 05:01:26.642742 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-09-30 05:01:29.976084 | controller | Output suppressed because no_log was given 2025-09-30 05:01:29.996549 | 2025-09-30 05:01:29.996752 | TASK [Create pull-secret.txt file] 2025-09-30 05:01:31.891409 | controller | Output suppressed because no_log was given 2025-09-30 05:01:31.905660 | 2025-09-30 05:01:31.905785 | TASK [Apply CRC features and print image build date] 2025-09-30 05:01:31.940797 | controller | ok 2025-09-30 05:01:31.957566 | controller | included: /var/lib/zuul/builds/c5b76151df2e4b4cb0e4218aced4e6ae/trusted/project_0/review.rdoproject.org/config/playbooks/crc/features.yaml 2025-09-30 05:01:31.966750 | 2025-09-30 05:01:31.966849 | TASK [Set additional parameters for crc - telemetry] 2025-09-30 05:01:32.537894 | controller | skipping: Conditional result was False 2025-09-30 05:01:32.543957 | 2025-09-30 05:01:32.544022 | TASK [Set additional parameters for crc - monitoring] 2025-09-30 05:01:33.074097 | controller | skipping: Conditional result was False 2025-09-30 05:01:33.087002 | 2025-09-30 05:01:33.087156 | TASK [Set minimum required memory to run the CRC when monitoring enabled] 2025-09-30 05:01:33.640871 | controller | skipping: Conditional result was False 2025-09-30 05:01:33.650781 | 2025-09-30 05:01:33.650897 | TASK [Set additional parameters for crc - enable microshift preset] 2025-09-30 05:01:34.186435 | controller | skipping: Conditional result was False 2025-09-30 05:01:34.208084 | 2025-09-30 05:01:34.208275 | TASK [Set additional parameters for crc - enable okd preset] 2025-09-30 05:01:34.769147 | controller | skipping: Conditional result was False 2025-09-30 05:01:34.774922 | 2025-09-30 05:01:34.774984 | TASK [Delete the cluster if there's a non-default bundle URL] 2025-09-30 05:01:35.304905 | controller | skipping: Conditional result was False 2025-09-30 05:01:35.310770 | 2025-09-30 05:01:35.310835 | TASK [Execute crc start command] 2025-09-30 05:05:09.741518 | controller | ok: Runtime: 0:03:33.943234 2025-09-30 05:05:09.752835 | 2025-09-30 05:05:09.753001 | TASK [Verify that OpenShift is up and running] 2025-09-30 05:05:09.781408 | controller | ok 2025-09-30 05:05:09.799955 | controller | included: /var/lib/zuul/builds/c5b76151df2e4b4cb0e4218aced4e6ae/trusted/project_0/review.rdoproject.org/config/playbooks/crc/verify_openshift_start.yaml 2025-09-30 05:05:09.810837 | 2025-09-30 05:05:09.810963 | TASK [Create script to login and verify services] 2025-09-30 05:05:11.081704 | controller | changed 2025-09-30 05:05:11.093977 | 2025-09-30 05:05:11.094103 | TASK [Ensure that user is logged] 2025-09-30 05:05:11.501528 | controller | Checking login to the cluster 1... 2025-09-30 05:05:12.493993 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:05:12.551789 | controller | 2025-09-30 05:05:12.551888 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:05:12.556347 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:05:17.558864 | controller | Checking login to the cluster 2... 2025-09-30 05:05:17.684542 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:05:17.703347 | controller | 2025-09-30 05:05:17.703402 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:05:17.708495 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:05:22.710694 | controller | Checking login to the cluster 3... 2025-09-30 05:05:22.850355 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:05:22.878543 | controller | 2025-09-30 05:05:22.878635 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:05:22.888640 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:05:27.891456 | controller | Checking login to the cluster 4... 2025-09-30 05:05:28.050924 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:05:28.076403 | controller | 2025-09-30 05:05:28.076483 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:05:28.081326 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:05:33.084530 | controller | Checking login to the cluster 5... 2025-09-30 05:05:33.243775 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:05:33.261141 | controller | 2025-09-30 05:05:33.261222 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:05:33.265969 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:05:38.268471 | controller | Checking login to the cluster 6... 2025-09-30 05:05:38.435847 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:05:38.468311 | controller | 2025-09-30 05:05:38.468412 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:05:38.479697 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:05:43.483300 | controller | Checking login to the cluster 7... 2025-09-30 05:05:43.606360 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:05:43.622129 | controller | 2025-09-30 05:05:43.622350 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:05:43.627619 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:05:48.632491 | controller | Checking login to the cluster 8... 2025-09-30 05:05:48.810115 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:05:48.850599 | controller | 2025-09-30 05:05:48.850695 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:05:48.858114 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:05:53.862695 | controller | Checking login to the cluster 9... 2025-09-30 05:05:54.025786 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:05:54.063297 | controller | 2025-09-30 05:05:54.063377 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:05:54.072279 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:05:59.075364 | controller | Checking login to the cluster 10... 2025-09-30 05:05:59.213041 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:05:59.267949 | controller | 2025-09-30 05:05:59.268084 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:05:59.272628 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:06:04.276829 | controller | Checking login to the cluster 11... 2025-09-30 05:06:04.439092 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:06:04.551016 | controller | 2025-09-30 05:06:04.551123 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:06:04.563546 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:06:09.567044 | controller | Checking login to the cluster 12... 2025-09-30 05:06:10.050903 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:06:10.507992 | controller | 2025-09-30 05:06:10.508065 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-09-30 05:06:10.515565 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:06:15.518942 | controller | Checking login to the cluster 13... 2025-09-30 05:06:15.729073 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:06:15.889508 | controller | 2025-09-30 05:06:15.889588 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-09-30 05:06:15.895116 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:06:20.898119 | controller | Checking login to the cluster 14... 2025-09-30 05:06:21.098025 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:06:21.358928 | controller | 2025-09-30 05:06:21.359027 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-09-30 05:06:21.363798 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:06:26.367849 | controller | Checking login to the cluster 15... 2025-09-30 05:06:26.621433 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:06:26.819220 | controller | 2025-09-30 05:06:26.819419 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-09-30 05:06:26.836962 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:06:31.839246 | controller | Checking login to the cluster 16... 2025-09-30 05:06:32.580649 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:06:33.771283 | controller | 2025-09-30 05:06:33.771364 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-09-30 05:06:33.780867 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:06:38.784159 | controller | Checking login to the cluster 17... 2025-09-30 05:06:38.986976 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:06:39.124458 | controller | 2025-09-30 05:06:39.124548 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-09-30 05:06:39.129405 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:06:44.133555 | controller | Checking login to the cluster 18... 2025-09-30 05:06:44.391967 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:06:44.535378 | controller | 2025-09-30 05:06:44.535467 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-09-30 05:06:44.540779 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:06:49.544938 | controller | Checking login to the cluster 19... 2025-09-30 05:06:49.710306 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:06:49.746153 | controller | 2025-09-30 05:06:49.746218 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:06:49.751525 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:06:54.754553 | controller | Checking login to the cluster 20... 2025-09-30 05:06:55.340263 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:06:56.142534 | controller | 2025-09-30 05:06:56.142626 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:06:56.153441 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:07:01.157292 | controller | Checking login to the cluster 21... 2025-09-30 05:07:01.320314 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:07:01.359324 | controller | 2025-09-30 05:07:01.359410 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:07:01.366445 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:07:06.368788 | controller | Checking login to the cluster 22... 2025-09-30 05:07:06.505934 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:07:06.530642 | controller | 2025-09-30 05:07:06.530711 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:07:06.535403 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:07:11.537895 | controller | Checking login to the cluster 23... 2025-09-30 05:07:11.694454 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:07:11.711563 | controller | 2025-09-30 05:07:11.711616 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:07:11.715901 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:07:16.717775 | controller | Checking login to the cluster 24... 2025-09-30 05:07:16.839707 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:07:16.855793 | controller | 2025-09-30 05:07:16.855866 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:07:16.860983 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:07:21.863663 | controller | Checking login to the cluster 25... 2025-09-30 05:07:21.977983 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:07:21.998132 | controller | 2025-09-30 05:07:21.998191 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:07:22.004609 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:07:27.009011 | controller | Checking login to the cluster 26... 2025-09-30 05:07:27.166068 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:07:27.190579 | controller | 2025-09-30 05:07:27.190644 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:07:27.198907 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:07:32.201567 | controller | Checking login to the cluster 27... 2025-09-30 05:07:32.358991 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:07:32.379829 | controller | 2025-09-30 05:07:32.379891 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:07:32.390177 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:07:37.393153 | controller | Checking login to the cluster 28... 2025-09-30 05:07:37.569295 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:07:37.595575 | controller | 2025-09-30 05:07:37.595665 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:07:37.602375 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:07:42.605658 | controller | Checking login to the cluster 29... 2025-09-30 05:07:42.714232 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:07:42.729524 | controller | 2025-09-30 05:07:42.729622 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:07:42.734715 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:07:47.737029 | controller | Checking login to the cluster 30... 2025-09-30 05:07:47.874845 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:07:47.890056 | controller | 2025-09-30 05:07:47.890112 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:07:47.898023 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:07:52.899920 | controller | Checking login to the cluster 31... 2025-09-30 05:07:53.029176 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:07:53.049035 | controller | 2025-09-30 05:07:53.049092 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-09-30 05:07:53.060868 | controller | Can not login to the CRC cluster. Sleeping... 2025-09-30 05:07:58.063018 | controller | Checking login to the cluster 32... 2025-09-30 05:07:58.238888 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-09-30 05:07:58.626749 | controller | 2025-09-30 05:07:58.626827 | controller | Login successful. 2025-09-30 05:07:58.680192 | controller | 2025-09-30 05:07:58.680264 | controller | You have access to 65 projects, the list has been suppressed. You can list all projects with 'oc projects' 2025-09-30 05:07:58.710302 | controller | 2025-09-30 05:07:58.710500 | controller | Using project "default". 2025-09-30 05:07:58.882572 | controller | changed 2025-09-30 05:07:58.896639 | 2025-09-30 05:07:58.896825 | TASK [Delete all openshift-marketplace pods] 2025-09-30 05:08:02.340083 | controller | pod "certified-operators-4rtgc" deleted 2025-09-30 05:08:03.483289 | controller | pod "certified-operators-f8szs" deleted 2025-09-30 05:08:05.395879 | controller | pod "community-operators-5zsqg" deleted 2025-09-30 05:08:06.806762 | controller | pod "community-operators-b5fnc" deleted 2025-09-30 05:08:07.025592 | controller | pod "marketplace-operator-79b997595-d2lpl" deleted 2025-09-30 05:08:07.057743 | controller | pod "redhat-marketplace-ps6xk" deleted 2025-09-30 05:08:07.137868 | controller | pod "redhat-marketplace-rh7tq" deleted 2025-09-30 05:08:07.203404 | controller | pod "redhat-operators-ldkpb" deleted 2025-09-30 05:08:07.245556 | controller | pod "redhat-operators-tqxl9" deleted 2025-09-30 05:08:12.969191 | controller | ok 2025-09-30 05:08:12.982180 | 2025-09-30 05:08:12.982343 | TASK [Copy script ensure_services_up.sh] 2025-09-30 05:08:13.051508 | controller | skipping: Conditional result was False 2025-09-30 05:08:13.063824 | 2025-09-30 05:08:13.063960 | TASK [Ensure all pods are up and running] 2025-09-30 05:08:13.611030 | controller | skipping: Conditional result was False 2025-09-30 05:08:13.624197 | 2025-09-30 05:08:13.624339 | TASK [Check if there is a image build date file] 2025-09-30 05:08:14.022660 | controller | ok 2025-09-30 05:08:14.036759 | 2025-09-30 05:08:14.036890 | TASK [Print image date if available] 2025-09-30 05:08:14.466921 | controller | Tue Apr 1 06:17:46 PM EDT 2025 2025-09-30 05:08:14.599317 | controller | changed 2025-09-30 05:08:14.613368 | 2025-09-30 05:08:14.613507 | TASK [Fix machineconfigpool] 2025-09-30 05:08:14.684099 | controller | skipping: Conditional result was False 2025-09-30 05:08:14.698200 | 2025-09-30 05:08:14.698342 | TASK [Show available nodes] 2025-09-30 05:08:16.300580 | controller | NAME STATUS ROLES AGE VERSION 2025-09-30 05:08:16.302712 | controller | crc Ready control-plane,master,worker 218d v1.31.5 2025-09-30 05:08:16.759440 | controller | ok: Runtime: 0:00:01.153766 2025-09-30 05:08:16.771758 | 2025-09-30 05:08:16.772029 | TASK [Configure insecure registry inside crc vm] 2025-09-30 05:08:16.809865 | controller | skipping: Conditional result was False 2025-09-30 05:08:16.822779 | 2025-09-30 05:08:16.822927 | TASK [Catch CRC IP] 2025-09-30 05:08:17.412573 | controller | 192.168.130.11 2025-09-30 05:08:17.909146 | controller | changed 2025-09-30 05:08:17.921741 | 2025-09-30 05:08:17.922038 | TASK [Check if id_ed25519 key exists] 2025-09-30 05:08:18.368127 | controller | ok 2025-09-30 05:08:18.387700 | 2025-09-30 05:08:18.387919 | TASK [Set fact if new keypair exists] 2025-09-30 05:08:18.432778 | controller | ok 2025-09-30 05:08:18.439312 | 2025-09-30 05:08:18.439397 | TASK [Run crc] 2025-09-30 05:08:20.091800 | controller | 2025-09-30 05:08:26.149823 | controller | PLAY [OpenShift secret copy and CRC securitization] **************************** 2025-09-30 05:08:26.149894 | controller | 2025-09-30 05:08:26.149901 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 05:08:26.149919 | controller | [WARNING]: Platform linux on host 192.168.130.11 is using the discovered Python 2025-09-30 05:08:26.189997 | controller | interpreter at /usr/bin/python3.9, but future installation of another Python 2025-09-30 05:08:26.190060 | controller | interpreter could change the meaning of that path. See 2025-09-30 05:08:26.190068 | controller | https://docs.ansible.com/ansible- 2025-09-30 05:08:26.190075 | controller | core/2.14/reference_appendices/interpreter_discovery.html for more information. 2025-09-30 05:08:26.190091 | controller | ok: [192.168.130.11] 2025-09-30 05:08:27.901052 | controller | 2025-09-30 05:08:27.901106 | controller | TASK [Copy pull-secret] ******************************************************** 2025-09-30 05:08:27.901120 | controller | changed: [192.168.130.11] 2025-09-30 05:08:29.403082 | controller | 2025-09-30 05:08:29.403145 | controller | TASK [Add crio config] ********************************************************* 2025-09-30 05:08:29.403163 | controller | changed: [192.168.130.11] 2025-09-30 05:08:33.082436 | controller | 2025-09-30 05:08:33.082504 | controller | TASK [Restart crio to pickup new configuration] ******************************** 2025-09-30 05:08:33.082536 | controller | changed: [192.168.130.11] 2025-09-30 05:08:33.134906 | controller | 2025-09-30 05:08:33.134965 | controller | PLAY RECAP ********************************************************************* 2025-09-30 05:08:33.134976 | controller | 192.168.130.11 : ok=4 changed=3 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 2025-09-30 05:08:33.134985 | controller | 2025-09-30 05:08:33.522811 | controller | changed 2025-09-30 05:08:33.528465 | 2025-09-30 05:08:33.528528 | TASK [Set slower etcd profile] 2025-09-30 05:08:33.608020 | controller | ok 2025-09-30 05:08:33.630499 | 2025-09-30 05:08:33.630577 | TASK [prepare-crc-cloud : Set slower profile] 2025-09-30 05:08:34.133004 | controller | etcd.operator.openshift.io/cluster patched 2025-09-30 05:08:34.181117 | controller | ok 2025-09-30 05:08:34.194108 | 2025-09-30 05:08:34.194242 | TASK [prepare-crc-cloud : Wait 30 seconds to apply] 2025-09-30 05:09:04.241355 | controller | ok 2025-09-30 05:09:04.252619 | 2025-09-30 05:09:04.252789 | TASK [prepare-crc-cloud : Get pod phase status] 2025-09-30 05:14:17.952360 | controller | ok 2025-09-30 05:14:17.973579 | 2025-09-30 05:14:17.973734 | TASK [Set limit for disk usage - IOPS and Read/Write] 2025-09-30 05:14:18.053916 | controller | ok 2025-09-30 05:14:18.067741 | controller | included: /var/lib/zuul/builds/c5b76151df2e4b4cb0e4218aced4e6ae/trusted/project_0/review.rdoproject.org/config/playbooks/crc/limit-disk-usage.yaml 2025-09-30 05:14:18.088732 | 2025-09-30 05:14:18.088874 | TASK [Set facts for disk limitation] 2025-09-30 05:14:18.157316 | controller | ok 2025-09-30 05:14:18.164419 | 2025-09-30 05:14:18.164500 | TASK [Print limits for the disk] 2025-09-30 05:14:18.206843 | controller | ok: Set limit to crc VM to the vda disk: iops 18000 read/write 262144000 2025-09-30 05:14:18.213803 | 2025-09-30 05:14:18.213892 | TASK [Set limit to crc VM to the vda disk] 2025-09-30 05:14:18.757148 | controller | 2025-09-30 05:14:19.253227 | controller | changed 2025-09-30 05:14:19.260518 | 2025-09-30 05:14:19.260591 | TASK [Pause machineconfigpool] 2025-09-30 05:14:19.334067 | controller | ok 2025-09-30 05:14:19.369520 | 2025-09-30 05:14:19.369697 | LOOP [prepare-crc-cloud : Pause the machineconfig configuration if mcp is not needed] 2025-09-30 05:14:20.010818 | controller | ok 2025-09-30 05:14:20.620211 | controller | ok 2025-09-30 05:14:20.642585 | 2025-09-30 05:14:20.642823 | TASK [prepare-crc-cloud : Print current machineconfigpool] 2025-09-30 05:14:21.249357 | controller | NAME CONFIG UPDATED UPDATING DEGRADED MACHINECOUNT READYMACHINECOUNT UPDATEDMACHINECOUNT DEGRADEDMACHINECOUNT AGE 2025-09-30 05:14:21.249490 | controller | master rendered-master-95020e6e79c40b4dd095817bccfc5060 True False False 1 1 1 0 218d 2025-09-30 05:14:21.249516 | controller | worker rendered-worker-594cc07c9feefb5e37f2530ac457d36c True False False 0 0 0 0 218d 2025-09-30 05:14:21.705164 | controller | ok 2025-09-30 05:14:21.758492 | 2025-09-30 05:14:21.758577 | PLAY [Set IOPS and Read/Write disk limitation excluding controller] 2025-09-30 05:14:21.758731 | 2025-09-30 05:14:21.758773 | PLAY RECAP 2025-09-30 05:14:21.758822 | controller | ok: 25 changed: 10 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 0 2025-09-30 05:14:21.758848 | 2025-09-30 05:14:21.872638 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/crc/simple-start.yaml@master] 2025-09-30 05:14:21.873870 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/read_global_vars.yml@main] 2025-09-30 05:14:22.438376 | 2025-09-30 05:14:22.438495 | PLAY [Load global variables] 2025-09-30 05:14:22.460267 | 2025-09-30 05:14:22.460353 | TASK [Read group_vars all file] 2025-09-30 05:14:22.489727 | controller | ok 2025-09-30 05:14:22.505616 | 2025-09-30 05:14:22.505711 | TASK [cifmw_helpers : Check if file is available] 2025-09-30 05:14:23.074061 | controller | ok 2025-09-30 05:14:23.079747 | 2025-09-30 05:14:23.079813 | TASK [cifmw_helpers : Read vars] 2025-09-30 05:14:23.109370 | 2025-09-30 05:14:23.109527 | LOOP [cifmw_helpers : Set vars as fact] 2025-09-30 05:14:23.167401 | 2025-09-30 05:14:23.167550 | PLAY RECAP 2025-09-30 05:14:23.167588 | controller | ok: 1 changed: 0 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-09-30 05:14:23.167609 | 2025-09-30 05:14:23.305429 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/read_global_vars.yml@main] 2025-09-30 05:14:23.307322 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main] 2025-09-30 05:14:23.873952 | 2025-09-30 05:14:23.874081 | PLAY [Run ci/playbooks/dump_zuul_data.yml] 2025-09-30 05:14:23.895320 | 2025-09-30 05:14:23.895394 | TASK [Create zuul-output directory] 2025-09-30 05:14:24.424172 | controller | changed 2025-09-30 05:14:24.431547 | 2025-09-30 05:14:24.431647 | TASK [Slurp Zuul inventory test] 2025-09-30 05:14:24.814913 | controller -> localhost | ok 2025-09-30 05:14:24.829877 | 2025-09-30 05:14:24.830018 | TASK [Save zuul inventory] 2025-09-30 05:14:26.446695 | controller | changed 2025-09-30 05:14:26.458463 | 2025-09-30 05:14:26.458596 | TASK [Save zuul vars without the change_message] 2025-09-30 05:14:28.398299 | controller | changed 2025-09-30 05:14:28.417839 | 2025-09-30 05:14:28.417895 | PLAY RECAP 2025-09-30 05:14:28.417962 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-09-30 05:14:28.417982 | 2025-09-30 05:14:28.522072 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main] 2025-09-30 05:14:28.523794 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main] 2025-09-30 05:14:29.155441 | 2025-09-30 05:14:29.155568 | PLAY [Run ci/playbooks/molecule-prepare.yml] 2025-09-30 05:14:29.176210 | 2025-09-30 05:14:29.176294 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh] 2025-09-30 05:14:29.205463 | controller | ok 2025-09-30 05:14:29.222693 | 2025-09-30 05:14:29.222770 | TASK [mirror-info-fork : Set mirror_fqdn if not defined] 2025-09-30 05:14:29.267785 | controller | skipping: Conditional result was False 2025-09-30 05:14:29.276090 | 2025-09-30 05:14:29.276181 | TASK [mirror-info-fork : Create /etc/ci] 2025-09-30 05:14:29.764888 | controller | ok 2025-09-30 05:14:29.777463 | 2025-09-30 05:14:29.777604 | TASK [mirror-info-fork : Install ci_mirror script] 2025-09-30 05:14:31.120346 | controller | ok 2025-09-30 05:14:31.138480 | 2025-09-30 05:14:31.138563 | TASK [Prepare workspace] 2025-09-30 05:14:31.171022 | controller | ok 2025-09-30 05:14:31.193078 | 2025-09-30 05:14:31.193144 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-09-30 05:14:31.685394 | controller | ok 2025-09-30 05:14:31.693971 | 2025-09-30 05:14:31.694062 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-09-30 05:14:32.867374 | controller | Output suppressed because no_log was given 2025-09-30 05:14:32.884055 | 2025-09-30 05:14:32.884246 | LOOP [Create zuul-output directory] 2025-09-30 05:14:33.262991 | controller | changed: "/home/zuul/ci-framework-data/logs" 2025-09-30 05:14:33.636464 | controller | ok: "/home/zuul/zuul-output/logs" 2025-09-30 05:14:33.651174 | 2025-09-30 05:14:33.651258 | TASK [Install required packages] 2025-09-30 05:14:50.060574 | controller | ok: Nothing to do 2025-09-30 05:14:50.066038 | 2025-09-30 05:14:50.066096 | TASK [Install venv] 2025-09-30 05:15:51.874630 | controller | changed 2025-09-30 05:15:51.942253 | 2025-09-30 05:15:51.942434 | PLAY RECAP 2025-09-30 05:15:51.942525 | controller | ok: 7 changed: 3 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-09-30 05:15:51.942569 | 2025-09-30 05:15:52.084050 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main] 2025-09-30 05:15:52.085084 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main] 2025-09-30 05:15:52.703371 | 2025-09-30 05:15:52.703506 | PLAY [Run ci/playbooks/molecule-test.yml] 2025-09-30 05:15:52.725312 | 2025-09-30 05:15:52.725405 | TASK [Gather required facts] 2025-09-30 05:15:53.519610 | controller | ok 2025-09-30 05:15:53.532430 | 2025-09-30 05:15:53.532714 | TASK [Load environment var if instructed to] 2025-09-30 05:15:53.571289 | controller | skipping: Conditional result was False 2025-09-30 05:15:53.584945 | 2025-09-30 05:15:53.585140 | TASK [Run molecule] 2025-09-30 05:15:54.953896 | controller | INFO Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml 2025-09-30 05:15:55.199382 | controller | INFO Running default > destroy 2025-09-30 05:15:55.199639 | controller | WARNING Skipping, instances are delegated. 2025-09-30 05:15:55.210108 | controller | INFO Running default > create 2025-09-30 05:15:55.211037 | controller | WARNING Skipping, instances are delegated. 2025-09-30 05:15:55.219339 | controller | INFO Running default > converge 2025-09-30 05:15:55.975052 | controller | 2025-09-30 05:15:55.975297 | controller | PLAY [Converge] **************************************************************** 2025-09-30 05:15:55.975525 | controller | 2025-09-30 05:15:55.975746 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 05:15:55.976090 | controller | Tuesday 30 September 2025 05:15:55 +0000 (0:00:00.011) 0:00:00.011 ***** 2025-09-30 05:15:57.245075 | controller | ok: [instance] 2025-09-30 05:15:57.245181 | controller | 2025-09-30 05:15:57.245479 | controller | TASK [Add crc hostname with it's IP to /etc/hosts] ***************************** 2025-09-30 05:15:57.245768 | controller | Tuesday 30 September 2025 05:15:57 +0000 (0:00:01.271) 0:00:01.282 ***** 2025-09-30 05:15:57.716004 | controller | changed: [instance] 2025-09-30 05:15:57.716068 | controller | 2025-09-30 05:15:57.716312 | controller | TASK [Check if new ssh keypair exists] ***************************************** 2025-09-30 05:15:57.716617 | controller | Tuesday 30 September 2025 05:15:57 +0000 (0:00:00.470) 0:00:01.752 ***** 2025-09-30 05:15:57.756492 | controller | 2025-09-30 05:15:57.756601 | controller | TASK [recognize_ssh_keypair : Check if id_ed25519 key exists] ****************** 2025-09-30 05:15:57.756652 | controller | Tuesday 30 September 2025 05:15:57 +0000 (0:00:00.040) 0:00:01.793 ***** 2025-09-30 05:15:58.195029 | controller | ok: [instance] 2025-09-30 05:15:58.195101 | controller | 2025-09-30 05:15:58.195209 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair exists] ****************** 2025-09-30 05:15:58.195358 | controller | Tuesday 30 September 2025 05:15:58 +0000 (0:00:00.439) 0:00:02.232 ***** 2025-09-30 05:15:58.225848 | controller | ok: [instance] 2025-09-30 05:15:58.225912 | controller | 2025-09-30 05:15:58.226074 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair does not exists] ********* 2025-09-30 05:15:58.226205 | controller | Tuesday 30 September 2025 05:15:58 +0000 (0:00:00.030) 0:00:02.263 ***** 2025-09-30 05:15:58.252949 | controller | skipping: [instance] 2025-09-30 05:15:58.253072 | controller | 2025-09-30 05:15:58.253256 | controller | TASK [Add the crc host dynamically] ******************************************** 2025-09-30 05:15:58.253382 | controller | Tuesday 30 September 2025 05:15:58 +0000 (0:00:00.027) 0:00:02.290 ***** 2025-09-30 05:15:58.278403 | controller | changed: [instance] 2025-09-30 05:15:58.278530 | controller | 2025-09-30 05:15:58.278689 | controller | TASK [Fetch crc network facts] ************************************************* 2025-09-30 05:15:58.278854 | controller | Tuesday 30 September 2025 05:15:58 +0000 (0:00:00.025) 0:00:02.316 ***** 2025-09-30 05:16:03.294503 | controller | ok: [instance -> crc] 2025-09-30 05:16:03.295146 | controller | 2025-09-30 05:16:03.295262 | controller | TASK [Load shared variables] *************************************************** 2025-09-30 05:16:03.295276 | controller | Tuesday 30 September 2025 05:16:03 +0000 (0:00:05.015) 0:00:07.331 ***** 2025-09-30 05:16:03.374351 | controller | ok: [instance] 2025-09-30 05:16:03.374424 | controller | 2025-09-30 05:16:03.374558 | controller | TASK [Call ci_multus role] ***************************************************** 2025-09-30 05:16:03.374704 | controller | Tuesday 30 September 2025 05:16:03 +0000 (0:00:00.079) 0:00:07.411 ***** 2025-09-30 05:16:03.437085 | controller | 2025-09-30 05:16:03.437186 | controller | TASK [ci_multus : Create manifests directory] ********************************** 2025-09-30 05:16:03.437358 | controller | Tuesday 30 September 2025 05:16:03 +0000 (0:00:00.062) 0:00:07.474 ***** 2025-09-30 05:16:03.823269 | controller | changed: [instance] 2025-09-30 05:16:03.823382 | controller | 2025-09-30 05:16:03.823452 | controller | TASK [networking_mapper : Check for Networking Environment Definition file existence] *** 2025-09-30 05:16:03.823579 | controller | Tuesday 30 September 2025 05:16:03 +0000 (0:00:00.386) 0:00:07.861 ***** 2025-09-30 05:16:03.854012 | controller | skipping: [instance] 2025-09-30 05:16:03.854056 | controller | 2025-09-30 05:16:03.854214 | controller | TASK [networking_mapper : Check for Networking Definition file existance] ****** 2025-09-30 05:16:03.854333 | controller | Tuesday 30 September 2025 05:16:03 +0000 (0:00:00.030) 0:00:07.891 ***** 2025-09-30 05:16:03.889392 | controller | skipping: [instance] 2025-09-30 05:16:03.889562 | controller | 2025-09-30 05:16:03.889783 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************ 2025-09-30 05:16:03.890087 | controller | Tuesday 30 September 2025 05:16:03 +0000 (0:00:00.034) 0:00:07.926 ***** 2025-09-30 05:16:03.919537 | controller | skipping: [instance] 2025-09-30 05:16:03.919772 | controller | 2025-09-30 05:16:03.920067 | controller | TASK [networking_mapper : Set cifmw_networking_env_definition is present] ****** 2025-09-30 05:16:03.920303 | controller | Tuesday 30 September 2025 05:16:03 +0000 (0:00:00.030) 0:00:07.957 ***** 2025-09-30 05:16:03.963849 | controller | skipping: [instance] 2025-09-30 05:16:03.964044 | controller | 2025-09-30 05:16:03.964258 | controller | TASK [ci_multus : Gather network layout from OCP host or default networks] ***** 2025-09-30 05:16:03.964463 | controller | Tuesday 30 September 2025 05:16:03 +0000 (0:00:00.043) 0:00:08.001 ***** 2025-09-30 05:16:04.022897 | controller | ok: [instance] 2025-09-30 05:16:04.022970 | controller | 2025-09-30 05:16:04.023150 | controller | TASK [ci_multus : Merge any available multus net info patches] ***************** 2025-09-30 05:16:04.023296 | controller | Tuesday 30 September 2025 05:16:04 +0000 (0:00:00.059) 0:00:08.060 ***** 2025-09-30 05:16:04.236035 | 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 05:16:04.236084 | controller | ok: [instance] => (item={'patchnetwork': {'gw_v4': '192.168.122.1', 'network_name': 'patchnetwork', 'network_v4': '192.168.122.0/24', 'interface_name': 'eth2', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}], 'multus_type': 'macvlan'}}}}) 2025-09-30 05:16:04.236203 | controller | ok: [instance] => (item={'bridge-to-linux-bridge': {'gw_v4': '192.168.122.1', 'network_name': 'bridge-to-linux-bridge', 'network_v4': '192.168.122.0/24', 'interface_name': 'eth1', 'tools': {'multus': {'ipv4_ranges': [{'start': '192.168.122.30', 'end': '192.168.122.70'}], 'multus_type': 'bridge', 'multus_attach': 'linux-bridge'}}}}) 2025-09-30 05:16:04.236295 | controller | 2025-09-30 05:16:04.236390 | controller | TASK [ci_multus : Remove any networks without Multus networking defined] ******* 2025-09-30 05:16:04.236483 | controller | Tuesday 30 September 2025 05:16:04 +0000 (0:00:00.212) 0:00:08.273 ***** 2025-09-30 05:16:04.358631 | controller | ok: [instance] 2025-09-30 05:16:04.358806 | controller | 2025-09-30 05:16:04.358832 | controller | TASK [ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined] *** 2025-09-30 05:16:04.358919 | controller | Tuesday 30 September 2025 05:16:04 +0000 (0:00:00.123) 0:00:08.396 ***** 2025-09-30 05:16:04.451424 | controller | ok: [instance] 2025-09-30 05:16:04.451541 | controller | 2025-09-30 05:16:04.451615 | controller | TASK [ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined] *** 2025-09-30 05:16:04.451759 | controller | Tuesday 30 September 2025 05:16:04 +0000 (0:00:00.092) 0:00:08.489 ***** 2025-09-30 05:16:04.537327 | controller | ok: [instance] 2025-09-30 05:16:04.537444 | controller | 2025-09-30 05:16:04.537469 | controller | TASK [ci_multus : Render NetworkAttachmenktDefinition manifests] *************** 2025-09-30 05:16:04.537598 | controller | Tuesday 30 September 2025 05:16:04 +0000 (0:00:00.085) 0:00:08.574 ***** 2025-09-30 05:16:05.189199 | controller | changed: [instance] 2025-09-30 05:16:05.189350 | controller | 2025-09-30 05:16:05.189585 | controller | TASK [ci_multus : Create the multus namespace] ********************************* 2025-09-30 05:16:05.189844 | controller | Tuesday 30 September 2025 05:16:05 +0000 (0:00:00.651) 0:00:09.226 ***** 2025-09-30 05:16:06.164080 | controller | changed: [instance] 2025-09-30 05:16:06.164332 | controller | 2025-09-30 05:16:06.992950 | controller | TASK [ci_multus : Apply network attachment definition manifests] *************** 2025-09-30 05:16:06.992982 | controller | Tuesday 30 September 2025 05:16:06 +0000 (0:00:00.975) 0:00:10.201 ***** 2025-09-30 05:16:06.992993 | controller | changed: [instance] 2025-09-30 05:16:06.993217 | controller | 2025-09-30 05:16:06.993286 | controller | PLAY RECAP ********************************************************************* 2025-09-30 05:16:06.993324 | controller | instance : ok=16 changed=6 unreachable=0 failed=0 skipped=5 rescued=0 ignored=0 2025-09-30 05:16:06.993337 | controller | 2025-09-30 05:16:06.993534 | controller | Tuesday 30 September 2025 05:16:06 +0000 (0:00:00.828) 0:00:11.030 ***** 2025-09-30 05:16:06.993577 | controller | =============================================================================== 2025-09-30 05:16:06.993601 | controller | Fetch crc network facts ------------------------------------------------- 5.02s 2025-09-30 05:16:06.993789 | controller | Gathering Facts --------------------------------------------------------- 1.27s 2025-09-30 05:16:06.993808 | controller | ci_multus : Create the multus namespace --------------------------------- 0.98s 2025-09-30 05:16:06.993836 | controller | ci_multus : Apply network attachment definition manifests --------------- 0.83s 2025-09-30 05:16:06.994147 | controller | ci_multus : Render NetworkAttachmenktDefinition manifests --------------- 0.65s 2025-09-30 05:16:06.994245 | controller | Add crc hostname with it's IP to /etc/hosts ----------------------------- 0.47s 2025-09-30 05:16:06.994253 | controller | recognize_ssh_keypair : Check if id_ed25519 key exists ------------------ 0.44s 2025-09-30 05:16:06.994261 | controller | ci_multus : Create manifests directory ---------------------------------- 0.39s 2025-09-30 05:16:06.995051 | controller | ci_multus : Merge any available multus net info patches ----------------- 0.21s 2025-09-30 05:16:06.995140 | controller | ci_multus : Remove any networks without Multus networking defined ------- 0.12s 2025-09-30 05:16:06.995148 | controller | ci_multus : Remove any networks not in cifmw_ci_multus_allow_list if defined --- 0.09s 2025-09-30 05:16:06.995155 | controller | ci_multus : Remove any networks in cifmw_ci_multus_deny_list if defined --- 0.09s 2025-09-30 05:16:06.995161 | controller | Load shared variables --------------------------------------------------- 0.08s 2025-09-30 05:16:06.995166 | controller | Call ci_multus role ----------------------------------------------------- 0.06s 2025-09-30 05:16:06.995172 | controller | ci_multus : Gather network layout from OCP host or default networks ----- 0.06s 2025-09-30 05:16:06.995178 | controller | networking_mapper : Set cifmw_networking_env_definition is present ------ 0.04s 2025-09-30 05:16:06.995186 | controller | Check if new ssh keypair exists ----------------------------------------- 0.04s 2025-09-30 05:16:06.995229 | controller | networking_mapper : Check for Networking Definition file existance ------ 0.03s 2025-09-30 05:16:06.995340 | controller | recognize_ssh_keypair : Set fact if new keypair exists ------------------ 0.03s 2025-09-30 05:16:06.995444 | controller | networking_mapper : Check for Networking Environment Definition file existence --- 0.03s 2025-09-30 05:16:07.081187 | controller | INFO Running default > verify 2025-09-30 05:16:07.081788 | controller | INFO Running Ansible Verifier 2025-09-30 05:16:07.574339 | controller | 2025-09-30 05:16:07.574444 | controller | PLAY [Verify] ****************************************************************** 2025-09-30 05:16:07.574783 | controller | 2025-09-30 05:16:07.574860 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 05:16:07.575120 | controller | Tuesday 30 September 2025 05:16:07 +0000 (0:00:00.015) 0:00:00.015 ***** 2025-09-30 05:16:08.806632 | controller | ok: [instance] 2025-09-30 05:16:08.806734 | controller | 2025-09-30 05:16:08.806923 | controller | TASK [Load shared variables] *************************************************** 2025-09-30 05:16:08.807070 | controller | Tuesday 30 September 2025 05:16:08 +0000 (0:00:01.232) 0:00:01.248 ***** 2025-09-30 05:16:08.836695 | controller | ok: [instance] 2025-09-30 05:16:08.836816 | controller | 2025-09-30 05:16:08.836966 | controller | TASK [Fetch files stat results] ************************************************ 2025-09-30 05:16:08.837498 | controller | Tuesday 30 September 2025 05:16:08 +0000 (0:00:00.030) 0:00:01.278 ***** 2025-09-30 05:16:09.264769 | controller | ok: [instance] 2025-09-30 05:16:09.264863 | controller | 2025-09-30 05:16:09.264960 | controller | TASK [Assert that expected file exist] ***************************************** 2025-09-30 05:16:09.264985 | controller | Tuesday 30 September 2025 05:16:09 +0000 (0:00:00.427) 0:00:01.705 ***** 2025-09-30 05:16:09.287893 | controller | ok: [instance] => changed=false 2025-09-30 05:16:09.288019 | controller | msg: All assertions passed 2025-09-30 05:16:09.288043 | controller | 2025-09-30 05:16:09.288364 | controller | TASK [Fetch file content] ****************************************************** 2025-09-30 05:16:09.288396 | controller | Tuesday 30 September 2025 05:16:09 +0000 (0:00:00.024) 0:00:01.729 ***** 2025-09-30 05:16:09.641380 | controller | ok: [instance] 2025-09-30 05:16:09.641490 | controller | 2025-09-30 05:16:09.641713 | controller | TASK [Set _ci_multus_nad variable] ********************************************* 2025-09-30 05:16:09.641927 | controller | Tuesday 30 September 2025 05:16:09 +0000 (0:00:00.352) 0:00:02.082 ***** 2025-09-30 05:16:09.702803 | controller | ok: [instance] 2025-09-30 05:16:09.702895 | controller | 2025-09-30 05:16:09.702916 | controller | TASK [Assert expected number of Network Attachment Definitions are created] **** 2025-09-30 05:16:09.703038 | controller | Tuesday 30 September 2025 05:16:09 +0000 (0:00:00.062) 0:00:02.144 ***** 2025-09-30 05:16:09.761851 | controller | ok: [instance] 2025-09-30 05:16:09.761984 | controller | 2025-09-30 05:16:09.762459 | controller | PLAY RECAP ********************************************************************* 2025-09-30 05:16:09.762652 | controller | instance : ok=7 changed=0 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 2025-09-30 05:16:09.762674 | controller | 2025-09-30 05:16:09.762694 | controller | Tuesday 30 September 2025 05:16:09 +0000 (0:00:00.059) 0:00:02.203 ***** 2025-09-30 05:16:09.762917 | controller | =============================================================================== 2025-09-30 05:16:09.762948 | controller | Gathering Facts --------------------------------------------------------- 1.23s 2025-09-30 05:16:09.763074 | controller | Fetch files stat results ------------------------------------------------ 0.43s 2025-09-30 05:16:09.763341 | controller | Fetch file content ------------------------------------------------------ 0.35s 2025-09-30 05:16:09.763498 | controller | Set _ci_multus_nad variable --------------------------------------------- 0.06s 2025-09-30 05:16:09.763520 | controller | Assert expected number of Network Attachment Definitions are created ---- 0.06s 2025-09-30 05:16:09.763634 | controller | Load shared variables --------------------------------------------------- 0.03s 2025-09-30 05:16:09.764151 | controller | Assert that expected file exist ----------------------------------------- 0.02s 2025-09-30 05:16:09.820521 | controller | INFO Verifier completed successfully. 2025-09-30 05:16:09.834586 | controller | INFO Running default > verify 2025-09-30 05:16:09.835058 | controller | INFO Running Ansible Verifier 2025-09-30 05:16:10.347791 | controller | 2025-09-30 05:16:10.347921 | controller | PLAY [Verify CRC] ************************************************************** 2025-09-30 05:16:10.348153 | controller | 2025-09-30 05:16:10.348379 | controller | TASK [Gathering Facts] ********************************************************* 2025-09-30 05:16:10.348620 | controller | Tuesday 30 September 2025 05:16:10 +0000 (0:00:00.017) 0:00:00.017 ***** 2025-09-30 05:16:12.550221 | controller | ok: [instance] 2025-09-30 05:16:12.550420 | controller | 2025-09-30 05:16:12.550726 | controller | TASK [Include default vars] **************************************************** 2025-09-30 05:16:12.551036 | controller | Tuesday 30 September 2025 05:16:12 +0000 (0:00:02.202) 0:00:02.220 ***** 2025-09-30 05:16:12.601904 | controller | ok: [instance] 2025-09-30 05:16:12.602021 | controller | 2025-09-30 05:16:12.602392 | controller | TASK [Check if NADs were created] ********************************************** 2025-09-30 05:16:12.602875 | controller | Tuesday 30 September 2025 05:16:12 +0000 (0:00:00.051) 0:00:02.271 ***** 2025-09-30 05:16:13.527815 | controller | ok: [instance] 2025-09-30 05:16:13.527986 | controller | 2025-09-30 05:16:13.528196 | controller | TASK [Store output spec] ******************************************************* 2025-09-30 05:16:13.528407 | controller | Tuesday 30 September 2025 05:16:13 +0000 (0:00:00.921) 0:00:03.192 ***** 2025-09-30 05:16:13.577663 | controller | ok: [instance] 2025-09-30 05:16:13.578333 | controller | 2025-09-30 05:16:13.635492 | controller | TASK [Ensure both lists have the same length] ********************************** 2025-09-30 05:16:13.635572 | controller | Tuesday 30 September 2025 05:16:13 +0000 (0:00:00.054) 0:00:03.246 ***** 2025-09-30 05:16:13.635595 | controller | ok: [instance] => changed=false 2025-09-30 05:16:13.635607 | controller | msg: All assertions passed 2025-09-30 05:16:13.635872 | controller | 2025-09-30 05:16:13.636105 | controller | TASK [Compare each corresponding element in the lists] ************************* 2025-09-30 05:16:13.636291 | controller | Tuesday 30 September 2025 05:16:13 +0000 (0:00:00.058) 0:00:03.305 ***** 2025-09-30 05:16:13.702215 | 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 05:16:13.702387 | controller | ansible_loop_var: item 2025-09-30 05:16:13.702604 | controller | item: 2025-09-30 05:16:13.702845 | controller | - |- 2025-09-30 05:16:13.703055 | controller | { 2025-09-30 05:16:13.703237 | controller | "cniVersion": "0.3.1", 2025-09-30 05:16:13.703496 | controller | "name": "bridge-to-linux-bridge", 2025-09-30 05:16:13.703708 | controller | "type": "bridge", 2025-09-30 05:16:13.703948 | controller | "bridge": "bridge-to-linux-bridge", 2025-09-30 05:16:13.704150 | controller | "ipam": { 2025-09-30 05:16:13.704362 | controller | "type": "whereabouts", 2025-09-30 05:16:13.704568 | controller | "range": "192.168.122.0/24", 2025-09-30 05:16:13.704764 | controller | "range_start": "192.168.122.30", 2025-09-30 05:16:13.704979 | controller | "range_end": "192.168.122.70" 2025-09-30 05:16:13.705185 | controller | } 2025-09-30 05:16:13.705360 | controller | } 2025-09-30 05:16:13.705578 | controller | - |- 2025-09-30 05:16:13.705805 | controller | { 2025-09-30 05:16:13.706016 | controller | "cniVersion": "0.3.1", 2025-09-30 05:16:13.706209 | controller | "name": "bridge-to-linux-bridge", 2025-09-30 05:16:13.706438 | controller | "type": "bridge", 2025-09-30 05:16:13.706620 | controller | "bridge": "bridge-to-linux-bridge", 2025-09-30 05:16:13.706830 | controller | "ipam": { 2025-09-30 05:16:13.707153 | controller | "type": "whereabouts", 2025-09-30 05:16:13.707236 | controller | "range": "192.168.122.0/24", 2025-09-30 05:16:13.707489 | controller | "range_start": "192.168.122.30", 2025-09-30 05:16:13.708025 | controller | "range_end": "192.168.122.70" 2025-09-30 05:16:13.708160 | controller | } 2025-09-30 05:16:13.708195 | controller | } 2025-09-30 05:16:13.708678 | controller | msg: All assertions passed 2025-09-30 05:16:13.708783 | 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 05:16:13.708805 | controller | ansible_loop_var: item 2025-09-30 05:16:13.709136 | controller | item: 2025-09-30 05:16:13.709197 | controller | - |- 2025-09-30 05:16:13.709410 | controller | { 2025-09-30 05:16:13.709603 | controller | "cniVersion": "0.3.1", 2025-09-30 05:16:13.709833 | controller | "name": "default", 2025-09-30 05:16:13.710017 | controller | "type": "bridge", 2025-09-30 05:16:13.710322 | controller | "bridge": "eth0", 2025-09-30 05:16:13.710420 | controller | "ipam": { 2025-09-30 05:16:13.710615 | controller | "type": "whereabouts", 2025-09-30 05:16:13.710836 | controller | "range": "192.168.122.0/24", 2025-09-30 05:16:13.711045 | controller | "range_start": "192.168.122.30", 2025-09-30 05:16:13.711550 | controller | "range_end": "192.168.122.70" 2025-09-30 05:16:13.712246 | controller | } 2025-09-30 05:16:13.712457 | controller | } 2025-09-30 05:16:13.712656 | controller | - |- 2025-09-30 05:16:13.713262 | controller | { 2025-09-30 05:16:13.713285 | controller | "cniVersion": "0.3.1", 2025-09-30 05:16:13.713297 | controller | "name": "default", 2025-09-30 05:16:13.713498 | controller | "type": "bridge", 2025-09-30 05:16:13.713821 | controller | "bridge": "eth0", 2025-09-30 05:16:13.714100 | controller | "ipam": { 2025-09-30 05:16:13.714309 | controller | "type": "whereabouts", 2025-09-30 05:16:13.714328 | controller | "range": "192.168.122.0/24", 2025-09-30 05:16:13.714497 | controller | "range_start": "192.168.122.30", 2025-09-30 05:16:13.714688 | controller | "range_end": "192.168.122.70" 2025-09-30 05:16:13.715776 | controller | } 2025-09-30 05:16:13.715867 | controller | } 2025-09-30 05:16:13.715881 | controller | msg: All assertions passed 2025-09-30 05:16:13.715890 | 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 05:16:13.715902 | controller | ansible_loop_var: item 2025-09-30 05:16:13.716542 | controller | item: 2025-09-30 05:16:13.716670 | controller | - |- 2025-09-30 05:16:13.716683 | controller | { 2025-09-30 05:16:13.716698 | controller | "cniVersion": "0.3.1", 2025-09-30 05:16:13.716964 | controller | "name": "patchnetwork", 2025-09-30 05:16:13.717159 | controller | "type": "macvlan", 2025-09-30 05:16:13.717357 | controller | "master": "eth2", 2025-09-30 05:16:13.717532 | controller | "ipam": { 2025-09-30 05:16:13.717768 | controller | "type": "whereabouts", 2025-09-30 05:16:13.717977 | controller | "range": "192.168.122.0/24", 2025-09-30 05:16:13.718157 | controller | "range_start": "192.168.122.30", 2025-09-30 05:16:13.718375 | controller | "range_end": "192.168.122.70" 2025-09-30 05:16:13.718545 | controller | } 2025-09-30 05:16:13.718813 | controller | } 2025-09-30 05:16:13.719003 | controller | - |- 2025-09-30 05:16:13.719194 | controller | { 2025-09-30 05:16:13.719384 | controller | "cniVersion": "0.3.1", 2025-09-30 05:16:13.719642 | controller | "name": "patchnetwork", 2025-09-30 05:16:13.719893 | controller | "type": "macvlan", 2025-09-30 05:16:13.720086 | controller | "master": "eth2", 2025-09-30 05:16:13.720274 | controller | "ipam": { 2025-09-30 05:16:13.720501 | controller | "type": "whereabouts", 2025-09-30 05:16:13.720697 | controller | "range": "192.168.122.0/24", 2025-09-30 05:16:13.720915 | controller | "range_start": "192.168.122.30", 2025-09-30 05:16:13.721104 | controller | "range_end": "192.168.122.70" 2025-09-30 05:16:13.721313 | controller | } 2025-09-30 05:16:13.721500 | controller | } 2025-09-30 05:16:13.721710 | controller | msg: All assertions passed 2025-09-30 05:16:13.721940 | controller | 2025-09-30 05:16:13.722139 | controller | TASK [Create a test pod to attach a network] *********************************** 2025-09-30 05:16:13.722346 | controller | Tuesday 30 September 2025 05:16:13 +0000 (0:00:00.067) 0:00:03.372 ***** 2025-09-30 05:16:24.656035 | controller | fatal: [instance]: FAILED! => changed=false 2025-09-30 05:16:24.656194 | controller | msg: 'Failed to create object: b''{"kind":"Status","apiVersion":"v1","metadata":{},"status":"Failure","message":"pods \\"pod-testnad\\" is forbidden: error fetching namespace \\"openstack\\": unable to find annotation openshift.io/sa.scc.uid-range","reason":"Forbidden","details":{"name":"pod-testnad","kind":"pods"},"code":403}\n''' 2025-09-30 05:16:24.656274 | controller | reason: Forbidden 2025-09-30 05:16:24.659940 | controller | 2025-09-30 05:16:24.660000 | controller | PLAY RECAP ********************************************************************* 2025-09-30 05:16:24.660043 | controller | instance : ok=6 changed=0 unreachable=0 failed=1 skipped=0 rescued=0 ignored=0 2025-09-30 05:16:24.660326 | controller | 2025-09-30 05:16:24.660998 | controller | Tuesday 30 September 2025 05:16:24 +0000 (0:00:10.958) 0:00:14.330 ***** 2025-09-30 05:16:24.661073 | controller | =============================================================================== 2025-09-30 05:16:24.661084 | controller | Create a test pod to attach a network ---------------------------------- 10.96s 2025-09-30 05:16:24.661093 | controller | Gathering Facts --------------------------------------------------------- 2.20s 2025-09-30 05:16:24.661248 | controller | Check if NADs were created ---------------------------------------------- 0.92s 2025-09-30 05:16:24.661391 | controller | Compare each corresponding element in the lists ------------------------- 0.07s 2025-09-30 05:16:24.661409 | controller | Ensure both lists have the same length ---------------------------------- 0.06s 2025-09-30 05:16:24.661748 | controller | Store output spec ------------------------------------------------------- 0.05s 2025-09-30 05:16:24.661951 | controller | Include default vars ---------------------------------------------------- 0.05s 2025-09-30 05:16:24.743415 | controller | CRITICAL Ansible return code was 2, command was: ['ansible-playbook', '--inventory', '/home/zuul/.cache/molecule/ci_multus/default/inventory', '--skip-tags', 'molecule-notest,notest', '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/ci_multus/molecule/default/verify_crc.yml'] 2025-09-30 05:16:24.743826 | controller | WARNING An error occurred during the test sequence action: 'verify'. Cleaning up. 2025-09-30 05:16:24.755093 | controller | INFO Running default > cleanup 2025-09-30 05:16:24.755636 | controller | WARNING Skipping, cleanup playbook not configured. 2025-09-30 05:16:24.767253 | controller | INFO Running default > destroy 2025-09-30 05:16:24.767572 | controller | WARNING Skipping, instances are delegated. 2025-09-30 05:16:24.768008 | controller | INFO Pruning extra files from scenario ephemeral directory 2025-09-30 05:16:24.770118 | controller | INFO Writing /tmp/report.html report. 2025-09-30 05:16:25.172128 | controller | ERROR 2025-09-30 05:16:25.172420 | controller | { 2025-09-30 05:16:25.172481 | controller | "delta": "0:00:30.691892", 2025-09-30 05:16:25.172525 | controller | "end": "2025-09-30 05:16:24.839412", 2025-09-30 05:16:25.172564 | controller | "msg": "non-zero return code", 2025-09-30 05:16:25.172600 | controller | "rc": 1, 2025-09-30 05:16:25.172644 | controller | "start": "2025-09-30 05:15:54.147520" 2025-09-30 05:16:25.172725 | controller | } failure 2025-09-30 05:16:25.179144 | 2025-09-30 05:16:25.179250 | PLAY RECAP 2025-09-30 05:16:25.179328 | controller | ok: 1 changed: 0 unreachable: 0 failed: 1 skipped: 1 rescued: 0 ignored: 0 2025-09-30 05:16:25.179372 | 2025-09-30 05:16:25.295187 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main] 2025-09-30 05:16:25.296124 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main] 2025-09-30 05:16:25.890710 | 2025-09-30 05:16:25.890833 | PLAY [Run ci/playbooks/collect-logs.yml] 2025-09-30 05:16:25.912130 | 2025-09-30 05:16:25.912267 | TASK [Filter out host if needed] 2025-09-30 05:16:25.921279 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller 2025-09-30 05:16:25.925850 | 2025-09-30 05:16:25.925911 | TASK [Ensure file is present] 2025-09-30 05:16:26.430028 | controller | ok 2025-09-30 05:16:26.444846 | 2025-09-30 05:16:26.444986 | TASK [Manage molecule report file] 2025-09-30 05:16:27.493776 | controller | changed 2025-09-30 05:16:27.505739 | 2025-09-30 05:16:27.505881 | TASK [Check if we get ci-framework-data basedir] 2025-09-30 05:16:27.880045 | controller | ok 2025-09-30 05:16:27.892010 | 2025-09-30 05:16:27.892142 | TASK [Create ci-framework-data log directory for zuul] 2025-09-30 05:16:28.347961 | controller | changed 2025-09-30 05:16:28.356654 | 2025-09-30 05:16:28.356786 | TASK [Copy ci-framework interesting files] 2025-09-30 05:16:28.741937 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory 2025-09-30 05:16:28.894870 | controller | changed 2025-09-30 05:16:28.909171 | 2025-09-30 05:16:28.909350 | TASK [Get SELinux listing] 2025-09-30 05:16:29.462006 | controller | changed 2025-09-30 05:16:29.474943 | 2025-09-30 05:16:29.475076 | TASK [Generate log index] 2025-09-30 05:16:30.941713 | controller | changed 2025-09-30 05:16:30.946855 | 2025-09-30 05:16:30.946916 | TASK [Get some env related data] 2025-09-30 05:16:31.746870 | controller | /home/zuul/.local/bin/ansible 2025-09-30 05:16:32.480985 | controller | changed 2025-09-30 05:16:32.533206 | 2025-09-30 05:16:32.533373 | TASK [Generate list of logs to collect in home directory] 2025-09-30 05:16:32.999062 | controller | ok: All paths examined 2025-09-30 05:16:33.012267 | 2025-09-30 05:16:33.012403 | LOOP [Copy logs from home directory] 2025-09-30 05:16:33.825399 | controller | changed: 2025-09-30 05:16:33.825855 | controller | { 2025-09-30 05:16:33.825914 | controller | "atime": 1743544925.4788878, 2025-09-30 05:16:33.825956 | controller | "ctime": 1743545329.1409318, 2025-09-30 05:16:33.825993 | controller | "dev": 64513, 2025-09-30 05:16:33.826027 | controller | "gid": 1000, 2025-09-30 05:16:33.826062 | controller | "gr_name": "zuul", 2025-09-30 05:16:33.826098 | controller | "inode": 4518807, 2025-09-30 05:16:33.826133 | controller | "isblk": false, 2025-09-30 05:16:33.826166 | controller | "ischr": false, 2025-09-30 05:16:33.826199 | controller | "isdir": false, 2025-09-30 05:16:33.826232 | controller | "isfifo": false, 2025-09-30 05:16:33.826290 | controller | "isgid": false, 2025-09-30 05:16:33.826324 | controller | "islnk": false, 2025-09-30 05:16:33.826357 | controller | "isreg": true, 2025-09-30 05:16:33.826391 | controller | "issock": false, 2025-09-30 05:16:33.826423 | controller | "isuid": false, 2025-09-30 05:16:33.826456 | controller | "mode": "0644", 2025-09-30 05:16:33.826488 | controller | "mtime": 1743545329.1409318, 2025-09-30 05:16:33.826520 | controller | "nlink": 1, 2025-09-30 05:16:33.826553 | controller | "path": "/home/zuul/crc-setup.log", 2025-09-30 05:16:33.826593 | controller | "pw_name": "zuul", 2025-09-30 05:16:33.826629 | controller | "rgrp": true, 2025-09-30 05:16:33.826690 | controller | "roth": true, 2025-09-30 05:16:33.826739 | controller | "rusr": true, 2025-09-30 05:16:33.826776 | controller | "size": 4108, 2025-09-30 05:16:33.826811 | controller | "uid": 1000, 2025-09-30 05:16:33.826845 | controller | "wgrp": false, 2025-09-30 05:16:33.826878 | controller | "woth": false, 2025-09-30 05:16:33.826918 | controller | "wusr": true, 2025-09-30 05:16:33.826954 | controller | "xgrp": false, 2025-09-30 05:16:33.826988 | controller | "xoth": false, 2025-09-30 05:16:33.827022 | controller | "xusr": false 2025-09-30 05:16:33.827057 | controller | } 2025-09-30 05:16:34.778286 | controller | changed: 2025-09-30 05:16:34.778491 | controller | { 2025-09-30 05:16:34.778553 | controller | "atime": 1759208711.4968007, 2025-09-30 05:16:34.778604 | controller | "ctime": 1759208709.6918178, 2025-09-30 05:16:34.778651 | controller | "dev": 64513, 2025-09-30 05:16:34.778787 | controller | "gid": 1000, 2025-09-30 05:16:34.778850 | controller | "gr_name": "zuul", 2025-09-30 05:16:34.778908 | controller | "inode": 4194437, 2025-09-30 05:16:34.778965 | controller | "isblk": false, 2025-09-30 05:16:34.779020 | controller | "ischr": false, 2025-09-30 05:16:34.779076 | controller | "isdir": false, 2025-09-30 05:16:34.779132 | controller | "isfifo": false, 2025-09-30 05:16:34.779194 | controller | "isgid": false, 2025-09-30 05:16:34.779249 | controller | "islnk": false, 2025-09-30 05:16:34.779306 | controller | "isreg": true, 2025-09-30 05:16:34.779364 | controller | "issock": false, 2025-09-30 05:16:34.779418 | controller | "isuid": false, 2025-09-30 05:16:34.779463 | controller | "mode": "0644", 2025-09-30 05:16:34.779506 | controller | "mtime": 1759208709.6918178, 2025-09-30 05:16:34.779550 | controller | "nlink": 1, 2025-09-30 05:16:34.779593 | controller | "path": "/home/zuul/crc-start.log", 2025-09-30 05:16:34.779636 | controller | "pw_name": "zuul", 2025-09-30 05:16:34.779880 | controller | "rgrp": true, 2025-09-30 05:16:34.780358 | controller | "roth": true, 2025-09-30 05:16:34.780431 | controller | "rusr": true, 2025-09-30 05:16:34.780471 | controller | "size": 3404, 2025-09-30 05:16:34.780506 | controller | "uid": 1000, 2025-09-30 05:16:34.780541 | controller | "wgrp": false, 2025-09-30 05:16:34.780575 | controller | "woth": false, 2025-09-30 05:16:34.780609 | controller | "wusr": true, 2025-09-30 05:16:34.780641 | controller | "xgrp": false, 2025-09-30 05:16:34.780726 | controller | "xoth": false, 2025-09-30 05:16:34.780766 | controller | "xusr": false 2025-09-30 05:16:34.780799 | controller | } 2025-09-30 05:16:35.540845 | controller | changed: 2025-09-30 05:16:35.541020 | controller | { 2025-09-30 05:16:35.541070 | controller | "atime": 1759209334.7830389, 2025-09-30 05:16:35.541108 | controller | "ctime": 1759209351.2708902, 2025-09-30 05:16:35.541145 | controller | "dev": 64513, 2025-09-30 05:16:35.541181 | controller | "gid": 1000, 2025-09-30 05:16:35.541216 | controller | "gr_name": "zuul", 2025-09-30 05:16:35.541250 | controller | "inode": 4340277, 2025-09-30 05:16:35.541284 | controller | "isblk": false, 2025-09-30 05:16:35.541318 | controller | "ischr": false, 2025-09-30 05:16:35.541351 | controller | "isdir": false, 2025-09-30 05:16:35.541385 | controller | "isfifo": false, 2025-09-30 05:16:35.541420 | controller | "isgid": false, 2025-09-30 05:16:35.541454 | controller | "islnk": false, 2025-09-30 05:16:35.541487 | controller | "isreg": true, 2025-09-30 05:16:35.541521 | controller | "issock": false, 2025-09-30 05:16:35.541555 | controller | "isuid": false, 2025-09-30 05:16:35.541589 | controller | "mode": "0644", 2025-09-30 05:16:35.541623 | controller | "mtime": 1759209351.2708902, 2025-09-30 05:16:35.541657 | controller | "nlink": 1, 2025-09-30 05:16:35.541737 | controller | "path": "/home/zuul/ansible.log", 2025-09-30 05:16:35.541775 | controller | "pw_name": "zuul", 2025-09-30 05:16:35.541810 | controller | "rgrp": true, 2025-09-30 05:16:35.541846 | controller | "roth": true, 2025-09-30 05:16:35.541886 | controller | "rusr": true, 2025-09-30 05:16:35.541923 | controller | "size": 6749, 2025-09-30 05:16:35.541958 | controller | "uid": 1000, 2025-09-30 05:16:35.541993 | controller | "wgrp": false, 2025-09-30 05:16:35.542028 | controller | "woth": false, 2025-09-30 05:16:35.542062 | controller | "wusr": true, 2025-09-30 05:16:35.542096 | controller | "xgrp": false, 2025-09-30 05:16:35.542130 | controller | "xoth": false, 2025-09-30 05:16:35.542163 | controller | "xusr": false 2025-09-30 05:16:35.542197 | controller | } 2025-09-30 05:16:35.559744 | 2025-09-30 05:16:35.559882 | TASK [Copy crio stats log file] 2025-09-30 05:16:35.587827 | controller | skipping: Conditional result was False 2025-09-30 05:16:35.601443 | 2025-09-30 05:16:35.601587 | TASK [Get SELinux related data] 2025-09-30 05:16:35.973616 | controller | 2025-09-30 05:16:36.150466 | controller | ERROR 2025-09-30 05:16:36.150845 | controller | { 2025-09-30 05:16:36.150915 | controller | "delta": "0:00:00.013246", 2025-09-30 05:16:36.150958 | controller | "end": "2025-09-30 05:16:35.975578", 2025-09-30 05:16:36.150994 | controller | "msg": "non-zero return code", 2025-09-30 05:16:36.151029 | controller | "rc": 1, 2025-09-30 05:16:36.151064 | controller | "start": "2025-09-30 05:16:35.962332" 2025-09-30 05:16:36.151098 | controller | } 2025-09-30 05:16:36.151145 | controller | ERROR: Ignoring Errors 2025-09-30 05:16:36.162521 | 2025-09-30 05:16:36.162652 | TASK [Create system configuration directory] 2025-09-30 05:16:36.516643 | controller | changed 2025-09-30 05:16:36.527812 | 2025-09-30 05:16:36.527979 | TASK [Get some of the system configurations] 2025-09-30 05:16:37.077494 | controller | changed 2025-09-30 05:16:37.088872 | 2025-09-30 05:16:37.089004 | TASK [Copy generated documentation if available] 2025-09-30 05:16:37.116473 | controller | skipping: Conditional result was False 2025-09-30 05:16:37.129230 | 2025-09-30 05:16:37.129364 | TASK [Copy generated AsciiDoc documentation if available] 2025-09-30 05:16:37.156117 | controller | skipping: Conditional result was False 2025-09-30 05:16:37.168806 | 2025-09-30 05:16:37.168935 | TASK [Compress logs bigger than 2MB] 2025-09-30 05:16:37.716977 | controller | changed 2025-09-30 05:16:37.730519 | 2025-09-30 05:16:37.730723 | TASK [Copy files from workspace on node] 2025-09-30 05:16:37.759434 | controller | ok 2025-09-30 05:16:37.802649 | 2025-09-30 05:16:37.802868 | TASK [fetch-output : Set log path for multiple nodes] 2025-09-30 05:16:37.829135 | controller | skipping: Conditional result was False 2025-09-30 05:16:37.842267 | 2025-09-30 05:16:37.842478 | TASK [fetch-output : Set log path for single node] 2025-09-30 05:16:37.889706 | controller | ok 2025-09-30 05:16:37.901104 | 2025-09-30 05:16:37.901238 | LOOP [fetch-output : Ensure local output dirs] 2025-09-30 05:16:38.201972 | controller -> localhost | ok: "/var/lib/zuul/builds/c5b76151df2e4b4cb0e4218aced4e6ae/work/logs" 2025-09-30 05:16:38.202402 | controller -> localhost | changed: All items complete 2025-09-30 05:16:38.202460 | 2025-09-30 05:16:38.413404 | controller -> localhost | changed: "/var/lib/zuul/builds/c5b76151df2e4b4cb0e4218aced4e6ae/work/artifacts" 2025-09-30 05:16:38.649709 | controller -> localhost | changed: "/var/lib/zuul/builds/c5b76151df2e4b4cb0e4218aced4e6ae/work/docs" 2025-09-30 05:16:38.669032 | 2025-09-30 05:16:38.669190 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-09-30 05:16:39.512427 | controller | changed: 2025-09-30 05:16:39.512802 | controller | .d..t...... ./ 2025-09-30 05:16:39.512863 | controller | >f+++++++++ README.html 2025-09-30 05:16:39.512907 | controller | >f+++++++++ ansible-execution.log 2025-09-30 05:16:39.512950 | controller | >f+++++++++ ansible.log 2025-09-30 05:16:39.512990 | controller | >f+++++++++ crc-setup.log 2025-09-30 05:16:39.513029 | controller | >f+++++++++ crc-start.log 2025-09-30 05:16:39.513068 | controller | >f+++++++++ dmesg.log 2025-09-30 05:16:39.513115 | controller | >f+++++++++ installed-pkgs.log 2025-09-30 05:16:39.513155 | controller | >f+++++++++ python.log 2025-09-30 05:16:39.513193 | controller | >f+++++++++ registries.conf 2025-09-30 05:16:39.513231 | controller | >f+++++++++ report.html 2025-09-30 05:16:39.513285 | controller | >f+++++++++ selinux-denials.log 2025-09-30 05:16:39.513325 | controller | >f+++++++++ selinux-listing.log 2025-09-30 05:16:39.513363 | controller | cd+++++++++ ci-framework-data/ 2025-09-30 05:16:39.513400 | controller | cd+++++++++ ci-framework-data/artifacts/ 2025-09-30 05:16:39.513437 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml 2025-09-30 05:16:39.513475 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/ 2025-09-30 05:16:39.513513 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/ci_multus/ 2025-09-30 05:16:39.513550 | controller | >f+++++++++ ci-framework-data/artifacts/manifests/ci_multus/ci_multus_nads.yml 2025-09-30 05:16:39.513587 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/ 2025-09-30 05:16:39.513624 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml 2025-09-30 05:16:39.513661 | controller | cd+++++++++ ci-framework-data/logs/ 2025-09-30 05:16:39.513738 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log 2025-09-30 05:16:39.513778 | controller | cd+++++++++ registries.conf.d/ 2025-09-30 05:16:39.513815 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf 2025-09-30 05:16:39.513853 | controller | cd+++++++++ system-config/ 2025-09-30 05:16:39.513889 | controller | cd+++++++++ system-config/libvirt/ 2025-09-30 05:16:39.513926 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf 2025-09-30 05:16:39.513963 | controller | >f+++++++++ system-config/libvirt/libvirt.conf 2025-09-30 05:16:39.514001 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf 2025-09-30 05:16:39.514038 | controller | >f+++++++++ system-config/libvirt/network.conf 2025-09-30 05:16:39.514075 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf 2025-09-30 05:16:39.514111 | controller | >f+++++++++ system-config/libvirt/qemu.conf 2025-09-30 05:16:39.514148 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf 2025-09-30 05:16:39.514185 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf 2025-09-30 05:16:39.514221 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf 2025-09-30 05:16:39.514257 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf 2025-09-30 05:16:39.514303 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf 2025-09-30 05:16:39.514340 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf 2025-09-30 05:16:39.514376 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf 2025-09-30 05:16:39.514411 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf 2025-09-30 05:16:39.514446 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf 2025-09-30 05:16:39.514482 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf 2025-09-30 05:16:40.154880 | controller | changed: .d..t...... ./ 2025-09-30 05:16:40.753851 | controller | changed: .d..t...... ./ 2025-09-30 05:16:40.789434 | 2025-09-30 05:16:40.789571 | TASK [Return artifact to Zuul] 2025-09-30 05:16:40.843786 | controller | ok 2025-09-30 05:16:40.871395 | 2025-09-30 05:16:40.871468 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host] 2025-09-30 05:16:40.871590 | 2025-09-30 05:16:40.871627 | PLAY RECAP 2025-09-30 05:16:40.871698 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1 2025-09-30 05:16:40.871733 | 2025-09-30 05:16:40.992389 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main] 2025-09-30 05:16:40.993291 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/dlrn/dlrn-report.yaml@master] 2025-09-30 05:16:41.555400 | 2025-09-30 05:16:41.555571 | PLAY [Report DLRN results after job run] 2025-09-30 05:16:41.576602 | 2025-09-30 05:16:41.576733 | TASK [Report job status to DLRN] 2025-09-30 05:16:41.597295 | controller | ok 2025-09-30 05:16:41.622172 | 2025-09-30 05:16:41.622272 | TASK [dlrn_report : Warning if DLRN is not running] 2025-09-30 05:16:41.686989 | controller | skipping: Conditional result was False 2025-09-30 05:16:41.693163 | 2025-09-30 05:16:41.693229 | TASK [dlrn_report : Install dlrnapi-client shyaml package] 2025-09-30 05:16:41.747414 | controller | skipping: Conditional result was False 2025-09-30 05:16:41.753475 | 2025-09-30 05:16:41.753545 | TASK [dlrn_report : Install kinit related package] 2025-09-30 05:16:41.797777 | controller | skipping: Conditional result was False 2025-09-30 05:16:41.803572 | 2025-09-30 05:16:41.803716 | TASK [dlrn_report : Install dlrn kerberos related packages] 2025-09-30 05:16:41.847928 | controller | skipping: Conditional result was False 2025-09-30 05:16:41.856262 | 2025-09-30 05:16:41.856338 | TASK [Set zuul-log-path fact] 2025-09-30 05:16:41.902785 | controller | skipping: Conditional result was False 2025-09-30 05:16:41.908642 | 2025-09-30 05:16:41.908726 | TASK [dlrn_report : Set the the value of cifmw_repo_setup_promotion when multiple dlrn tags are used] 2025-09-30 05:16:41.963142 | controller | skipping: Conditional result was False 2025-09-30 05:16:41.969478 | 2025-09-30 05:16:41.969549 | TASK [Get hash related data from repo_setup role] 2025-09-30 05:16:42.013826 | controller | skipping: Conditional result was False 2025-09-30 05:16:42.020183 | 2025-09-30 05:16:42.020248 | TASK [dlrn_report : Perform kinit for DLRN kerberos authentication] 2025-09-30 05:16:42.549230 | controller | skipping: Conditional result was False 2025-09-30 05:16:42.556124 | 2025-09-30 05:16:42.556199 | TASK [dlrn_report : Set empty value for dlrnapi password] 2025-09-30 05:16:42.630969 | controller | skipping: Conditional result was False 2025-09-30 05:16:42.637093 | 2025-09-30 05:16:42.637161 | TASK [dlrn_report : Report results to dlrn for the tested hash] 2025-09-30 05:16:43.168189 | controller | skipping: Conditional result was False 2025-09-30 05:16:43.222194 | 2025-09-30 05:16:43.222314 | PLAY RECAP 2025-09-30 05:16:43.222375 | controller | ok: 0 changed: 0 unreachable: 0 failed: 0 skipped: 10 rescued: 0 ignored: 0 2025-09-30 05:16:43.222403 | 2025-09-30 05:16:43.337051 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/dlrn/dlrn-report.yaml@master] 2025-09-30 05:16:43.338651 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-09-30 05:16:43.922174 | 2025-09-30 05:16:43.922310 | PLAY [all] 2025-09-30 05:16:43.941091 | 2025-09-30 05:16:43.941171 | TASK [include_role : fetch-output] 2025-09-30 05:16:43.980266 | controller | ok 2025-09-30 05:16:43.998352 | 2025-09-30 05:16:43.998434 | TASK [fetch-output : Set log path for multiple nodes] 2025-09-30 05:16:44.042435 | controller | skipping: Conditional result was False 2025-09-30 05:16:44.047967 | 2025-09-30 05:16:44.048032 | TASK [fetch-output : Set log path for single node] 2025-09-30 05:16:44.077000 | controller | ok 2025-09-30 05:16:44.081951 | 2025-09-30 05:16:44.082015 | LOOP [fetch-output : Ensure local output dirs] 2025-09-30 05:16:44.489813 | controller -> localhost | ok: "/var/lib/zuul/builds/c5b76151df2e4b4cb0e4218aced4e6ae/work/logs" 2025-09-30 05:16:44.749058 | controller -> localhost | ok: "/var/lib/zuul/builds/c5b76151df2e4b4cb0e4218aced4e6ae/work/artifacts" 2025-09-30 05:16:44.977097 | controller -> localhost | ok: "/var/lib/zuul/builds/c5b76151df2e4b4cb0e4218aced4e6ae/work/docs" 2025-09-30 05:16:44.999485 | 2025-09-30 05:16:44.999727 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-09-30 05:16:45.825141 | controller | ok 2025-09-30 05:16:45.825585 | controller | ok: All items complete 2025-09-30 05:16:45.825646 | 2025-09-30 05:16:46.451005 | controller | ok 2025-09-30 05:16:47.039536 | controller | ok 2025-09-30 05:16:47.052384 | 2025-09-30 05:16:47.052527 | TASK [include_role : fetch-output-openshift] 2025-09-30 05:16:47.079818 | controller | skipping: Conditional result was False 2025-09-30 05:16:47.093713 | 2025-09-30 05:16:47.093859 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-09-30 05:16:47.569963 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.013922 2025-09-30 05:16:47.870576 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.013930 2025-09-30 05:16:47.930518 | 2025-09-30 05:16:47.930682 | PLAY [all] 2025-09-30 05:16:47.952231 | 2025-09-30 05:16:47.952326 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-09-30 05:16:48.563825 | controller | changed 2025-09-30 05:16:48.614964 | 2025-09-30 05:16:48.615041 | PLAY RECAP 2025-09-30 05:16:48.615096 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-09-30 05:16:48.615124 | 2025-09-30 05:16:48.728103 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-09-30 05:16:48.729320 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-09-30 05:16:49.376691 | 2025-09-30 05:16:49.376825 | PLAY [localhost] 2025-09-30 05:16:49.394628 | 2025-09-30 05:16:49.394722 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-09-30 05:16:49.824730 | localhost | changed 2025-09-30 05:16:49.834796 | 2025-09-30 05:16:49.834960 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-09-30 05:16:49.881256 | localhost | ok 2025-09-30 05:16:49.898656 | 2025-09-30 05:16:49.898855 | TASK [add-fileserver : Create SSH private key tempfile] 2025-09-30 05:16:50.333856 | localhost | changed 2025-09-30 05:16:50.344243 | 2025-09-30 05:16:50.344474 | TASK [add-fileserver : Create SSH private key from secret] 2025-09-30 05:16:51.123588 | localhost | changed 2025-09-30 05:16:51.134479 | 2025-09-30 05:16:51.134612 | TASK [add-fileserver : Add fileserver ssh key] 2025-09-30 05:16:51.568733 | localhost | Identity added: /var/lib/zuul/builds/c5b76151df2e4b4cb0e4218aced4e6ae/work/tmp/ansible.kkck599q (/var/lib/zuul/builds/c5b76151df2e4b4cb0e4218aced4e6ae/work/tmp/ansible.kkck599q) 2025-09-30 05:16:51.569087 | localhost | ok: Runtime: 0:00:00.012686 2025-09-30 05:16:51.578389 | 2025-09-30 05:16:51.578522 | TASK [add-fileserver : Remove SSH private key from disk] 2025-09-30 05:16:51.909522 | localhost | ok: Runtime: 0:00:00.009489 2025-09-30 05:16:51.921028 | 2025-09-30 05:16:51.921168 | TASK [add-fileserver : Add fileserver to inventory] 2025-09-30 05:16:52.007600 | localhost | changed 2025-09-30 05:16:52.016771 | 2025-09-30 05:16:52.016902 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-09-30 05:16:52.479277 | localhost | changed 2025-09-30 05:16:52.521944 | 2025-09-30 05:16:52.522016 | PLAY [localhost] 2025-09-30 05:16:52.538369 | 2025-09-30 05:16:52.538449 | TASK [Generate bulk log download script] 2025-09-30 05:16:52.560003 | localhost | ok 2025-09-30 05:16:52.576051 | 2025-09-30 05:16:52.576137 | TASK [local-log-download : Check API endpoint is defined] 2025-09-30 05:16:52.629635 | localhost | ok: All assertions passed 2025-09-30 05:16:52.639942 | 2025-09-30 05:16:52.640074 | TASK [local-log-download : Create download script] 2025-09-30 05:16:53.106451 | localhost -> localhost | changed 2025-09-30 05:16:53.125084 | 2025-09-30 05:16:53.125222 | TASK [Register quick-download link] 2025-09-30 05:16:53.190688 | localhost | ok 2025-09-30 05:16:53.211773 | 2025-09-30 05:16:53.211852 | PLAY [logserver.rdoproject.org] 2025-09-30 05:16:53.224720 | 2025-09-30 05:16:53.224800 | TASK [Set zuul-log-path fact] 2025-09-30 05:16:53.243583 | logserver.rdoproject.org | ok 2025-09-30 05:16:53.256255 | 2025-09-30 05:16:53.256430 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-09-30 05:16:53.294201 | logserver.rdoproject.org | ok 2025-09-30 05:16:53.301366 | 2025-09-30 05:16:53.301450 | TASK [upload-logs : Create log directories] 2025-09-30 05:16:54.014534 | logserver.rdoproject.org | changed 2025-09-30 05:16:54.021324 | 2025-09-30 05:16:54.021457 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-09-30 05:16:54.344394 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009005 2025-09-30 05:16:54.354843 | 2025-09-30 05:16:54.355270 | TASK [upload-logs : Upload logs to log server] 2025-09-30 05:16:55.091226 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-09-30 05:16:55.097793 | 2025-09-30 05:16:55.097921 | LOOP [upload-logs : Compress console log and json output] 2025-09-30 05:16:55.163839 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 05:16:55.175548 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 05:16:55.183201 | 2025-09-30 05:16:55.183358 | LOOP [upload-logs : Upload compressed console log and json output] 2025-09-30 05:16:55.229783 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 05:16:55.229990 | 2025-09-30 05:16:55.233075 | logserver.rdoproject.org | skipping: Conditional result was False 2025-09-30 05:16:55.248713 | 2025-09-30 05:16:55.248872 | LOOP [upload-logs : Upload console log and json output]