2025-12-05 07:59:57.532197 | Job console starting... 2025-12-05 07:59:57.742915 | Updating repositories 2025-12-05 07:59:58.544566 | Preparing job workspace 2025-12-05 08:00:07.373968 | Running Ansible setup... 2025-12-05 08:00:10.261243 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 08:00:10.769792 | 2025-12-05 08:00:10.769886 | PLAY [localhost] 2025-12-05 08:00:10.778145 | 2025-12-05 08:00:10.778215 | TASK [Gathering Facts] 2025-12-05 08:00:11.565061 | localhost | ok 2025-12-05 08:00:11.578324 | 2025-12-05 08:00:11.578405 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2025-12-05 08:00:11.918361 | localhost -> localhost | changed 2025-12-05 08:00:11.923873 | 2025-12-05 08:00:11.923957 | TASK [log-inventory : Copy ansible inventory to logs dir] 2025-12-05 08:00:12.620830 | localhost -> localhost | changed 2025-12-05 08:00:12.628959 | 2025-12-05 08:00:12.629028 | TASK [Setup log path fact] 2025-12-05 08:00:12.645970 | localhost | ok 2025-12-05 08:00:12.657349 | 2025-12-05 08:00:12.657418 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 08:00:12.674222 | localhost | ok 2025-12-05 08:00:12.681712 | 2025-12-05 08:00:12.681781 | TASK [emit-job-header : Print job information] 2025-12-05 08:00:12.709232 | # Job Information 2025-12-05 08:00:12.709353 | Ansible Version: 2.15.12 2025-12-05 08:00:12.709384 | Job: cifmw-molecule-test_operator 2025-12-05 08:00:12.709407 | Pipeline: github-check 2025-12-05 08:00:12.709427 | Executor: ibm-bm3-ze.softwarefactory-project.io 2025-12-05 08:00:12.709447 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3533 2025-12-05 08:00:12.709466 | Log URL (when completed): https://logserver.rdoproject.org/2bf/rdoproject.org/2bfed13692af4e8d9668c54288568b91/ 2025-12-05 08:00:12.709485 | Event ID: 3db02a50-d1b0-11f0-9846-5651ce46395f 2025-12-05 08:00:12.713259 | 2025-12-05 08:00:12.713328 | LOOP [emit-job-header : Print node information] 2025-12-05 08:00:12.795612 | localhost | ok: 2025-12-05 08:00:12.795776 | localhost | # Node Information 2025-12-05 08:00:12.795807 | localhost | Inventory Hostname: controller 2025-12-05 08:00:12.795833 | localhost | Hostname: np0005546479 2025-12-05 08:00:12.795856 | localhost | Username: zuul 2025-12-05 08:00:12.795878 | localhost | Distro: CentOS 9 2025-12-05 08:00:12.795898 | localhost | Provider: ibm-bm3-nodepool 2025-12-05 08:00:12.795916 | localhost | Region: regionOne 2025-12-05 08:00:12.795934 | localhost | Label: cloud-centos-9-stream-tripleo-ibm 2025-12-05 08:00:12.795953 | localhost | Product Name: OpenStack Compute 2025-12-05 08:00:12.795971 | localhost | Interface IP: 192.168.25.83 2025-12-05 08:00:12.815625 | 2025-12-05 08:00:12.815725 | PLAY [all] 2025-12-05 08:00:12.821838 | 2025-12-05 08:00:12.821908 | TASK [Gather network facts] 2025-12-05 08:00:13.160760 | controller | ok 2025-12-05 08:00:13.174520 | 2025-12-05 08:00:13.174585 | TASK [include_role : start-zuul-console] 2025-12-05 08:00:13.191855 | controller | ok 2025-12-05 08:00:13.203822 | 2025-12-05 08:00:13.203889 | TASK [start-zuul-console : Start zuul_console daemon.] 2025-12-05 08:00:13.504422 | controller | ok 2025-12-05 08:00:13.517861 | 2025-12-05 08:00:13.517962 | TASK [include_role : add-build-sshkey] 2025-12-05 08:00:13.536236 | controller | ok 2025-12-05 08:00:13.548712 | 2025-12-05 08:00:13.548778 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2025-12-05 08:00:13.746082 | controller -> localhost | ok 2025-12-05 08:00:13.751671 | 2025-12-05 08:00:13.751739 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2025-12-05 08:00:13.769148 | controller | ok 2025-12-05 08:00:13.790380 | controller | included: /var/lib/zuul/builds/2bfed13692af4e8d9668c54288568b91/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2025-12-05 08:00:13.796290 | 2025-12-05 08:00:13.796357 | TASK [add-build-sshkey : Create Temp SSH key] 2025-12-05 08:00:14.481013 | controller -> localhost | Generating public/private rsa key pair. 2025-12-05 08:00:14.481181 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/2bfed13692af4e8d9668c54288568b91/work/2bfed13692af4e8d9668c54288568b91_id_rsa. 2025-12-05 08:00:14.481216 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/2bfed13692af4e8d9668c54288568b91/work/2bfed13692af4e8d9668c54288568b91_id_rsa.pub. 2025-12-05 08:00:14.481242 | controller -> localhost | The key fingerprint is: 2025-12-05 08:00:14.481280 | controller -> localhost | SHA256:WqS2kff0BxOisUmD4tULGbHpQVvVwb6iEInGNbEFV84 zuul-build-sshkey 2025-12-05 08:00:14.481305 | controller -> localhost | The key's randomart image is: 2025-12-05 08:00:14.481327 | controller -> localhost | +---[RSA 3072]----+ 2025-12-05 08:00:14.481348 | controller -> localhost | | *++ooo.. | 2025-12-05 08:00:14.481369 | controller -> localhost | | .o& o o | 2025-12-05 08:00:14.481390 | controller -> localhost | | ..o@o* E.. | 2025-12-05 08:00:14.481411 | controller -> localhost | | .++oB B ... | 2025-12-05 08:00:14.481430 | controller -> localhost | | .. *.S . o. | 2025-12-05 08:00:14.481449 | controller -> localhost | | ..* o...o | 2025-12-05 08:00:14.481468 | controller -> localhost | | o. .... . | 2025-12-05 08:00:14.481489 | controller -> localhost | | . . | 2025-12-05 08:00:14.481507 | controller -> localhost | | | 2025-12-05 08:00:14.481526 | controller -> localhost | +----[SHA256]-----+ 2025-12-05 08:00:14.481567 | controller -> localhost | ok: Runtime: 0:00:00.333053 2025-12-05 08:00:14.487067 | 2025-12-05 08:00:14.487127 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2025-12-05 08:00:14.514379 | controller | ok 2025-12-05 08:00:14.524088 | controller | included: /var/lib/zuul/builds/2bfed13692af4e8d9668c54288568b91/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2025-12-05 08:00:14.532277 | 2025-12-05 08:00:14.532342 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2025-12-05 08:00:14.545685 | controller | skipping: Conditional result was False 2025-12-05 08:00:14.550800 | 2025-12-05 08:00:14.550867 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2025-12-05 08:00:14.893031 | controller | changed 2025-12-05 08:00:14.897843 | 2025-12-05 08:00:14.897912 | TASK [add-build-sshkey : Make sure user has a .ssh] 2025-12-05 08:00:15.088585 | controller | ok 2025-12-05 08:00:15.093522 | 2025-12-05 08:00:15.093590 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2025-12-05 08:00:15.618733 | controller | changed 2025-12-05 08:00:15.624171 | 2025-12-05 08:00:15.624256 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2025-12-05 08:00:16.131410 | controller | changed 2025-12-05 08:00:16.136441 | 2025-12-05 08:00:16.136511 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2025-12-05 08:00:16.149801 | controller | skipping: Conditional result was False 2025-12-05 08:00:16.156288 | 2025-12-05 08:00:16.156359 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2025-12-05 08:00:16.470773 | controller -> localhost | changed 2025-12-05 08:00:16.480060 | 2025-12-05 08:00:16.480130 | TASK [add-build-sshkey : Add back temp key] 2025-12-05 08:00:16.701140 | controller -> localhost | Identity added: /var/lib/zuul/builds/2bfed13692af4e8d9668c54288568b91/work/2bfed13692af4e8d9668c54288568b91_id_rsa (zuul-build-sshkey) 2025-12-05 08:00:16.701321 | controller -> localhost | ok: Runtime: 0:00:00.006358 2025-12-05 08:00:16.706758 | 2025-12-05 08:00:16.706823 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2025-12-05 08:00:16.988023 | controller | ok 2025-12-05 08:00:16.992561 | 2025-12-05 08:00:16.992629 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2025-12-05 08:00:17.016233 | controller | skipping: Conditional result was False 2025-12-05 08:00:17.026117 | 2025-12-05 08:00:17.026291 | TASK [include_role : validate-host] 2025-12-05 08:00:17.043475 | controller | ok 2025-12-05 08:00:17.062386 | 2025-12-05 08:00:17.062454 | TASK [validate-host : Define zuul_info_dir fact] 2025-12-05 08:00:17.089484 | controller | ok 2025-12-05 08:00:17.093801 | 2025-12-05 08:00:17.093865 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2025-12-05 08:00:17.289064 | controller -> localhost | ok 2025-12-05 08:00:17.294722 | 2025-12-05 08:00:17.294789 | TASK [validate-host : Collect information about the host] 2025-12-05 08:00:17.880550 | controller | ok 2025-12-05 08:00:17.888417 | 2025-12-05 08:00:17.888497 | TASK [validate-host : Sanitize hostname] 2025-12-05 08:00:17.977607 | controller | ok 2025-12-05 08:00:17.983364 | 2025-12-05 08:00:17.983434 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2025-12-05 08:00:18.396998 | controller -> localhost | changed 2025-12-05 08:00:18.401790 | 2025-12-05 08:00:18.401854 | TASK [validate-host : Collect information about zuul worker] 2025-12-05 08:00:18.733527 | controller | ok 2025-12-05 08:00:18.738754 | 2025-12-05 08:00:18.738823 | TASK [validate-host : Write out all zuul information for each host] 2025-12-05 08:00:19.087754 | controller -> localhost | changed 2025-12-05 08:00:19.096563 | 2025-12-05 08:00:19.096635 | TASK [include_role : prepare-workspace-openshift] 2025-12-05 08:00:19.109303 | controller | skipping: Conditional result was False 2025-12-05 08:00:19.114232 | 2025-12-05 08:00:19.114308 | TASK [include_role : remove-zuul-sshkey] 2025-12-05 08:00:19.127675 | controller | skipping: Conditional result was False 2025-12-05 08:00:19.132675 | 2025-12-05 08:00:19.132742 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2025-12-05 08:00:19.320620 | controller | ok: "logs" 2025-12-05 08:00:19.320845 | controller | ok: All items complete 2025-12-05 08:00:19.320875 | 2025-12-05 08:00:19.479570 | controller | ok: "artifacts" 2025-12-05 08:00:19.642620 | controller | ok: "docs" 2025-12-05 08:00:19.659289 | 2025-12-05 08:00:19.659385 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2025-12-05 08:00:19.851605 | controller | changed: "logs" 2025-12-05 08:00:20.023191 | controller | changed: "artifacts" 2025-12-05 08:00:20.187479 | controller | changed: "docs" 2025-12-05 08:00:20.211737 | 2025-12-05 08:00:20.211834 | PLAY RECAP 2025-12-05 08:00:20.211880 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-05 08:00:20.211909 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 08:00:20.211928 | 2025-12-05 08:00:20.288239 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master] 2025-12-05 08:00:20.289019 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master] 2025-12-05 08:00:20.856636 | 2025-12-05 08:00:20.856766 | PLAY [all] 2025-12-05 08:00:20.875631 | 2025-12-05 08:00:20.875722 | TASK [mirror-info-fork : Set mirror_fqdn if not defined] 2025-12-05 08:00:20.924262 | controller | ok 2025-12-05 08:00:20.929043 | 2025-12-05 08:00:20.929118 | TASK [mirror-info-fork : Create /etc/ci] 2025-12-05 08:00:21.251549 | controller | changed 2025-12-05 08:00:21.256962 | 2025-12-05 08:00:21.257033 | TASK [mirror-info-fork : Install ci_mirror script] 2025-12-05 08:00:22.033556 | controller | changed 2025-12-05 08:00:22.043215 | 2025-12-05 08:00:22.043294 | LOOP [add-authorized-keys : Enable access via build key on all nodes] 2025-12-05 08:00:22.388088 | controller | changed: 2025-12-05 08:00:22.388409 | controller | { 2025-12-05 08:00:22.388449 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com" 2025-12-05 08:00:22.388488 | controller | } 2025-12-05 08:00:22.578976 | controller | changed: 2025-12-05 08:00:22.579027 | controller | { 2025-12-05 08:00:22.579056 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com" 2025-12-05 08:00:22.579078 | controller | } 2025-12-05 08:00:22.774298 | controller | changed: 2025-12-05 08:00:22.774372 | controller | { 2025-12-05 08:00:22.774399 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com" 2025-12-05 08:00:22.774422 | controller | } 2025-12-05 08:00:22.968413 | controller | changed: 2025-12-05 08:00:22.968585 | controller | { 2025-12-05 08:00:22.968624 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com" 2025-12-05 08:00:22.968672 | controller | } 2025-12-05 08:00:23.161529 | controller | changed: 2025-12-05 08:00:23.161629 | controller | { 2025-12-05 08:00:23.161681 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com" 2025-12-05 08:00:23.161708 | controller | } 2025-12-05 08:00:23.357815 | controller | changed: 2025-12-05 08:00:23.357894 | controller | { 2025-12-05 08:00:23.357925 | controller | "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com" 2025-12-05 08:00:23.357947 | controller | } 2025-12-05 08:00:23.557105 | controller | changed: 2025-12-05 08:00:23.557172 | controller | { 2025-12-05 08:00:23.557201 | 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-12-05 08:00:23.557223 | controller | } 2025-12-05 08:00:23.755032 | controller | changed: 2025-12-05 08:00:23.755116 | controller | { 2025-12-05 08:00:23.755145 | 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-12-05 08:00:23.755167 | controller | } 2025-12-05 08:00:23.949454 | controller | changed: 2025-12-05 08:00:23.949537 | controller | { 2025-12-05 08:00:23.949565 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner" 2025-12-05 08:00:23.949586 | controller | } 2025-12-05 08:00:24.147016 | controller | changed: 2025-12-05 08:00:24.147102 | controller | { 2025-12-05 08:00:24.147130 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com" 2025-12-05 08:00:24.147151 | controller | } 2025-12-05 08:00:24.342389 | controller | changed: 2025-12-05 08:00:24.342462 | controller | { 2025-12-05 08:00:24.342488 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com" 2025-12-05 08:00:24.342509 | controller | } 2025-12-05 08:00:24.555572 | controller | changed: 2025-12-05 08:00:24.555641 | controller | { 2025-12-05 08:00:24.555689 | controller | "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com" 2025-12-05 08:00:24.555712 | controller | } 2025-12-05 08:00:24.736875 | controller | changed: 2025-12-05 08:00:24.736955 | controller | { 2025-12-05 08:00:24.736989 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith" 2025-12-05 08:00:24.737017 | controller | } 2025-12-05 08:00:24.932668 | controller | changed: 2025-12-05 08:00:24.932741 | controller | { 2025-12-05 08:00:24.932768 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel" 2025-12-05 08:00:24.932789 | controller | } 2025-12-05 08:00:25.131949 | controller | changed: 2025-12-05 08:00:25.132026 | controller | { 2025-12-05 08:00:25.132054 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux" 2025-12-05 08:00:25.132076 | controller | } 2025-12-05 08:00:25.332291 | controller | changed: 2025-12-05 08:00:25.332363 | controller | { 2025-12-05 08:00:25.332391 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr" 2025-12-05 08:00:25.332414 | controller | } 2025-12-05 08:00:25.536253 | controller | changed: 2025-12-05 08:00:25.536325 | controller | { 2025-12-05 08:00:25.536351 | 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-12-05 08:00:25.536373 | controller | } 2025-12-05 08:00:25.738573 | controller | changed: 2025-12-05 08:00:25.738742 | controller | { 2025-12-05 08:00:25.738779 | 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-12-05 08:00:25.738811 | controller | } 2025-12-05 08:00:25.939025 | controller | changed: 2025-12-05 08:00:25.939098 | controller | { 2025-12-05 08:00:25.939124 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9" 2025-12-05 08:00:25.939144 | controller | } 2025-12-05 08:00:26.141467 | controller | changed: 2025-12-05 08:00:26.141541 | controller | { 2025-12-05 08:00:26.141568 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora" 2025-12-05 08:00:26.141589 | controller | } 2025-12-05 08:00:26.341998 | controller | changed: 2025-12-05 08:00:26.342080 | controller | { 2025-12-05 08:00:26.342106 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac" 2025-12-05 08:00:26.342126 | controller | } 2025-12-05 08:00:26.550779 | controller | changed: 2025-12-05 08:00:26.550849 | controller | { 2025-12-05 08:00:26.550876 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop" 2025-12-05 08:00:26.550897 | controller | } 2025-12-05 08:00:26.753396 | controller | changed: 2025-12-05 08:00:26.753468 | controller | { 2025-12-05 08:00:26.753496 | 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-12-05 08:00:26.753519 | controller | } 2025-12-05 08:00:26.953972 | controller | changed: 2025-12-05 08:00:26.954045 | controller | { 2025-12-05 08:00:26.954073 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com" 2025-12-05 08:00:26.954095 | controller | } 2025-12-05 08:00:27.159723 | controller | changed: 2025-12-05 08:00:27.159804 | controller | { 2025-12-05 08:00:27.159832 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com" 2025-12-05 08:00:27.159854 | controller | } 2025-12-05 08:00:27.357715 | controller | changed: 2025-12-05 08:00:27.357792 | controller | { 2025-12-05 08:00:27.357820 | controller | "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono" 2025-12-05 08:00:27.357841 | controller | } 2025-12-05 08:00:27.379804 | 2025-12-05 08:00:27.379868 | TASK [Set timezone to UTC] 2025-12-05 08:00:27.755635 | controller | changed: executed `/bin/timedatectl set-timezone UTC` 2025-12-05 08:00:27.760636 | 2025-12-05 08:00:27.760965 | TASK [Create nodepool directory] 2025-12-05 08:00:27.955701 | controller | changed 2025-12-05 08:00:27.961098 | 2025-12-05 08:00:27.961159 | TASK [Create nodepool sub_nodes file] 2025-12-05 08:00:28.435643 | controller | changed 2025-12-05 08:00:28.441965 | 2025-12-05 08:00:28.442033 | TASK [Create nodepool sub_nodes_private file] 2025-12-05 08:00:28.916475 | controller | changed 2025-12-05 08:00:28.921784 | 2025-12-05 08:00:28.921841 | LOOP [Populate nodepool sub_nodes file] 2025-12-05 08:00:28.949868 | 2025-12-05 08:00:28.949984 | LOOP [Populate nodepool sub_nodes_private file] 2025-12-05 08:00:28.978043 | 2025-12-05 08:00:28.978164 | TASK [Create nodepool primary file] 2025-12-05 08:00:29.001695 | controller | skipping: Conditional result was False 2025-12-05 08:00:29.007059 | 2025-12-05 08:00:29.007129 | TASK [Create nodepool node_private for this node] 2025-12-05 08:00:29.519856 | controller | changed 2025-12-05 08:00:29.525130 | 2025-12-05 08:00:29.525204 | LOOP [Copy ssh keys to nodepool directory] 2025-12-05 08:00:29.836778 | controller | ok: Item: id_rsa Runtime: 0:00:00.004309 2025-12-05 08:00:29.836928 | 2025-12-05 08:00:29.995222 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.004171 2025-12-05 08:00:30.011028 | 2025-12-05 08:00:30.011133 | TASK [Add sudoers role for zuul-sudo-grep.sh] 2025-12-05 08:00:30.518755 | controller | changed 2025-12-05 08:00:30.523922 | 2025-12-05 08:00:30.523983 | TASK [Validate sudoers config after edits] 2025-12-05 08:00:30.732512 | controller | /etc/sudoers: parsed OK 2025-12-05 08:00:30.732589 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK 2025-12-05 08:00:30.732600 | controller | /etc/sudoers.d/zuul: parsed OK 2025-12-05 08:00:30.732607 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK 2025-12-05 08:00:31.050434 | controller | ok: Runtime: 0:00:00.005020 2025-12-05 08:00:31.056094 | 2025-12-05 08:00:31.056157 | TASK [Show the environment passed in to job shell scripts] 2025-12-05 08:00:31.252837 | controller | SHELL=/bin/bash 2025-12-05 08:00:31.252883 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework 2025-12-05 08:00:31.252893 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework 2025-12-05 08:00:31.252901 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/34/3534/1088d6d967ec40daf4d458b96d952747a4005ed9^openstack-k8s-operators/ci-framework:main:refs/changes/33/3533/55f01069a17466b830bd3545661d609fcea41e07 2025-12-05 08:00:31.252910 | controller | PWD=/home/zuul 2025-12-05 08:00:31.252915 | controller | ZUUL_PIPELINE=github-check 2025-12-05 08:00:31.252971 | controller | LOGNAME=zuul 2025-12-05 08:00:31.252981 | controller | XDG_SESSION_TYPE=tty 2025-12-05 08:00:31.252987 | controller | _=/usr/bin/env 2025-12-05 08:00:31.252992 | controller | MOTD_SHOWN=pam 2025-12-05 08:00:31.252997 | controller | HOME=/home/zuul 2025-12-05 08:00:31.253003 | controller | LANG=en_US.UTF-8 2025-12-05 08:00:31.253010 | controller | SSH_CONNECTION=192.168.25.12 55822 192.168.25.83 22 2025-12-05 08:00:31.253017 | 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-12-05 08:00:31.253023 | controller | ZUUL_CHANGE_IDS=3534,1088d6d967ec40daf4d458b96d952747a4005ed9 3533,55f01069a17466b830bd3545661d609fcea41e07 2025-12-05 08:00:31.253028 | controller | WORKSPACE=/home/zuul/workspace 2025-12-05 08:00:31.253034 | controller | XDG_SESSION_CLASS=user 2025-12-05 08:00:31.253039 | controller | SELINUX_ROLE_REQUESTED= 2025-12-05 08:00:31.253045 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s 2025-12-05 08:00:31.253050 | controller | USER=zuul 2025-12-05 08:00:31.253055 | controller | ZUUL_VOTING=True 2025-12-05 08:00:31.253061 | controller | BUILD_TIMEOUT=1800000 2025-12-05 08:00:31.253066 | controller | SELINUX_USE_CURRENT_RANGE= 2025-12-05 08:00:31.253071 | controller | SHLVL=1 2025-12-05 08:00:31.253077 | controller | ZUUL_PATCHSET=55f01069a17466b830bd3545661d609fcea41e07 2025-12-05 08:00:31.253082 | controller | XDG_SESSION_ID=1 2025-12-05 08:00:31.253088 | controller | ZUUL_BRANCH=main 2025-12-05 08:00:31.253093 | controller | XDG_RUNTIME_DIR=/run/user/1000 2025-12-05 08:00:31.253099 | controller | SSH_CLIENT=192.168.25.12 55822 22 2025-12-05 08:00:31.253106 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/ 2025-12-05 08:00:31.253112 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima: 2025-12-05 08:00:31.253117 | controller | which_declare=declare -f 2025-12-05 08:00:31.253123 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin 2025-12-05 08:00:31.253129 | controller | SELINUX_LEVEL_REQUESTED= 2025-12-05 08:00:31.253135 | controller | ZUUL_CHANGE=3533 2025-12-05 08:00:31.253140 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus 2025-12-05 08:00:31.253145 | controller | ZUUL_UUID=2bfed13692af4e8d9668c54288568b91 2025-12-05 08:00:31.253151 | controller | BASH_FUNC_which%%=() { ( alias; 2025-12-05 08:00:31.253156 | controller | eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@ 2025-12-05 08:00:31.253161 | controller | } 2025-12-05 08:00:31.579373 | controller | ok: Runtime: 0:00:00.005416 2025-12-05 08:00:31.585046 | 2025-12-05 08:00:31.585114 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars] 2025-12-05 08:00:31.598813 | controller | skipping: Conditional result was False 2025-12-05 08:00:31.604022 | 2025-12-05 08:00:31.604151 | TASK [Symlink /home/zuul-worker/workspace] 2025-12-05 08:00:32.126298 | controller | skipping: Conditional result was False 2025-12-05 08:00:32.132394 | 2025-12-05 08:00:32.132480 | TASK [Ensure legacy workspace directory] 2025-12-05 08:00:32.312863 | controller | changed 2025-12-05 08:00:32.330967 | 2025-12-05 08:00:32.331031 | PLAY RECAP 2025-12-05 08:00:32.331076 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2025-12-05 08:00:32.331099 | 2025-12-05 08:00:32.400739 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master] 2025-12-05 08:00:32.401474 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main] 2025-12-05 08:00:32.916919 | 2025-12-05 08:00:32.917020 | PLAY [Run ci/playbooks/dump_zuul_data.yml] 2025-12-05 08:00:32.936499 | 2025-12-05 08:00:32.936573 | TASK [Create zuul-output directory] 2025-12-05 08:00:33.243311 | controller | changed 2025-12-05 08:00:33.248171 | 2025-12-05 08:00:33.248255 | TASK [Slurp Zuul inventory test] 2025-12-05 08:00:33.514890 | controller -> localhost | ok 2025-12-05 08:00:33.520837 | 2025-12-05 08:00:33.520903 | TASK [Save zuul inventory] 2025-12-05 08:00:34.228576 | controller | changed 2025-12-05 08:00:34.234134 | 2025-12-05 08:00:34.234201 | TASK [Save zuul vars without the change_message] 2025-12-05 08:00:34.818489 | controller | changed 2025-12-05 08:00:34.835679 | 2025-12-05 08:00:34.835775 | PLAY RECAP 2025-12-05 08:00:34.835822 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0 2025-12-05 08:00:34.835846 | 2025-12-05 08:00:34.897150 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main] 2025-12-05 08:00:34.897895 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main] 2025-12-05 08:00:35.424361 | 2025-12-05 08:00:35.424470 | PLAY [Run ci/playbooks/molecule-prepare.yml] 2025-12-05 08:00:35.444198 | 2025-12-05 08:00:35.444277 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh] 2025-12-05 08:00:35.462432 | controller | ok 2025-12-05 08:00:35.478531 | 2025-12-05 08:00:35.478609 | TASK [mirror-info-fork : Set mirror_fqdn if not defined] 2025-12-05 08:00:35.501567 | controller | skipping: Conditional result was False 2025-12-05 08:00:35.507076 | 2025-12-05 08:00:35.507149 | TASK [mirror-info-fork : Create /etc/ci] 2025-12-05 08:00:35.808430 | controller | ok 2025-12-05 08:00:35.813825 | 2025-12-05 08:00:35.813894 | TASK [mirror-info-fork : Install ci_mirror script] 2025-12-05 08:00:36.411045 | controller | ok 2025-12-05 08:00:36.424139 | 2025-12-05 08:00:36.424208 | TASK [Prepare workspace] 2025-12-05 08:00:36.441962 | controller | ok 2025-12-05 08:00:36.458227 | 2025-12-05 08:00:36.458319 | TASK [prepare-workspace : Start zuul_console daemon.] 2025-12-05 08:00:36.749993 | controller | ok 2025-12-05 08:00:36.755799 | 2025-12-05 08:00:36.755870 | TASK [prepare-workspace : Synchronize src repos to workspace directory.] 2025-12-05 08:00:39.129688 | controller | Output suppressed because no_log was given 2025-12-05 08:00:39.138483 | 2025-12-05 08:00:39.138545 | LOOP [Create zuul-output directory] 2025-12-05 08:00:39.319365 | controller | changed: "/home/zuul/ci-framework-data/logs" 2025-12-05 08:00:39.470224 | controller | ok: "/home/zuul/zuul-output/logs" 2025-12-05 08:00:39.485750 | 2025-12-05 08:00:39.485812 | TASK [Install required packages] 2025-12-05 08:01:37.994544 | controller | changed 2025-12-05 08:01:37.999492 | 2025-12-05 08:01:37.999552 | TASK [Install venv] 2025-12-05 08:02:41.774069 | controller | changed 2025-12-05 08:02:41.815943 | 2025-12-05 08:02:41.816013 | PLAY RECAP 2025-12-05 08:02:41.816054 | controller | ok: 7 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-05 08:02:41.816076 | 2025-12-05 08:02:41.874095 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main] 2025-12-05 08:02:41.874915 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main] 2025-12-05 08:02:42.378993 | 2025-12-05 08:02:42.379094 | PLAY [Run ci/playbooks/molecule-test.yml] 2025-12-05 08:02:42.399146 | 2025-12-05 08:02:42.399238 | TASK [Gather required facts] 2025-12-05 08:02:42.863998 | controller | ok 2025-12-05 08:02:42.869181 | 2025-12-05 08:02:42.869275 | TASK [Load environment var if instructed to] 2025-12-05 08:02:42.883406 | controller | skipping: Conditional result was False 2025-12-05 08:02:42.888885 | 2025-12-05 08:02:42.888952 | TASK [Ensure group_vars dir exists] 2025-12-05 08:02:43.189998 | controller | ok 2025-12-05 08:02:43.195784 | 2025-12-05 08:02:43.195851 | TASK [Print related variables] 2025-12-05 08:02:43.223925 | controller | ok: 2025-12-05 08:02:43.224064 | controller | mol_config_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config_local.yml 2025-12-05 08:02:43.224093 | controller | roles_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_operator 2025-12-05 08:02:43.228817 | 2025-12-05 08:02:43.228881 | TASK [Run molecule] 2025-12-05 08:02:44.140003 | controller | INFO Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml 2025-12-05 08:02:44.209715 | controller | INFO Performing prerun with role_name_check=0... 2025-12-05 08:03:00.748538 | controller | WARNING Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/dec929/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections). 2025-12-05 08:03:00.749001 | controller | WARNING Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/dec929/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-12-05 08:03:00.749463 | controller | WARNING Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/dec929/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections). 2025-12-05 08:03:00.749915 | controller | WARNING Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/dec929/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections). 2025-12-05 08:03:00.750442 | controller | WARNING Another version of 'cifmw.general' 1.0.0+35405424 was found installed in /home/zuul/.cache/ansible-compat/dec929/collections/ansible_collections, only the first one will be used, 1.0.0+35405424 (/home/zuul/.ansible/collections/ansible_collections). 2025-12-05 08:03:00.750908 | controller | WARNING Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/dec929/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections). 2025-12-05 08:03:00.751345 | controller | WARNING Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/dec929/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections). 2025-12-05 08:03:00.751824 | controller | WARNING Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/dec929/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections). 2025-12-05 08:03:00.752275 | controller | WARNING Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/dec929/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-12-05 08:03:00.752702 | controller | WARNING Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/dec929/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-12-05 08:03:00.753122 | controller | WARNING Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/dec929/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections). 2025-12-05 08:03:00.753594 | controller | WARNING Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/dec929/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-12-05 08:03:00.754023 | controller | WARNING Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/dec929/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-12-05 08:03:00.754454 | controller | WARNING Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/dec929/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections). 2025-12-05 08:03:00.754905 | controller | WARNING Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/dec929/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections). 2025-12-05 08:03:00.763973 | controller | INFO Running default > prepare 2025-12-05 08:03:01.419150 | controller | 2025-12-05 08:03:01.419212 | controller | PLAY [Converge] **************************************************************** 2025-12-05 08:03:01.419344 | controller | 2025-12-05 08:03:01.419451 | controller | TASK [Gathering Facts] ********************************************************* 2025-12-05 08:03:01.419573 | controller | Friday 05 December 2025 08:03:01 +0000 (0:00:00.012) 0:00:00.012 ******* 2025-12-05 08:03:02.228900 | controller | ok: [instance] 2025-12-05 08:03:02.228990 | controller | 2025-12-05 08:03:02.229122 | controller | TASK [test_operator : Cleanup previous test-operator resources] **************** 2025-12-05 08:03:02.229280 | controller | Friday 05 December 2025 08:03:02 +0000 (0:00:00.810) 0:00:00.822 ******* 2025-12-05 08:03:02.255704 | controller | skipping: [instance] 2025-12-05 08:03:02.255795 | controller | 2025-12-05 08:03:02.255924 | controller | TASK [test_operator : Ensure test_operator folder exists] ********************** 2025-12-05 08:03:02.256048 | controller | Friday 05 December 2025 08:03:02 +0000 (0:00:00.026) 0:00:00.849 ******* 2025-12-05 08:03:02.552134 | controller | changed: [instance] 2025-12-05 08:03:02.552201 | controller | 2025-12-05 08:03:02.552334 | controller | TASK [test_operator : Get openstack-operator csv information] ****************** 2025-12-05 08:03:02.552438 | controller | Friday 05 December 2025 08:03:02 +0000 (0:00:00.296) 0:00:01.145 ******* 2025-12-05 08:03:02.574976 | controller | skipping: [instance] 2025-12-05 08:03:02.575080 | controller | 2025-12-05 08:03:02.575184 | controller | TASK [test_operator : Get full name of openstack-operator CSV] ***************** 2025-12-05 08:03:02.575312 | controller | Friday 05 December 2025 08:03:02 +0000 (0:00:00.022) 0:00:01.168 ******* 2025-12-05 08:03:02.596517 | controller | skipping: [instance] 2025-12-05 08:03:02.596639 | controller | 2025-12-05 08:03:02.596762 | controller | TASK [test_operator : Get index of test-operator image] ************************ 2025-12-05 08:03:02.596878 | controller | Friday 05 December 2025 08:03:02 +0000 (0:00:00.021) 0:00:01.190 ******* 2025-12-05 08:03:02.620394 | controller | skipping: [instance] 2025-12-05 08:03:02.620498 | controller | 2025-12-05 08:03:02.620638 | controller | TASK [test_operator : Patch test-operator version in CSV] ********************** 2025-12-05 08:03:02.620758 | controller | Friday 05 December 2025 08:03:02 +0000 (0:00:00.023) 0:00:01.214 ******* 2025-12-05 08:03:02.642042 | controller | skipping: [instance] 2025-12-05 08:03:02.642148 | controller | 2025-12-05 08:03:02.642278 | controller | TASK [test_operator : Get test-operator-controller-manager pod information] **** 2025-12-05 08:03:02.642386 | controller | Friday 05 December 2025 08:03:02 +0000 (0:00:00.021) 0:00:01.235 ******* 2025-12-05 08:03:02.665066 | controller | skipping: [instance] 2025-12-05 08:03:02.665175 | controller | 2025-12-05 08:03:02.665309 | controller | TASK [test_operator : Get full name of test-operator-controller-manager pod] *** 2025-12-05 08:03:02.665405 | controller | Friday 05 December 2025 08:03:02 +0000 (0:00:00.022) 0:00:01.258 ******* 2025-12-05 08:03:02.687147 | controller | skipping: [instance] 2025-12-05 08:03:02.687270 | controller | 2025-12-05 08:03:02.687389 | controller | TASK [test_operator : Wait until the test-operator-controller-manager is reloaded] *** 2025-12-05 08:03:02.687485 | controller | Friday 05 December 2025 08:03:02 +0000 (0:00:00.022) 0:00:01.280 ******* 2025-12-05 08:03:02.711404 | controller | skipping: [instance] 2025-12-05 08:03:02.711483 | controller | 2025-12-05 08:03:02.711603 | controller | TASK [test_operator : Delete CRDs created by test-operator] ******************** 2025-12-05 08:03:02.711713 | controller | Friday 05 December 2025 08:03:02 +0000 (0:00:00.024) 0:00:01.305 ******* 2025-12-05 08:03:02.751142 | controller | skipping: [instance] => (item=tempests.test.openstack.org) 2025-12-05 08:03:02.751233 | controller | skipping: [instance] => (item=tobikoes.test.openstack.org) 2025-12-05 08:03:02.751362 | controller | skipping: [instance] => (item=ansibletests.test.openstack.org) 2025-12-05 08:03:02.751466 | controller | skipping: [instance] => (item=horizontests.test.openstack.org) 2025-12-05 08:03:02.751583 | controller | skipping: [instance] 2025-12-05 08:03:02.751672 | controller | 2025-12-05 08:03:02.751775 | controller | TASK [test_operator : Clone test-operator repository and checkout into specified version] *** 2025-12-05 08:03:02.751872 | controller | Friday 05 December 2025 08:03:02 +0000 (0:00:00.039) 0:00:01.344 ******* 2025-12-05 08:03:02.773694 | controller | skipping: [instance] 2025-12-05 08:03:02.773771 | controller | 2025-12-05 08:03:02.773992 | controller | TASK [test_operator : Run make generate manifests install from /tmp/test-operator dir] *** 2025-12-05 08:03:02.795442 | controller | Friday 05 December 2025 08:03:02 +0000 (0:00:00.022) 0:00:01.367 ******* 2025-12-05 08:03:02.795470 | controller | skipping: [instance] 2025-12-05 08:03:02.795520 | controller | 2025-12-05 08:03:02.795634 | controller | TASK [test_operator : Call test stages loop] *********************************** 2025-12-05 08:03:02.795732 | controller | Friday 05 December 2025 08:03:02 +0000 (0:00:00.021) 0:00:01.389 ******* 2025-12-05 08:03:02.824760 | controller | skipping: [instance] => (item={'name': 'tempest', 'type': 'tempest'}) 2025-12-05 08:03:02.824835 | controller | skipping: [instance] 2025-12-05 08:03:02.824924 | controller | 2025-12-05 08:03:02.825020 | controller | TASK [test_operator : Fail when any tests failed] ****************************** 2025-12-05 08:03:02.825117 | controller | Friday 05 December 2025 08:03:02 +0000 (0:00:00.029) 0:00:01.418 ******* 2025-12-05 08:03:02.866528 | controller | skipping: [instance] 2025-12-05 08:03:02.866643 | controller | 2025-12-05 08:03:02.866739 | controller | PLAY RECAP ********************************************************************* 2025-12-05 08:03:02.866840 | controller | instance : ok=2 changed=1 unreachable=0 failed=0 skipped=13 rescued=0 ignored=0 2025-12-05 08:03:02.866932 | controller | 2025-12-05 08:03:02.867232 | controller | Friday 05 December 2025 08:03:02 +0000 (0:00:00.041) 0:00:01.460 ******* 2025-12-05 08:03:02.867358 | controller | =============================================================================== 2025-12-05 08:03:02.867448 | controller | Gathering Facts --------------------------------------------------------- 0.81s 2025-12-05 08:03:02.867541 | controller | test_operator : Ensure test_operator folder exists ---------------------- 0.30s 2025-12-05 08:03:02.867646 | controller | test_operator : Fail when any tests failed ------------------------------ 0.04s 2025-12-05 08:03:02.867737 | controller | test_operator : Delete CRDs created by test-operator -------------------- 0.04s 2025-12-05 08:03:02.867825 | controller | test_operator : Call test stages loop ----------------------------------- 0.03s 2025-12-05 08:03:02.867921 | controller | test_operator : Cleanup previous test-operator resources ---------------- 0.03s 2025-12-05 08:03:02.868018 | controller | test_operator : Wait until the test-operator-controller-manager is reloaded --- 0.02s 2025-12-05 08:03:02.868115 | controller | test_operator : Get index of test-operator image ------------------------ 0.02s 2025-12-05 08:03:02.868207 | controller | test_operator : Get test-operator-controller-manager pod information ---- 0.02s 2025-12-05 08:03:02.868338 | controller | test_operator : Get openstack-operator csv information ------------------ 0.02s 2025-12-05 08:03:02.868433 | controller | test_operator : Clone test-operator repository and checkout into specified version --- 0.02s 2025-12-05 08:03:02.868521 | controller | test_operator : Get full name of test-operator-controller-manager pod --- 0.02s 2025-12-05 08:03:02.868625 | controller | test_operator : Patch test-operator version in CSV ---------------------- 0.02s 2025-12-05 08:03:02.868719 | controller | test_operator : Run make generate manifests install from /tmp/test-operator dir --- 0.02s 2025-12-05 08:03:02.868812 | controller | test_operator : Get full name of openstack-operator CSV ----------------- 0.02s 2025-12-05 08:03:02.925898 | controller | INFO Running default > converge 2025-12-05 08:03:03.342315 | controller | 2025-12-05 08:03:03.342373 | controller | PLAY [Converge] **************************************************************** 2025-12-05 08:03:03.342474 | controller | 2025-12-05 08:03:03.342583 | controller | TASK [Gathering Facts] ********************************************************* 2025-12-05 08:03:03.342685 | controller | Friday 05 December 2025 08:03:03 +0000 (0:00:00.015) 0:00:00.015 ******* 2025-12-05 08:03:04.127412 | controller | ok: [instance] 2025-12-05 08:03:04.127508 | controller | 2025-12-05 08:03:04.127649 | controller | TASK [test_operator : Cleanup previous test-operator resources] **************** 2025-12-05 08:03:04.127780 | controller | Friday 05 December 2025 08:03:04 +0000 (0:00:00.785) 0:00:00.800 ******* 2025-12-05 08:03:04.153666 | controller | skipping: [instance] 2025-12-05 08:03:04.153753 | controller | 2025-12-05 08:03:04.153854 | controller | TASK [test_operator : Ensure test_operator folder exists] ********************** 2025-12-05 08:03:04.153955 | controller | Friday 05 December 2025 08:03:04 +0000 (0:00:00.026) 0:00:00.827 ******* 2025-12-05 08:03:04.443466 | controller | ok: [instance] 2025-12-05 08:03:04.443518 | controller | 2025-12-05 08:03:04.443530 | controller | TASK [test_operator : Get openstack-operator csv information] ****************** 2025-12-05 08:03:04.443643 | controller | Friday 05 December 2025 08:03:04 +0000 (0:00:00.289) 0:00:01.116 ******* 2025-12-05 08:03:04.466058 | controller | skipping: [instance] 2025-12-05 08:03:04.466118 | controller | 2025-12-05 08:03:04.466239 | controller | TASK [test_operator : Get full name of openstack-operator CSV] ***************** 2025-12-05 08:03:04.466367 | controller | Friday 05 December 2025 08:03:04 +0000 (0:00:00.022) 0:00:01.139 ******* 2025-12-05 08:03:04.488230 | controller | skipping: [instance] 2025-12-05 08:03:04.488310 | controller | 2025-12-05 08:03:04.488438 | controller | TASK [test_operator : Get index of test-operator image] ************************ 2025-12-05 08:03:04.488526 | controller | Friday 05 December 2025 08:03:04 +0000 (0:00:00.022) 0:00:01.161 ******* 2025-12-05 08:03:04.510723 | controller | skipping: [instance] 2025-12-05 08:03:04.510791 | controller | 2025-12-05 08:03:04.510911 | controller | TASK [test_operator : Patch test-operator version in CSV] ********************** 2025-12-05 08:03:04.511015 | controller | Friday 05 December 2025 08:03:04 +0000 (0:00:00.022) 0:00:01.184 ******* 2025-12-05 08:03:04.532099 | controller | skipping: [instance] 2025-12-05 08:03:04.532183 | controller | 2025-12-05 08:03:04.532305 | controller | TASK [test_operator : Get test-operator-controller-manager pod information] **** 2025-12-05 08:03:04.532437 | controller | Friday 05 December 2025 08:03:04 +0000 (0:00:00.021) 0:00:01.205 ******* 2025-12-05 08:03:04.552391 | controller | skipping: [instance] 2025-12-05 08:03:04.552485 | controller | 2025-12-05 08:03:04.552604 | controller | TASK [test_operator : Get full name of test-operator-controller-manager pod] *** 2025-12-05 08:03:04.552705 | controller | Friday 05 December 2025 08:03:04 +0000 (0:00:00.020) 0:00:01.226 ******* 2025-12-05 08:03:04.572735 | controller | skipping: [instance] 2025-12-05 08:03:04.572793 | controller | 2025-12-05 08:03:04.572885 | controller | TASK [test_operator : Wait until the test-operator-controller-manager is reloaded] *** 2025-12-05 08:03:04.572991 | controller | Friday 05 December 2025 08:03:04 +0000 (0:00:00.020) 0:00:01.246 ******* 2025-12-05 08:03:04.595946 | controller | skipping: [instance] 2025-12-05 08:03:04.596030 | controller | 2025-12-05 08:03:04.596139 | controller | TASK [test_operator : Delete CRDs created by test-operator] ******************** 2025-12-05 08:03:04.596241 | controller | Friday 05 December 2025 08:03:04 +0000 (0:00:00.023) 0:00:01.269 ******* 2025-12-05 08:03:04.634735 | controller | skipping: [instance] => (item=tempests.test.openstack.org) 2025-12-05 08:03:04.634856 | controller | skipping: [instance] => (item=tobikoes.test.openstack.org) 2025-12-05 08:03:04.634975 | controller | skipping: [instance] => (item=ansibletests.test.openstack.org) 2025-12-05 08:03:04.635083 | controller | skipping: [instance] => (item=horizontests.test.openstack.org) 2025-12-05 08:03:04.635179 | controller | skipping: [instance] 2025-12-05 08:03:04.635288 | controller | 2025-12-05 08:03:04.635391 | controller | TASK [test_operator : Clone test-operator repository and checkout into specified version] *** 2025-12-05 08:03:04.635486 | controller | Friday 05 December 2025 08:03:04 +0000 (0:00:00.038) 0:00:01.308 ******* 2025-12-05 08:03:04.656449 | controller | skipping: [instance] 2025-12-05 08:03:04.656539 | controller | 2025-12-05 08:03:04.656662 | controller | TASK [test_operator : Run make generate manifests install from /tmp/test-operator dir] *** 2025-12-05 08:03:04.656767 | controller | Friday 05 December 2025 08:03:04 +0000 (0:00:00.022) 0:00:01.330 ******* 2025-12-05 08:03:04.677944 | controller | skipping: [instance] 2025-12-05 08:03:04.678051 | controller | 2025-12-05 08:03:04.678154 | controller | TASK [test_operator : Call test stages loop] *********************************** 2025-12-05 08:03:04.678277 | controller | Friday 05 December 2025 08:03:04 +0000 (0:00:00.021) 0:00:01.351 ******* 2025-12-05 08:03:04.707368 | controller | skipping: [instance] => (item={'name': 'tempest', 'type': 'tempest'}) 2025-12-05 08:03:04.707497 | controller | skipping: [instance] 2025-12-05 08:03:04.707630 | controller | 2025-12-05 08:03:04.707755 | controller | TASK [test_operator : Fail when any tests failed] ****************************** 2025-12-05 08:03:04.707875 | controller | Friday 05 December 2025 08:03:04 +0000 (0:00:00.029) 0:00:01.380 ******* 2025-12-05 08:03:04.750427 | controller | skipping: [instance] 2025-12-05 08:03:04.750503 | controller | 2025-12-05 08:03:04.750618 | controller | PLAY RECAP ********************************************************************* 2025-12-05 08:03:04.750726 | controller | instance : ok=2 changed=0 unreachable=0 failed=0 skipped=13 rescued=0 ignored=0 2025-12-05 08:03:04.750822 | controller | 2025-12-05 08:03:04.750922 | controller | Friday 05 December 2025 08:03:04 +0000 (0:00:00.043) 0:00:01.423 ******* 2025-12-05 08:03:04.751021 | controller | =============================================================================== 2025-12-05 08:03:04.751113 | controller | Gathering Facts --------------------------------------------------------- 0.79s 2025-12-05 08:03:04.751215 | controller | test_operator : Ensure test_operator folder exists ---------------------- 0.29s 2025-12-05 08:03:04.751337 | controller | test_operator : Fail when any tests failed ------------------------------ 0.04s 2025-12-05 08:03:04.751429 | controller | test_operator : Delete CRDs created by test-operator -------------------- 0.04s 2025-12-05 08:03:04.751520 | controller | test_operator : Call test stages loop ----------------------------------- 0.03s 2025-12-05 08:03:04.751631 | controller | test_operator : Cleanup previous test-operator resources ---------------- 0.03s 2025-12-05 08:03:04.751727 | controller | test_operator : Wait until the test-operator-controller-manager is reloaded --- 0.02s 2025-12-05 08:03:04.751820 | controller | test_operator : Get openstack-operator csv information ------------------ 0.02s 2025-12-05 08:03:04.751910 | controller | test_operator : Get full name of openstack-operator CSV ----------------- 0.02s 2025-12-05 08:03:04.752006 | controller | test_operator : Get index of test-operator image ------------------------ 0.02s 2025-12-05 08:03:04.752102 | controller | test_operator : Clone test-operator repository and checkout into specified version --- 0.02s 2025-12-05 08:03:04.752195 | controller | test_operator : Patch test-operator version in CSV ---------------------- 0.02s 2025-12-05 08:03:04.752346 | controller | test_operator : Run make generate manifests install from /tmp/test-operator dir --- 0.02s 2025-12-05 08:03:04.752404 | controller | test_operator : Get test-operator-controller-manager pod information ---- 0.02s 2025-12-05 08:03:04.752493 | controller | test_operator : Get full name of test-operator-controller-manager pod --- 0.02s 2025-12-05 08:03:04.805036 | controller | INFO Running default > cleanup 2025-12-05 08:03:04.805443 | controller | WARNING Skipping, cleanup playbook not configured. 2025-12-05 08:03:04.806013 | controller | INFO Writing /tmp/report.html report. 2025-12-05 08:03:05.278105 | controller | changed 2025-12-05 08:03:05.296411 | 2025-12-05 08:03:05.296483 | PLAY RECAP 2025-12-05 08:03:05.296529 | controller | ok: 4 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0 2025-12-05 08:03:05.296558 | 2025-12-05 08:03:05.370791 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main] 2025-12-05 08:03:05.371592 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main] 2025-12-05 08:03:05.927543 | 2025-12-05 08:03:05.927770 | PLAY [Run ci/playbooks/collect-logs.yml] 2025-12-05 08:03:05.950506 | 2025-12-05 08:03:05.950602 | TASK [Filter out host if needed] 2025-12-05 08:03:05.959368 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller 2025-12-05 08:03:05.963850 | 2025-12-05 08:03:05.963918 | TASK [Ensure file is present] 2025-12-05 08:03:06.268569 | controller | ok 2025-12-05 08:03:06.276747 | 2025-12-05 08:03:06.276835 | TASK [Manage molecule report file] 2025-12-05 08:03:06.806510 | controller | changed 2025-12-05 08:03:06.813277 | 2025-12-05 08:03:06.813345 | TASK [Check if we get ci-framework-data basedir] 2025-12-05 08:03:07.008283 | controller | ok 2025-12-05 08:03:07.014836 | 2025-12-05 08:03:07.014926 | TASK [Create ci-framework-data log directory for zuul] 2025-12-05 08:03:07.321228 | controller | changed 2025-12-05 08:03:07.327103 | 2025-12-05 08:03:07.327185 | TASK [Copy ci-framework interesting files] 2025-12-05 08:03:07.851400 | controller | changed 2025-12-05 08:03:07.857986 | 2025-12-05 08:03:07.858059 | TASK [Get SELinux listing] 2025-12-05 08:03:08.387914 | controller | changed 2025-12-05 08:03:08.395243 | 2025-12-05 08:03:08.395321 | TASK [Generate log index] 2025-12-05 08:03:09.007406 | controller | changed 2025-12-05 08:03:09.013027 | 2025-12-05 08:03:09.013118 | TASK [Get some env related data] 2025-12-05 08:03:09.535879 | controller | /home/zuul/.local/bin/ansible 2025-12-05 08:03:10.539009 | controller | changed 2025-12-05 08:03:10.545546 | 2025-12-05 08:03:10.545685 | TASK [Generate list of logs to collect in home directory] 2025-12-05 08:03:10.831316 | controller | ok: All paths examined 2025-12-05 08:03:10.836496 | 2025-12-05 08:03:10.836559 | LOOP [Copy logs from home directory] 2025-12-05 08:03:11.160376 | controller | changed: 2025-12-05 08:03:11.160492 | controller | { 2025-12-05 08:03:11.160519 | controller | "atime": 1764921745.588444, 2025-12-05 08:03:11.160539 | controller | "ctime": 1764921761.3425531, 2025-12-05 08:03:11.160557 | controller | "dev": 64513, 2025-12-05 08:03:11.160574 | controller | "gid": 1000, 2025-12-05 08:03:11.160589 | controller | "gr_name": "zuul", 2025-12-05 08:03:11.160605 | controller | "inode": 5091892, 2025-12-05 08:03:11.160621 | controller | "isblk": false, 2025-12-05 08:03:11.160636 | controller | "ischr": false, 2025-12-05 08:03:11.160666 | controller | "isdir": false, 2025-12-05 08:03:11.160689 | controller | "isfifo": false, 2025-12-05 08:03:11.160705 | controller | "isgid": false, 2025-12-05 08:03:11.160720 | controller | "islnk": false, 2025-12-05 08:03:11.160734 | controller | "isreg": true, 2025-12-05 08:03:11.160748 | controller | "issock": false, 2025-12-05 08:03:11.160763 | controller | "isuid": false, 2025-12-05 08:03:11.160777 | controller | "mode": "0644", 2025-12-05 08:03:11.160791 | controller | "mtime": 1764921761.3425531, 2025-12-05 08:03:11.160805 | controller | "nlink": 1, 2025-12-05 08:03:11.160819 | controller | "path": "/home/zuul/ansible.log", 2025-12-05 08:03:11.160833 | controller | "pw_name": "zuul", 2025-12-05 08:03:11.160848 | controller | "rgrp": true, 2025-12-05 08:03:11.160862 | controller | "roth": true, 2025-12-05 08:03:11.160876 | controller | "rusr": true, 2025-12-05 08:03:11.160890 | controller | "size": 6749, 2025-12-05 08:03:11.160904 | controller | "uid": 1000, 2025-12-05 08:03:11.160918 | controller | "wgrp": false, 2025-12-05 08:03:11.160931 | controller | "woth": false, 2025-12-05 08:03:11.160945 | controller | "wusr": true, 2025-12-05 08:03:11.160962 | controller | "xgrp": false, 2025-12-05 08:03:11.160976 | controller | "xoth": false, 2025-12-05 08:03:11.160990 | controller | "xusr": false 2025-12-05 08:03:11.161004 | controller | } 2025-12-05 08:03:11.174886 | 2025-12-05 08:03:11.174985 | TASK [Copy crio stats log file] 2025-12-05 08:03:11.189348 | controller | skipping: Conditional result was False 2025-12-05 08:03:11.195343 | 2025-12-05 08:03:11.195406 | TASK [Get SELinux related data] 2025-12-05 08:03:11.405629 | controller | 2025-12-05 08:03:11.735483 | controller | ERROR 2025-12-05 08:03:11.735645 | controller | { 2025-12-05 08:03:11.735713 | controller | "delta": "0:00:00.006996", 2025-12-05 08:03:11.735738 | controller | "end": "2025-12-05 08:03:11.406034", 2025-12-05 08:03:11.735756 | controller | "msg": "non-zero return code", 2025-12-05 08:03:11.735771 | controller | "rc": 1, 2025-12-05 08:03:11.735787 | controller | "start": "2025-12-05 08:03:11.399038" 2025-12-05 08:03:11.735801 | controller | } 2025-12-05 08:03:11.735822 | controller | ERROR: Ignoring Errors 2025-12-05 08:03:11.740923 | 2025-12-05 08:03:11.740983 | TASK [Create system configuration directory] 2025-12-05 08:03:11.931940 | controller | changed 2025-12-05 08:03:11.936941 | 2025-12-05 08:03:11.937003 | TASK [Get some of the system configurations] 2025-12-05 08:03:12.464649 | controller | changed 2025-12-05 08:03:12.469934 | 2025-12-05 08:03:12.470000 | TASK [Copy generated documentation if available] 2025-12-05 08:03:12.483699 | controller | skipping: Conditional result was False 2025-12-05 08:03:12.489063 | 2025-12-05 08:03:12.489121 | TASK [Copy generated AsciiDoc documentation if available] 2025-12-05 08:03:12.502525 | controller | skipping: Conditional result was False 2025-12-05 08:03:12.508554 | 2025-12-05 08:03:12.508615 | TASK [Compress logs bigger than 2MB] 2025-12-05 08:03:13.033794 | controller | changed 2025-12-05 08:03:13.039410 | 2025-12-05 08:03:13.039477 | TASK [Copy files from workspace on node] 2025-12-05 08:03:13.057816 | controller | ok 2025-12-05 08:03:13.079722 | 2025-12-05 08:03:13.079788 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-05 08:03:13.094007 | controller | skipping: Conditional result was False 2025-12-05 08:03:13.099810 | 2025-12-05 08:03:13.099875 | TASK [fetch-output : Set log path for single node] 2025-12-05 08:03:13.128744 | controller | ok 2025-12-05 08:03:13.134548 | 2025-12-05 08:03:13.134608 | LOOP [fetch-output : Ensure local output dirs] 2025-12-05 08:03:13.357710 | controller -> localhost | ok: "/var/lib/zuul/builds/2bfed13692af4e8d9668c54288568b91/work/logs" 2025-12-05 08:03:13.357933 | controller -> localhost | changed: All items complete 2025-12-05 08:03:13.357966 | 2025-12-05 08:03:13.551307 | controller -> localhost | changed: "/var/lib/zuul/builds/2bfed13692af4e8d9668c54288568b91/work/artifacts" 2025-12-05 08:03:13.756886 | controller -> localhost | changed: "/var/lib/zuul/builds/2bfed13692af4e8d9668c54288568b91/work/docs" 2025-12-05 08:03:13.772389 | 2025-12-05 08:03:13.772456 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-05 08:03:14.374231 | controller | changed: 2025-12-05 08:03:14.374424 | controller | .d..t...... ./ 2025-12-05 08:03:14.374455 | controller | >f+++++++++ README.html 2025-12-05 08:03:14.374477 | controller | >f+++++++++ ansible-execution.log 2025-12-05 08:03:14.374498 | controller | >f+++++++++ ansible.log 2025-12-05 08:03:14.374516 | controller | >f+++++++++ dmesg.log 2025-12-05 08:03:14.374533 | controller | >f+++++++++ installed-pkgs.log 2025-12-05 08:03:14.374550 | controller | >f+++++++++ python.log 2025-12-05 08:03:14.374571 | controller | >f+++++++++ registries.conf 2025-12-05 08:03:14.374590 | controller | >f+++++++++ report.html 2025-12-05 08:03:14.374608 | controller | >f+++++++++ selinux-denials.log 2025-12-05 08:03:14.374627 | controller | >f+++++++++ selinux-listing.log 2025-12-05 08:03:14.374644 | controller | cd+++++++++ ci-framework-data/ 2025-12-05 08:03:14.374687 | controller | cd+++++++++ ci-framework-data/artifacts/ 2025-12-05 08:03:14.374709 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml 2025-12-05 08:03:14.374728 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/ 2025-12-05 08:03:14.374744 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml 2025-12-05 08:03:14.374760 | controller | cd+++++++++ ci-framework-data/logs/ 2025-12-05 08:03:14.374776 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log 2025-12-05 08:03:14.374792 | controller | cd+++++++++ ci-framework-data/tests/ 2025-12-05 08:03:14.374808 | controller | cd+++++++++ ci-framework-data/tests/test_operator/ 2025-12-05 08:03:14.374832 | controller | cd+++++++++ registries.conf.d/ 2025-12-05 08:03:14.374850 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf 2025-12-05 08:03:14.374866 | controller | cd+++++++++ system-config/ 2025-12-05 08:03:14.374882 | controller | cd+++++++++ system-config/libvirt/ 2025-12-05 08:03:14.374898 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf 2025-12-05 08:03:14.374913 | controller | >f+++++++++ system-config/libvirt/libvirt.conf 2025-12-05 08:03:14.746672 | controller | changed: .d..t...... ./ 2025-12-05 08:03:15.133961 | controller | changed: .d..t...... ./ 2025-12-05 08:03:15.148774 | 2025-12-05 08:03:15.148884 | TASK [Return artifact to Zuul] 2025-12-05 08:03:15.178685 | controller | ok 2025-12-05 08:03:15.198359 | 2025-12-05 08:03:15.198415 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host] 2025-12-05 08:03:15.198514 | 2025-12-05 08:03:15.198543 | PLAY RECAP 2025-12-05 08:03:15.198580 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1 2025-12-05 08:03:15.198601 | 2025-12-05 08:03:15.289390 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main] 2025-12-05 08:03:15.290249 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 08:03:15.863397 | 2025-12-05 08:03:15.863545 | PLAY [all] 2025-12-05 08:03:15.883234 | 2025-12-05 08:03:15.883317 | TASK [include_role : fetch-output] 2025-12-05 08:03:15.913842 | controller | ok 2025-12-05 08:03:15.931685 | 2025-12-05 08:03:15.931777 | TASK [fetch-output : Set log path for multiple nodes] 2025-12-05 08:03:15.980127 | controller | skipping: Conditional result was False 2025-12-05 08:03:15.986509 | 2025-12-05 08:03:15.986590 | TASK [fetch-output : Set log path for single node] 2025-12-05 08:03:16.028161 | controller | ok 2025-12-05 08:03:16.033542 | 2025-12-05 08:03:16.033610 | LOOP [fetch-output : Ensure local output dirs] 2025-12-05 08:03:16.377711 | controller -> localhost | ok: "/var/lib/zuul/builds/2bfed13692af4e8d9668c54288568b91/work/logs" 2025-12-05 08:03:16.577442 | controller -> localhost | ok: "/var/lib/zuul/builds/2bfed13692af4e8d9668c54288568b91/work/artifacts" 2025-12-05 08:03:16.772255 | controller -> localhost | ok: "/var/lib/zuul/builds/2bfed13692af4e8d9668c54288568b91/work/docs" 2025-12-05 08:03:16.793003 | 2025-12-05 08:03:16.793301 | LOOP [fetch-output : Collect logs, artifacts and docs] 2025-12-05 08:03:17.364905 | controller | ok 2025-12-05 08:03:17.365104 | controller | ok: All items complete 2025-12-05 08:03:17.365133 | 2025-12-05 08:03:17.754068 | controller | ok 2025-12-05 08:03:18.152276 | controller | ok 2025-12-05 08:03:18.174070 | 2025-12-05 08:03:18.174243 | TASK [include_role : fetch-output-openshift] 2025-12-05 08:03:18.189531 | controller | skipping: Conditional result was False 2025-12-05 08:03:18.196433 | 2025-12-05 08:03:18.196504 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2025-12-05 08:03:18.558267 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.009865 2025-12-05 08:03:18.764604 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.009545 2025-12-05 08:03:18.795688 | 2025-12-05 08:03:18.795856 | PLAY [all] 2025-12-05 08:03:18.810004 | 2025-12-05 08:03:18.810075 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2025-12-05 08:03:19.228491 | controller | changed 2025-12-05 08:03:19.250392 | 2025-12-05 08:03:19.250478 | PLAY RECAP 2025-12-05 08:03:19.250528 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0 2025-12-05 08:03:19.250551 | 2025-12-05 08:03:19.356404 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master] 2025-12-05 08:03:19.357672 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master] 2025-12-05 08:03:19.948198 | 2025-12-05 08:03:19.948342 | PLAY [localhost] 2025-12-05 08:03:19.965603 | 2025-12-05 08:03:19.965696 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2025-12-05 08:03:20.290168 | localhost | changed 2025-12-05 08:03:20.296795 | 2025-12-05 08:03:20.296881 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2025-12-05 08:03:20.327023 | localhost | ok 2025-12-05 08:03:20.334922 | 2025-12-05 08:03:20.334992 | TASK [add-fileserver : Create SSH private key tempfile] 2025-12-05 08:03:20.658605 | localhost | changed 2025-12-05 08:03:20.665634 | 2025-12-05 08:03:20.665743 | TASK [add-fileserver : Create SSH private key from secret] 2025-12-05 08:03:21.242353 | localhost | changed 2025-12-05 08:03:21.247564 | 2025-12-05 08:03:21.247675 | TASK [add-fileserver : Add fileserver ssh key] 2025-12-05 08:03:21.611911 | localhost | Identity added: /var/lib/zuul/builds/2bfed13692af4e8d9668c54288568b91/work/tmp/ansible.j5d3wo8s (/var/lib/zuul/builds/2bfed13692af4e8d9668c54288568b91/work/tmp/ansible.j5d3wo8s) 2025-12-05 08:03:21.612158 | localhost | ok: Runtime: 0:00:00.009212 2025-12-05 08:03:21.616785 | 2025-12-05 08:03:21.616900 | TASK [add-fileserver : Remove SSH private key from disk] 2025-12-05 08:03:21.860358 | localhost | ok: Runtime: 0:00:00.006154 2025-12-05 08:03:21.865760 | 2025-12-05 08:03:21.865857 | TASK [add-fileserver : Add fileserver to inventory] 2025-12-05 08:03:21.927151 | localhost | changed 2025-12-05 08:03:21.931354 | 2025-12-05 08:03:21.931426 | TASK [add-fileserver : Add fileserver server to known hosts] 2025-12-05 08:03:22.274593 | localhost | changed 2025-12-05 08:03:22.295412 | 2025-12-05 08:03:22.295533 | PLAY [localhost] 2025-12-05 08:03:22.307201 | 2025-12-05 08:03:22.307283 | TASK [Generate bulk log download script] 2025-12-05 08:03:22.334317 | localhost | ok 2025-12-05 08:03:22.347202 | 2025-12-05 08:03:22.347321 | TASK [local-log-download : Check API endpoint is defined] 2025-12-05 08:03:22.375804 | localhost | ok: All assertions passed 2025-12-05 08:03:22.381546 | 2025-12-05 08:03:22.381708 | TASK [local-log-download : Create download script] 2025-12-05 08:03:22.750399 | localhost -> localhost | changed 2025-12-05 08:03:22.766300 | 2025-12-05 08:03:22.766403 | TASK [Register quick-download link] 2025-12-05 08:03:22.784774 | localhost | ok 2025-12-05 08:03:22.823808 | 2025-12-05 08:03:22.823888 | PLAY [logserver.rdoproject.org] 2025-12-05 08:03:22.833439 | 2025-12-05 08:03:22.833499 | TASK [Set zuul-log-path fact] 2025-12-05 08:03:22.850192 | logserver.rdoproject.org | ok 2025-12-05 08:03:22.859904 | 2025-12-05 08:03:22.859982 | TASK [set-zuul-log-path-fact : Set log path for a build] 2025-12-05 08:03:22.888618 | logserver.rdoproject.org | ok 2025-12-05 08:03:22.894162 | 2025-12-05 08:03:22.894247 | TASK [upload-logs : Create log directories] 2025-12-05 08:03:24.642815 | logserver.rdoproject.org | changed 2025-12-05 08:03:24.646280 | 2025-12-05 08:03:24.646352 | TASK [upload-logs : Ensure logs are readable before uploading] 2025-12-05 08:03:24.886909 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.006475 2025-12-05 08:03:24.892500 | 2025-12-05 08:03:24.892575 | TASK [upload-logs : Upload logs to log server] 2025-12-05 08:03:26.362348 | logserver.rdoproject.org | Output suppressed because no_log was given 2025-12-05 08:03:26.365839 | 2025-12-05 08:03:26.365909 | LOOP [upload-logs : Compress console log and json output] 2025-12-05 08:03:26.414236 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 08:03:26.430207 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 08:03:26.436204 | 2025-12-05 08:03:26.436321 | LOOP [upload-logs : Upload compressed console log and json output] 2025-12-05 08:03:26.475392 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 08:03:26.475625 | 2025-12-05 08:03:26.478732 | logserver.rdoproject.org | skipping: Conditional result was False 2025-12-05 08:03:26.484760 | 2025-12-05 08:03:26.484876 | LOOP [upload-logs : Upload console log and json output]