2025-10-02 20:53:39.285384 | Job console starting... 2025-10-02 20:53:39.303537 | Updating repositories 2025-10-02 20:53:39.343355 | Preparing job workspace 2025-10-02 20:53:45.670681 | Running Ansible setup... 2025-10-02 20:53:51.306644 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 20:53:51.914905 | 2025-10-02 20:53:51.915038 | PLAY [localhost] 2025-10-02 20:53:51.927038 | 2025-10-02 20:53:51.927118 | TASK [Gathering Facts] 2025-10-02 20:53:53.316359 | localhost | ok 2025-10-02 20:53:53.333302 | 2025-10-02 20:53:53.333487 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-10-02 20:53:53.814494 | localhost -> localhost | changed 2025-10-02 20:53:53.820803 | 2025-10-02 20:53:53.820877 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-10-02 20:53:54.796259 | localhost -> localhost | changed 2025-10-02 20:53:54.810838 | 2025-10-02 20:53:54.810975 | TASK [Setup log path fact] 2025-10-02 20:53:54.834915 | localhost | ok 2025-10-02 20:53:54.850227 | 2025-10-02 20:53:54.850305 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 20:53:54.877195 | localhost | ok 2025-10-02 20:53:54.898660 | 2025-10-02 20:53:54.898748 | TASK [emit-job-header : Print job information] 2025-10-02 20:53:54.932450 | # Job Information 2025-10-02 20:53:54.932645 | Ansible Version: 2.15.12 2025-10-02 20:53:54.932675 | Job: cifmw-molecule-ci_nmstate 2025-10-02 20:53:54.932696 | Pipeline: github-check 2025-10-02 20:53:54.932714 | Executor: ze01.softwarefactory-project.io 2025-10-02 20:53:54.932733 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362 2025-10-02 20:53:54.932752 | Log URL (when completed): https://logserver.rdoproject.org/8fb/rdoproject.org/8fb77a034eea47af87900f7b49e3027f/ 2025-10-02 20:53:54.932771 | Event ID: b3260540-9fd1-11f0-99c1-8299ec1f8fbb 2025-10-02 20:53:54.936431 | 2025-10-02 20:53:54.936491 | LOOP [emit-job-header : Print node information] 2025-10-02 20:53:55.035457 | localhost | ok: 2025-10-02 20:53:55.035774 | localhost | # Node Information 2025-10-02 20:53:55.035805 | localhost | Inventory Hostname: controller 2025-10-02 20:53:55.035828 | localhost | Hostname: np0005467387 2025-10-02 20:53:55.035848 | localhost | Username: zuul 2025-10-02 20:53:55.035869 | localhost | Distro: CentOS 9 2025-10-02 20:53:55.035887 | localhost | Provider: vexxhost-nodepool-tripleo 2025-10-02 20:53:55.035905 | localhost | Region: RegionOne 2025-10-02 20:53:55.035923 | localhost | Label: centos-9-stream-crc-2-48-0-xxl 2025-10-02 20:53:55.035940 | localhost | Product Name: OpenStack Nova 2025-10-02 20:53:55.035956 | localhost | Interface IP: 38.102.83.115 2025-10-02 20:53:55.059408 | 2025-10-02 20:53:55.059465 | PLAY [all] 2025-10-02 20:53:55.065714 | 2025-10-02 20:53:55.065774 | TASK [Gather network facts] 2025-10-02 20:53:55.690004 | controller | ok 2025-10-02 20:53:55.720067 | 2025-10-02 20:53:55.720166 | TASK [include_role : start-zuul-console] 2025-10-02 20:53:55.748269 | controller | ok 2025-10-02 20:53:55.770961 | 2025-10-02 20:53:55.771121 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-10-02 20:53:56.325490 | controller | ok 2025-10-02 20:53:56.347361 | 2025-10-02 20:53:56.347493 | TASK [include_role : add-build-sshkey] 2025-10-02 20:53:56.377578 | controller | ok 2025-10-02 20:53:56.399187 | 2025-10-02 20:53:56.399317 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-10-02 20:53:56.690632 | controller -> localhost | ok 2025-10-02 20:53:56.696514 | 2025-10-02 20:53:56.696606 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-10-02 20:53:56.726295 | controller | ok 2025-10-02 20:53:56.739772 | controller | included: /var/lib/zuul/builds/8fb77a034eea47af87900f7b49e3027f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-10-02 20:53:56.745891 | 2025-10-02 20:53:56.745993 | TASK [add-build-sshkey : Create Temp SSH key] 2025-10-02 20:53:58.334517 | controller -> localhost | Generating public/private rsa key pair. 2025-10-02 20:53:58.334717 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/8fb77a034eea47af87900f7b49e3027f/work/8fb77a034eea47af87900f7b49e3027f_id_rsa. 2025-10-02 20:53:58.334750 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/8fb77a034eea47af87900f7b49e3027f/work/8fb77a034eea47af87900f7b49e3027f_id_rsa.pub. 2025-10-02 20:53:58.334774 | controller -> localhost | The key fingerprint is: 2025-10-02 20:53:58.334795 | controller -> localhost | SHA256:AER7LpqNZTMUfII2ib9kZJ4vK87jBdLqHnk7rsUO5s0 zuul-build-sshkey 2025-10-02 20:53:58.334815 | controller -> localhost | The key's randomart image is: 2025-10-02 20:53:58.334834 | controller -> localhost | +---[RSA 3072]----+ 2025-10-02 20:53:58.334853 | controller -> localhost | | . *= | 2025-10-02 20:53:58.334872 | controller -> localhost | |. B o+. | 2025-10-02 20:53:58.334892 | controller -> localhost | | * oooo | 2025-10-02 20:53:58.334911 | controller -> localhost | | .*. o . | 2025-10-02 20:53:58.334929 | controller -> localhost | |.+.o* . S | 2025-10-02 20:53:58.334947 | controller -> localhost | |..*B.+ | 2025-10-02 20:53:58.334965 | controller -> localhost | |.=+B. | 2025-10-02 20:53:58.334983 | controller -> localhost | |*.@.. | 2025-10-02 20:53:58.335001 | controller -> localhost | |+X+E. | 2025-10-02 20:53:58.335038 | controller -> localhost | +----[SHA256]-----+ 2025-10-02 20:53:58.335083 | controller -> localhost | ok: Runtime: 0:00:01.127776 2025-10-02 20:53:58.340659 | 2025-10-02 20:53:58.340725 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-10-02 20:53:58.359634 | controller | ok 2025-10-02 20:53:58.372825 | controller | included: /var/lib/zuul/builds/8fb77a034eea47af87900f7b49e3027f/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-10-02 20:53:58.381249 | 2025-10-02 20:53:58.381452 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-10-02 20:53:58.404982 | controller | skipping: Conditional result was False 2025-10-02 20:53:58.410527 | 2025-10-02 20:53:58.410623 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-10-02 20:53:59.125655 | controller | changed 2025-10-02 20:53:59.130950 | 2025-10-02 20:53:59.131052 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-10-02 20:53:59.607603 | controller | ok 2025-10-02 20:53:59.614460 | 2025-10-02 20:53:59.614541 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-10-02 20:54:01.600508 | controller | changed 2025-10-02 20:54:01.611978 | 2025-10-02 20:54:01.612176 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-10-02 20:54:03.648849 | controller | changed 2025-10-02 20:54:03.656404 | 2025-10-02 20:54:03.656531 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-10-02 20:54:03.683175 | controller | skipping: Conditional result was False 2025-10-02 20:54:03.703994 | 2025-10-02 20:54:03.704166 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-10-02 20:54:04.102874 | controller -> localhost | changed 2025-10-02 20:54:04.124615 | 2025-10-02 20:54:04.124738 | TASK [add-build-sshkey : Add back temp key] 2025-10-02 20:54:04.425324 | controller -> localhost | Identity added: /var/lib/zuul/builds/8fb77a034eea47af87900f7b49e3027f/work/8fb77a034eea47af87900f7b49e3027f_id_rsa (zuul-build-sshkey) 2025-10-02 20:54:04.425541 | controller -> localhost | ok: Runtime: 0:00:00.009741 2025-10-02 20:54:04.468505 | 2025-10-02 20:54:04.468651 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-10-02 20:54:04.958893 | controller | ok 2025-10-02 20:54:04.963741 | 2025-10-02 20:54:04.963804 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-10-02 20:54:05.002923 | controller | skipping: Conditional result was False 2025-10-02 20:54:05.012730 | 2025-10-02 20:54:05.012799 | TASK [include_role : validate-host] 2025-10-02 20:54:05.059253 | controller | ok 2025-10-02 20:54:05.083590 | 2025-10-02 20:54:05.083710 | TASK [validate-host : Define zuul_info_dir fact] 2025-10-02 20:54:05.115898 | controller | ok 2025-10-02 20:54:05.125946 | 2025-10-02 20:54:05.126091 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-10-02 20:54:05.376398 | controller -> localhost | ok 2025-10-02 20:54:05.383062 | 2025-10-02 20:54:05.383134 | TASK [validate-host : Collect information about the host] 2025-10-02 20:54:06.355997 | controller | ok 2025-10-02 20:54:06.377582 | 2025-10-02 20:54:06.377739 | TASK [validate-host : Sanitize hostname] 2025-10-02 20:54:06.428935 | controller | ok 2025-10-02 20:54:06.433960 | 2025-10-02 20:54:06.436130 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-10-02 20:54:06.886469 | controller -> localhost | changed 2025-10-02 20:54:06.891940 | 2025-10-02 20:54:06.892006 | TASK [validate-host : Collect information about zuul worker] 2025-10-02 20:54:07.468938 | controller | ok 2025-10-02 20:54:07.475373 | 2025-10-02 20:54:07.475459 | TASK [validate-host : Write out all zuul information for each host] 2025-10-02 20:54:07.898117 | controller -> localhost | changed 2025-10-02 20:54:07.908718 | 2025-10-02 20:54:07.908865 | TASK [include_role : prepare-workspace-openshift] 2025-10-02 20:54:07.922728 | controller | skipping: Conditional result was False 2025-10-02 20:54:07.929173 | 2025-10-02 20:54:07.929290 | TASK [include_role : remove-zuul-sshkey] 2025-10-02 20:54:07.947035 | controller | skipping: Conditional result was False 2025-10-02 20:54:07.953478 | 2025-10-02 20:54:07.953571 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-10-02 20:54:08.378956 | controller | ok: "logs" 2025-10-02 20:54:08.379327 | controller | ok: All items complete 2025-10-02 20:54:08.379376 | 2025-10-02 20:54:08.773559 | controller | ok: "artifacts" 2025-10-02 20:54:09.134291 | controller | ok: "docs" 2025-10-02 20:54:09.147810 | 2025-10-02 20:54:09.147999 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-10-02 20:54:09.629253 | controller | changed: "logs" 2025-10-02 20:54:09.996775 | controller | changed: "artifacts" 2025-10-02 20:54:10.352869 | controller | changed: "docs" 2025-10-02 20:54:10.394616 | 2025-10-02 20:54:10.394742 | PLAY RECAP 2025-10-02 20:54:10.394818 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-02 20:54:10.394871 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 20:54:10.394904 | 2025-10-02 20:54:10.509104 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-10-02 20:54:10.509881 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master] 2025-10-02 20:54:11.127199 | 2025-10-02 20:54:11.127479 | PLAY [all] 2025-10-02 20:54:11.148624 | 2025-10-02 20:54:11.148715 | TASK [mirror-info-fork : Set mirror_fqdn if not defined] 2025-10-02 20:54:11.201992 | controller | ok 2025-10-02 20:54:11.207896 | 2025-10-02 20:54:11.208010 | TASK [mirror-info-fork : Create /etc/ci] 2025-10-02 20:54:11.863635 | controller | changed 2025-10-02 20:54:11.871652 | 2025-10-02 20:54:11.871747 | TASK [mirror-info-fork : Install ci_mirror script] 2025-10-02 20:54:14.052865 | controller | changed 2025-10-02 20:54:14.063805 | 2025-10-02 20:54:14.063900 | LOOP [add-authorized-keys : Enable access via build key on all nodes] 2025-10-02 20:54:14.725308 | controller | changed: 2025-10-02 20:54:14.725481 | controller | { 2025-10-02 20:54:14.725511 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com" 2025-10-02 20:54:14.725540 | controller | } 2025-10-02 20:54:15.166504 | controller | changed: 2025-10-02 20:54:15.166648 | controller | { 2025-10-02 20:54:15.166705 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com" 2025-10-02 20:54:15.166750 | controller | } 2025-10-02 20:54:15.620340 | controller | changed: 2025-10-02 20:54:15.620459 | controller | { 2025-10-02 20:54:15.620493 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com" 2025-10-02 20:54:15.620520 | controller | } 2025-10-02 20:54:16.078080 | controller | changed: 2025-10-02 20:54:16.078195 | controller | { 2025-10-02 20:54:16.078226 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com" 2025-10-02 20:54:16.078251 | controller | } 2025-10-02 20:54:16.496476 | controller | changed: 2025-10-02 20:54:16.496625 | controller | { 2025-10-02 20:54:16.496678 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com" 2025-10-02 20:54:16.496719 | controller | } 2025-10-02 20:54:16.963977 | controller | changed: 2025-10-02 20:54:16.964107 | controller | { 2025-10-02 20:54:16.964134 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com" 2025-10-02 20:54:16.964155 | controller | } 2025-10-02 20:54:17.401131 | controller | changed: 2025-10-02 20:54:17.401278 | controller | { 2025-10-02 20:54:17.401331 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDLOQd4ZLtkZXQGY6UwAr/06ppWQK4fDO3HaqxPk98csyOCBXsliSKK39Bso828+5srIXiW7aI6aC9P5mwi4mUZlGPfJlQbfrcGvY+b/SocuvaGK+1RrHLoJCT52LBhwgrzlXio2jeksZeein8iaTrhsPrOAs7KggIL/rB9hEiB3NaOPWhhoCP4vlW6MEMExGcqB/1FVxXFBPnLkEyW0Lk7ycVflZl2ocRxbfjZi0+tI1Wlinp8PvSQSc/WVrAcDgKjc/mB4ODPOyYy3G8FHgfMsrXSDEyjBKgLKMsdCrAUcqJQWjkqXleXSYOV4q3pzL+9umK+q/e3P/bIoSFQzmJKTU1eDfuvPXmow9F5H54fii/Da7ezlMJ+wPGHJrRAkmzvMbALy7xwswLhZMkOGNtRcPqaKYRmIBKpw3o6bCTtcNUHOtOQnzwY8JzrM2eBWJBXAANYw+9/ho80JIiwhg29CFNpVBuHbql2YxJQNrnl90guN65rYNpDxdIluweyUf8= anbanerj@kaermorhen" 2025-10-02 20:54:17.401377 | controller | } 2025-10-02 20:54:17.787662 | controller | changed: 2025-10-02 20:54:17.787762 | controller | { 2025-10-02 20:54:17.787790 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC3VwV8Im9kRm49lt3tM36hj4Zv27FxGo4C1Q/0jqhzFmHY7RHbmeRr8ObhwWoHjXSozKWg8FL5ER0z3hTwL0W6lez3sL7hUaCmSuZmG5Hnl3x4vTSxDI9JZ/Y65rtYiiWQo2fC5xJhU/4+0e5e/pseCm8cKRSu+SaxhO+sd6FDojA2x1BzOzKiQRDy/1zWGp/cZkxcEuB1wHI5LMzN03c67vmbu+fhZRAUO4dQkvcnj2LrhQtpa+ytvnSjr8icMDosf1OsbSffwZFyHB/hfWGAfe0eIeSA2XPraxiPknXxiPKx2MJsaUTYbsZcm3EjFdHBBMumw5rBI74zLrMRvCO9GwBEmGT4rFng1nP+yw5DB8sn2zqpOsPg1LYRwCPOUveC13P6pgsZZPh812e8v5EKnETct+5XI3dVpdw6CnNiLwAyVAF15DJvBGT/u1k0Myg/bQn+Gv9k2MSj6LvQmf6WbZu2Wgjm30z3FyCneBqTL7mLF19YXzeC0ufHz5pnO1E= dasm@fedora" 2025-10-02 20:54:17.787818 | controller | } 2025-10-02 20:54:18.230485 | controller | changed: 2025-10-02 20:54:18.230655 | controller | { 2025-10-02 20:54:18.230708 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner" 2025-10-02 20:54:18.230747 | controller | } 2025-10-02 20:54:18.675781 | controller | changed: 2025-10-02 20:54:18.675934 | controller | { 2025-10-02 20:54:18.675986 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com" 2025-10-02 20:54:18.676063 | controller | } 2025-10-02 20:54:19.102369 | controller | changed: 2025-10-02 20:54:19.102474 | controller | { 2025-10-02 20:54:19.102497 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com" 2025-10-02 20:54:19.102516 | controller | } 2025-10-02 20:54:19.547293 | controller | changed: 2025-10-02 20:54:19.547423 | controller | { 2025-10-02 20:54:19.547473 | controller | "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com" 2025-10-02 20:54:19.547515 | controller | } 2025-10-02 20:54:19.943068 | controller | changed: 2025-10-02 20:54:19.943168 | controller | { 2025-10-02 20:54:19.943192 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith" 2025-10-02 20:54:19.943212 | controller | } 2025-10-02 20:54:20.382863 | controller | changed: 2025-10-02 20:54:20.383144 | controller | { 2025-10-02 20:54:20.383211 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel" 2025-10-02 20:54:20.383255 | controller | } 2025-10-02 20:54:20.803426 | controller | changed: 2025-10-02 20:54:20.803577 | controller | { 2025-10-02 20:54:20.803629 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux" 2025-10-02 20:54:20.803675 | controller | } 2025-10-02 20:54:21.228121 | controller | changed: 2025-10-02 20:54:21.228276 | controller | { 2025-10-02 20:54:21.228326 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr" 2025-10-02 20:54:21.228365 | controller | } 2025-10-02 20:54:21.653321 | controller | changed: 2025-10-02 20:54:21.653429 | controller | { 2025-10-02 20:54:21.653483 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQCfNtF7NvKl915TGsGGoseUb06Hj8L/S4toWf0hExeY+F00woL6NvBlJD0nDct+P5a22I4EhvoQCRQ8reaPCm1lybR3uiRIJsj+8zkVvLwby9LXzfZorlNG9ofjd00FEmB09uW/YvTl6Q9XwwwX6tInzIOv3TMqTHHGOL74ibbj8J/FJR0cFEyj0z4WQRvtkh32xAHl83gbuINryMt0sqRI+clj2381NKL55DRLQrVw0gsfqqxiHAnXg21qWmc4J+b9e9kiuAFQjcjwTVkwJCcg3xbPwC/qokYRby/Y5S40UUd7/jEARGXT7RZgpzTuDd1oZiCVrnrqJNPaMNdVv5MLeFdf1B7iIe5aa/fGouX7AO4SdKhZUdnJmCFAGvjC6S3JMZ2wAcUl+OHnssfmdj7XL50cLo27vjuzMtLAgSqi6N99m92WCF2s8J9aVzszX7Xz9OKZCeGsiVJp3/NdABKzSEAyM9xBD/5Vho894Sav+otpySHe3p6RUTgbB5Zu8VyZRZ/UtB3ueXxyo764yrc6qWIDqrehm84Xm9g+/jpIBzGPl07NUNJpdt/6Sgf9RIKXw/7XypO5yZfUcuFNGTxLfqjTNrtgLZNcjfav6sSdVXVcMPL//XNuRdKmVFaO76eV/oGMQGr1fGcCD+N+CpI7+Q+fCNB6VFWG4nZFuI/Iuw== averdagu@redhat.com" 2025-10-02 20:54:21.653510 | controller | } 2025-10-02 20:54:22.105350 | controller | changed: 2025-10-02 20:54:22.105509 | controller | { 2025-10-02 20:54:22.105560 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDq8l27xI+QlQVdS4djp9ogSoyrNE2+Ox6vKPdhSNL1J3PE5w+WCSvMz9A5gnNuH810zwbekEApbxTze/gLQJwBHA52CChfURpXrFaxY7ePXRElwKAL3mJfzBWY/c5jnNL9TCVmFJTGZkFZP3Nh+BMgZvL6xBkt3WKm6Uq18qzd9XeKcZusrA+O+uLv1fVeQnadY9RIqOCyeFYCzLWrUfTyE8x/XG0hAWIM7qpnF2cALQS2h9n4hW5ybiUN790H08wf9hFwEf5nxY9Z9dVkPFQiTSGKNBzmnCXU9skxS/xhpFjJ5duGSZdtAHe9O+nGZm9c67hxgtf8e5PDuqAdXEv2cf6e3VBAt+Bz8EKI3yosTj0oZHfwr42Yzb1l/SKy14Rggsrc9KAQlrGXan6+u2jcQqqx7l+SWmnpFiWTV9u5cWj2IgOhApOitmRBPYqk9rE2usfO0hLn/Pj/R/Nau4803e1/EikdLE7Ps95s9mX5jRDjAoUa2JwFF5RsVFyL910= ashigupt@ashigupt.remote.csb" 2025-10-02 20:54:22.105602 | controller | } 2025-10-02 20:54:22.481243 | controller | changed: 2025-10-02 20:54:22.481439 | controller | { 2025-10-02 20:54:22.481531 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9" 2025-10-02 20:54:22.481573 | controller | } 2025-10-02 20:54:22.931989 | controller | changed: 2025-10-02 20:54:22.932280 | controller | { 2025-10-02 20:54:22.932339 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora" 2025-10-02 20:54:22.932382 | controller | } 2025-10-02 20:54:23.338751 | controller | changed: 2025-10-02 20:54:23.338857 | controller | { 2025-10-02 20:54:23.338880 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac" 2025-10-02 20:54:23.338899 | controller | } 2025-10-02 20:54:23.752994 | controller | changed: 2025-10-02 20:54:23.753194 | controller | { 2025-10-02 20:54:23.753244 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop" 2025-10-02 20:54:23.753283 | controller | } 2025-10-02 20:54:24.188944 | controller | changed: 2025-10-02 20:54:24.189088 | controller | { 2025-10-02 20:54:24.189125 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQDZdI7t1cxYx65heVI24HTV4F7oQLW1zyfxHreL2TIJKxjyrUUKIFEUmTutcBlJRLNT2Eoix6x1sOw9YrchloCLcn//SGfTElr9mSc5jbjb7QXEU+zJMhtxyEJ1Po3CUGnj7ckiIXw7wcawZtrEOAQ9pH3ExYCJcEMiyNjRQZCxT3tPK+S4B95EWh5Fsrz9CkwpjNRPPH7LigCeQTM3Wc7r97utAslBUUvYceDSLA7rMgkitJE38b7rZBeYzsGQ8YYUBjTCtehqQXxCRjizbHWaaZkBU+N3zkKB6n/iCNGIO690NK7A/qb6msTijiz1PeuM8ThOsi9qXnbX5v0PoTpcFSojV7NHAQ71f0XXuS43FhZctT+Dcx44dT8Fb5vJu2cJGrk+qF8ZgJYNpRS7gPg0EG2EqjK7JMf9ULdjSu0r+KlqIAyLvtzT4eOnQipoKlb/WG5D/0ohKv7OMQ352ggfkBFIQsRXyyTCT98Ft9juqPuahi3CAQmP4H9dyE+7+Kz437PEtsxLmfm6naNmWi7Ee1DqWPwS8rEajsm4sNM4wW9gdBboJQtc0uZw0DfLj1I9r3Mc8Ol0jYtz0yNQDSzVLrGCaJlC311trU70tZ+ZkAVV6Mn8lOhSbj1cK0lvSr6ZK4dgqGl3I1eTZJJhbLNdg7UOVaiRx9543+C/p/As7w== brjackma@redhat.com" 2025-10-02 20:54:24.189154 | controller | } 2025-10-02 20:54:24.671085 | controller | changed: 2025-10-02 20:54:24.671526 | controller | { 2025-10-02 20:54:24.671606 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com" 2025-10-02 20:54:24.671667 | controller | } 2025-10-02 20:54:25.104856 | controller | changed: 2025-10-02 20:54:25.105052 | controller | { 2025-10-02 20:54:25.105111 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com" 2025-10-02 20:54:25.105152 | controller | } 2025-10-02 20:54:25.520566 | controller | changed: 2025-10-02 20:54:25.520709 | controller | { 2025-10-02 20:54:25.520758 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono" 2025-10-02 20:54:25.520798 | controller | } 2025-10-02 20:54:25.550907 | 2025-10-02 20:54:25.551085 | TASK [Set timezone to UTC] 2025-10-02 20:54:26.392233 | controller | changed: executed `/bin/timedatectl set-timezone UTC` 2025-10-02 20:54:26.400862 | 2025-10-02 20:54:26.400981 | TASK [Create nodepool directory] 2025-10-02 20:54:26.868310 | controller | changed 2025-10-02 20:54:26.882466 | 2025-10-02 20:54:26.882633 | TASK [Create nodepool sub_nodes file] 2025-10-02 20:54:28.609307 | controller | changed 2025-10-02 20:54:28.614278 | 2025-10-02 20:54:28.614343 | TASK [Create nodepool sub_nodes_private file] 2025-10-02 20:54:30.413128 | controller | changed 2025-10-02 20:54:30.427413 | 2025-10-02 20:54:30.427598 | LOOP [Populate nodepool sub_nodes file] 2025-10-02 20:54:30.468867 | 2025-10-02 20:54:30.469276 | LOOP [Populate nodepool sub_nodes_private file] 2025-10-02 20:54:30.511654 | 2025-10-02 20:54:30.511946 | TASK [Create nodepool primary file] 2025-10-02 20:54:30.539290 | controller | skipping: Conditional result was False 2025-10-02 20:54:30.551904 | 2025-10-02 20:54:30.552170 | TASK [Create nodepool node_private for this node] 2025-10-02 20:54:32.339531 | controller | changed 2025-10-02 20:54:32.345243 | 2025-10-02 20:54:32.345309 | LOOP [Copy ssh keys to nodepool directory] 2025-10-02 20:54:32.923725 | controller | ok: Item: id_rsa Runtime: 0:00:00.012352 2025-10-02 20:54:32.923929 | 2025-10-02 20:54:33.290331 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.009129 2025-10-02 20:54:33.312883 | 2025-10-02 20:54:33.313133 | TASK [Add sudoers role for zuul-sudo-grep.sh] 2025-10-02 20:54:35.104424 | controller | changed 2025-10-02 20:54:35.109831 | 2025-10-02 20:54:35.109892 | TASK [Validate sudoers config after edits] 2025-10-02 20:54:35.591859 | controller | /etc/sudoers: parsed OK 2025-10-02 20:54:35.591965 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK 2025-10-02 20:54:35.591983 | controller | /etc/sudoers.d/zuul: parsed OK 2025-10-02 20:54:35.591997 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK 2025-10-02 20:54:35.670963 | controller | ok: Runtime: 0:00:00.009153 2025-10-02 20:54:35.677180 | 2025-10-02 20:54:35.677310 | TASK [Show the environment passed in to job shell scripts] 2025-10-02 20:54:36.135180 | controller | SHELL=/bin/bash 2025-10-02 20:54:36.135289 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework 2025-10-02 20:54:36.135302 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework 2025-10-02 20:54:36.135313 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/62/3362/41f2edaa0ac45cd85919f70775e84cf472326a6e 2025-10-02 20:54:36.135326 | controller | PWD=/home/zuul 2025-10-02 20:54:36.135352 | controller | ZUUL_PIPELINE=github-check 2025-10-02 20:54:36.135360 | controller | LOGNAME=zuul 2025-10-02 20:54:36.135368 | controller | XDG_SESSION_TYPE=tty 2025-10-02 20:54:36.135375 | controller | _=/usr/bin/env 2025-10-02 20:54:36.135382 | controller | MOTD_SHOWN=pam 2025-10-02 20:54:36.135389 | controller | HOME=/home/zuul 2025-10-02 20:54:36.135396 | controller | LANG=en_US.UTF-8 2025-10-02 20:54:36.135403 | controller | SSH_CONNECTION=38.102.83.114 50306 38.102.83.115 22 2025-10-02 20:54:36.135411 | controller | TOX_TESTENV_PASSENV=ZUUL_UUID ZUUL_PROJECT ZUUL_SHORT_PROJECT_NAME ZUUL_PIPELINE ZUUL_VOTING WORKSPACE BUILD_TIMEOUT ZUUL_BRANCH ZUUL_CHANGES ZUUL_CHANGE_IDS ZUUL_CHANGE ZUUL_PATCHSET 2025-10-02 20:54:36.135423 | controller | ZUUL_CHANGE_IDS=3362,41f2edaa0ac45cd85919f70775e84cf472326a6e 2025-10-02 20:54:36.135496 | controller | WORKSPACE=/home/zuul/workspace 2025-10-02 20:54:36.135508 | controller | XDG_SESSION_CLASS=user 2025-10-02 20:54:36.135516 | controller | SELINUX_ROLE_REQUESTED= 2025-10-02 20:54:36.135524 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s 2025-10-02 20:54:36.135531 | controller | USER=zuul 2025-10-02 20:54:36.135539 | controller | ZUUL_VOTING=True 2025-10-02 20:54:36.135546 | controller | BUILD_TIMEOUT=1800000 2025-10-02 20:54:36.135553 | controller | SELINUX_USE_CURRENT_RANGE= 2025-10-02 20:54:36.135561 | controller | SHLVL=1 2025-10-02 20:54:36.135568 | controller | ZUUL_PATCHSET=41f2edaa0ac45cd85919f70775e84cf472326a6e 2025-10-02 20:54:36.135576 | controller | XDG_SESSION_ID=1 2025-10-02 20:54:36.135583 | controller | ZUUL_BRANCH=main 2025-10-02 20:54:36.135590 | controller | XDG_RUNTIME_DIR=/run/user/1000 2025-10-02 20:54:36.135598 | controller | SSH_CLIENT=38.102.83.114 50306 22 2025-10-02 20:54:36.135605 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/ 2025-10-02 20:54:36.135613 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima: 2025-10-02 20:54:36.135621 | controller | which_declare=declare -f 2025-10-02 20:54:36.135629 | 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-10-02 20:54:36.135637 | controller | SELINUX_LEVEL_REQUESTED= 2025-10-02 20:54:36.135645 | controller | ZUUL_CHANGE=3362 2025-10-02 20:54:36.135652 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus 2025-10-02 20:54:36.135660 | controller | ZUUL_UUID=8fb77a034eea47af87900f7b49e3027f 2025-10-02 20:54:36.135668 | controller | BASH_FUNC_which%%=() { ( alias; 2025-10-02 20:54:36.135676 | controller | eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@ 2025-10-02 20:54:36.135684 | controller | } 2025-10-02 20:54:36.254495 | controller | ok: Runtime: 0:00:00.012477 2025-10-02 20:54:36.266968 | 2025-10-02 20:54:36.267208 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars] 2025-10-02 20:54:36.294198 | controller | skipping: Conditional result was False 2025-10-02 20:54:36.306988 | 2025-10-02 20:54:36.307218 | TASK [Symlink /home/zuul-worker/workspace] 2025-10-02 20:54:36.856627 | controller | skipping: Conditional result was False 2025-10-02 20:54:36.862698 | 2025-10-02 20:54:36.862762 | TASK [Ensure legacy workspace directory] 2025-10-02 20:54:37.265100 | controller | changed 2025-10-02 20:54:37.305600 | 2025-10-02 20:54:37.305691 | PLAY RECAP 2025-10-02 20:54:37.305749 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-10-02 20:54:37.305780 | 2025-10-02 20:54:37.414916 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master] 2025-10-02 20:54:37.415714 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/crc/podman.yaml@master] 2025-10-02 20:54:38.061583 | 2025-10-02 20:54:38.061690 | PLAY [all,!compute] 2025-10-02 20:54:38.084239 | 2025-10-02 20:54:38.084349 | TASK [Enable container-tools rhel-modules for c8/crc node] 2025-10-02 20:54:38.620456 | controller | skipping: Conditional result was False 2025-10-02 20:54:38.635645 | 2025-10-02 20:54:38.635850 | TASK [Install podman] 2025-10-02 20:54:38.694120 | controller | skipping: Conditional result was False 2025-10-02 20:54:38.702461 | 2025-10-02 20:54:38.702572 | TASK [Set var name for quay login zuul secret] 2025-10-02 20:54:38.748113 | controller | skipping: Conditional result was False 2025-10-02 20:54:38.756037 | 2025-10-02 20:54:38.756133 | TASK [Print the username] 2025-10-02 20:54:39.296182 | controller | skipping: Conditional result was False 2025-10-02 20:54:39.314297 | 2025-10-02 20:54:39.314522 | TASK [Fail when user or password is not set] 2025-10-02 20:54:39.366921 | controller | skipping: Conditional result was False 2025-10-02 20:54:39.392152 | 2025-10-02 20:54:39.392328 | TASK [Set vars for quay login] 2025-10-02 20:54:39.458044 | 2025-10-02 20:54:39.458208 | LOOP [Perform container registry login(s) with podman] 2025-10-02 20:54:39.519780 | 2025-10-02 20:54:39.519930 | LOOP [Perform container registry login(s) with buildah] 2025-10-02 20:54:39.610355 | 2025-10-02 20:54:39.610508 | TASK [Set Insecure registry for content provider] 2025-10-02 20:54:39.659118 | controller | skipping: Conditional result was False 2025-10-02 20:54:39.680141 | 2025-10-02 20:54:39.680255 | PLAY RECAP 2025-10-02 20:54:39.680295 | controller | ok: 0 changed: 0 unreachable: 0 failed: 0 skipped: 9 rescued: 0 ignored: 0 2025-10-02 20:54:39.680315 | 2025-10-02 20:54:39.783816 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/crc/podman.yaml@master] 2025-10-02 20:54:39.784638 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/crc/simple-start.yaml@master] 2025-10-02 20:54:40.354003 | 2025-10-02 20:54:40.354127 | PLAY [Prefer ipv4 over ipv6] 2025-10-02 20:54:40.373425 | 2025-10-02 20:54:40.373538 | TASK [Configure /etc/gai.conf to prever ipv4 over ipv6] 2025-10-02 20:54:40.418135 | controller | skipping: Conditional result was False 2025-10-02 20:54:40.438348 | 2025-10-02 20:54:40.438425 | PLAY [controller] 2025-10-02 20:54:40.452605 | 2025-10-02 20:54:40.452690 | TASK [Fail when openshift_pull_sec not provided] 2025-10-02 20:54:40.466257 | controller | skipping: Conditional result was False 2025-10-02 20:54:40.472552 | 2025-10-02 20:54:40.472620 | TASK [Clone repos in the job workspace] 2025-10-02 20:54:40.490419 | controller | ok 2025-10-02 20:54:40.506364 | 2025-10-02 20:54:40.506439 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-02 20:54:40.944412 | controller | ok 2025-10-02 20:54:40.957697 | 2025-10-02 20:54:40.957880 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-02 20:54:44.425174 | controller | Output suppressed because no_log was given 2025-10-02 20:54:44.447987 | 2025-10-02 20:54:44.448168 | TASK [Create pull-secret.txt file] 2025-10-02 20:54:46.220658 | controller | Output suppressed because no_log was given 2025-10-02 20:54:46.228097 | 2025-10-02 20:54:46.228228 | TASK [Apply CRC features and print image build date] 2025-10-02 20:54:46.253924 | controller | ok 2025-10-02 20:54:46.261461 | controller | included: /var/lib/zuul/builds/8fb77a034eea47af87900f7b49e3027f/trusted/project_0/review.rdoproject.org/config/playbooks/crc/features.yaml 2025-10-02 20:54:46.268319 | 2025-10-02 20:54:46.268401 | TASK [Set additional parameters for crc - telemetry] 2025-10-02 20:54:46.802082 | controller | skipping: Conditional result was False 2025-10-02 20:54:46.866398 | 2025-10-02 20:54:46.866514 | TASK [Set additional parameters for crc - monitoring] 2025-10-02 20:54:47.396552 | controller | skipping: Conditional result was False 2025-10-02 20:54:47.409436 | 2025-10-02 20:54:47.409617 | TASK [Set minimum required memory to run the CRC when monitoring enabled] 2025-10-02 20:54:47.967515 | controller | skipping: Conditional result was False 2025-10-02 20:54:47.983283 | 2025-10-02 20:54:47.983465 | TASK [Set additional parameters for crc - enable microshift preset] 2025-10-02 20:54:48.543972 | controller | skipping: Conditional result was False 2025-10-02 20:54:48.556999 | 2025-10-02 20:54:48.557232 | TASK [Set additional parameters for crc - enable okd preset] 2025-10-02 20:54:49.111150 | controller | skipping: Conditional result was False 2025-10-02 20:54:49.117140 | 2025-10-02 20:54:49.117213 | TASK [Delete the cluster if there's a non-default bundle URL] 2025-10-02 20:54:49.646962 | controller | skipping: Conditional result was False 2025-10-02 20:54:49.652812 | 2025-10-02 20:54:49.652879 | TASK [Execute crc start command] 2025-10-02 20:57:48.417615 | controller | ok: Runtime: 0:02:58.111403 2025-10-02 20:57:48.423188 | 2025-10-02 20:57:48.423253 | TASK [Verify that OpenShift is up and running] 2025-10-02 20:57:48.442167 | controller | ok 2025-10-02 20:57:48.452675 | controller | included: /var/lib/zuul/builds/8fb77a034eea47af87900f7b49e3027f/trusted/project_0/review.rdoproject.org/config/playbooks/crc/verify_openshift_start.yaml 2025-10-02 20:57:48.459426 | 2025-10-02 20:57:48.459487 | TASK [Create script to login and verify services] 2025-10-02 20:57:50.121799 | controller | changed 2025-10-02 20:57:50.134231 | 2025-10-02 20:57:50.134375 | TASK [Ensure that user is logged] 2025-10-02 20:57:50.578042 | controller | Checking login to the cluster 1... 2025-10-02 20:57:51.680944 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:57:51.755289 | controller | 2025-10-02 20:57:51.755389 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:57:51.760942 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:57:56.764138 | controller | Checking login to the cluster 2... 2025-10-02 20:57:56.899412 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:57:56.919679 | controller | 2025-10-02 20:57:56.919735 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:57:56.925540 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:58:01.928132 | controller | Checking login to the cluster 3... 2025-10-02 20:58:02.090773 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:58:02.117047 | controller | 2025-10-02 20:58:02.117151 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:58:02.125853 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:58:07.128409 | controller | Checking login to the cluster 4... 2025-10-02 20:58:07.290058 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:58:07.318918 | controller | 2025-10-02 20:58:07.318988 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:58:07.328423 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:58:12.331873 | controller | Checking login to the cluster 5... 2025-10-02 20:58:12.476229 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:58:12.507310 | controller | 2025-10-02 20:58:12.507412 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:58:12.511935 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:58:17.516082 | controller | Checking login to the cluster 6... 2025-10-02 20:58:17.691750 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:58:17.718601 | controller | 2025-10-02 20:58:17.718703 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:58:17.725789 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:58:22.729033 | controller | Checking login to the cluster 7... 2025-10-02 20:58:22.905454 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:58:22.946129 | controller | 2025-10-02 20:58:22.946162 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:58:22.957160 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:58:27.965879 | controller | Checking login to the cluster 8... 2025-10-02 20:58:28.187701 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:58:28.237253 | controller | 2025-10-02 20:58:28.237416 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:58:28.248682 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:58:33.252916 | controller | Checking login to the cluster 9... 2025-10-02 20:58:33.394294 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:58:33.411934 | controller | 2025-10-02 20:58:33.411995 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:58:33.417676 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:58:38.420734 | controller | Checking login to the cluster 10... 2025-10-02 20:58:38.613047 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:58:38.676498 | controller | 2025-10-02 20:58:38.676574 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:58:38.687055 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:58:43.692062 | controller | Checking login to the cluster 11... 2025-10-02 20:58:43.902274 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:58:44.037665 | controller | 2025-10-02 20:58:44.037977 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:58:44.051440 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:58:49.055543 | controller | Checking login to the cluster 12... 2025-10-02 20:58:49.253818 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:58:49.467784 | controller | 2025-10-02 20:58:49.467890 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:58:49.475810 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:58:54.480879 | controller | Checking login to the cluster 13... 2025-10-02 20:58:54.739924 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:58:55.853710 | controller | 2025-10-02 20:58:55.853862 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:58:55.867947 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:59:00.873020 | controller | Checking login to the cluster 14... 2025-10-02 20:59:01.125184 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:59:01.402694 | controller | 2025-10-02 20:59:01.402791 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:59:01.415011 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:59:06.418118 | controller | Checking login to the cluster 15... 2025-10-02 20:59:08.043790 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:59:10.168292 | controller | 2025-10-02 20:59:10.168442 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-10-02 20:59:10.178469 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:59:15.182728 | controller | Checking login to the cluster 16... 2025-10-02 20:59:15.498259 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:59:15.760434 | controller | 2025-10-02 20:59:15.760530 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-10-02 20:59:15.767888 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:59:20.772554 | controller | Checking login to the cluster 17... 2025-10-02 20:59:22.072832 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:59:22.533040 | controller | 2025-10-02 20:59:22.533127 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-10-02 20:59:22.544760 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:59:27.551199 | controller | Checking login to the cluster 18... 2025-10-02 20:59:27.783895 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:59:28.339236 | controller | 2025-10-02 20:59:28.339356 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-10-02 20:59:28.349953 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:59:33.353852 | controller | Checking login to the cluster 19... 2025-10-02 20:59:33.518928 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:59:33.603377 | controller | 2025-10-02 20:59:33.603441 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-10-02 20:59:33.609427 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:59:38.613561 | controller | Checking login to the cluster 20... 2025-10-02 20:59:38.800624 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:59:38.921372 | controller | 2025-10-02 20:59:38.921483 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-10-02 20:59:38.934218 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:59:43.937247 | controller | Checking login to the cluster 21... 2025-10-02 20:59:44.109594 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:59:44.149931 | controller | 2025-10-02 20:59:44.149979 | controller | Error from server (InternalError): Internal error occurred: unexpected response: 503 2025-10-02 20:59:44.159453 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:59:49.161625 | controller | Checking login to the cluster 22... 2025-10-02 20:59:49.371483 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:59:49.399988 | controller | 2025-10-02 20:59:49.400117 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:59:49.410448 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:59:54.413437 | controller | Checking login to the cluster 23... 2025-10-02 20:59:54.608210 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:59:54.628189 | controller | 2025-10-02 20:59:54.628280 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:59:54.634630 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 20:59:59.637393 | controller | Checking login to the cluster 24... 2025-10-02 20:59:59.757038 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 20:59:59.775545 | controller | 2025-10-02 20:59:59.775575 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 20:59:59.785022 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 21:00:04.787969 | controller | Checking login to the cluster 25... 2025-10-02 21:00:04.977734 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 21:00:05.018095 | controller | 2025-10-02 21:00:05.018193 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 21:00:05.024694 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 21:00:10.028408 | controller | Checking login to the cluster 26... 2025-10-02 21:00:10.151540 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 21:00:10.178473 | controller | 2025-10-02 21:00:10.178554 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 21:00:10.187787 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 21:00:15.191978 | controller | Checking login to the cluster 27... 2025-10-02 21:00:15.379714 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 21:00:15.398635 | controller | 2025-10-02 21:00:15.398700 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 21:00:15.404035 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 21:00:20.407817 | controller | Checking login to the cluster 28... 2025-10-02 21:00:20.552402 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 21:00:20.572337 | controller | 2025-10-02 21:00:20.572417 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 21:00:20.581958 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 21:00:25.586458 | controller | Checking login to the cluster 29... 2025-10-02 21:00:25.769579 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 21:00:25.788559 | controller | 2025-10-02 21:00:25.788627 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 21:00:25.798276 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 21:00:30.801865 | controller | Checking login to the cluster 30... 2025-10-02 21:00:30.951622 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 21:00:30.985796 | controller | 2025-10-02 21:00:30.985953 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 21:00:30.993238 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 21:00:35.996074 | controller | Checking login to the cluster 31... 2025-10-02 21:00:36.148999 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 21:00:36.167560 | controller | 2025-10-02 21:00:36.167596 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 21:00:36.175749 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 21:00:41.177926 | controller | Checking login to the cluster 32... 2025-10-02 21:00:41.355616 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 21:00:41.377255 | controller | 2025-10-02 21:00:41.377300 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 21:00:41.390143 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 21:00:46.392879 | controller | Checking login to the cluster 33... 2025-10-02 21:00:46.585709 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 21:00:46.618131 | controller | 2025-10-02 21:00:46.618221 | controller | The connection to the server oauth-openshift.apps-crc.testing was refused - did you specify the right host or port? 2025-10-02 21:00:46.632068 | controller | Can not login to the CRC cluster. Sleeping... 2025-10-02 21:00:51.635387 | controller | Checking login to the cluster 34... 2025-10-02 21:00:51.783885 | controller | WARNING: Using insecure TLS client config. Setting this option is not supported! 2025-10-02 21:00:57.462260 | controller | 2025-10-02 21:00:57.462410 | controller | Login successful. 2025-10-02 21:00:57.530703 | controller | 2025-10-02 21:00:57.530778 | controller | You have access to 65 projects, the list has been suppressed. You can list all projects with 'oc projects' 2025-10-02 21:00:57.568108 | controller | 2025-10-02 21:00:57.568304 | controller | Using project "default". 2025-10-02 21:00:57.907533 | controller | changed 2025-10-02 21:00:57.921568 | 2025-10-02 21:00:57.921703 | TASK [Delete all openshift-marketplace pods] 2025-10-02 21:01:01.929477 | controller | pod "certified-operators-dqgkd" deleted 2025-10-02 21:01:03.507111 | controller | pod "certified-operators-f8szs" deleted 2025-10-02 21:01:05.245126 | controller | pod "community-operators-5zsqg" deleted 2025-10-02 21:01:08.276565 | controller | pod "community-operators-q6pmb" deleted 2025-10-02 21:01:08.812158 | controller | pod "marketplace-operator-79b997595-d2lpl" deleted 2025-10-02 21:01:11.924930 | controller | pod "redhat-marketplace-ps6xk" deleted 2025-10-02 21:01:11.967877 | controller | pod "redhat-marketplace-q7xtx" deleted 2025-10-02 21:01:12.043613 | controller | pod "redhat-operators-jsqwb" deleted 2025-10-02 21:01:12.122373 | controller | pod "redhat-operators-tqxl9" deleted 2025-10-02 21:01:23.506515 | controller | ok 2025-10-02 21:01:23.519338 | 2025-10-02 21:01:23.519536 | TASK [Copy script ensure_services_up.sh] 2025-10-02 21:01:23.576939 | controller | skipping: Conditional result was False 2025-10-02 21:01:23.589416 | 2025-10-02 21:01:23.589594 | TASK [Ensure all pods are up and running] 2025-10-02 21:01:24.141108 | controller | skipping: Conditional result was False 2025-10-02 21:01:24.149412 | 2025-10-02 21:01:24.149518 | TASK [Check if there is a image build date file] 2025-10-02 21:01:24.660822 | controller | ok 2025-10-02 21:01:24.668417 | 2025-10-02 21:01:24.668543 | TASK [Print image date if available] 2025-10-02 21:01:25.036660 | controller | Tue Apr 1 06:17:46 PM EDT 2025 2025-10-02 21:01:25.208654 | controller | changed 2025-10-02 21:01:25.220649 | 2025-10-02 21:01:25.220812 | TASK [Fix machineconfigpool] 2025-10-02 21:01:25.288865 | controller | skipping: Conditional result was False 2025-10-02 21:01:25.297429 | 2025-10-02 21:01:25.297549 | TASK [Show available nodes] 2025-10-02 21:01:26.925671 | controller | NAME STATUS ROLES AGE VERSION 2025-10-02 21:01:26.928049 | controller | crc Ready control-plane,master,worker 221d v1.31.5 2025-10-02 21:01:27.383905 | controller | ok: Runtime: 0:00:01.129680 2025-10-02 21:01:27.391658 | 2025-10-02 21:01:27.391777 | TASK [Configure insecure registry inside crc vm] 2025-10-02 21:01:27.417329 | controller | skipping: Conditional result was False 2025-10-02 21:01:27.426057 | 2025-10-02 21:01:27.426180 | TASK [Catch CRC IP] 2025-10-02 21:01:27.973114 | controller | 192.168.130.11 2025-10-02 21:01:28.468148 | controller | changed 2025-10-02 21:01:28.483718 | 2025-10-02 21:01:28.483879 | TASK [Check if id_ed25519 key exists] 2025-10-02 21:01:28.867802 | controller | ok 2025-10-02 21:01:28.879588 | 2025-10-02 21:01:28.879725 | TASK [Set fact if new keypair exists] 2025-10-02 21:01:28.917057 | controller | ok 2025-10-02 21:01:28.927724 | 2025-10-02 21:01:28.928090 | TASK [Run crc] 2025-10-02 21:01:30.843550 | controller | 2025-10-02 21:01:40.741966 | controller | PLAY [OpenShift secret copy and CRC securitization] **************************** 2025-10-02 21:01:40.742028 | controller | 2025-10-02 21:01:40.742036 | controller | TASK [Gathering Facts] ********************************************************* 2025-10-02 21:01:40.742049 | controller | [WARNING]: Platform linux on host 192.168.130.11 is using the discovered Python 2025-10-02 21:01:40.782217 | controller | interpreter at /usr/bin/python3.9, but future installation of another Python 2025-10-02 21:01:40.782262 | controller | interpreter could change the meaning of that path. See 2025-10-02 21:01:40.782269 | controller | https://docs.ansible.com/ansible- 2025-10-02 21:01:40.782276 | controller | core/2.14/reference_appendices/interpreter_discovery.html for more information. 2025-10-02 21:01:40.782289 | controller | ok: [192.168.130.11] 2025-10-02 21:01:42.417371 | controller | 2025-10-02 21:01:42.417427 | controller | TASK [Copy pull-secret] ******************************************************** 2025-10-02 21:01:42.417441 | controller | changed: [192.168.130.11] 2025-10-02 21:01:43.789235 | controller | 2025-10-02 21:01:43.789307 | controller | TASK [Add crio config] ********************************************************* 2025-10-02 21:01:43.789340 | controller | changed: [192.168.130.11] 2025-10-02 21:01:47.007712 | controller | 2025-10-02 21:01:47.007797 | controller | TASK [Restart crio to pickup new configuration] ******************************** 2025-10-02 21:01:47.007817 | controller | changed: [192.168.130.11] 2025-10-02 21:01:47.061658 | controller | 2025-10-02 21:01:47.061729 | controller | PLAY RECAP ********************************************************************* 2025-10-02 21:01:47.061737 | controller | 192.168.130.11 : ok=4 changed=3 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 2025-10-02 21:01:47.061753 | controller | 2025-10-02 21:01:47.554492 | controller | changed 2025-10-02 21:01:47.566572 | 2025-10-02 21:01:47.566751 | TASK [Set slower etcd profile] 2025-10-02 21:01:47.616181 | controller | ok 2025-10-02 21:01:47.656674 | 2025-10-02 21:01:47.656836 | TASK [prepare-crc-cloud : Set slower profile] 2025-10-02 21:01:48.238661 | controller | etcd.operator.openshift.io/cluster patched 2025-10-02 21:01:48.695843 | controller | ok 2025-10-02 21:01:48.709733 | 2025-10-02 21:01:48.709913 | TASK [prepare-crc-cloud : Wait 30 seconds to apply] 2025-10-02 21:02:18.762067 | controller | ok 2025-10-02 21:02:18.773381 | 2025-10-02 21:02:18.773515 | TASK [prepare-crc-cloud : Get pod phase status] 2025-10-02 21:07:32.655848 | controller | ok 2025-10-02 21:07:32.678153 | 2025-10-02 21:07:32.678300 | TASK [Set limit for disk usage - IOPS and Read/Write] 2025-10-02 21:07:32.759142 | controller | ok 2025-10-02 21:07:32.774203 | controller | included: /var/lib/zuul/builds/8fb77a034eea47af87900f7b49e3027f/trusted/project_0/review.rdoproject.org/config/playbooks/crc/limit-disk-usage.yaml 2025-10-02 21:07:32.795553 | 2025-10-02 21:07:32.795722 | TASK [Set facts for disk limitation] 2025-10-02 21:07:32.835154 | controller | ok 2025-10-02 21:07:32.846532 | 2025-10-02 21:07:32.846675 | TASK [Print limits for the disk] 2025-10-02 21:07:32.897536 | controller | ok: Set limit to crc VM to the vda disk: iops 18000 read/write 262144000 2025-10-02 21:07:32.947922 | 2025-10-02 21:07:32.948084 | TASK [Set limit to crc VM to the vda disk] 2025-10-02 21:07:33.496370 | controller | 2025-10-02 21:07:33.981485 | controller | changed 2025-10-02 21:07:33.992835 | 2025-10-02 21:07:33.992966 | TASK [Pause machineconfigpool] 2025-10-02 21:07:34.071758 | controller | ok 2025-10-02 21:07:34.119876 | 2025-10-02 21:07:34.119983 | LOOP [prepare-crc-cloud : Pause the machineconfig configuration if mcp is not needed] 2025-10-02 21:07:34.796290 | controller | ok 2025-10-02 21:07:35.351517 | controller | ok 2025-10-02 21:07:35.371275 | 2025-10-02 21:07:35.371445 | TASK [prepare-crc-cloud : Print current machineconfigpool] 2025-10-02 21:07:36.102331 | controller | NAME CONFIG UPDATED UPDATING DEGRADED MACHINECOUNT READYMACHINECOUNT UPDATEDMACHINECOUNT DEGRADEDMACHINECOUNT AGE 2025-10-02 21:07:36.102440 | controller | master rendered-master-95020e6e79c40b4dd095817bccfc5060 True False False 1 1 1 0 221d 2025-10-02 21:07:36.116092 | controller | worker rendered-worker-594cc07c9feefb5e37f2530ac457d36c True False False 0 0 0 0 221d 2025-10-02 21:07:36.428262 | controller | ok 2025-10-02 21:07:36.480587 | 2025-10-02 21:07:36.480709 | PLAY [Set IOPS and Read/Write disk limitation excluding controller] 2025-10-02 21:07:36.480842 | 2025-10-02 21:07:36.480884 | PLAY RECAP 2025-10-02 21:07:36.480937 | controller | ok: 25 changed: 10 unreachable: 0 failed: 0 skipped: 12 rescued: 0 ignored: 0 2025-10-02 21:07:36.480968 | 2025-10-02 21:07:36.589408 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/crc/simple-start.yaml@master] 2025-10-02 21:07:36.591806 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main] 2025-10-02 21:07:37.160320 | 2025-10-02 21:07:37.160422 | PLAY [Run ci/playbooks/dump_zuul_data.yml] 2025-10-02 21:07:37.180637 | 2025-10-02 21:07:37.180715 | TASK [Create zuul-output directory] 2025-10-02 21:07:37.671679 | controller | changed 2025-10-02 21:07:37.683708 | 2025-10-02 21:07:37.683867 | TASK [Slurp Zuul inventory test] 2025-10-02 21:07:38.071622 | controller -> localhost | ok 2025-10-02 21:07:38.082161 | 2025-10-02 21:07:38.082284 | TASK [Save zuul inventory] 2025-10-02 21:07:39.793484 | controller | changed 2025-10-02 21:07:39.804836 | 2025-10-02 21:07:39.805004 | TASK [Save zuul vars without the change_message] 2025-10-02 21:07:41.117581 | controller | changed 2025-10-02 21:07:41.159543 | 2025-10-02 21:07:41.159674 | PLAY RECAP 2025-10-02 21:07:41.159742 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-10-02 21:07:41.159778 | 2025-10-02 21:07:41.257671 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main] 2025-10-02 21:07:41.259372 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main] 2025-10-02 21:07:41.891539 | 2025-10-02 21:07:41.891645 | PLAY [Run ci/playbooks/molecule-prepare.yml] 2025-10-02 21:07:41.913358 | 2025-10-02 21:07:41.913456 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh] 2025-10-02 21:07:41.936038 | controller | ok 2025-10-02 21:07:41.953930 | 2025-10-02 21:07:41.954053 | TASK [mirror-info-fork : Set mirror_fqdn if not defined] 2025-10-02 21:07:41.998803 | controller | skipping: Conditional result was False 2025-10-02 21:07:42.006722 | 2025-10-02 21:07:42.006811 | TASK [mirror-info-fork : Create /etc/ci] 2025-10-02 21:07:42.520745 | controller | ok 2025-10-02 21:07:42.533109 | 2025-10-02 21:07:42.533280 | TASK [mirror-info-fork : Install ci_mirror script] 2025-10-02 21:07:43.813263 | controller | ok 2025-10-02 21:07:43.828704 | 2025-10-02 21:07:43.828821 | TASK [Prepare workspace] 2025-10-02 21:07:43.851126 | controller | ok 2025-10-02 21:07:43.877191 | 2025-10-02 21:07:43.877325 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-10-02 21:07:44.374133 | controller | ok 2025-10-02 21:07:44.386703 | 2025-10-02 21:07:44.386832 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-10-02 21:07:45.543831 | controller | Output suppressed because no_log was given 2025-10-02 21:07:45.565059 | 2025-10-02 21:07:45.565199 | LOOP [Create zuul-output directory] 2025-10-02 21:07:45.979994 | controller | changed: "/home/zuul/ci-framework-data/logs" 2025-10-02 21:07:46.324739 | controller | ok: "/home/zuul/zuul-output/logs" 2025-10-02 21:07:46.340649 | 2025-10-02 21:07:46.340769 | TASK [Install required packages] 2025-10-02 21:08:02.242395 | controller | ok: Nothing to do 2025-10-02 21:08:02.254509 | 2025-10-02 21:08:02.254705 | TASK [Install venv] 2025-10-02 21:09:09.300926 | controller | changed 2025-10-02 21:09:09.350675 | 2025-10-02 21:09:09.350779 | PLAY RECAP 2025-10-02 21:09:09.350835 | controller | ok: 7 changed: 2 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-10-02 21:09:09.350865 | 2025-10-02 21:09:09.449181 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main] 2025-10-02 21:09:09.450063 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main] 2025-10-02 21:09:09.980616 | 2025-10-02 21:09:09.980716 | PLAY [Run ci/playbooks/molecule-test.yml] 2025-10-02 21:09:10.001162 | 2025-10-02 21:09:10.001239 | TASK [Gather required facts] 2025-10-02 21:09:10.718392 | controller | ok 2025-10-02 21:09:10.731855 | 2025-10-02 21:09:10.732060 | TASK [Load environment var if instructed to] 2025-10-02 21:09:10.770035 | controller | skipping: Conditional result was False 2025-10-02 21:09:10.782869 | 2025-10-02 21:09:10.783087 | TASK [Run molecule] 2025-10-02 21:09:12.163397 | controller | INFO Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml 2025-10-02 21:09:12.243575 | controller | INFO Performing prerun with role_name_check=0... 2025-10-02 21:09:29.889599 | controller | WARNING Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-02 21:09:29.890246 | controller | WARNING Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-02 21:09:29.891269 | controller | WARNING Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-02 21:09:29.892275 | controller | WARNING Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-02 21:09:29.893419 | controller | WARNING Another version of 'cifmw.general' 1.0.0+41f2edaa was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 1.0.0+41f2edaa (/home/zuul/.ansible/collections/ansible_collections). 2025-10-02 21:09:29.894434 | controller | WARNING Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-02 21:09:29.895411 | controller | WARNING Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-02 21:09:29.896451 | controller | WARNING Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-02 21:09:29.897469 | controller | WARNING Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-02 21:09:29.898448 | controller | WARNING Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-02 21:09:29.899428 | controller | WARNING Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-02 21:09:29.900407 | controller | WARNING Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-02 21:09:29.901412 | controller | WARNING Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-02 21:09:29.902471 | controller | WARNING Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-02 21:09:29.903467 | controller | WARNING Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/2ef247/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections). 2025-10-02 21:09:29.924913 | controller | INFO Running default > prepare 2025-10-02 21:09:30.752931 | controller | 2025-10-02 21:09:30.753034 | controller | PLAY [Prepare] ***************************************************************** 2025-10-02 21:09:30.753103 | controller | 2025-10-02 21:09:30.753299 | controller | TASK [Gathering Facts] ********************************************************* 2025-10-02 21:09:30.753406 | controller | Thursday 02 October 2025 21:09:30 +0000 (0:00:00.013) 0:00:00.013 ****** 2025-10-02 21:09:31.953250 | controller | ok: [instance] 2025-10-02 21:09:31.953390 | controller | 2025-10-02 21:09:31.953695 | controller | TASK [test_deps : Gather facts if they don't exist] **************************** 2025-10-02 21:09:31.953902 | controller | Thursday 02 October 2025 21:09:31 +0000 (0:00:01.200) 0:00:01.214 ****** 2025-10-02 21:09:31.993700 | controller | skipping: [instance] 2025-10-02 21:09:31.993874 | controller | 2025-10-02 21:09:31.994117 | controller | TASK [test_deps : Gather variables for each operating system] ****************** 2025-10-02 21:09:31.994359 | controller | Thursday 02 October 2025 21:09:31 +0000 (0:00:00.039) 0:00:01.254 ****** 2025-10-02 21:09:32.070744 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml) 2025-10-02 21:09:32.070801 | controller | 2025-10-02 21:09:32.071019 | controller | TASK [test_deps : Detect mirrors file] ***************************************** 2025-10-02 21:09:32.071168 | controller | Thursday 02 October 2025 21:09:32 +0000 (0:00:00.077) 0:00:01.331 ****** 2025-10-02 21:09:32.454137 | controller | ok: [instance] 2025-10-02 21:09:32.454217 | controller | 2025-10-02 21:09:32.454376 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] *********** 2025-10-02 21:09:32.454550 | controller | Thursday 02 October 2025 21:09:32 +0000 (0:00:00.383) 0:00:01.714 ****** 2025-10-02 21:09:32.932810 | controller | ok: [instance] 2025-10-02 21:09:32.932926 | controller | 2025-10-02 21:09:32.932941 | controller | TASK [test_deps : Disable ubi 9 repos] ***************************************** 2025-10-02 21:09:32.932953 | controller | Thursday 02 October 2025 21:09:32 +0000 (0:00:00.479) 0:00:02.193 ****** 2025-10-02 21:09:33.951810 | controller | ok: [instance] => (item=ubi-9-appstream) 2025-10-02 21:09:33.951953 | controller | ok: [instance] => (item=ubi-9-baseos) 2025-10-02 21:09:33.952117 | controller | ok: [instance] => (item=ubi-9-codeready-builder) 2025-10-02 21:09:33.952140 | controller | 2025-10-02 21:09:33.952267 | controller | TASK [Deploy repo-setup] ******************************************************* 2025-10-02 21:09:33.952459 | controller | Thursday 02 October 2025 21:09:33 +0000 (0:00:01.018) 0:00:03.212 ****** 2025-10-02 21:09:34.028591 | controller | 2025-10-02 21:09:34.028703 | controller | TASK [repo_setup : Ensure directories are present] ***************************** 2025-10-02 21:09:34.028802 | controller | Thursday 02 October 2025 21:09:34 +0000 (0:00:00.076) 0:00:03.289 ****** 2025-10-02 21:09:34.822563 | controller | changed: [instance] => (item=tmp) 2025-10-02 21:09:34.822710 | controller | changed: [instance] => (item=artifacts/repositories) 2025-10-02 21:09:34.822727 | controller | changed: [instance] => (item=venv/repo_setup) 2025-10-02 21:09:34.823034 | controller | 2025-10-02 21:09:34.823381 | controller | TASK [repo_setup : Make sure git-core package is installed] ******************** 2025-10-02 21:09:34.823732 | controller | Thursday 02 October 2025 21:09:34 +0000 (0:00:00.792) 0:00:04.082 ****** 2025-10-02 21:09:35.879306 | controller | ok: [instance] 2025-10-02 21:09:35.879992 | controller | 2025-10-02 21:09:37.090921 | controller | TASK [repo_setup : Get repo-setup repository] ********************************** 2025-10-02 21:09:37.090992 | controller | Thursday 02 October 2025 21:09:35 +0000 (0:00:01.056) 0:00:05.139 ****** 2025-10-02 21:09:37.091017 | controller | changed: [instance] 2025-10-02 21:09:45.080550 | controller | 2025-10-02 21:09:45.080619 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************ 2025-10-02 21:09:45.080627 | controller | Thursday 02 October 2025 21:09:37 +0000 (0:00:01.210) 0:00:06.350 ****** 2025-10-02 21:09:45.080642 | controller | changed: [instance] 2025-10-02 21:09:45.080723 | controller | 2025-10-02 21:09:45.080743 | controller | TASK [repo_setup : Install repo-setup package] ********************************* 2025-10-02 21:09:45.080752 | controller | Thursday 02 October 2025 21:09:45 +0000 (0:00:07.990) 0:00:14.340 ****** 2025-10-02 21:09:46.152986 | controller | changed: [instance] 2025-10-02 21:09:46.153153 | controller | 2025-10-02 21:09:46.153503 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] *** 2025-10-02 21:09:46.153787 | controller | Thursday 02 October 2025 21:09:46 +0000 (0:00:01.073) 0:00:15.413 ****** 2025-10-02 21:09:46.194218 | controller | skipping: [instance] 2025-10-02 21:09:46.194443 | controller | 2025-10-02 21:09:46.194669 | controller | TASK [repo_setup : Run repo-setup] ********************************************* 2025-10-02 21:09:46.194921 | controller | Thursday 02 October 2025 21:09:46 +0000 (0:00:00.042) 0:00:15.455 ****** 2025-10-02 21:09:47.076654 | controller | changed: [instance] 2025-10-02 21:09:47.076870 | controller | 2025-10-02 21:09:47.077090 | controller | TASK [repo_setup : Get component repo] ***************************************** 2025-10-02 21:09:47.077347 | controller | Thursday 02 October 2025 21:09:47 +0000 (0:00:00.881) 0:00:16.337 ****** 2025-10-02 21:09:47.139364 | controller | skipping: [instance] 2025-10-02 21:09:47.139654 | controller | 2025-10-02 21:09:47.139986 | controller | TASK [repo_setup : Rename component repo] ************************************** 2025-10-02 21:09:47.140263 | controller | Thursday 02 October 2025 21:09:47 +0000 (0:00:00.062) 0:00:16.399 ****** 2025-10-02 21:09:47.200409 | controller | skipping: [instance] 2025-10-02 21:09:47.200766 | controller | 2025-10-02 21:09:47.202046 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] ******* 2025-10-02 21:09:47.202433 | controller | Thursday 02 October 2025 21:09:47 +0000 (0:00:00.060) 0:00:16.459 ****** 2025-10-02 21:09:47.275692 | controller | skipping: [instance] 2025-10-02 21:09:47.275977 | controller | 2025-10-02 21:09:47.276343 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************ 2025-10-02 21:09:47.276661 | controller | Thursday 02 October 2025 21:09:47 +0000 (0:00:00.075) 0:00:16.535 ****** 2025-10-02 21:09:47.851018 | controller | changed: [instance] 2025-10-02 21:09:47.851282 | controller | 2025-10-02 21:09:47.851695 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] ******************* 2025-10-02 21:09:47.852045 | controller | Thursday 02 October 2025 21:09:47 +0000 (0:00:00.575) 0:00:17.111 ****** 2025-10-02 21:09:48.508502 | controller | changed: [instance] 2025-10-02 21:09:48.508949 | controller | 2025-10-02 21:09:48.560855 | controller | TASK [repo_setup : Dump current-podified hash] ********************************* 2025-10-02 21:09:48.560943 | controller | Thursday 02 October 2025 21:09:48 +0000 (0:00:00.658) 0:00:17.769 ****** 2025-10-02 21:09:48.560980 | controller | skipping: [instance] 2025-10-02 21:09:48.612574 | controller | 2025-10-02 21:09:48.612649 | controller | TASK [repo_setup : Slurp current podified hash] ******************************** 2025-10-02 21:09:48.612675 | controller | Thursday 02 October 2025 21:09:48 +0000 (0:00:00.051) 0:00:17.821 ****** 2025-10-02 21:09:48.612706 | controller | skipping: [instance] 2025-10-02 21:09:48.612771 | controller | 2025-10-02 21:09:48.613019 | controller | TASK [repo_setup : Update the value of full_hash] ****************************** 2025-10-02 21:09:48.613170 | controller | Thursday 02 October 2025 21:09:48 +0000 (0:00:00.051) 0:00:17.872 ****** 2025-10-02 21:09:48.667044 | controller | skipping: [instance] 2025-10-02 21:09:48.667212 | controller | 2025-10-02 21:09:48.667587 | controller | TASK [repo_setup : Export hashes facts for further use] ************************ 2025-10-02 21:09:48.667658 | controller | Thursday 02 October 2025 21:09:48 +0000 (0:00:00.054) 0:00:17.927 ****** 2025-10-02 21:09:48.737855 | controller | ok: [instance] 2025-10-02 21:09:48.783378 | controller | 2025-10-02 21:09:48.783452 | controller | TASK [repo_setup : Create download directory] ********************************** 2025-10-02 21:09:48.783463 | controller | Thursday 02 October 2025 21:09:48 +0000 (0:00:00.071) 0:00:17.998 ****** 2025-10-02 21:09:48.783481 | controller | skipping: [instance] 2025-10-02 21:09:48.783519 | controller | 2025-10-02 21:09:48.783643 | controller | TASK [repo_setup : Print the URL to request] *********************************** 2025-10-02 21:09:48.783658 | controller | Thursday 02 October 2025 21:09:48 +0000 (0:00:00.045) 0:00:18.044 ****** 2025-10-02 21:09:48.818951 | controller | skipping: [instance] 2025-10-02 21:09:48.819009 | controller | 2025-10-02 21:09:48.819284 | controller | TASK [Download the RPM] ******************************************************** 2025-10-02 21:09:48.855079 | controller | Thursday 02 October 2025 21:09:48 +0000 (0:00:00.036) 0:00:18.080 ****** 2025-10-02 21:09:48.855174 | controller | skipping: [instance] 2025-10-02 21:09:48.855300 | controller | 2025-10-02 21:09:48.855394 | controller | TASK [repo_setup : Install RHOS Release tool] ********************************** 2025-10-02 21:09:48.893989 | controller | Thursday 02 October 2025 21:09:48 +0000 (0:00:00.035) 0:00:18.116 ****** 2025-10-02 21:09:48.894030 | controller | skipping: [instance] 2025-10-02 21:09:48.894066 | controller | 2025-10-02 21:09:48.894079 | controller | TASK [repo_setup : Get rhos-release tool version] ****************************** 2025-10-02 21:09:48.894258 | controller | Thursday 02 October 2025 21:09:48 +0000 (0:00:00.038) 0:00:18.155 ****** 2025-10-02 21:09:48.930549 | controller | skipping: [instance] 2025-10-02 21:09:48.930623 | controller | 2025-10-02 21:09:48.930638 | controller | TASK [repo_setup : Print rhos-release tool version] **************************** 2025-10-02 21:09:48.930716 | controller | Thursday 02 October 2025 21:09:48 +0000 (0:00:00.036) 0:00:18.191 ****** 2025-10-02 21:09:48.965952 | controller | skipping: [instance] 2025-10-02 21:09:48.966132 | controller | 2025-10-02 21:09:48.966170 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] *** 2025-10-02 21:09:48.999168 | controller | Thursday 02 October 2025 21:09:48 +0000 (0:00:00.035) 0:00:18.227 ****** 2025-10-02 21:09:48.999219 | controller | skipping: [instance] 2025-10-02 21:09:49.275225 | controller | 2025-10-02 21:09:49.275276 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] *************************** 2025-10-02 21:09:49.275286 | controller | Thursday 02 October 2025 21:09:48 +0000 (0:00:00.032) 0:00:18.260 ****** 2025-10-02 21:09:49.275301 | controller | ok: [instance] 2025-10-02 21:09:49.275412 | controller | 2025-10-02 21:09:49.275660 | controller | TASK [repo_setup : Use RDO proxy mirrors] ************************************** 2025-10-02 21:09:49.275901 | controller | Thursday 02 October 2025 21:09:49 +0000 (0:00:00.276) 0:00:18.536 ****** 2025-10-02 21:09:49.549403 | controller | changed: [instance] 2025-10-02 21:09:49.549547 | controller | 2025-10-02 21:09:49.549795 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] *** 2025-10-02 21:09:49.549996 | controller | Thursday 02 October 2025 21:09:49 +0000 (0:00:00.274) 0:00:18.810 ****** 2025-10-02 21:09:49.912005 | controller | changed: [instance] 2025-10-02 21:09:49.912204 | controller | 2025-10-02 21:09:49.912448 | controller | TASK [repo_setup : Check for gating.repo file on content provider] ************* 2025-10-02 21:09:49.912673 | controller | Thursday 02 October 2025 21:09:49 +0000 (0:00:00.361) 0:00:19.172 ****** 2025-10-02 21:09:49.953545 | controller | skipping: [instance] 2025-10-02 21:09:49.953718 | controller | 2025-10-02 21:09:49.953968 | controller | TASK [repo_setup : Populate gating repo from content provider ip] ************** 2025-10-02 21:09:49.954212 | controller | Thursday 02 October 2025 21:09:49 +0000 (0:00:00.042) 0:00:19.214 ****** 2025-10-02 21:09:49.997092 | controller | skipping: [instance] 2025-10-02 21:09:49.997259 | controller | 2025-10-02 21:09:49.997523 | controller | TASK [repo_setup : Check for DLRN repo at the destination] ********************* 2025-10-02 21:09:49.997788 | controller | Thursday 02 October 2025 21:09:49 +0000 (0:00:00.043) 0:00:19.258 ****** 2025-10-02 21:09:50.025237 | controller | skipping: [instance] 2025-10-02 21:09:50.025432 | controller | 2025-10-02 21:09:50.025669 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] *** 2025-10-02 21:09:50.025891 | controller | Thursday 02 October 2025 21:09:50 +0000 (0:00:00.028) 0:00:19.286 ****** 2025-10-02 21:09:50.052509 | controller | skipping: [instance] 2025-10-02 21:09:50.053152 | controller | 2025-10-02 21:09:50.095354 | controller | TASK [repo_setup : Check for DLRN component repo] ****************************** 2025-10-02 21:09:50.095379 | controller | Thursday 02 October 2025 21:09:50 +0000 (0:00:00.027) 0:00:19.313 ****** 2025-10-02 21:09:50.095391 | controller | skipping: [instance] 2025-10-02 21:09:50.095568 | controller | 2025-10-02 21:09:50.095842 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] *** 2025-10-02 21:09:50.096518 | controller | Thursday 02 October 2025 21:09:50 +0000 (0:00:00.042) 0:00:19.356 ****** 2025-10-02 21:09:50.124663 | controller | skipping: [instance] 2025-10-02 21:09:50.124907 | controller | 2025-10-02 21:09:50.125202 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ******** 2025-10-02 21:09:50.125512 | controller | Thursday 02 October 2025 21:09:50 +0000 (0:00:00.029) 0:00:19.385 ****** 2025-10-02 21:09:50.150177 | controller | skipping: [instance] 2025-10-02 21:09:50.150409 | controller | 2025-10-02 21:09:50.150423 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ****** 2025-10-02 21:09:50.150638 | controller | Thursday 02 October 2025 21:09:50 +0000 (0:00:00.025) 0:00:19.411 ****** 2025-10-02 21:09:50.205556 | controller | skipping: [instance] 2025-10-02 21:09:50.205606 | controller | 2025-10-02 21:09:50.205709 | controller | TASK [repo_setup : Cleanup existing metadata] ********************************** 2025-10-02 21:09:50.205823 | controller | Thursday 02 October 2025 21:09:50 +0000 (0:00:00.055) 0:00:19.466 ****** 2025-10-02 21:09:50.232035 | controller | skipping: [instance] 2025-10-02 21:09:50.232160 | controller | 2025-10-02 21:09:50.232343 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] ********* 2025-10-02 21:09:50.232506 | controller | Thursday 02 October 2025 21:09:50 +0000 (0:00:00.027) 0:00:19.493 ****** 2025-10-02 21:09:50.269366 | controller | skipping: [instance] 2025-10-02 21:09:50.269528 | controller | 2025-10-02 21:09:50.269742 | controller | TASK [test_deps : Look for redhat-release rpm] ********************************* 2025-10-02 21:09:50.269955 | controller | Thursday 02 October 2025 21:09:50 +0000 (0:00:00.036) 0:00:19.530 ****** 2025-10-02 21:09:50.325527 | controller | skipping: [instance] 2025-10-02 21:09:50.325623 | controller | 2025-10-02 21:09:50.325785 | controller | TASK [test_deps : Remove redhat-release] *************************************** 2025-10-02 21:09:50.325932 | controller | Thursday 02 October 2025 21:09:50 +0000 (0:00:00.056) 0:00:19.586 ****** 2025-10-02 21:09:50.388502 | controller | skipping: [instance] 2025-10-02 21:09:50.388648 | controller | 2025-10-02 21:09:50.388891 | controller | TASK [test_deps : Install centos-stream-release] ******************************* 2025-10-02 21:09:50.389113 | controller | Thursday 02 October 2025 21:09:50 +0000 (0:00:00.062) 0:00:19.649 ****** 2025-10-02 21:09:50.452423 | controller | skipping: [instance] 2025-10-02 21:09:50.452625 | controller | 2025-10-02 21:09:50.452889 | controller | TASK [test_deps : Install additional packages] ********************************* 2025-10-02 21:09:50.453163 | controller | Thursday 02 October 2025 21:09:50 +0000 (0:00:00.063) 0:00:19.712 ****** 2025-10-02 21:09:50.510205 | controller | skipping: [instance] 2025-10-02 21:09:50.510344 | controller | 2025-10-02 21:09:50.510612 | controller | TASK [test_deps : Install selinux python libs] ********************************* 2025-10-02 21:09:50.510847 | controller | Thursday 02 October 2025 21:09:50 +0000 (0:00:00.058) 0:00:19.771 ****** 2025-10-02 21:10:29.007855 | controller | ok: [instance] 2025-10-02 21:10:29.008211 | controller | 2025-10-02 21:10:29.008374 | controller | TASK [test_deps : Install python yaml libs] ************************************ 2025-10-02 21:10:29.008396 | controller | Thursday 02 October 2025 21:10:29 +0000 (0:00:38.496) 0:00:58.267 ****** 2025-10-02 21:10:30.495404 | controller | ok: [instance] 2025-10-02 21:10:30.495461 | controller | 2025-10-02 21:10:30.495568 | controller | TASK [test_deps : Install extra packages] ************************************** 2025-10-02 21:10:30.495669 | controller | Thursday 02 October 2025 21:10:30 +0000 (0:00:01.488) 0:00:59.756 ****** 2025-10-02 21:10:30.554511 | controller | skipping: [instance] 2025-10-02 21:10:30.554597 | controller | 2025-10-02 21:10:30.554671 | controller | PLAY RECAP ********************************************************************* 2025-10-02 21:10:30.554812 | controller | instance : ok=19 changed=9 unreachable=0 failed=0 skipped=30 rescued=0 ignored=0 2025-10-02 21:10:30.554916 | controller | 2025-10-02 21:10:30.555003 | controller | Thursday 02 October 2025 21:10:30 +0000 (0:00:00.059) 0:00:59.815 ****** 2025-10-02 21:10:30.555100 | controller | =============================================================================== 2025-10-02 21:10:30.555197 | controller | test_deps : Install selinux python libs -------------------------------- 38.50s 2025-10-02 21:10:30.555301 | controller | repo_setup : Initialize python venv and install requirements ------------ 7.99s 2025-10-02 21:10:30.555444 | controller | test_deps : Install python yaml libs ------------------------------------ 1.49s 2025-10-02 21:10:30.555521 | controller | repo_setup : Get repo-setup repository ---------------------------------- 1.21s 2025-10-02 21:10:30.555664 | controller | Gathering Facts --------------------------------------------------------- 1.20s 2025-10-02 21:10:30.555729 | controller | repo_setup : Install repo-setup package --------------------------------- 1.07s 2025-10-02 21:10:30.555844 | controller | repo_setup : Make sure git-core package is installed -------------------- 1.06s 2025-10-02 21:10:30.555948 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 1.02s 2025-10-02 21:10:30.556040 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.88s 2025-10-02 21:10:30.556141 | controller | repo_setup : Ensure directories are present ----------------------------- 0.79s 2025-10-02 21:10:30.556238 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.66s 2025-10-02 21:10:30.556358 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.58s 2025-10-02 21:10:30.556466 | controller | test_deps : Disable ubi host subscription-manager integration ----------- 0.48s 2025-10-02 21:10:30.556576 | controller | test_deps : Detect mirrors file ----------------------------------------- 0.38s 2025-10-02 21:10:30.556666 | controller | repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist) --- 0.36s 2025-10-02 21:10:30.556795 | controller | repo_setup : Check for /etc/ci/mirror_info.sh --------------------------- 0.28s 2025-10-02 21:10:30.556886 | controller | repo_setup : Use RDO proxy mirrors -------------------------------------- 0.27s 2025-10-02 21:10:30.556974 | controller | test_deps : Gather variables for each operating system ------------------ 0.08s 2025-10-02 21:10:30.557077 | controller | Deploy repo-setup ------------------------------------------------------- 0.08s 2025-10-02 21:10:30.557174 | controller | repo_setup : Disable component repo in current-podified dlrn repo ------- 0.08s 2025-10-02 21:10:30.636531 | controller | INFO Running default > converge 2025-10-02 21:10:31.124026 | controller | 2025-10-02 21:10:31.124249 | controller | PLAY [Add crc to the inventory] ************************************************ 2025-10-02 21:10:31.124607 | controller | 2025-10-02 21:10:31.125067 | controller | TASK [Gathering Facts] ********************************************************* 2025-10-02 21:10:31.125462 | controller | Thursday 02 October 2025 21:10:31 +0000 (0:00:00.014) 0:00:00.014 ****** 2025-10-02 21:10:32.246149 | controller | ok: [instance] 2025-10-02 21:10:32.246291 | controller | 2025-10-02 21:10:32.246563 | controller | TASK [Add crc hostname with it's IP to /etc/hosts] ***************************** 2025-10-02 21:10:32.246863 | controller | Thursday 02 October 2025 21:10:32 +0000 (0:00:01.123) 0:00:01.137 ****** 2025-10-02 21:10:32.652676 | controller | changed: [instance] 2025-10-02 21:10:32.652757 | controller | 2025-10-02 21:10:32.653351 | controller | TASK [Check if new ssh keypair exists] ***************************************** 2025-10-02 21:10:32.689360 | controller | Thursday 02 October 2025 21:10:32 +0000 (0:00:00.405) 0:00:01.543 ****** 2025-10-02 21:10:32.689405 | controller | 2025-10-02 21:10:32.689473 | controller | TASK [recognize_ssh_keypair : Check if id_ed25519 key exists] ****************** 2025-10-02 21:10:32.689646 | controller | Thursday 02 October 2025 21:10:32 +0000 (0:00:00.037) 0:00:01.580 ****** 2025-10-02 21:10:33.109139 | controller | ok: [instance] 2025-10-02 21:10:33.109247 | controller | 2025-10-02 21:10:33.109481 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair exists] ****************** 2025-10-02 21:10:33.109696 | controller | Thursday 02 October 2025 21:10:33 +0000 (0:00:00.418) 0:00:01.999 ****** 2025-10-02 21:10:33.148367 | controller | ok: [instance] 2025-10-02 21:10:33.148574 | controller | 2025-10-02 21:10:33.148889 | controller | TASK [recognize_ssh_keypair : Set fact if new keypair does not exists] ********* 2025-10-02 21:10:33.149168 | controller | Thursday 02 October 2025 21:10:33 +0000 (0:00:00.039) 0:00:02.039 ****** 2025-10-02 21:10:33.182648 | controller | skipping: [instance] 2025-10-02 21:10:33.182873 | controller | 2025-10-02 21:10:33.183237 | controller | TASK [Add the crc host dynamically] ******************************************** 2025-10-02 21:10:33.183577 | controller | Thursday 02 October 2025 21:10:33 +0000 (0:00:00.034) 0:00:02.073 ****** 2025-10-02 21:10:33.259889 | controller | changed: [instance] 2025-10-02 21:10:33.260717 | controller | 2025-10-02 21:10:33.814794 | controller | TASK [Add a dummy ethernet interface to target the crc NMstate] **************** 2025-10-02 21:10:33.814837 | controller | Thursday 02 October 2025 21:10:33 +0000 (0:00:00.076) 0:00:02.150 ****** 2025-10-02 21:10:33.814853 | controller | changed: [instance] 2025-10-02 21:10:40.533827 | controller | 2025-10-02 21:10:40.533885 | controller | PLAY [Get CRC facts] *********************************************************** 2025-10-02 21:10:40.533903 | controller | 2025-10-02 21:10:40.533918 | controller | TASK [Fetch crc network facts] ************************************************* 2025-10-02 21:10:40.533933 | controller | Thursday 02 October 2025 21:10:33 +0000 (0:00:00.553) 0:00:02.703 ****** 2025-10-02 21:10:40.533956 | controller | ok: [crc] 2025-10-02 21:10:40.590498 | controller | 2025-10-02 21:10:40.590542 | controller | PLAY [Converge] **************************************************************** 2025-10-02 21:10:40.590553 | controller | 2025-10-02 21:10:40.590562 | controller | TASK [Set common molecule test facts] ****************************************** 2025-10-02 21:10:40.590570 | controller | Thursday 02 October 2025 21:10:40 +0000 (0:00:06.719) 0:00:09.423 ****** 2025-10-02 21:10:40.590584 | controller | ok: [instance] 2025-10-02 21:10:40.591056 | controller | 2025-10-02 21:10:40.591094 | controller | TASK [Prepare the Networking Env Definition for ci_nmstate role] *************** 2025-10-02 21:10:40.652711 | controller | Thursday 02 October 2025 21:10:40 +0000 (0:00:00.057) 0:00:09.481 ****** 2025-10-02 21:10:40.652772 | controller | 2025-10-02 21:10:40.653243 | controller | TASK [networking_mapper : Check for Networking Definition file existence] ****** 2025-10-02 21:10:40.769548 | controller | Thursday 02 October 2025 21:10:40 +0000 (0:00:00.062) 0:00:09.544 ****** 2025-10-02 21:10:40.769609 | controller | skipping: [instance] 2025-10-02 21:10:40.897053 | controller | 2025-10-02 21:10:40.897117 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************ 2025-10-02 21:10:40.897128 | controller | Thursday 02 October 2025 21:10:40 +0000 (0:00:00.115) 0:00:09.659 ****** 2025-10-02 21:10:40.897143 | controller | skipping: [instance] 2025-10-02 21:10:40.940930 | controller | 2025-10-02 21:10:40.940985 | controller | TASK [networking_mapper : Check for interfaces info file existence] ************ 2025-10-02 21:10:40.941004 | controller | Thursday 02 October 2025 21:10:40 +0000 (0:00:00.128) 0:00:09.788 ****** 2025-10-02 21:10:40.941027 | controller | skipping: [instance] 2025-10-02 21:10:40.984644 | controller | 2025-10-02 21:10:40.984702 | controller | TASK [networking_mapper : Load the interfaces info from file] ****************** 2025-10-02 21:10:40.984720 | controller | Thursday 02 October 2025 21:10:40 +0000 (0:00:00.043) 0:00:09.831 ****** 2025-10-02 21:10:40.984743 | controller | skipping: [instance] 2025-10-02 21:10:41.007730 | controller | 2025-10-02 21:10:41.007779 | controller | TASK [networking_mapper : Ensure local fact is empty] ************************** 2025-10-02 21:10:41.007790 | controller | Thursday 02 October 2025 21:10:40 +0000 (0:00:00.043) 0:00:09.875 ****** 2025-10-02 21:10:41.007806 | controller | ok: [instance] 2025-10-02 21:10:41.008219 | controller | 2025-10-02 21:10:41.008274 | controller | TASK [networking_mapper : Set the input Networking Definition and patch it if needed] *** 2025-10-02 21:10:41.147595 | controller | Thursday 02 October 2025 21:10:41 +0000 (0:00:00.023) 0:00:09.898 ****** 2025-10-02 21:10:41.147680 | controller | ok: [instance] => (item={'networks': {'default': {'network': '38.102.83.0/24', 'gateway': '38.102.83.1', 'dns': ['1.1.1.1', '1.0.0.1'], 'mtu': '1450'}, 'testing-untagged': {'network': '172.17.20.0/24', 'dns': ['192.168.130.11', '192.168.130.1'], 'mtu': '1500'}, 'testing-vlan': {'network': '172.17.21.0/24', 'vlan': 21}}, 'instances': {'crc': {'networks': {'testing-untagged': {'ip': '172.17.20.5'}, 'testing-vlan': {'ip': '172.17.21.5', 'trunk-parent': 'testing-untagged'}}}, 'instance': {'networks': {'default': {'ip': '38.102.83.115'}}}}}) 2025-10-02 21:10:41.176628 | controller | 2025-10-02 21:10:41.176670 | controller | TASK [networking_mapper : Gather facts if requested] *************************** 2025-10-02 21:10:41.176694 | controller | Thursday 02 October 2025 21:10:41 +0000 (0:00:00.140) 0:00:10.038 ****** 2025-10-02 21:10:41.176708 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/networking_mapper/tasks/_gather_facts.yml for instance 2025-10-02 21:10:41.560047 | controller | 2025-10-02 21:10:41.560115 | controller | TASK [networking_mapper : Gather the facts] ************************************ 2025-10-02 21:10:41.560137 | controller | Thursday 02 October 2025 21:10:41 +0000 (0:00:00.028) 0:00:10.067 ****** 2025-10-02 21:10:41.560159 | controller | skipping: [instance] => (item=crc) 2025-10-02 21:10:42.339465 | controller | skipping: [instance] => (item=instance) 2025-10-02 21:10:42.339509 | controller | skipping: [instance] 2025-10-02 21:10:42.339519 | controller | 2025-10-02 21:10:42.339526 | controller | TASK [networking_mapper : Save instances refreshed facts for troubleshooting purposes] *** 2025-10-02 21:10:42.339533 | controller | Thursday 02 October 2025 21:10:41 +0000 (0:00:00.381) 0:00:10.449 ****** 2025-10-02 21:10:42.339544 | controller | changed: [instance] 2025-10-02 21:10:42.791353 | controller | 2025-10-02 21:10:42.791432 | controller | TASK [networking_mapper : Ensure CI infrastructure dir exists] ***************** 2025-10-02 21:10:42.791449 | controller | Thursday 02 October 2025 21:10:42 +0000 (0:00:00.780) 0:00:11.229 ****** 2025-10-02 21:10:42.791487 | controller | changed: [instance] 2025-10-02 21:10:43.410006 | controller | 2025-10-02 21:10:43.410056 | controller | TASK [networking_mapper : Write the Networking Definition to file] ************* 2025-10-02 21:10:43.410067 | controller | Thursday 02 October 2025 21:10:42 +0000 (0:00:00.451) 0:00:11.681 ****** 2025-10-02 21:10:43.410083 | controller | changed: [instance] 2025-10-02 21:10:43.410122 | controller | 2025-10-02 21:10:43.410582 | controller | TASK [networking_mapper : Call the networking mapper] ************************** 2025-10-02 21:10:43.410747 | controller | Thursday 02 October 2025 21:10:43 +0000 (0:00:00.619) 0:00:12.301 ****** 2025-10-02 21:10:43.537100 | controller | ok: [instance] 2025-10-02 21:10:43.537210 | controller | 2025-10-02 21:10:43.537235 | controller | TASK [networking_mapper : Set networking mapper facts] ************************* 2025-10-02 21:10:43.537552 | controller | Thursday 02 October 2025 21:10:43 +0000 (0:00:00.126) 0:00:12.427 ****** 2025-10-02 21:10:43.593592 | controller | ok: [instance] 2025-10-02 21:10:43.594006 | controller | 2025-10-02 21:10:43.594064 | controller | TASK [networking_mapper : Write the Networking Environment Definition to file] *** 2025-10-02 21:10:44.174920 | controller | Thursday 02 October 2025 21:10:43 +0000 (0:00:00.056) 0:00:12.483 ****** 2025-10-02 21:10:44.174975 | controller | changed: [instance] 2025-10-02 21:10:44.175086 | controller | 2025-10-02 21:10:44.175097 | controller | TASK [Call the role under test] ************************************************ 2025-10-02 21:10:44.175108 | controller | Thursday 02 October 2025 21:10:44 +0000 (0:00:00.581) 0:00:13.065 ****** 2025-10-02 21:10:44.242793 | controller | 2025-10-02 21:10:44.243060 | controller | TASK [networking_mapper : Check for Networking Environment Definition file existence] *** 2025-10-02 21:10:44.243303 | controller | Thursday 02 October 2025 21:10:44 +0000 (0:00:00.068) 0:00:13.134 ****** 2025-10-02 21:10:44.271694 | controller | skipping: [instance] 2025-10-02 21:10:44.272427 | controller | 2025-10-02 21:10:44.272693 | controller | TASK [networking_mapper : Check for Networking Definition file existance] ****** 2025-10-02 21:10:44.272988 | controller | Thursday 02 October 2025 21:10:44 +0000 (0:00:00.028) 0:00:13.163 ****** 2025-10-02 21:10:44.299264 | controller | skipping: [instance] 2025-10-02 21:10:44.299503 | controller | 2025-10-02 21:10:44.299759 | controller | TASK [networking_mapper : Load the Networking Definition from file] ************ 2025-10-02 21:10:44.300010 | controller | Thursday 02 October 2025 21:10:44 +0000 (0:00:00.027) 0:00:13.190 ****** 2025-10-02 21:10:44.332033 | controller | skipping: [instance] 2025-10-02 21:10:44.332252 | controller | 2025-10-02 21:10:44.332567 | controller | TASK [networking_mapper : Set cifmw_networking_env_definition is present] ****** 2025-10-02 21:10:44.332782 | controller | Thursday 02 October 2025 21:10:44 +0000 (0:00:00.032) 0:00:13.223 ****** 2025-10-02 21:10:44.376117 | controller | skipping: [instance] 2025-10-02 21:10:44.376262 | controller | 2025-10-02 21:10:44.376430 | controller | TASK [ci_nmstate : Initialize NMstates for each instance] ********************** 2025-10-02 21:10:44.376606 | controller | Thursday 02 October 2025 21:10:44 +0000 (0:00:00.044) 0:00:13.267 ****** 2025-10-02 21:10:44.439861 | controller | ok: [instance] 2025-10-02 21:10:44.440023 | controller | 2025-10-02 21:10:44.440237 | controller | TASK [ci_nmstate : Build NMstates from the Networking Environment Definition] *** 2025-10-02 21:10:44.440423 | controller | Thursday 02 October 2025 21:10:44 +0000 (0:00:00.063) 0:00:13.331 ****** 2025-10-02 21:10:44.514436 | controller | ok: [instance] => (item=crc) 2025-10-02 21:10:44.514678 | controller | ok: [instance] => (item=instance) 2025-10-02 21:10:44.514885 | controller | 2025-10-02 21:10:44.515119 | controller | TASK [ci_nmstate : Get k8s nodes] ********************************************** 2025-10-02 21:10:44.515342 | controller | Thursday 02 October 2025 21:10:44 +0000 (0:00:00.074) 0:00:13.405 ****** 2025-10-02 21:10:45.531398 | controller | ok: [instance] 2025-10-02 21:10:45.665363 | controller | 2025-10-02 21:10:45.665429 | controller | TASK [ci_nmstate : Set the hosts that will provision nmstate using k8s] ******** 2025-10-02 21:10:45.665446 | controller | Thursday 02 October 2025 21:10:45 +0000 (0:00:01.015) 0:00:14.421 ****** 2025-10-02 21:10:45.665470 | controller | ok: [instance] 2025-10-02 21:10:45.665535 | controller | 2025-10-02 21:10:45.665739 | controller | TASK [ci_nmstate : Provision k8s workers with nmstate] ************************* 2025-10-02 21:10:45.665966 | controller | Thursday 02 October 2025 21:10:45 +0000 (0:00:00.134) 0:00:14.556 ****** 2025-10-02 21:10:45.761058 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/ci_nmstate/tasks/nmstate_k8s_install.yml for instance 2025-10-02 21:10:45.761245 | controller | 2025-10-02 21:10:45.761500 | controller | TASK [ci_nmstate : Create the target dir to dump NMstate manifests] ************ 2025-10-02 21:10:45.761733 | controller | Thursday 02 October 2025 21:10:45 +0000 (0:00:00.096) 0:00:14.652 ****** 2025-10-02 21:10:46.081150 | controller | changed: [instance] 2025-10-02 21:10:46.081211 | controller | 2025-10-02 21:10:46.081302 | controller | TASK [ci_nmstate : Create the nmstate namespace] ******************************* 2025-10-02 21:10:46.081444 | controller | Thursday 02 October 2025 21:10:46 +0000 (0:00:00.320) 0:00:14.972 ****** 2025-10-02 21:10:47.077057 | controller | changed: [instance] 2025-10-02 21:10:47.077128 | controller | 2025-10-02 21:10:47.077243 | controller | TASK [ci_nmstate : Generate the OperatorGroup final CR] ************************ 2025-10-02 21:10:47.077386 | controller | Thursday 02 October 2025 21:10:47 +0000 (0:00:00.995) 0:00:15.968 ****** 2025-10-02 21:10:47.155560 | controller | ok: [instance] => (item={'apiVersion': 'operators.coreos.com/v1', 'kind': 'OperatorGroup', 'metadata': {'annotations': {'olm.providedAPIs': 'NMState.v1.nmstate.io'}, 'name': 'openshift-nmstate', 'namespace': 'openshift-nmstate'}, 'spec': {'targetNamespaces': ['openshift-nmstate']}}) 2025-10-02 21:10:47.155631 | controller | 2025-10-02 21:10:47.155750 | controller | TASK [ci_nmstate : Generate the Subscription final CR] ************************* 2025-10-02 21:10:47.155872 | controller | Thursday 02 October 2025 21:10:47 +0000 (0:00:00.078) 0:00:16.047 ****** 2025-10-02 21:10:47.232779 | controller | ok: [instance] => (item={'apiVersion': 'operators.coreos.com/v1alpha1', 'kind': 'Subscription', 'metadata': {'labels': {'operators.coreos.com/kubernetes-nmstate-operator.openshift-nmstate': ''}, 'name': 'kubernetes-nmstate-operator', 'namespace': 'openshift-nmstate'}, 'spec': {'channel': 'stable', 'installPlanApproval': 'Automatic', 'name': 'kubernetes-nmstate-operator', 'source': 'redhat-operators', 'sourceNamespace': 'openshift-marketplace'}}) 2025-10-02 21:10:47.232846 | controller | 2025-10-02 21:10:47.232856 | controller | TASK [ci_nmstate : Save k8s nmstate OLM manifests as artifacts] **************** 2025-10-02 21:10:47.232964 | controller | Thursday 02 October 2025 21:10:47 +0000 (0:00:00.077) 0:00:16.124 ****** 2025-10-02 21:10:48.124424 | controller | changed: [instance] => (item=openshift-nmstate) 2025-10-02 21:10:48.124618 | controller | changed: [instance] => (item=kubernetes-nmstate-operator) 2025-10-02 21:10:48.124836 | controller | 2025-10-02 21:10:48.125127 | controller | TASK [ci_nmstate : Create the OLM subscription resources] ********************** 2025-10-02 21:10:48.125392 | controller | Thursday 02 October 2025 21:10:48 +0000 (0:00:00.890) 0:00:17.015 ****** 2025-10-02 21:10:49.642520 | controller | changed: [instance] => (item=openshift-nmstate) 2025-10-02 21:10:49.642590 | controller | changed: [instance] => (item=kubernetes-nmstate-operator) 2025-10-02 21:10:49.643198 | controller | 2025-10-02 21:11:10.866148 | controller | TASK [ci_nmstate : Wait for nmstate operator to be installed] ****************** 2025-10-02 21:11:10.866237 | controller | Thursday 02 October 2025 21:10:49 +0000 (0:00:01.518) 0:00:18.533 ****** 2025-10-02 21:11:10.866262 | controller | FAILED - RETRYING: [instance]: Wait for nmstate operator to be installed (12 retries left). 2025-10-02 21:11:10.866291 | controller | FAILED - RETRYING: [instance]: Wait for nmstate operator to be installed (11 retries left). 2025-10-02 21:11:10.866303 | controller | ok: [instance] 2025-10-02 21:11:10.866990 | controller | 2025-10-02 21:11:10.867068 | controller | TASK [ci_nmstate : Save nmstate operator config as an artifact] **************** 2025-10-02 21:11:11.275545 | controller | Thursday 02 October 2025 21:11:10 +0000 (0:00:21.224) 0:00:39.757 ****** 2025-10-02 21:11:11.275619 | controller | changed: [instance] 2025-10-02 21:11:12.160261 | controller | 2025-10-02 21:11:12.160354 | controller | TASK [ci_nmstate : Trigger nmstate operator to install nmstate] **************** 2025-10-02 21:11:12.160376 | controller | Thursday 02 October 2025 21:11:11 +0000 (0:00:00.409) 0:00:40.166 ****** 2025-10-02 21:11:12.160400 | controller | changed: [instance] 2025-10-02 21:11:12.160468 | controller | 2025-10-02 21:11:12.163937 | controller | TASK [ci_nmstate : Wait for nsmtate Deployments to be ready] ******************* 2025-10-02 21:11:43.547733 | controller | Thursday 02 October 2025 21:11:12 +0000 (0:00:00.884) 0:00:41.051 ****** 2025-10-02 21:11:43.547866 | controller | ok: [instance] 2025-10-02 21:11:43.548128 | controller | 2025-10-02 21:11:44.654087 | controller | TASK [ci_nmstate : Wait for nsmtate DaemonSet to be ready] ********************* 2025-10-02 21:11:44.654130 | controller | Thursday 02 October 2025 21:11:43 +0000 (0:00:31.387) 0:01:12.438 ****** 2025-10-02 21:11:44.654145 | controller | ok: [instance] 2025-10-02 21:11:44.654654 | controller | 2025-10-02 21:11:44.654679 | controller | TASK [ci_nmstate : Provision nncps] ******************************************** 2025-10-02 21:11:44.654864 | controller | Thursday 02 October 2025 21:11:44 +0000 (0:00:01.105) 0:01:13.544 ****** 2025-10-02 21:11:44.707729 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/ci_nmstate/tasks/nmstate_k8s_provision_node.yml for instance => (item=crc) 2025-10-02 21:11:44.707981 | controller | 2025-10-02 21:11:44.708005 | controller | TASK [ci_nmstate : Prepare the k8s nmstate nncp to apply] ********************** 2025-10-02 21:11:44.708270 | controller | Thursday 02 October 2025 21:11:44 +0000 (0:00:00.053) 0:01:13.598 ****** 2025-10-02 21:11:44.822688 | controller | ok: [instance] 2025-10-02 21:11:44.822854 | controller | 2025-10-02 21:11:44.823064 | controller | TASK [ci_nmstate : Save k8s nmstate nncp manifests as artifacts] *************** 2025-10-02 21:11:44.823270 | controller | Thursday 02 October 2025 21:11:44 +0000 (0:00:00.115) 0:01:13.713 ****** 2025-10-02 21:11:45.328367 | controller | changed: [instance] 2025-10-02 21:11:45.328420 | controller | 2025-10-02 21:11:45.328520 | controller | TASK [ci_nmstate : Provision nmstate nncp for the node worker] ***************** 2025-10-02 21:11:45.328711 | controller | Thursday 02 October 2025 21:11:45 +0000 (0:00:00.505) 0:01:14.219 ****** 2025-10-02 21:11:46.264582 | controller | changed: [instance] 2025-10-02 21:11:46.264697 | controller | 2025-10-02 21:11:46.264803 | controller | TASK [ci_nmstate : Wait for nsmtate nncp to be ready] ************************** 2025-10-02 21:11:46.264977 | controller | Thursday 02 October 2025 21:11:46 +0000 (0:00:00.930) 0:01:15.150 ****** 2025-10-02 21:12:52.386149 | controller | fatal: [instance]: FAILED! => changed=false 2025-10-02 21:12:52.386570 | controller | api_found: true 2025-10-02 21:12:52.386638 | controller | attempts: 6 2025-10-02 21:12:52.387086 | controller | resources: 2025-10-02 21:12:52.387127 | controller | - apiVersion: nmstate.io/v1 2025-10-02 21:12:52.387528 | controller | kind: NodeNetworkConfigurationPolicy 2025-10-02 21:12:52.387582 | controller | metadata: 2025-10-02 21:12:52.387612 | controller | annotations: 2025-10-02 21:12:52.387831 | controller | nmstate.io/webhook-mutating-timestamp: '1759439505994154857' 2025-10-02 21:12:52.387871 | controller | creationTimestamp: '2025-10-02T21:11:46Z' 2025-10-02 21:12:52.387985 | controller | generation: 1 2025-10-02 21:12:52.388484 | controller | managedFields: 2025-10-02 21:12:52.389634 | controller | - apiVersion: nmstate.io/v1 2025-10-02 21:12:52.389700 | controller | fieldsType: FieldsV1 2025-10-02 21:12:52.390025 | controller | fieldsV1: 2025-10-02 21:12:52.390067 | controller | f:spec: 2025-10-02 21:12:52.390088 | controller | .: {} 2025-10-02 21:12:52.390107 | controller | f:desiredState: 2025-10-02 21:12:52.390127 | controller | .: {} 2025-10-02 21:12:52.390154 | controller | f:dns-resolver: 2025-10-02 21:12:52.390309 | controller | .: {} 2025-10-02 21:12:52.390575 | controller | f:config: 2025-10-02 21:12:52.390844 | controller | .: {} 2025-10-02 21:12:52.391096 | controller | f:search: {} 2025-10-02 21:12:52.391401 | controller | f:server: {} 2025-10-02 21:12:52.391656 | controller | f:interfaces: {} 2025-10-02 21:12:52.391918 | controller | f:nodeSelector: 2025-10-02 21:12:52.392193 | controller | .: {} 2025-10-02 21:12:52.392484 | controller | f:kubernetes.io/hostname: {} 2025-10-02 21:12:52.392749 | controller | f:node-role.kubernetes.io/worker: {} 2025-10-02 21:12:52.393013 | controller | manager: OpenAPI-Generator 2025-10-02 21:12:52.393295 | controller | operation: Update 2025-10-02 21:12:52.393542 | controller | time: '2025-10-02T21:11:45Z' 2025-10-02 21:12:52.393832 | controller | - apiVersion: nmstate.io/v1 2025-10-02 21:12:52.394059 | controller | fieldsType: FieldsV1 2025-10-02 21:12:52.394300 | controller | fieldsV1: 2025-10-02 21:12:52.394582 | controller | f:status: 2025-10-02 21:12:52.394835 | controller | .: {} 2025-10-02 21:12:52.395067 | controller | f:conditions: {} 2025-10-02 21:12:52.395361 | controller | f:lastUnavailableNodeCountUpdate: {} 2025-10-02 21:12:52.395603 | controller | f:unavailableNodeCount: {} 2025-10-02 21:12:52.395862 | controller | manager: manager 2025-10-02 21:12:52.396156 | controller | operation: Update 2025-10-02 21:12:52.396439 | controller | subresource: status 2025-10-02 21:12:52.396698 | controller | time: '2025-10-02T21:11:49Z' 2025-10-02 21:12:52.396910 | controller | name: crc 2025-10-02 21:12:52.397215 | controller | resourceVersion: '35613' 2025-10-02 21:12:52.397488 | controller | uid: 0f0130e9-3d18-4837-921c-2f87eef81568 2025-10-02 21:12:52.397749 | controller | spec: 2025-10-02 21:12:52.398012 | controller | desiredState: 2025-10-02 21:12:52.398279 | controller | dns-resolver: 2025-10-02 21:12:52.398553 | controller | config: 2025-10-02 21:12:52.398811 | controller | search: 2025-10-02 21:12:52.399067 | controller | - testing-untagged.example.com 2025-10-02 21:12:52.399365 | controller | - testing-vlan.example.com 2025-10-02 21:12:52.399623 | controller | server: 2025-10-02 21:12:52.399883 | controller | - 192.168.130.11 2025-10-02 21:12:52.400226 | controller | - 192.168.130.1 2025-10-02 21:12:52.400467 | controller | interfaces: 2025-10-02 21:12:52.400759 | controller | - description: testing-untagged 2025-10-02 21:12:52.400986 | controller | ipv4: 2025-10-02 21:12:52.401245 | controller | address: 2025-10-02 21:12:52.401434 | controller | - ip: 172.17.20.5 2025-10-02 21:12:52.401573 | controller | prefix-length: 24 2025-10-02 21:12:52.401748 | controller | enabled: true 2025-10-02 21:12:52.401893 | controller | ipv6: 2025-10-02 21:12:52.402051 | controller | enabled: false 2025-10-02 21:12:52.402193 | controller | mtu: 1500 2025-10-02 21:12:52.402400 | controller | name: enp6s0 2025-10-02 21:12:52.402546 | controller | state: up 2025-10-02 21:12:52.402708 | controller | type: ethernet 2025-10-02 21:12:52.402868 | controller | - description: testing-vlan 2025-10-02 21:12:52.403031 | controller | ipv4: 2025-10-02 21:12:52.403182 | controller | address: 2025-10-02 21:12:52.403358 | controller | - ip: 172.17.21.5 2025-10-02 21:12:52.403531 | controller | prefix-length: 24 2025-10-02 21:12:52.403688 | controller | enabled: true 2025-10-02 21:12:52.403851 | controller | ipv6: 2025-10-02 21:12:52.404019 | controller | enabled: false 2025-10-02 21:12:52.404177 | controller | mtu: 1496 2025-10-02 21:12:52.404376 | controller | name: enp6s0.21 2025-10-02 21:12:52.404543 | controller | state: up 2025-10-02 21:12:52.404695 | controller | type: vlan 2025-10-02 21:12:52.404854 | controller | vlan: 2025-10-02 21:12:52.404994 | controller | base-iface: enp6s0 2025-10-02 21:12:52.405173 | controller | id: 21 2025-10-02 21:12:52.405347 | controller | nodeSelector: 2025-10-02 21:12:52.405496 | controller | kubernetes.io/hostname: crc 2025-10-02 21:12:52.405654 | controller | node-role.kubernetes.io/worker: '' 2025-10-02 21:12:52.405849 | controller | status: 2025-10-02 21:12:52.406025 | controller | conditions: 2025-10-02 21:12:52.406177 | controller | - lastHeartbeatTime: '2025-10-02T21:11:49Z' 2025-10-02 21:12:52.406347 | controller | lastTransitionTime: '2025-10-02T21:11:46Z' 2025-10-02 21:12:52.406503 | controller | reason: ConfigurationProgressing 2025-10-02 21:12:52.406650 | controller | status: Unknown 2025-10-02 21:12:52.406840 | controller | type: Available 2025-10-02 21:12:52.406984 | controller | - lastHeartbeatTime: '2025-10-02T21:11:49Z' 2025-10-02 21:12:52.407127 | controller | lastTransitionTime: '2025-10-02T21:11:46Z' 2025-10-02 21:12:52.407357 | controller | reason: ConfigurationProgressing 2025-10-02 21:12:52.407502 | controller | status: Unknown 2025-10-02 21:12:52.407656 | controller | type: Degraded 2025-10-02 21:12:52.407819 | controller | - lastHeartbeatTime: '2025-10-02T21:11:49Z' 2025-10-02 21:12:52.408021 | controller | lastTransitionTime: '2025-10-02T21:11:49Z' 2025-10-02 21:12:52.408153 | controller | message: Policy is progressing 0/1 nodes finished 2025-10-02 21:12:52.408306 | controller | reason: ConfigurationProgressing 2025-10-02 21:12:52.408488 | controller | status: 'True' 2025-10-02 21:12:52.408647 | controller | type: Progressing 2025-10-02 21:12:52.408797 | controller | lastUnavailableNodeCountUpdate: '2025-10-02T21:11:49Z' 2025-10-02 21:12:52.408957 | controller | unavailableNodeCount: 1 2025-10-02 21:12:52.409235 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (6 retries left). 2025-10-02 21:12:52.409437 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (5 retries left). 2025-10-02 21:12:52.409606 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (4 retries left). 2025-10-02 21:12:52.409774 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (3 retries left). 2025-10-02 21:12:52.409944 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (2 retries left). 2025-10-02 21:12:52.410122 | controller | FAILED - RETRYING: [instance]: Wait for nsmtate nncp to be ready (1 retries left). 2025-10-02 21:12:52.410279 | controller | 2025-10-02 21:12:52.410446 | controller | PLAY RECAP ********************************************************************* 2025-10-02 21:12:52.410616 | controller | crc : ok=1 changed=0 unreachable=0 failed=0 skipped=0 rescued=0 ignored=0 2025-10-02 21:12:52.410784 | controller | instance : ok=36 changed=15 unreachable=0 failed=1 skipped=10 rescued=0 ignored=0 2025-10-02 21:12:52.410934 | controller | 2025-10-02 21:12:52.411107 | controller | Thursday 02 October 2025 21:12:52 +0000 (0:01:06.133) 0:02:21.283 ****** 2025-10-02 21:12:52.411273 | controller | =============================================================================== 2025-10-02 21:12:52.411439 | controller | ci_nmstate : Wait for nsmtate nncp to be ready ------------------------- 66.13s 2025-10-02 21:12:52.411604 | controller | ci_nmstate : Wait for nsmtate Deployments to be ready ------------------ 31.39s 2025-10-02 21:12:52.411763 | controller | ci_nmstate : Wait for nmstate operator to be installed ----------------- 21.22s 2025-10-02 21:12:52.411919 | controller | Fetch crc network facts ------------------------------------------------- 6.72s 2025-10-02 21:12:52.412121 | controller | ci_nmstate : Create the OLM subscription resources ---------------------- 1.52s 2025-10-02 21:12:52.412289 | controller | Gathering Facts --------------------------------------------------------- 1.12s 2025-10-02 21:12:52.412459 | controller | ci_nmstate : Wait for nsmtate DaemonSet to be ready --------------------- 1.11s 2025-10-02 21:12:52.412613 | controller | ci_nmstate : Get k8s nodes ---------------------------------------------- 1.02s 2025-10-02 21:12:52.412788 | controller | ci_nmstate : Create the nmstate namespace ------------------------------- 1.00s 2025-10-02 21:12:52.412951 | controller | ci_nmstate : Provision nmstate nncp for the node worker ----------------- 0.93s 2025-10-02 21:12:52.413103 | controller | ci_nmstate : Save k8s nmstate OLM manifests as artifacts ---------------- 0.89s 2025-10-02 21:12:52.413297 | controller | ci_nmstate : Trigger nmstate operator to install nmstate ---------------- 0.88s 2025-10-02 21:12:52.413464 | controller | networking_mapper : Save instances refreshed facts for troubleshooting purposes --- 0.78s 2025-10-02 21:12:52.413629 | controller | networking_mapper : Write the Networking Definition to file ------------- 0.62s 2025-10-02 21:12:52.413794 | controller | networking_mapper : Write the Networking Environment Definition to file --- 0.58s 2025-10-02 21:12:52.413959 | controller | Add a dummy ethernet interface to target the crc NMstate ---------------- 0.55s 2025-10-02 21:12:52.414115 | controller | ci_nmstate : Save k8s nmstate nncp manifests as artifacts --------------- 0.51s 2025-10-02 21:12:52.414288 | controller | networking_mapper : Ensure CI infrastructure dir exists ----------------- 0.45s 2025-10-02 21:12:52.414461 | controller | recognize_ssh_keypair : Check if id_ed25519 key exists ------------------ 0.42s 2025-10-02 21:12:52.414626 | controller | ci_nmstate : Save nmstate operator config as an artifact ---------------- 0.41s 2025-10-02 21:12:52.491109 | controller | CRITICAL Ansible return code was 2, command was: ['ansible-playbook', '--inventory', '/home/zuul/.cache/molecule/ci_nmstate/default/inventory', '--skip-tags', 'molecule-notest,notest', '/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/ci_nmstate/molecule/default/converge.yml'] 2025-10-02 21:12:52.491910 | controller | WARNING An error occurred during the test sequence action: 'converge'. Cleaning up. 2025-10-02 21:12:52.511274 | controller | INFO Running default > cleanup 2025-10-02 21:12:52.512207 | controller | WARNING Skipping, cleanup playbook not configured. 2025-10-02 21:12:52.523562 | controller | INFO Running default > destroy 2025-10-02 21:12:52.523952 | controller | WARNING Skipping, instances are delegated. 2025-10-02 21:12:52.524405 | controller | INFO Pruning extra files from scenario ephemeral directory 2025-10-02 21:12:52.526361 | controller | INFO Writing /tmp/report.html report. 2025-10-02 21:12:52.639994 | controller | ERROR 2025-10-02 21:12:52.640332 | controller | { 2025-10-02 21:12:52.640400 | controller | "delta": "0:03:41.218532", 2025-10-02 21:12:52.640447 | controller | "end": "2025-10-02 21:12:52.582423", 2025-10-02 21:12:52.640492 | controller | "msg": "non-zero return code", 2025-10-02 21:12:52.640531 | controller | "rc": 1, 2025-10-02 21:12:52.640579 | controller | "start": "2025-10-02 21:09:11.363891" 2025-10-02 21:12:52.640622 | controller | } failure 2025-10-02 21:12:52.654890 | 2025-10-02 21:12:52.655111 | PLAY RECAP 2025-10-02 21:12:52.655203 | controller | ok: 1 changed: 0 unreachable: 0 failed: 1 skipped: 1 rescued: 0 ignored: 0 2025-10-02 21:12:52.655254 | 2025-10-02 21:12:52.769842 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main] 2025-10-02 21:12:52.771704 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main] 2025-10-02 21:12:53.367042 | 2025-10-02 21:12:53.367143 | PLAY [Run ci/playbooks/collect-logs.yml] 2025-10-02 21:12:53.387849 | 2025-10-02 21:12:53.387937 | TASK [Filter out host if needed] 2025-10-02 21:12:53.396501 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller 2025-10-02 21:12:53.401124 | 2025-10-02 21:12:53.401188 | TASK [Ensure file is present] 2025-10-02 21:12:53.931077 | controller | ok 2025-10-02 21:12:53.943588 | 2025-10-02 21:12:53.943744 | TASK [Manage molecule report file] 2025-10-02 21:12:54.496966 | controller | changed 2025-10-02 21:12:54.507939 | 2025-10-02 21:12:54.508103 | TASK [Check if we get ci-framework-data basedir] 2025-10-02 21:12:54.838639 | controller | ok 2025-10-02 21:12:54.850892 | 2025-10-02 21:12:54.851053 | TASK [Create ci-framework-data log directory for zuul] 2025-10-02 21:12:55.353857 | controller | changed 2025-10-02 21:12:55.363645 | 2025-10-02 21:12:55.363763 | TASK [Copy ci-framework interesting files] 2025-10-02 21:12:55.758926 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory 2025-10-02 21:12:55.910586 | controller | changed 2025-10-02 21:12:55.924061 | 2025-10-02 21:12:55.924212 | TASK [Get SELinux listing] 2025-10-02 21:12:56.468199 | controller | changed 2025-10-02 21:12:56.481758 | 2025-10-02 21:12:56.481914 | TASK [Generate log index] 2025-10-02 21:12:57.928388 | controller | changed 2025-10-02 21:12:57.935545 | 2025-10-02 21:12:57.935641 | TASK [Get some env related data] 2025-10-02 21:12:58.805747 | controller | /home/zuul/.local/bin/ansible 2025-10-02 21:12:59.470737 | controller | changed 2025-10-02 21:12:59.516680 | 2025-10-02 21:12:59.516828 | TASK [Generate list of logs to collect in home directory] 2025-10-02 21:13:00.024787 | controller | ok: All paths examined 2025-10-02 21:13:00.037234 | 2025-10-02 21:13:00.037383 | LOOP [Copy logs from home directory] 2025-10-02 21:13:01.068164 | controller | changed: 2025-10-02 21:13:01.068577 | controller | { 2025-10-02 21:13:01.068645 | controller | "atime": 1743544925.4788878, 2025-10-02 21:13:01.068695 | controller | "ctime": 1743545329.1409318, 2025-10-02 21:13:01.068741 | controller | "dev": 64513, 2025-10-02 21:13:01.068780 | controller | "gid": 1000, 2025-10-02 21:13:01.068825 | controller | "gr_name": "zuul", 2025-10-02 21:13:01.068869 | controller | "inode": 4518807, 2025-10-02 21:13:01.068912 | controller | "isblk": false, 2025-10-02 21:13:01.068954 | controller | "ischr": false, 2025-10-02 21:13:01.069006 | controller | "isdir": false, 2025-10-02 21:13:01.069097 | controller | "isfifo": false, 2025-10-02 21:13:01.069143 | controller | "isgid": false, 2025-10-02 21:13:01.069184 | controller | "islnk": false, 2025-10-02 21:13:01.069226 | controller | "isreg": true, 2025-10-02 21:13:01.069266 | controller | "issock": false, 2025-10-02 21:13:01.069307 | controller | "isuid": false, 2025-10-02 21:13:01.069347 | controller | "mode": "0644", 2025-10-02 21:13:01.069387 | controller | "mtime": 1743545329.1409318, 2025-10-02 21:13:01.069428 | controller | "nlink": 1, 2025-10-02 21:13:01.069468 | controller | "path": "/home/zuul/crc-setup.log", 2025-10-02 21:13:01.069540 | controller | "pw_name": "zuul", 2025-10-02 21:13:01.069585 | controller | "rgrp": true, 2025-10-02 21:13:01.069628 | controller | "roth": true, 2025-10-02 21:13:01.069670 | controller | "rusr": true, 2025-10-02 21:13:01.069711 | controller | "size": 4108, 2025-10-02 21:13:01.069752 | controller | "uid": 1000, 2025-10-02 21:13:01.069792 | controller | "wgrp": false, 2025-10-02 21:13:01.069833 | controller | "woth": false, 2025-10-02 21:13:01.069878 | controller | "wusr": true, 2025-10-02 21:13:01.069921 | controller | "xgrp": false, 2025-10-02 21:13:01.069964 | controller | "xoth": false, 2025-10-02 21:13:01.070005 | controller | "xusr": false 2025-10-02 21:13:01.070112 | controller | } 2025-10-02 21:13:01.890340 | controller | changed: 2025-10-02 21:13:01.890441 | controller | { 2025-10-02 21:13:01.890465 | controller | "atime": 1759438670.573964, 2025-10-02 21:13:01.890483 | controller | "ctime": 1759438668.334901, 2025-10-02 21:13:01.890500 | controller | "dev": 64513, 2025-10-02 21:13:01.890517 | controller | "gid": 1000, 2025-10-02 21:13:01.890533 | controller | "gr_name": "zuul", 2025-10-02 21:13:01.890733 | controller | "inode": 4194437, 2025-10-02 21:13:01.890758 | controller | "isblk": false, 2025-10-02 21:13:01.890775 | controller | "ischr": false, 2025-10-02 21:13:01.890791 | controller | "isdir": false, 2025-10-02 21:13:01.890806 | controller | "isfifo": false, 2025-10-02 21:13:01.890821 | controller | "isgid": false, 2025-10-02 21:13:01.890835 | controller | "islnk": false, 2025-10-02 21:13:01.890850 | controller | "isreg": true, 2025-10-02 21:13:01.890866 | controller | "issock": false, 2025-10-02 21:13:01.890881 | controller | "isuid": false, 2025-10-02 21:13:01.890895 | controller | "mode": "0644", 2025-10-02 21:13:01.890911 | controller | "mtime": 1759438668.334901, 2025-10-02 21:13:01.890926 | controller | "nlink": 1, 2025-10-02 21:13:01.890942 | controller | "path": "/home/zuul/crc-start.log", 2025-10-02 21:13:01.890957 | controller | "pw_name": "zuul", 2025-10-02 21:13:01.890973 | controller | "rgrp": true, 2025-10-02 21:13:01.890989 | controller | "roth": true, 2025-10-02 21:13:01.891004 | controller | "rusr": true, 2025-10-02 21:13:01.891040 | controller | "size": 3404, 2025-10-02 21:13:01.891073 | controller | "uid": 1000, 2025-10-02 21:13:01.891091 | controller | "wgrp": false, 2025-10-02 21:13:01.891112 | controller | "woth": false, 2025-10-02 21:13:01.891127 | controller | "wusr": true, 2025-10-02 21:13:01.891142 | controller | "xgrp": false, 2025-10-02 21:13:01.891157 | controller | "xoth": false, 2025-10-02 21:13:01.891173 | controller | "xusr": false 2025-10-02 21:13:01.891188 | controller | } 2025-10-02 21:13:02.599371 | controller | changed: 2025-10-02 21:13:02.599514 | controller | { 2025-10-02 21:13:02.599566 | controller | "atime": 1759439331.6546452, 2025-10-02 21:13:02.599609 | controller | "ctime": 1759439348.6201236, 2025-10-02 21:13:02.599646 | controller | "dev": 64513, 2025-10-02 21:13:02.599684 | controller | "gid": 1000, 2025-10-02 21:13:02.599719 | controller | "gr_name": "zuul", 2025-10-02 21:13:02.599754 | controller | "inode": 4685800, 2025-10-02 21:13:02.599789 | controller | "isblk": false, 2025-10-02 21:13:02.599823 | controller | "ischr": false, 2025-10-02 21:13:02.599871 | controller | "isdir": false, 2025-10-02 21:13:02.599906 | controller | "isfifo": false, 2025-10-02 21:13:02.599938 | controller | "isgid": false, 2025-10-02 21:13:02.599972 | controller | "islnk": false, 2025-10-02 21:13:02.600005 | controller | "isreg": true, 2025-10-02 21:13:02.600108 | controller | "issock": false, 2025-10-02 21:13:02.600146 | controller | "isuid": false, 2025-10-02 21:13:02.600181 | controller | "mode": "0644", 2025-10-02 21:13:02.600217 | controller | "mtime": 1759439348.6201236, 2025-10-02 21:13:02.600251 | controller | "nlink": 1, 2025-10-02 21:13:02.600285 | controller | "path": "/home/zuul/ansible.log", 2025-10-02 21:13:02.600320 | controller | "pw_name": "zuul", 2025-10-02 21:13:02.600354 | controller | "rgrp": true, 2025-10-02 21:13:02.600388 | controller | "roth": true, 2025-10-02 21:13:02.600427 | controller | "rusr": true, 2025-10-02 21:13:02.600467 | controller | "size": 6749, 2025-10-02 21:13:02.600502 | controller | "uid": 1000, 2025-10-02 21:13:02.600538 | controller | "wgrp": false, 2025-10-02 21:13:02.600572 | controller | "woth": false, 2025-10-02 21:13:02.600606 | controller | "wusr": true, 2025-10-02 21:13:02.600641 | controller | "xgrp": false, 2025-10-02 21:13:02.600675 | controller | "xoth": false, 2025-10-02 21:13:02.600710 | controller | "xusr": false 2025-10-02 21:13:02.600744 | controller | } 2025-10-02 21:13:02.615941 | 2025-10-02 21:13:02.616057 | TASK [Copy crio stats log file] 2025-10-02 21:13:02.641197 | controller | skipping: Conditional result was False 2025-10-02 21:13:02.649974 | 2025-10-02 21:13:02.650079 | TASK [Get SELinux related data] 2025-10-02 21:13:03.039454 | controller | 2025-10-02 21:13:03.187831 | controller | ERROR 2025-10-02 21:13:03.188202 | controller | { 2025-10-02 21:13:03.188263 | controller | "delta": "0:00:00.012916", 2025-10-02 21:13:03.188303 | controller | "end": "2025-10-02 21:13:03.040573", 2025-10-02 21:13:03.188338 | controller | "msg": "non-zero return code", 2025-10-02 21:13:03.188372 | controller | "rc": 1, 2025-10-02 21:13:03.188407 | controller | "start": "2025-10-02 21:13:03.027657" 2025-10-02 21:13:03.188440 | controller | } 2025-10-02 21:13:03.188484 | controller | ERROR: Ignoring Errors 2025-10-02 21:13:03.199884 | 2025-10-02 21:13:03.200082 | TASK [Create system configuration directory] 2025-10-02 21:13:03.573678 | controller | changed 2025-10-02 21:13:03.584645 | 2025-10-02 21:13:03.584775 | TASK [Get some of the system configurations] 2025-10-02 21:13:04.135507 | controller | changed 2025-10-02 21:13:04.146699 | 2025-10-02 21:13:04.146823 | TASK [Copy generated documentation if available] 2025-10-02 21:13:04.174268 | controller | skipping: Conditional result was False 2025-10-02 21:13:04.186846 | 2025-10-02 21:13:04.186975 | TASK [Copy generated AsciiDoc documentation if available] 2025-10-02 21:13:04.213783 | controller | skipping: Conditional result was False 2025-10-02 21:13:04.226826 | 2025-10-02 21:13:04.226950 | TASK [Compress logs bigger than 2MB] 2025-10-02 21:13:04.774348 | controller | changed 2025-10-02 21:13:04.781935 | 2025-10-02 21:13:04.782066 | TASK [Copy files from workspace on node] 2025-10-02 21:13:04.804247 | controller | ok 2025-10-02 21:13:04.836976 | 2025-10-02 21:13:04.837177 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-02 21:13:04.862369 | controller | skipping: Conditional result was False 2025-10-02 21:13:04.873559 | 2025-10-02 21:13:04.873729 | TASK [fetch-output : Set log path for single node] 2025-10-02 21:13:04.915773 | controller | ok 2025-10-02 21:13:04.921319 | 2025-10-02 21:13:04.921403 | LOOP [fetch-output : Ensure local output dirs] 2025-10-02 21:13:05.196668 | controller -> localhost | ok: "/var/lib/zuul/builds/8fb77a034eea47af87900f7b49e3027f/work/logs" 2025-10-02 21:13:05.197285 | controller -> localhost | changed: All items complete 2025-10-02 21:13:05.197371 | 2025-10-02 21:13:05.460676 | controller -> localhost | changed: "/var/lib/zuul/builds/8fb77a034eea47af87900f7b49e3027f/work/artifacts" 2025-10-02 21:13:05.694583 | controller -> localhost | changed: "/var/lib/zuul/builds/8fb77a034eea47af87900f7b49e3027f/work/docs" 2025-10-02 21:13:05.704199 | 2025-10-02 21:13:05.704271 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-02 21:13:06.568800 | controller | changed: 2025-10-02 21:13:06.568974 | controller | .d..t...... ./ 2025-10-02 21:13:06.569000 | controller | >f+++++++++ README.html 2025-10-02 21:13:06.569038 | controller | >f+++++++++ ansible-execution.log 2025-10-02 21:13:06.569058 | controller | >f+++++++++ ansible.log 2025-10-02 21:13:06.569075 | controller | >f+++++++++ crc-setup.log 2025-10-02 21:13:06.569092 | controller | >f+++++++++ crc-start.log 2025-10-02 21:13:06.569108 | controller | >f+++++++++ dmesg.log 2025-10-02 21:13:06.569131 | controller | >f+++++++++ installed-pkgs.log 2025-10-02 21:13:06.569148 | controller | >f+++++++++ python.log 2025-10-02 21:13:06.569164 | controller | >f+++++++++ registries.conf 2025-10-02 21:13:06.569180 | controller | >f+++++++++ report.html 2025-10-02 21:13:06.569196 | controller | >f+++++++++ selinux-denials.log 2025-10-02 21:13:06.569212 | controller | >f+++++++++ selinux-listing.log 2025-10-02 21:13:06.569227 | controller | cd+++++++++ ci-framework-data/ 2025-10-02 21:13:06.569243 | controller | cd+++++++++ ci-framework-data/artifacts/ 2025-10-02 21:13:06.569259 | controller | >f+++++++++ ci-framework-data/artifacts/networking-mapper-instances-facts.yml 2025-10-02 21:13:06.569276 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml 2025-10-02 21:13:06.569293 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/ 2025-10-02 21:13:06.569311 | controller | cd+++++++++ ci-framework-data/artifacts/manifests/nmstate/ 2025-10-02 21:13:06.569329 | controller | >f+++++++++ ci-framework-data/artifacts/manifests/nmstate/crc-nncp.yaml 2025-10-02 21:13:06.569344 | controller | >f+++++++++ ci-framework-data/artifacts/manifests/nmstate/nmstate-nmstate-olm.yaml 2025-10-02 21:13:06.569360 | controller | >f+++++++++ ci-framework-data/artifacts/manifests/nmstate/nmstate-operatorgroup-olm.yaml 2025-10-02 21:13:06.569392 | controller | >f+++++++++ ci-framework-data/artifacts/manifests/nmstate/nmstate-subscription-olm.yaml 2025-10-02 21:13:06.569410 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/ 2025-10-02 21:13:06.569427 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml 2025-10-02 21:13:06.569443 | controller | cd+++++++++ ci-framework-data/artifacts/repositories/ 2025-10-02 21:13:06.569459 | controller | >f+++++++++ ci-framework-data/artifacts/repositories/delorean.repo.md5 2025-10-02 21:13:06.569475 | controller | cd+++++++++ ci-framework-data/logs/ 2025-10-02 21:13:06.569491 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log 2025-10-02 21:13:06.569507 | controller | cd+++++++++ registries.conf.d/ 2025-10-02 21:13:06.569522 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf 2025-10-02 21:13:06.569538 | controller | cd+++++++++ system-config/ 2025-10-02 21:13:06.569553 | controller | cd+++++++++ system-config/libvirt/ 2025-10-02 21:13:06.569568 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf 2025-10-02 21:13:06.569584 | controller | >f+++++++++ system-config/libvirt/libvirt.conf 2025-10-02 21:13:06.569599 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf 2025-10-02 21:13:06.569614 | controller | >f+++++++++ system-config/libvirt/network.conf 2025-10-02 21:13:06.569629 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf 2025-10-02 21:13:06.569644 | controller | >f+++++++++ system-config/libvirt/qemu.conf 2025-10-02 21:13:06.569659 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf 2025-10-02 21:13:06.569674 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf 2025-10-02 21:13:06.569689 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf 2025-10-02 21:13:06.569704 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf 2025-10-02 21:13:06.569726 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf 2025-10-02 21:13:06.569741 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf 2025-10-02 21:13:06.569756 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf 2025-10-02 21:13:06.569771 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf 2025-10-02 21:13:06.569786 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf 2025-10-02 21:13:06.569801 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf 2025-10-02 21:13:07.195468 | controller | changed: .d..t...... ./ 2025-10-02 21:13:07.820327 | controller | changed: .d..t...... ./ 2025-10-02 21:13:07.846711 | 2025-10-02 21:13:07.846915 | TASK [Return artifact to Zuul] 2025-10-02 21:13:07.905976 | controller | ok 2025-10-02 21:13:07.946906 | 2025-10-02 21:13:07.946989 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host] 2025-10-02 21:13:07.947135 | 2025-10-02 21:13:07.947172 | PLAY RECAP 2025-10-02 21:13:07.947219 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1 2025-10-02 21:13:07.947246 | 2025-10-02 21:13:08.068268 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main] 2025-10-02 21:13:08.069944 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/dlrn/dlrn-report.yaml@master] 2025-10-02 21:13:08.638203 | 2025-10-02 21:13:08.638306 | PLAY [Report DLRN results after job run] 2025-10-02 21:13:08.659094 | 2025-10-02 21:13:08.659166 | TASK [Report job status to DLRN] 2025-10-02 21:13:08.677863 | controller | ok 2025-10-02 21:13:08.700554 | 2025-10-02 21:13:08.700630 | TASK [dlrn_report : Warning if DLRN is not running] 2025-10-02 21:13:08.755236 | controller | skipping: Conditional result was False 2025-10-02 21:13:08.763054 | 2025-10-02 21:13:08.763148 | TASK [dlrn_report : Install dlrnapi-client shyaml package] 2025-10-02 21:13:08.808576 | controller | skipping: Conditional result was False 2025-10-02 21:13:08.821339 | 2025-10-02 21:13:08.821492 | TASK [dlrn_report : Install kinit related package] 2025-10-02 21:13:08.869153 | controller | skipping: Conditional result was False 2025-10-02 21:13:08.881679 | 2025-10-02 21:13:08.881833 | TASK [dlrn_report : Install dlrn kerberos related packages] 2025-10-02 21:13:08.929401 | controller | skipping: Conditional result was False 2025-10-02 21:13:08.941864 | 2025-10-02 21:13:08.942001 | TASK [Set zuul-log-path fact] 2025-10-02 21:13:08.992701 | controller | skipping: Conditional result was False 2025-10-02 21:13:09.004551 | 2025-10-02 21:13:09.004691 | TASK [dlrn_report : Set the the value of cifmw_repo_setup_promotion when multiple dlrn tags are used] 2025-10-02 21:13:09.053080 | controller | skipping: Conditional result was False 2025-10-02 21:13:09.065841 | 2025-10-02 21:13:09.066070 | TASK [Get hash related data from repo_setup role] 2025-10-02 21:13:09.113847 | controller | skipping: Conditional result was False 2025-10-02 21:13:09.128118 | 2025-10-02 21:13:09.128268 | TASK [dlrn_report : Perform kinit for DLRN kerberos authentication] 2025-10-02 21:13:09.678852 | controller | skipping: Conditional result was False 2025-10-02 21:13:09.693769 | 2025-10-02 21:13:09.693929 | TASK [dlrn_report : Set empty value for dlrnapi password] 2025-10-02 21:13:09.773488 | controller | skipping: Conditional result was False 2025-10-02 21:13:09.786160 | 2025-10-02 21:13:09.786453 | TASK [dlrn_report : Report results to dlrn for the tested hash] 2025-10-02 21:13:10.337261 | controller | skipping: Conditional result was False 2025-10-02 21:13:10.391277 | 2025-10-02 21:13:10.391426 | PLAY RECAP 2025-10-02 21:13:10.391509 | controller | ok: 0 changed: 0 unreachable: 0 failed: 0 skipped: 10 rescued: 0 ignored: 0 2025-10-02 21:13:10.391553 | 2025-10-02 21:13:10.498930 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/dlrn/dlrn-report.yaml@master] 2025-10-02 21:13:10.499721 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 21:13:11.058043 | 2025-10-02 21:13:11.058208 | PLAY [all] 2025-10-02 21:13:11.077654 | 2025-10-02 21:13:11.077738 | TASK [include_role : fetch-output] 2025-10-02 21:13:11.117324 | controller | ok 2025-10-02 21:13:11.134800 | 2025-10-02 21:13:11.134888 | TASK [fetch-output : Set log path for multiple nodes] 2025-10-02 21:13:11.199606 | controller | skipping: Conditional result was False 2025-10-02 21:13:11.205304 | 2025-10-02 21:13:11.205371 | TASK [fetch-output : Set log path for single node] 2025-10-02 21:13:11.244753 | controller | ok 2025-10-02 21:13:11.251203 | 2025-10-02 21:13:11.251298 | LOOP [fetch-output : Ensure local output dirs] 2025-10-02 21:13:11.649809 | controller -> localhost | ok: "/var/lib/zuul/builds/8fb77a034eea47af87900f7b49e3027f/work/logs" 2025-10-02 21:13:11.879663 | controller -> localhost | ok: "/var/lib/zuul/builds/8fb77a034eea47af87900f7b49e3027f/work/artifacts" 2025-10-02 21:13:12.145289 | controller -> localhost | ok: "/var/lib/zuul/builds/8fb77a034eea47af87900f7b49e3027f/work/docs" 2025-10-02 21:13:12.167865 | 2025-10-02 21:13:12.168162 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-10-02 21:13:12.990565 | controller | ok 2025-10-02 21:13:12.990893 | controller | ok: All items complete 2025-10-02 21:13:12.990952 | 2025-10-02 21:13:13.552156 | controller | ok 2025-10-02 21:13:14.129332 | controller | ok 2025-10-02 21:13:14.163548 | 2025-10-02 21:13:14.163753 | TASK [include_role : fetch-output-openshift] 2025-10-02 21:13:14.190618 | controller | skipping: Conditional result was False 2025-10-02 21:13:14.204207 | 2025-10-02 21:13:14.204360 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-10-02 21:13:14.680358 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.012583 2025-10-02 21:13:14.933735 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.013415 2025-10-02 21:13:14.987222 | 2025-10-02 21:13:14.987381 | PLAY [all] 2025-10-02 21:13:15.008322 | 2025-10-02 21:13:15.008437 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-10-02 21:13:15.576507 | controller | changed 2025-10-02 21:13:15.623162 | 2025-10-02 21:13:15.623277 | PLAY RECAP 2025-10-02 21:13:15.623331 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-10-02 21:13:15.623358 | 2025-10-02 21:13:15.721498 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-10-02 21:13:15.723090 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-10-02 21:13:16.365854 | 2025-10-02 21:13:16.365967 | PLAY [localhost] 2025-10-02 21:13:16.383856 | 2025-10-02 21:13:16.383941 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-10-02 21:13:16.806079 | localhost | changed 2025-10-02 21:13:16.817316 | 2025-10-02 21:13:16.817500 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-10-02 21:13:16.844704 | localhost | ok 2025-10-02 21:13:16.862471 | 2025-10-02 21:13:16.862636 | TASK [add-fileserver : Create SSH private key tempfile] 2025-10-02 21:13:17.219864 | localhost | changed 2025-10-02 21:13:17.227777 | 2025-10-02 21:13:17.227875 | TASK [add-fileserver : Create SSH private key from secret] 2025-10-02 21:13:17.873817 | localhost | changed 2025-10-02 21:13:17.884937 | 2025-10-02 21:13:17.885133 | TASK [add-fileserver : Add fileserver ssh key] 2025-10-02 21:13:18.345843 | localhost | Identity added: /var/lib/zuul/builds/8fb77a034eea47af87900f7b49e3027f/work/tmp/ansible.il92tpf8 (/var/lib/zuul/builds/8fb77a034eea47af87900f7b49e3027f/work/tmp/ansible.il92tpf8) 2025-10-02 21:13:18.346097 | localhost | ok: Runtime: 0:00:00.012992 2025-10-02 21:13:18.351893 | 2025-10-02 21:13:18.351972 | TASK [add-fileserver : Remove SSH private key from disk] 2025-10-02 21:13:18.670512 | localhost | ok: Runtime: 0:00:00.008183 2025-10-02 21:13:18.678274 | 2025-10-02 21:13:18.678408 | TASK [add-fileserver : Add fileserver to inventory] 2025-10-02 21:13:18.761621 | localhost | changed 2025-10-02 21:13:18.767436 | 2025-10-02 21:13:18.767540 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-10-02 21:13:19.214611 | localhost | changed 2025-10-02 21:13:19.234869 | 2025-10-02 21:13:19.234952 | PLAY [localhost] 2025-10-02 21:13:19.247232 | 2025-10-02 21:13:19.247292 | TASK [Generate bulk log download script] 2025-10-02 21:13:19.266230 | localhost | ok 2025-10-02 21:13:19.277759 | 2025-10-02 21:13:19.277824 | TASK [local-log-download : Check API endpoint is defined] 2025-10-02 21:13:19.325159 | localhost | ok: All assertions passed 2025-10-02 21:13:19.329617 | 2025-10-02 21:13:19.329680 | TASK [local-log-download : Create download script] 2025-10-02 21:13:19.799883 | localhost -> localhost | changed 2025-10-02 21:13:19.808650 | 2025-10-02 21:13:19.808713 | TASK [Register quick-download link] 2025-10-02 21:13:19.837357 | localhost | ok 2025-10-02 21:13:19.874004 | 2025-10-02 21:13:19.874119 | PLAY [logserver.rdoproject.org] 2025-10-02 21:13:19.883192 | 2025-10-02 21:13:19.883249 | TASK [Set zuul-log-path fact] 2025-10-02 21:13:19.899443 | logserver.rdoproject.org | ok 2025-10-02 21:13:19.908107 | 2025-10-02 21:13:19.908186 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-10-02 21:13:19.944765 | logserver.rdoproject.org | ok 2025-10-02 21:13:19.949753 | 2025-10-02 21:13:19.949813 | TASK [upload-logs : Create log directories] 2025-10-02 21:13:20.886650 | logserver.rdoproject.org | changed 2025-10-02 21:13:20.893487 | 2025-10-02 21:13:20.893620 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-10-02 21:13:21.186351 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.009266 2025-10-02 21:13:21.196235 | 2025-10-02 21:13:21.196373 | TASK [upload-logs : Upload logs to log server] 2025-10-02 21:13:21.943681 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-10-02 21:13:21.950137 | 2025-10-02 21:13:21.950273 | LOOP [upload-logs : Compress console log and json output] 2025-10-02 21:13:22.014373 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 21:13:22.025513 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 21:13:22.036978 | 2025-10-02 21:13:22.037179 | LOOP [upload-logs : Upload compressed console log and json output] 2025-10-02 21:13:22.083764 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 21:13:22.084222 | 2025-10-02 21:13:22.086912 | logserver.rdoproject.org | skipping: Conditional result was False 2025-10-02 21:13:22.102957 | 2025-10-02 21:13:22.103287 | LOOP [upload-logs : Upload console log and json output]