2025-10-08 16:10:15.246887 | Job console starting...
2025-10-08 16:10:15.487570 | Updating repositories
2025-10-08 16:10:16.225716 | Preparing job workspace
2025-10-08 16:10:27.468004 | Running Ansible setup...
2025-10-08 16:10:31.008358 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-08 16:10:31.751372 | 
2025-10-08 16:10:31.751473 | PLAY [localhost]
2025-10-08 16:10:31.759951 | 
2025-10-08 16:10:31.760025 | TASK [Gathering Facts]
2025-10-08 16:10:32.994448 | localhost | ok
2025-10-08 16:10:33.010291 | 
2025-10-08 16:10:33.010420 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-08 16:10:33.380172 | localhost -> localhost | changed
2025-10-08 16:10:33.385984 | 
2025-10-08 16:10:33.386088 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-08 16:10:34.347564 | localhost -> localhost | changed
2025-10-08 16:10:34.357075 | 
2025-10-08 16:10:34.357328 | TASK [Setup log path fact]
2025-10-08 16:10:34.395248 | localhost | ok
2025-10-08 16:10:34.413096 | 
2025-10-08 16:10:34.413183 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-08 16:10:34.440848 | localhost | ok
2025-10-08 16:10:34.448543 | 
2025-10-08 16:10:34.448629 | TASK [emit-job-header : Print job information]
2025-10-08 16:10:34.476247 | # Job Information
2025-10-08 16:10:34.476366 | Ansible Version: 2.15.12
2025-10-08 16:10:34.476395 | Job: cifmw-molecule-os_net_setup
2025-10-08 16:10:34.476418 | Pipeline: github-check
2025-10-08 16:10:34.476438 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-10-08 16:10:34.476458 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3368
2025-10-08 16:10:34.476477 | Log URL (when completed): https://logserver.rdoproject.org/21f/rdoproject.org/21f233acfca840e09eddb40ac7652094/
2025-10-08 16:10:34.476497 | Event ID: b612d780-a45c-11f0-87cb-9ea07ef2b05c
2025-10-08 16:10:34.493839 | 
2025-10-08 16:10:34.493939 | LOOP [emit-job-header : Print node information]
2025-10-08 16:10:34.635340 | localhost | ok:
2025-10-08 16:10:34.635570 | localhost | # Node Information
2025-10-08 16:10:34.635608 | localhost | Inventory Hostname: controller
2025-10-08 16:10:34.635636 | localhost | Hostname: np0005477437
2025-10-08 16:10:34.635656 | localhost | Username: zuul
2025-10-08 16:10:34.635739 | localhost | Distro: CentOS 9
2025-10-08 16:10:34.635772 | localhost | Provider: ibm-bm4-nodepool
2025-10-08 16:10:34.635814 | localhost | Region: regionOne
2025-10-08 16:10:34.635834 | localhost | Label: cloud-centos-9-stream-tripleo-ibm
2025-10-08 16:10:34.635852 | localhost | Product Name: OpenStack Compute
2025-10-08 16:10:34.635870 | localhost | Interface IP: 192.168.26.92
2025-10-08 16:10:34.660331 | 
2025-10-08 16:10:34.660414 | PLAY [all]
2025-10-08 16:10:34.666737 | 
2025-10-08 16:10:34.666804 | TASK [Gather network facts]
2025-10-08 16:10:35.046417 | controller | ok
2025-10-08 16:10:35.085844 | 
2025-10-08 16:10:35.085950 | TASK [include_role : start-zuul-console]
2025-10-08 16:10:35.125447 | controller | ok
2025-10-08 16:10:35.149071 | 
2025-10-08 16:10:35.149150 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-08 16:10:35.614899 | controller | ok
2025-10-08 16:10:35.630602 | 
2025-10-08 16:10:35.630994 | TASK [include_role : add-build-sshkey]
2025-10-08 16:10:35.679699 | controller | ok
2025-10-08 16:10:35.695886 | 
2025-10-08 16:10:35.696037 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-08 16:10:35.922288 | controller -> localhost | ok
2025-10-08 16:10:35.928631 | 
2025-10-08 16:10:35.928702 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-08 16:10:35.978326 | controller | ok
2025-10-08 16:10:35.996663 | controller | included: /var/lib/zuul/builds/21f233acfca840e09eddb40ac7652094/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-08 16:10:36.019879 | 
2025-10-08 16:10:36.019996 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-08 16:10:36.810899 | controller -> localhost | Generating public/private rsa key pair.
2025-10-08 16:10:36.811117 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/21f233acfca840e09eddb40ac7652094/work/21f233acfca840e09eddb40ac7652094_id_rsa.
2025-10-08 16:10:36.811151 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/21f233acfca840e09eddb40ac7652094/work/21f233acfca840e09eddb40ac7652094_id_rsa.pub.
2025-10-08 16:10:36.811176 | controller -> localhost | The key fingerprint is:
2025-10-08 16:10:36.811198 | controller -> localhost | SHA256:dRcmBO5CfFxAVa5lxMTOe03SD/8EMNFpoxXYXg/HaXY zuul-build-sshkey
2025-10-08 16:10:36.811218 | controller -> localhost | The key's randomart image is:
2025-10-08 16:10:36.811236 | controller -> localhost | +---[RSA 3072]----+
2025-10-08 16:10:36.811255 | controller -> localhost | |         .+=*XB+.|
2025-10-08 16:10:36.811274 | controller -> localhost | |       . o .+=@=E|
2025-10-08 16:10:36.811294 | controller -> localhost | |        o = .XB*o|
2025-10-08 16:10:36.811313 | controller -> localhost | |       . + ..=B +|
2025-10-08 16:10:36.811331 | controller -> localhost | |        S . .  Bo|
2025-10-08 16:10:36.811348 | controller -> localhost | |         .    . *|
2025-10-08 16:10:36.811366 | controller -> localhost | |               o.|
2025-10-08 16:10:36.811386 | controller -> localhost | |                .|
2025-10-08 16:10:36.811404 | controller -> localhost | |                 |
2025-10-08 16:10:36.811422 | controller -> localhost | +----[SHA256]-----+
2025-10-08 16:10:36.811465 | controller -> localhost | ok: Runtime: 0:00:00.369420
2025-10-08 16:10:36.817520 | 
2025-10-08 16:10:36.817602 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-08 16:10:36.835941 | controller | ok
2025-10-08 16:10:36.852847 | controller | included: /var/lib/zuul/builds/21f233acfca840e09eddb40ac7652094/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-08 16:10:36.861291 | 
2025-10-08 16:10:36.861375 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-08 16:10:36.875336 | controller | skipping: Conditional result was False
2025-10-08 16:10:36.881296 | 
2025-10-08 16:10:36.881380 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-08 16:10:37.265994 | controller | changed
2025-10-08 16:10:37.273324 | 
2025-10-08 16:10:37.273436 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-08 16:10:37.496259 | controller | ok
2025-10-08 16:10:37.501392 | 
2025-10-08 16:10:37.501461 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-08 16:10:38.192470 | controller | changed
2025-10-08 16:10:38.205812 | 
2025-10-08 16:10:38.205928 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-08 16:10:38.857875 | controller | changed
2025-10-08 16:10:38.862847 | 
2025-10-08 16:10:38.862973 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-08 16:10:38.876858 | controller | skipping: Conditional result was False
2025-10-08 16:10:38.882546 | 
2025-10-08 16:10:38.882637 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-08 16:10:39.368628 | controller -> localhost | changed
2025-10-08 16:10:39.378698 | 
2025-10-08 16:10:39.378771 | TASK [add-build-sshkey : Add back temp key]
2025-10-08 16:10:39.692022 | controller -> localhost | Identity added: /var/lib/zuul/builds/21f233acfca840e09eddb40ac7652094/work/21f233acfca840e09eddb40ac7652094_id_rsa (zuul-build-sshkey)
2025-10-08 16:10:39.692200 | controller -> localhost | ok: Runtime: 0:00:00.017523
2025-10-08 16:10:39.697715 | 
2025-10-08 16:10:39.697779 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-08 16:10:40.018187 | controller | ok
2025-10-08 16:10:40.023754 | 
2025-10-08 16:10:40.028306 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-08 16:10:40.055618 | controller | skipping: Conditional result was False
2025-10-08 16:10:40.065986 | 
2025-10-08 16:10:40.066078 | TASK [include_role : validate-host]
2025-10-08 16:10:40.085667 | controller | ok
2025-10-08 16:10:40.107021 | 
2025-10-08 16:10:40.107107 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-08 16:10:40.141397 | controller | ok
2025-10-08 16:10:40.147359 | 
2025-10-08 16:10:40.147446 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-08 16:10:40.414243 | controller -> localhost | ok
2025-10-08 16:10:40.420330 | 
2025-10-08 16:10:40.420397 | TASK [validate-host : Collect information about the host]
2025-10-08 16:10:41.081518 | controller | ok
2025-10-08 16:10:41.090066 | 
2025-10-08 16:10:41.090148 | TASK [validate-host : Sanitize hostname]
2025-10-08 16:10:41.142991 | controller | ok
2025-10-08 16:10:41.148273 | 
2025-10-08 16:10:41.148363 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-08 16:10:41.631491 | controller -> localhost | changed
2025-10-08 16:10:41.637213 | 
2025-10-08 16:10:41.637291 | TASK [validate-host : Collect information about zuul worker]
2025-10-08 16:10:41.981133 | controller | ok
2025-10-08 16:10:41.985711 | 
2025-10-08 16:10:41.985778 | TASK [validate-host : Write out all zuul information for each host]
2025-10-08 16:10:42.555872 | controller -> localhost | changed
2025-10-08 16:10:42.565125 | 
2025-10-08 16:10:42.565194 | TASK [include_role : prepare-workspace-openshift]
2025-10-08 16:10:42.588405 | controller | skipping: Conditional result was False
2025-10-08 16:10:42.594147 | 
2025-10-08 16:10:42.594213 | TASK [include_role : remove-zuul-sshkey]
2025-10-08 16:10:42.628396 | controller | skipping: Conditional result was False
2025-10-08 16:10:42.633977 | 
2025-10-08 16:10:42.634050 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-08 16:10:42.886530 | controller | ok: "logs"
2025-10-08 16:10:42.886767 | controller | ok: All items complete
2025-10-08 16:10:42.886799 | 
2025-10-08 16:10:43.063554 | controller | ok: "artifacts"
2025-10-08 16:10:43.227049 | controller | ok: "docs"
2025-10-08 16:10:43.237260 | 
2025-10-08 16:10:43.237341 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-08 16:10:43.433791 | controller | changed: "logs"
2025-10-08 16:10:43.603720 | controller | changed: "artifacts"
2025-10-08 16:10:43.776966 | controller | changed: "docs"
2025-10-08 16:10:43.799281 | 
2025-10-08 16:10:43.799346 | PLAY RECAP
2025-10-08 16:10:43.799391 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-08 16:10:43.799420 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-08 16:10:43.799439 | 
2025-10-08 16:10:43.898259 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-08 16:10:43.899035 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-08 16:10:44.478749 | 
2025-10-08 16:10:44.478855 | PLAY [all]
2025-10-08 16:10:44.499961 | 
2025-10-08 16:10:44.500042 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-08 16:10:44.549019 | controller | ok
2025-10-08 16:10:44.562062 | 
2025-10-08 16:10:44.562156 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-08 16:10:44.996591 | controller | changed
2025-10-08 16:10:45.003335 | 
2025-10-08 16:10:45.003412 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-08 16:10:45.871334 | controller | changed
2025-10-08 16:10:45.888730 | 
2025-10-08 16:10:45.888819 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-10-08 16:10:46.280696 | controller | changed:
2025-10-08 16:10:46.280859 | controller | {
2025-10-08 16:10:46.280890 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-10-08 16:10:46.280952 | controller | }
2025-10-08 16:10:46.499059 | controller | changed:
2025-10-08 16:10:46.499156 | controller | {
2025-10-08 16:10:46.499187 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-10-08 16:10:46.499208 | controller | }
2025-10-08 16:10:46.712205 | controller | changed:
2025-10-08 16:10:46.712300 | controller | {
2025-10-08 16:10:46.712327 | 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-08 16:10:46.712347 | controller | }
2025-10-08 16:10:46.931882 | controller | changed:
2025-10-08 16:10:46.931990 | controller | {
2025-10-08 16:10:46.932022 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-10-08 16:10:46.932045 | controller | }
2025-10-08 16:10:47.151004 | controller | changed:
2025-10-08 16:10:47.151091 | controller | {
2025-10-08 16:10:47.151120 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-10-08 16:10:47.151141 | controller | }
2025-10-08 16:10:47.355743 | controller | changed:
2025-10-08 16:10:47.356032 | controller | {
2025-10-08 16:10:47.356074 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-10-08 16:10:47.356098 | controller | }
2025-10-08 16:10:47.557017 | controller | changed:
2025-10-08 16:10:47.557105 | controller | {
2025-10-08 16:10:47.557134 | 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-08 16:10:47.557157 | controller | }
2025-10-08 16:10:47.775179 | controller | changed:
2025-10-08 16:10:47.775254 | controller | {
2025-10-08 16:10:47.775282 | 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-08 16:10:47.775304 | controller | }
2025-10-08 16:10:47.970695 | controller | changed:
2025-10-08 16:10:47.970786 | controller | {
2025-10-08 16:10:47.970814 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-10-08 16:10:47.970835 | controller | }
2025-10-08 16:10:48.182715 | controller | changed:
2025-10-08 16:10:48.182851 | controller | {
2025-10-08 16:10:48.182884 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-10-08 16:10:48.182925 | controller | }
2025-10-08 16:10:48.389752 | controller | changed:
2025-10-08 16:10:48.389839 | controller | {
2025-10-08 16:10:48.389867 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-10-08 16:10:48.389889 | controller | }
2025-10-08 16:10:48.628325 | controller | changed:
2025-10-08 16:10:48.628413 | controller | {
2025-10-08 16:10:48.628443 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-10-08 16:10:48.628545 | controller | }
2025-10-08 16:10:48.847855 | controller | changed:
2025-10-08 16:10:48.847976 | controller | {
2025-10-08 16:10:48.848006 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-10-08 16:10:48.848028 | controller | }
2025-10-08 16:10:49.075344 | controller | changed:
2025-10-08 16:10:49.075431 | controller | {
2025-10-08 16:10:49.075460 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-10-08 16:10:49.075482 | controller | }
2025-10-08 16:10:49.277164 | controller | changed:
2025-10-08 16:10:49.277257 | controller | {
2025-10-08 16:10:49.277287 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-10-08 16:10:49.277310 | controller | }
2025-10-08 16:10:49.477872 | controller | changed:
2025-10-08 16:10:49.477963 | controller | {
2025-10-08 16:10:49.477991 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-10-08 16:10:49.478012 | controller | }
2025-10-08 16:10:49.682489 | controller | changed:
2025-10-08 16:10:49.682596 | controller | {
2025-10-08 16:10:49.682627 | 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-08 16:10:49.682651 | controller | }
2025-10-08 16:10:49.909705 | controller | changed:
2025-10-08 16:10:49.909803 | controller | {
2025-10-08 16:10:49.909831 | 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-08 16:10:49.909863 | controller | }
2025-10-08 16:10:50.130264 | controller | changed:
2025-10-08 16:10:50.130349 | controller | {
2025-10-08 16:10:50.130377 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-10-08 16:10:50.130398 | controller | }
2025-10-08 16:10:50.343410 | controller | changed:
2025-10-08 16:10:50.343509 | controller | {
2025-10-08 16:10:50.343537 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-10-08 16:10:50.343559 | controller | }
2025-10-08 16:10:50.579451 | controller | changed:
2025-10-08 16:10:50.579544 | controller | {
2025-10-08 16:10:50.579585 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-10-08 16:10:50.579608 | controller | }
2025-10-08 16:10:50.782734 | controller | changed:
2025-10-08 16:10:50.782825 | controller | {
2025-10-08 16:10:50.782852 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-10-08 16:10:50.782874 | controller | }
2025-10-08 16:10:50.980972 | controller | changed:
2025-10-08 16:10:50.981044 | controller | {
2025-10-08 16:10:50.981071 | 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-08 16:10:50.981093 | controller | }
2025-10-08 16:10:51.181321 | controller | changed:
2025-10-08 16:10:51.181405 | controller | {
2025-10-08 16:10:51.181432 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-10-08 16:10:51.181452 | controller | }
2025-10-08 16:10:51.386166 | controller | changed:
2025-10-08 16:10:51.386255 | controller | {
2025-10-08 16:10:51.386281 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-10-08 16:10:51.386302 | controller | }
2025-10-08 16:10:51.599705 | controller | changed:
2025-10-08 16:10:51.599798 | controller | {
2025-10-08 16:10:51.599825 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-10-08 16:10:51.599845 | controller | }
2025-10-08 16:10:51.619451 | 
2025-10-08 16:10:51.619691 | TASK [Set timezone to UTC]
2025-10-08 16:10:52.013398 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-10-08 16:10:52.019294 | 
2025-10-08 16:10:52.019360 | TASK [Create nodepool directory]
2025-10-08 16:10:52.220558 | controller | changed
2025-10-08 16:10:52.226171 | 
2025-10-08 16:10:52.226238 | TASK [Create nodepool sub_nodes file]
2025-10-08 16:10:52.753660 | controller | changed
2025-10-08 16:10:52.759449 | 
2025-10-08 16:10:52.759589 | TASK [Create nodepool sub_nodes_private file]
2025-10-08 16:10:53.267432 | controller | changed
2025-10-08 16:10:53.272281 | 
2025-10-08 16:10:53.272347 | LOOP [Populate nodepool sub_nodes file]
2025-10-08 16:10:53.302016 | 
2025-10-08 16:10:53.302138 | LOOP [Populate nodepool sub_nodes_private file]
2025-10-08 16:10:53.331532 | 
2025-10-08 16:10:53.331676 | TASK [Create nodepool primary file]
2025-10-08 16:10:53.355346 | controller | skipping: Conditional result was False
2025-10-08 16:10:53.361411 | 
2025-10-08 16:10:53.361496 | TASK [Create nodepool node_private for this node]
2025-10-08 16:10:53.906803 | controller | changed
2025-10-08 16:10:53.913787 | 
2025-10-08 16:10:53.913867 | LOOP [Copy ssh keys to nodepool directory]
2025-10-08 16:10:54.251319 | controller | ok: Item: id_rsa Runtime: 0:00:00.005060
2025-10-08 16:10:54.251501 | 
2025-10-08 16:10:54.440726 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.005454
2025-10-08 16:10:54.457347 | 
2025-10-08 16:10:54.457482 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-10-08 16:10:54.995841 | controller | changed
2025-10-08 16:10:55.002244 | 
2025-10-08 16:10:55.002328 | TASK [Validate sudoers config after edits]
2025-10-08 16:10:55.231975 | controller | /etc/sudoers: parsed OK
2025-10-08 16:10:55.232058 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-10-08 16:10:55.232069 | controller | /etc/sudoers.d/zuul: parsed OK
2025-10-08 16:10:55.232076 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-10-08 16:10:55.529167 | controller | ok: Runtime: 0:00:00.005569
2025-10-08 16:10:55.534772 | 
2025-10-08 16:10:55.534856 | TASK [Show the environment passed in to job shell scripts]
2025-10-08 16:10:55.757021 | controller | SHELL=/bin/bash
2025-10-08 16:10:55.757074 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-10-08 16:10:55.757084 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-10-08 16:10:55.757091 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/85/3385/f8a3c957fc51bd892aee4b1f66ce262682944823^openstack-k8s-operators/ci-framework:main:refs/changes/68/3368/127d45eecba72e2daf3d33e73e380ccf7b6e7649
2025-10-08 16:10:55.757100 | controller | PWD=/home/zuul
2025-10-08 16:10:55.757106 | controller | ZUUL_PIPELINE=github-check
2025-10-08 16:10:55.757159 | controller | LOGNAME=zuul
2025-10-08 16:10:55.757169 | controller | XDG_SESSION_TYPE=tty
2025-10-08 16:10:55.757175 | controller | _=/usr/bin/env
2025-10-08 16:10:55.757180 | controller | MOTD_SHOWN=pam
2025-10-08 16:10:55.757186 | controller | HOME=/home/zuul
2025-10-08 16:10:55.757191 | controller | LANG=en_US.UTF-8
2025-10-08 16:10:55.757197 | controller | SSH_CONNECTION=192.168.26.12 36180 192.168.26.92 22
2025-10-08 16:10:55.757203 | 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-08 16:10:55.757208 | controller | ZUUL_CHANGE_IDS=3385,f8a3c957fc51bd892aee4b1f66ce262682944823 3368,127d45eecba72e2daf3d33e73e380ccf7b6e7649
2025-10-08 16:10:55.757214 | controller | WORKSPACE=/home/zuul/workspace
2025-10-08 16:10:55.757220 | controller | XDG_SESSION_CLASS=user
2025-10-08 16:10:55.757226 | controller | SELINUX_ROLE_REQUESTED=
2025-10-08 16:10:55.757253 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-10-08 16:10:55.757262 | controller | USER=zuul
2025-10-08 16:10:55.757268 | controller | ZUUL_VOTING=True
2025-10-08 16:10:55.757273 | controller | BUILD_TIMEOUT=1800000
2025-10-08 16:10:55.757279 | controller | SELINUX_USE_CURRENT_RANGE=
2025-10-08 16:10:55.757284 | controller | SHLVL=1
2025-10-08 16:10:55.757290 | controller | ZUUL_PATCHSET=127d45eecba72e2daf3d33e73e380ccf7b6e7649
2025-10-08 16:10:55.757295 | controller | XDG_SESSION_ID=1
2025-10-08 16:10:55.757301 | controller | ZUUL_BRANCH=main
2025-10-08 16:10:55.757306 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-10-08 16:10:55.757311 | controller | SSH_CLIENT=192.168.26.12 36180 22
2025-10-08 16:10:55.757317 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-10-08 16:10:55.757322 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-10-08 16:10:55.757328 | controller | which_declare=declare -f
2025-10-08 16:10:55.757334 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-10-08 16:10:55.757340 | controller | SELINUX_LEVEL_REQUESTED=
2025-10-08 16:10:55.757345 | controller | ZUUL_CHANGE=3368
2025-10-08 16:10:55.757351 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-10-08 16:10:55.757356 | controller | ZUUL_UUID=21f233acfca840e09eddb40ac7652094
2025-10-08 16:10:55.757362 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-10-08 16:10:55.757370 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-10-08 16:10:55.757375 | controller | }
2025-10-08 16:10:56.059969 | controller | ok: Runtime: 0:00:00.005681
2025-10-08 16:10:56.065484 | 
2025-10-08 16:10:56.065547 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-10-08 16:10:56.078935 | controller | skipping: Conditional result was False
2025-10-08 16:10:56.084290 | 
2025-10-08 16:10:56.084355 | TASK [Symlink /home/zuul-worker/workspace]
2025-10-08 16:10:56.609056 | controller | skipping: Conditional result was False
2025-10-08 16:10:56.615369 | 
2025-10-08 16:10:56.615435 | TASK [Ensure legacy workspace directory]
2025-10-08 16:10:56.799459 | controller | changed
2025-10-08 16:10:56.818011 | 
2025-10-08 16:10:56.818067 | PLAY RECAP
2025-10-08 16:10:56.818110 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-08 16:10:56.818134 | 
2025-10-08 16:10:56.897788 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-08 16:10:56.898759 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-08 16:10:57.469551 | 
2025-10-08 16:10:57.469670 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-10-08 16:10:57.490901 | 
2025-10-08 16:10:57.491020 | TASK [Create zuul-output directory]
2025-10-08 16:10:57.867434 | controller | changed
2025-10-08 16:10:57.872557 | 
2025-10-08 16:10:57.872651 | TASK [Slurp Zuul inventory test]
2025-10-08 16:10:58.171438 | controller -> localhost | ok
2025-10-08 16:10:58.178972 | 
2025-10-08 16:10:58.179044 | TASK [Save zuul inventory]
2025-10-08 16:10:58.953011 | controller | changed
2025-10-08 16:10:58.958921 | 
2025-10-08 16:10:58.959004 | TASK [Save zuul vars without the change_message]
2025-10-08 16:10:59.549471 | controller | changed
2025-10-08 16:10:59.567290 | 
2025-10-08 16:10:59.567367 | PLAY RECAP
2025-10-08 16:10:59.567413 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-08 16:10:59.567435 | 
2025-10-08 16:10:59.643290 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-08 16:10:59.644074 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-08 16:11:00.199854 | 
2025-10-08 16:11:00.199972 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-10-08 16:11:00.220404 | 
2025-10-08 16:11:00.220477 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-10-08 16:11:00.249172 | controller | ok
2025-10-08 16:11:00.266477 | 
2025-10-08 16:11:00.266615 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-08 16:11:00.300560 | controller | skipping: Conditional result was False
2025-10-08 16:11:00.306225 | 
2025-10-08 16:11:00.306309 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-08 16:11:00.618138 | controller | ok
2025-10-08 16:11:00.623720 | 
2025-10-08 16:11:00.623790 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-08 16:11:01.231336 | controller | ok
2025-10-08 16:11:01.243168 | 
2025-10-08 16:11:01.243274 | TASK [Prepare workspace]
2025-10-08 16:11:01.272439 | controller | ok
2025-10-08 16:11:01.291819 | 
2025-10-08 16:11:01.291938 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-08 16:11:01.584561 | controller | ok
2025-10-08 16:11:01.591266 | 
2025-10-08 16:11:01.591350 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-08 16:11:04.034534 | controller | Output suppressed because no_log was given
2025-10-08 16:11:04.043977 | 
2025-10-08 16:11:04.044047 | LOOP [Create zuul-output directory]
2025-10-08 16:11:04.234509 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-10-08 16:11:04.396676 | controller | ok: "/home/zuul/zuul-output/logs"
2025-10-08 16:11:04.402883 | 
2025-10-08 16:11:04.402982 | TASK [Install required packages]
2025-10-08 16:12:04.526485 | controller | changed
2025-10-08 16:12:04.537339 | 
2025-10-08 16:12:04.537431 | TASK [Install venv]
2025-10-08 16:13:05.950535 | controller | changed
2025-10-08 16:13:05.977272 | 
2025-10-08 16:13:05.977337 | PLAY RECAP
2025-10-08 16:13:05.977382 | controller | ok: 7 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-08 16:13:05.977406 | 
2025-10-08 16:13:06.105198 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-08 16:13:06.106887 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-08 16:13:06.940417 | 
2025-10-08 16:13:06.940528 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-10-08 16:13:06.961270 | 
2025-10-08 16:13:06.961359 | TASK [Gather required facts]
2025-10-08 16:13:07.469318 | controller | ok
2025-10-08 16:13:07.475518 | 
2025-10-08 16:13:07.475595 | TASK [Load environment var if instructed to]
2025-10-08 16:13:07.506827 | controller | skipping: Conditional result was False
2025-10-08 16:13:07.512614 | 
2025-10-08 16:13:07.512721 | TASK [Ensure group_vars dir exists]
2025-10-08 16:13:07.830590 | controller | ok
2025-10-08 16:13:07.837225 | 
2025-10-08 16:13:07.837296 | TASK [Run molecule]
2025-10-08 16:13:08.787710 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-10-08 16:13:08.857119 | controller | INFO     Performing prerun with role_name_check=0...
2025-10-08 16:13:25.635751 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/c32a66/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 16:13:25.636168 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/c32a66/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 16:13:25.636644 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/c32a66/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 16:13:25.637095 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/c32a66/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 16:13:25.637599 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+4772ac9e was found installed in /home/zuul/.cache/ansible-compat/c32a66/collections/ansible_collections, only the first one will be used, 1.0.0+4772ac9e (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 16:13:25.638044 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/c32a66/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 16:13:25.638514 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/c32a66/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 16:13:25.638928 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/c32a66/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 16:13:25.639400 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/c32a66/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 16:13:25.639837 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/c32a66/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 16:13:25.640320 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/c32a66/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 16:13:25.640763 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/c32a66/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 16:13:25.641213 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/c32a66/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 16:13:25.641679 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/c32a66/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 16:13:25.642103 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/c32a66/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 16:13:25.651842 | controller | INFO     Running default > prepare
2025-10-08 16:13:26.322043 | controller |
2025-10-08 16:13:26.322146 | controller | PLAY [Prepare] *****************************************************************
2025-10-08 16:13:26.322266 | controller |
2025-10-08 16:13:26.322362 | controller | TASK [Gathering Facts] *********************************************************
2025-10-08 16:13:26.322461 | controller | Wednesday 08 October 2025  16:13:26 +0000 (0:00:00.014)       0:00:00.014 *****
2025-10-08 16:13:27.159008 | controller | ok: [instance]
2025-10-08 16:13:27.159096 | controller |
2025-10-08 16:13:27.159216 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-10-08 16:13:27.159345 | controller | Wednesday 08 October 2025  16:13:27 +0000 (0:00:00.837)       0:00:00.852 *****
2025-10-08 16:13:27.176285 | controller | skipping: [instance]
2025-10-08 16:13:27.176402 | controller |
2025-10-08 16:13:27.176534 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-10-08 16:13:27.176664 | controller | Wednesday 08 October 2025  16:13:27 +0000 (0:00:00.017)       0:00:00.869 *****
2025-10-08 16:13:27.216411 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-10-08 16:13:27.216522 | controller |
2025-10-08 16:13:27.216652 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-10-08 16:13:27.216778 | controller | Wednesday 08 October 2025  16:13:27 +0000 (0:00:00.040)       0:00:00.909 *****
2025-10-08 16:13:27.488219 | controller | ok: [instance]
2025-10-08 16:13:27.488309 | controller |
2025-10-08 16:13:27.488415 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-10-08 16:13:27.488519 | controller | Wednesday 08 October 2025  16:13:27 +0000 (0:00:00.271)       0:00:01.181 *****
2025-10-08 16:13:27.791756 | controller | ok: [instance]
2025-10-08 16:13:27.791830 | controller |
2025-10-08 16:13:27.791935 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-10-08 16:13:27.792040 | controller | Wednesday 08 October 2025  16:13:27 +0000 (0:00:00.303)       0:00:01.484 *****
2025-10-08 16:13:28.472617 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-10-08 16:13:28.472704 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-10-08 16:13:28.472819 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-10-08 16:13:28.472922 | controller |
2025-10-08 16:13:28.473026 | controller | TASK [Deploy repo-setup] *******************************************************
2025-10-08 16:13:28.473142 | controller | Wednesday 08 October 2025  16:13:28 +0000 (0:00:00.680)       0:00:02.165 *****
2025-10-08 16:13:28.532512 | controller |
2025-10-08 16:13:28.532615 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-10-08 16:13:28.532724 | controller | Wednesday 08 October 2025  16:13:28 +0000 (0:00:00.060)       0:00:02.225 *****
2025-10-08 16:13:29.070601 | controller | changed: [instance] => (item=tmp)
2025-10-08 16:13:29.070689 | controller | changed: [instance] => (item=artifacts/repositories)
2025-10-08 16:13:29.070801 | controller | changed: [instance] => (item=venv/repo_setup)
2025-10-08 16:13:29.070899 | controller |
2025-10-08 16:13:29.071003 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-10-08 16:13:29.071108 | controller | Wednesday 08 October 2025  16:13:29 +0000 (0:00:00.537)       0:00:02.763 *****
2025-10-08 16:13:29.859307 | controller | ok: [instance]
2025-10-08 16:13:29.859355 | controller |
2025-10-08 16:13:29.859366 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-10-08 16:13:29.859493 | controller | Wednesday 08 October 2025  16:13:29 +0000 (0:00:00.788)       0:00:03.552 *****
2025-10-08 16:13:30.996728 | controller | changed: [instance]
2025-10-08 16:13:38.845318 | controller |
2025-10-08 16:13:38.845355 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-10-08 16:13:38.845366 | controller | Wednesday 08 October 2025  16:13:30 +0000 (0:00:01.137)       0:00:04.689 *****
2025-10-08 16:13:38.845376 | controller | changed: [instance]
2025-10-08 16:13:39.557378 | controller |
2025-10-08 16:13:39.557416 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-10-08 16:13:39.557425 | controller | Wednesday 08 October 2025  16:13:38 +0000 (0:00:07.848)       0:00:12.538 *****
2025-10-08 16:13:39.557435 | controller | changed: [instance]
2025-10-08 16:13:39.578319 | controller |
2025-10-08 16:13:39.578346 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-10-08 16:13:39.578355 | controller | Wednesday 08 October 2025  16:13:39 +0000 (0:00:00.712)       0:00:13.250 *****
2025-10-08 16:13:39.578366 | controller | skipping: [instance]
2025-10-08 16:13:40.409315 | controller |
2025-10-08 16:13:40.409347 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-10-08 16:13:40.409355 | controller | Wednesday 08 October 2025  16:13:39 +0000 (0:00:00.021)       0:00:13.271 *****
2025-10-08 16:13:40.409365 | controller | changed: [instance]
2025-10-08 16:13:40.409388 | controller |
2025-10-08 16:13:40.409583 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-10-08 16:13:40.445819 | controller | Wednesday 08 October 2025  16:13:40 +0000 (0:00:00.831)       0:00:14.102 *****
2025-10-08 16:13:40.445856 | controller | skipping: [instance]
2025-10-08 16:13:40.482838 | controller |
2025-10-08 16:13:40.482870 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-10-08 16:13:40.482878 | controller | Wednesday 08 October 2025  16:13:40 +0000 (0:00:00.036)       0:00:14.138 *****
2025-10-08 16:13:40.482888 | controller | skipping: [instance]
2025-10-08 16:13:40.518382 | controller |
2025-10-08 16:13:40.518426 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-10-08 16:13:40.518437 | controller | Wednesday 08 October 2025  16:13:40 +0000 (0:00:00.036)       0:00:14.175 *****
2025-10-08 16:13:40.518451 | controller | skipping: [instance]
2025-10-08 16:13:41.097757 | controller |
2025-10-08 16:13:41.097791 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-10-08 16:13:41.097799 | controller | Wednesday 08 October 2025  16:13:40 +0000 (0:00:00.036)       0:00:14.211 *****
2025-10-08 16:13:41.097809 | controller | changed: [instance]
2025-10-08 16:13:41.546847 | controller |
2025-10-08 16:13:41.546879 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-10-08 16:13:41.546887 | controller | Wednesday 08 October 2025  16:13:41 +0000 (0:00:00.579)       0:00:14.790 *****
2025-10-08 16:13:41.546897 | controller | changed: [instance]
2025-10-08 16:13:41.577308 | controller |
2025-10-08 16:13:41.577340 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-10-08 16:13:41.577348 | controller | Wednesday 08 October 2025  16:13:41 +0000 (0:00:00.449)       0:00:15.239 *****
2025-10-08 16:13:41.577358 | controller | skipping: [instance]
2025-10-08 16:13:41.577383 | controller |
2025-10-08 16:13:41.577646 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-10-08 16:13:41.628349 | controller | Wednesday 08 October 2025  16:13:41 +0000 (0:00:00.030)       0:00:15.270 *****
2025-10-08 16:13:41.628410 | controller | skipping: [instance]
2025-10-08 16:13:41.657012 | controller |
2025-10-08 16:13:41.657037 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-10-08 16:13:41.657046 | controller | Wednesday 08 October 2025  16:13:41 +0000 (0:00:00.050)       0:00:15.321 *****
2025-10-08 16:13:41.657056 | controller | skipping: [instance]
2025-10-08 16:13:41.695144 | controller |
2025-10-08 16:13:41.695176 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-10-08 16:13:41.695185 | controller | Wednesday 08 October 2025  16:13:41 +0000 (0:00:00.028)       0:00:15.350 *****
2025-10-08 16:13:41.695197 | controller | ok: [instance]
2025-10-08 16:13:41.722578 | controller |
2025-10-08 16:13:41.722609 | controller | TASK [repo_setup : Create download directory] **********************************
2025-10-08 16:13:41.722617 | controller | Wednesday 08 October 2025  16:13:41 +0000 (0:00:00.037)       0:00:15.387 *****
2025-10-08 16:13:41.722627 | controller | skipping: [instance]
2025-10-08 16:13:41.750197 | controller |
2025-10-08 16:13:41.750247 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-10-08 16:13:41.750259 | controller | Wednesday 08 October 2025  16:13:41 +0000 (0:00:00.027)       0:00:15.415 *****
2025-10-08 16:13:41.750278 | controller | skipping: [instance]
2025-10-08 16:13:41.776932 | controller |
2025-10-08 16:13:41.776962 | controller | TASK [Download the RPM] ********************************************************
2025-10-08 16:13:41.776971 | controller | Wednesday 08 October 2025  16:13:41 +0000 (0:00:00.027)       0:00:15.442 *****
2025-10-08 16:13:41.776982 | controller | skipping: [instance]
2025-10-08 16:13:41.777147 | controller |
2025-10-08 16:13:41.777342 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-10-08 16:13:41.777503 | controller | Wednesday 08 October 2025  16:13:41 +0000 (0:00:00.027)       0:00:15.470 *****
2025-10-08 16:13:41.804219 | controller | skipping: [instance]
2025-10-08 16:13:41.804456 | controller |
2025-10-08 16:13:41.804636 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-10-08 16:13:41.804806 | controller | Wednesday 08 October 2025  16:13:41 +0000 (0:00:00.027)       0:00:15.497 *****
2025-10-08 16:13:41.831702 | controller | skipping: [instance]
2025-10-08 16:13:41.831872 | controller |
2025-10-08 16:13:41.832015 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-10-08 16:13:41.832164 | controller | Wednesday 08 October 2025  16:13:41 +0000 (0:00:00.027)       0:00:15.524 *****
2025-10-08 16:13:41.862303 | controller | skipping: [instance]
2025-10-08 16:13:41.862489 | controller |
2025-10-08 16:13:41.862671 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-10-08 16:13:41.862840 | controller | Wednesday 08 October 2025  16:13:41 +0000 (0:00:00.030)       0:00:15.555 *****
2025-10-08 16:13:41.889298 | controller | skipping: [instance]
2025-10-08 16:13:41.889483 | controller |
2025-10-08 16:13:41.889654 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-10-08 16:13:41.889819 | controller | Wednesday 08 October 2025  16:13:41 +0000 (0:00:00.027)       0:00:15.582 *****
2025-10-08 16:13:42.073848 | controller | ok: [instance]
2025-10-08 16:13:42.285299 | controller |
2025-10-08 16:13:42.285329 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-10-08 16:13:42.285337 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.184)       0:00:15.766 *****
2025-10-08 16:13:42.285347 | controller | changed: [instance]
2025-10-08 16:13:42.285546 | controller |
2025-10-08 16:13:42.285581 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-10-08 16:13:42.518867 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.211)       0:00:15.978 *****
2025-10-08 16:13:42.518921 | controller | changed: [instance]
2025-10-08 16:13:42.539919 | controller |
2025-10-08 16:13:42.539940 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-10-08 16:13:42.539948 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.233)       0:00:16.211 *****
2025-10-08 16:13:42.539957 | controller | skipping: [instance]
2025-10-08 16:13:42.561042 | controller |
2025-10-08 16:13:42.561061 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-10-08 16:13:42.561069 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.021)       0:00:16.232 *****
2025-10-08 16:13:42.561078 | controller | skipping: [instance]
2025-10-08 16:13:42.583098 | controller |
2025-10-08 16:13:42.583121 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-10-08 16:13:42.583149 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.021)       0:00:16.254 *****
2025-10-08 16:13:42.583160 | controller | skipping: [instance]
2025-10-08 16:13:42.604663 | controller |
2025-10-08 16:13:42.604684 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-10-08 16:13:42.604692 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.021)       0:00:16.276 *****
2025-10-08 16:13:42.604701 | controller | skipping: [instance]
2025-10-08 16:13:42.626756 | controller |
2025-10-08 16:13:42.626778 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-10-08 16:13:42.626793 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.021)       0:00:16.297 *****
2025-10-08 16:13:42.626804 | controller | skipping: [instance]
2025-10-08 16:13:42.648417 | controller |
2025-10-08 16:13:42.648439 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-10-08 16:13:42.648456 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.021)       0:00:16.319 *****
2025-10-08 16:13:42.648467 | controller | skipping: [instance]
2025-10-08 16:13:42.648639 | controller |
2025-10-08 16:13:42.648806 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-10-08 16:13:42.648987 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.021)       0:00:16.341 *****
2025-10-08 16:13:42.664801 | controller | skipping: [instance]
2025-10-08 16:13:42.664951 | controller |
2025-10-08 16:13:42.665092 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-10-08 16:13:42.665267 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.016)       0:00:16.358 *****
2025-10-08 16:13:42.694298 | controller | skipping: [instance]
2025-10-08 16:13:42.694481 | controller |
2025-10-08 16:13:42.694621 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-10-08 16:13:42.694757 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.029)       0:00:16.387 *****
2025-10-08 16:13:42.710942 | controller | skipping: [instance]
2025-10-08 16:13:42.731430 | controller |
2025-10-08 16:13:42.731470 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-10-08 16:13:42.731479 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.016)       0:00:16.404 *****
2025-10-08 16:13:42.731491 | controller | skipping: [instance]
2025-10-08 16:13:42.731519 | controller |
2025-10-08 16:13:42.731527 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-10-08 16:13:42.731629 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.020)       0:00:16.424 *****
2025-10-08 16:13:42.766599 | controller | skipping: [instance]
2025-10-08 16:13:42.798325 | controller |
2025-10-08 16:13:42.798344 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-10-08 16:13:42.798351 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.035)       0:00:16.459 *****
2025-10-08 16:13:42.798360 | controller | skipping: [instance]
2025-10-08 16:13:42.828848 | controller |
2025-10-08 16:13:42.828866 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-10-08 16:13:42.828874 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.031)       0:00:16.491 *****
2025-10-08 16:13:42.828883 | controller | skipping: [instance]
2025-10-08 16:13:42.859043 | controller |
2025-10-08 16:13:42.859061 | controller | TASK [test_deps : Install additional packages] *********************************
2025-10-08 16:13:42.859069 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.030)       0:00:16.521 *****
2025-10-08 16:13:42.859078 | controller | skipping: [instance]
2025-10-08 16:14:32.475823 | controller |
2025-10-08 16:14:32.475856 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-10-08 16:14:32.475865 | controller | Wednesday 08 October 2025  16:13:42 +0000 (0:00:00.030)       0:00:16.552 *****
2025-10-08 16:14:32.475876 | controller | ok: [instance]
2025-10-08 16:14:33.613680 | controller |
2025-10-08 16:14:33.613711 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-10-08 16:14:33.613719 | controller | Wednesday 08 October 2025  16:14:32 +0000 (0:00:49.616)       0:01:06.168 *****
2025-10-08 16:14:33.613730 | controller | ok: [instance]
2025-10-08 16:14:33.660776 | controller |
2025-10-08 16:14:33.660805 | controller | TASK [test_deps : Install extra packages] **************************************
2025-10-08 16:14:33.660813 | controller | Wednesday 08 October 2025  16:14:33 +0000 (0:00:01.137)       0:01:07.306 *****
2025-10-08 16:14:33.660823 | controller | skipping: [instance]
2025-10-08 16:14:33.722333 | controller |
2025-10-08 16:14:33.722357 | controller | PLAY RECAP *********************************************************************
2025-10-08 16:14:33.722365 | controller | instance                   : ok=19   changed=9    unreachable=0    failed=0    skipped=30   rescued=0    ignored=0
2025-10-08 16:14:33.722372 | controller |
2025-10-08 16:14:33.722378 | controller | Wednesday 08 October 2025  16:14:33 +0000 (0:00:00.044)       0:01:07.351 *****
2025-10-08 16:14:33.722383 | controller | ===============================================================================
2025-10-08 16:14:33.722388 | controller | test_deps : Install selinux python libs -------------------------------- 49.62s
2025-10-08 16:14:33.722400 | controller | repo_setup : Initialize python venv and install requirements ------------ 7.85s
2025-10-08 16:14:33.722405 | controller | test_deps : Install python yaml libs ------------------------------------ 1.14s
2025-10-08 16:14:33.722411 | controller | repo_setup : Get repo-setup repository ---------------------------------- 1.14s
2025-10-08 16:14:33.722420 | controller | Gathering Facts --------------------------------------------------------- 0.84s
2025-10-08 16:14:33.722426 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.83s
2025-10-08 16:14:33.722431 | controller | repo_setup : Make sure git-core package is installed -------------------- 0.79s
2025-10-08 16:14:33.722436 | controller | repo_setup : Install repo-setup package --------------------------------- 0.71s
2025-10-08 16:14:33.722441 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.68s
2025-10-08 16:14:33.722447 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.58s
2025-10-08 16:14:33.722452 | controller | repo_setup : Ensure directories are present ----------------------------- 0.54s
2025-10-08 16:14:33.722457 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.45s
2025-10-08 16:14:33.722462 | controller | test_deps : Disable ubi host subscription-manager integration ----------- 0.30s
2025-10-08 16:14:33.722467 | controller | test_deps : Detect mirrors file ----------------------------------------- 0.27s
2025-10-08 16:14:33.722473 | controller | repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist) --- 0.23s
2025-10-08 16:14:33.722478 | controller | repo_setup : Use RDO proxy mirrors -------------------------------------- 0.21s
2025-10-08 16:14:33.722484 | controller | repo_setup : Check for /etc/ci/mirror_info.sh --------------------------- 0.18s
2025-10-08 16:14:33.722489 | controller | Deploy repo-setup ------------------------------------------------------- 0.06s
2025-10-08 16:14:33.722494 | controller | repo_setup : Slurp current podified hash -------------------------------- 0.05s
2025-10-08 16:14:33.722499 | controller | test_deps : Install extra packages -------------------------------------- 0.04s
2025-10-08 16:14:33.722509 | controller | INFO     Running default > converge
2025-10-08 16:14:34.147144 | controller |
2025-10-08 16:14:34.176141 | controller | PLAY [Converge] ****************************************************************
2025-10-08 16:14:34.176169 | controller |
2025-10-08 16:14:34.176177 | controller | TASK [Include os_net_setup] ****************************************************
2025-10-08 16:14:34.176183 | controller | Wednesday 08 October 2025  16:14:34 +0000 (0:00:00.044)       0:00:00.044 *****
2025-10-08 16:14:34.176193 | controller |
2025-10-08 16:14:34.207048 | controller | TASK [os_net_setup : Delete existing subnets] **********************************
2025-10-08 16:14:34.207067 | controller | Wednesday 08 October 2025  16:14:34 +0000 (0:00:00.029)       0:00:00.074 *****
2025-10-08 16:14:34.207078 | controller | skipping: [instance] => (item=[{'name': 'public', 'external': True, 'shared': False, 'is_default': True, 'provider_network_type': 'flat', 'provider_physical_network': 'datacentre', 'availability_zone_hints': [], 'subnets': [{'name': 'public_subnet', 'cidr': '192.168.122.0/24', 'allocation_pool_start': '192.168.122.171', 'allocation_pool_end': '192.168.122.250', 'gateway_ip': '192.168.122.1', 'enable_dhcp': True}]}, {'name': 'public_subnet', 'cidr': '192.168.122.0/24', 'allocation_pool_start': '192.168.122.171', 'allocation_pool_end': '192.168.122.250', 'gateway_ip': '192.168.122.1', 'enable_dhcp': True}])
2025-10-08 16:14:34.238910 | controller | skipping: [instance]
2025-10-08 16:14:34.238933 | controller |
2025-10-08 16:14:34.238942 | controller | TASK [os_net_setup : Delete existing subnet pools] *****************************
2025-10-08 16:14:34.238949 | controller | Wednesday 08 October 2025  16:14:34 +0000 (0:00:00.030)       0:00:00.105 *****
2025-10-08 16:14:34.238960 | controller | skipping: [instance] => (item={'name': 'shared-pool-ipv4', 'default_prefix_length': 26, 'prefixes': '10.1.0.0/20', 'is_default': True, 'is_shared': True})
2025-10-08 16:14:34.268295 | controller | skipping: [instance] => (item={'name': 'shared-pool-ipv6', 'default_prefix_length': 64, 'prefixes': 'fdfe:381f:8400::/56', 'is_default': True, 'is_shared': True})
2025-10-08 16:14:34.268330 | controller | skipping: [instance]
2025-10-08 16:14:34.268337 | controller |
2025-10-08 16:14:34.268343 | controller | TASK [os_net_setup : Delete existing networks] *********************************
2025-10-08 16:14:34.268354 | controller | Wednesday 08 October 2025  16:14:34 +0000 (0:00:00.031)       0:00:00.137 *****
2025-10-08 16:14:34.268363 | controller | skipping: [instance] => (item={'name': 'public', 'external': True, 'shared': False, 'is_default': True, 'provider_network_type': 'flat', 'provider_physical_network': 'datacentre', 'availability_zone_hints': [], 'subnets': [{'name': 'public_subnet', 'cidr': '192.168.122.0/24', 'allocation_pool_start': '192.168.122.171', 'allocation_pool_end': '192.168.122.250', 'gateway_ip': '192.168.122.1', 'enable_dhcp': True}]})
2025-10-08 16:14:34.268413 | controller | skipping: [instance]
2025-10-08 16:14:34.268421 | controller |
2025-10-08 16:14:34.268426 | controller | TASK [os_net_setup : Print network creation commands] **************************
2025-10-08 16:14:34.268434 | controller | Wednesday 08 October 2025  16:14:34 +0000 (0:00:00.029)       0:00:00.166 *****
2025-10-08 16:14:34.318369 | controller | ok: [instance] =>
2025-10-08 16:14:34.318430 | controller |   msg: |-
2025-10-08 16:14:34.319485 | controller |     set -euo pipefail
2025-10-08 16:14:34.345333 | controller |     oc exec -n openstack openstackclient -- openstack network create \
2025-10-08 16:14:34.345357 | controller |         --external \
2025-10-08 16:14:34.345364 | controller |         --default \
2025-10-08 16:14:34.345370 | controller |         --provider-network-type flat \
2025-10-08 16:14:34.345382 | controller |         --provider-physical-network datacentre \
2025-10-08 16:14:34.345388 | controller |         --no-share \
2025-10-08 16:14:34.345393 | controller |         public
2025-10-08 16:14:34.345399 | controller |
2025-10-08 16:14:34.345405 | controller | TASK [os_net_setup : Create networks] ******************************************
2025-10-08 16:14:34.345410 | controller | Wednesday 08 October 2025  16:14:34 +0000 (0:00:00.050)       0:00:00.216 *****
2025-10-08 16:14:34.345419 | controller | skipping: [instance]
2025-10-08 16:14:34.345448 | controller |
2025-10-08 16:14:34.345457 | controller | TASK [os_net_setup : Print subnet command creation] ****************************
2025-10-08 16:14:34.345474 | controller | Wednesday 08 October 2025  16:14:34 +0000 (0:00:00.027)       0:00:00.243 *****
2025-10-08 16:14:34.402914 | controller | ok: [instance] =>
2025-10-08 16:14:34.429218 | controller |   msg: |-
2025-10-08 16:14:34.429262 | controller |     set -euo pipefail
2025-10-08 16:14:34.429273 | controller |     oc exec -n openstack openstackclient -- openstack subnet create \
2025-10-08 16:14:34.429281 | controller |         --allocation-pool start=192.168.122.171,end=192.168.122.250 \
2025-10-08 16:14:34.429288 | controller |         --subnet-range 192.168.122.0/24 \
2025-10-08 16:14:34.429296 | controller |         --gateway 192.168.122.1 \
2025-10-08 16:14:34.429303 | controller |         --network public \
2025-10-08 16:14:34.429310 | controller |         public_subnet
2025-10-08 16:14:34.429316 | controller |
2025-10-08 16:14:34.429323 | controller | TASK [os_net_setup : Create subnets] *******************************************
2025-10-08 16:14:34.429339 | controller | Wednesday 08 October 2025  16:14:34 +0000 (0:00:00.056)       0:00:00.300 *****
2025-10-08 16:14:34.429352 | controller | skipping: [instance]
2025-10-08 16:14:34.465358 | controller |
2025-10-08 16:14:34.465393 | controller | TASK [os_net_setup : Print subnet pools command creation] **********************
2025-10-08 16:14:34.465402 | controller | Wednesday 08 October 2025  16:14:34 +0000 (0:00:00.027)       0:00:00.327 *****
2025-10-08 16:14:34.465412 | controller | ok: [instance] =>
2025-10-08 16:14:34.465463 | controller |   msg: |-
2025-10-08 16:14:34.465471 | controller |     set -euo pipefail
2025-10-08 16:14:34.465478 | controller |     oc exec -n openstack openstackclient -- openstack subnet pool create \
2025-10-08 16:14:34.465483 | controller |         --default-prefix-length 26 \
2025-10-08 16:14:34.465489 | controller |         --pool-prefix 10.1.0.0/20 \
2025-10-08 16:14:34.465495 | controller |         --default \
2025-10-08 16:14:34.465500 | controller |         --share \
2025-10-08 16:14:34.465508 | controller |         shared-pool-ipv4
2025-10-08 16:14:34.465641 | controller |     oc exec -n openstack openstackclient -- openstack subnet pool create \
2025-10-08 16:14:34.465655 | controller |         --default-prefix-length 64 \
2025-10-08 16:14:34.465758 | controller |         --pool-prefix fdfe:381f:8400::/56 \
2025-10-08 16:14:34.465869 | controller |         --default \
2025-10-08 16:14:34.465976 | controller |         --share \
2025-10-08 16:14:34.466114 | controller |         shared-pool-ipv6
2025-10-08 16:14:34.466221 | controller |
2025-10-08 16:14:34.466348 | controller | TASK [os_net_setup : Create subnet pools] **************************************
2025-10-08 16:14:34.466469 | controller | Wednesday 08 October 2025  16:14:34 +0000 (0:00:00.035)       0:00:00.363 *****
2025-10-08 16:14:34.511493 | controller | skipping: [instance]
2025-10-08 16:14:34.511651 | controller |
2025-10-08 16:14:34.511753 | controller | PLAY RECAP *********************************************************************
2025-10-08 16:14:34.511878 | controller | instance                   : ok=3    changed=0    unreachable=0    failed=0    skipped=6    rescued=0    ignored=0
2025-10-08 16:14:34.511978 | controller |
2025-10-08 16:14:34.512111 | controller | Wednesday 08 October 2025  16:14:34 +0000 (0:00:00.047)       0:00:00.410 *****
2025-10-08 16:14:34.512222 | controller | ===============================================================================
2025-10-08 16:14:34.512364 | controller | os_net_setup : Print subnet command creation ---------------------------- 0.06s
2025-10-08 16:14:34.512481 | controller | os_net_setup : Print network creation commands -------------------------- 0.05s
2025-10-08 16:14:34.512591 | controller | os_net_setup : Create subnet pools -------------------------------------- 0.05s
2025-10-08 16:14:34.512711 | controller | os_net_setup : Print subnet pools command creation ---------------------- 0.04s
2025-10-08 16:14:34.512819 | controller | os_net_setup : Delete existing subnet pools ----------------------------- 0.03s
2025-10-08 16:14:34.512931 | controller | os_net_setup : Delete existing subnets ---------------------------------- 0.03s
2025-10-08 16:14:34.513037 | controller | Include os_net_setup ---------------------------------------------------- 0.03s
2025-10-08 16:14:34.513178 | controller | os_net_setup : Delete existing networks --------------------------------- 0.03s
2025-10-08 16:14:34.513312 | controller | os_net_setup : Create networks ------------------------------------------ 0.03s
2025-10-08 16:14:34.513428 | controller | os_net_setup : Create subnets ------------------------------------------- 0.03s
2025-10-08 16:14:34.569520 | controller | INFO     Running default > cleanup
2025-10-08 16:14:34.569907 | controller | WARNING  Skipping, cleanup playbook not configured.
2025-10-08 16:14:34.570512 | controller | INFO     Writing /tmp/report.html report.
2025-10-08 16:14:34.966378 | controller | changed
2025-10-08 16:14:34.986753 | 
2025-10-08 16:14:34.986823 | PLAY RECAP
2025-10-08 16:14:34.986867 | controller | ok: 3 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-08 16:14:34.986890 | 
2025-10-08 16:14:35.081483 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-08 16:14:35.082331 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-08 16:14:35.654714 | 
2025-10-08 16:14:35.654825 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-10-08 16:14:35.676645 | 
2025-10-08 16:14:35.676874 | TASK [Filter out host if needed]
2025-10-08 16:14:35.686011 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-10-08 16:14:35.691205 | 
2025-10-08 16:14:35.691277 | TASK [Ensure file is present]
2025-10-08 16:14:36.056106 | controller | ok
2025-10-08 16:14:36.062782 | 
2025-10-08 16:14:36.062859 | TASK [Manage molecule report file]
2025-10-08 16:14:36.585726 | controller | changed
2025-10-08 16:14:36.590927 | 
2025-10-08 16:14:36.590999 | TASK [Check if we get ci-framework-data basedir]
2025-10-08 16:14:36.793081 | controller | ok
2025-10-08 16:14:36.799386 | 
2025-10-08 16:14:36.799456 | TASK [Create ci-framework-data log directory for zuul]
2025-10-08 16:14:37.132625 | controller | changed
2025-10-08 16:14:37.137843 | 
2025-10-08 16:14:37.137945 | TASK [Copy ci-framework interesting files]
2025-10-08 16:14:37.335715 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2025-10-08 16:14:37.662147 | controller | changed
2025-10-08 16:14:37.667463 | 
2025-10-08 16:14:37.667535 | TASK [Get SELinux listing]
2025-10-08 16:14:38.190881 | controller | changed
2025-10-08 16:14:38.197493 | 
2025-10-08 16:14:38.197575 | TASK [Generate log index]
2025-10-08 16:14:38.828970 | controller | changed
2025-10-08 16:14:38.835175 | 
2025-10-08 16:14:38.835243 | TASK [Get some env related data]
2025-10-08 16:14:39.367931 | controller | /home/zuul/.local/bin/ansible
2025-10-08 16:14:40.360930 | controller | changed
2025-10-08 16:14:40.367025 | 
2025-10-08 16:14:40.367097 | TASK [Generate list of logs to collect in home directory]
2025-10-08 16:14:40.670216 | controller | ok: All paths examined
2025-10-08 16:14:40.675459 | 
2025-10-08 16:14:40.675536 | LOOP [Copy logs from home directory]
2025-10-08 16:14:40.999846 | controller | changed:
2025-10-08 16:14:40.999983 | controller | {
2025-10-08 16:14:41.000014 | controller |   "atime": 1759939969.61425,
2025-10-08 16:14:41.000035 | controller |   "ctime": 1759939985.5274398,
2025-10-08 16:14:41.000053 | controller |   "dev": 64513,
2025-10-08 16:14:41.000071 | controller |   "gid": 1000,
2025-10-08 16:14:41.000088 | controller |   "gr_name": "zuul",
2025-10-08 16:14:41.000106 | controller |   "inode": 4449304,
2025-10-08 16:14:41.000122 | controller |   "isblk": false,
2025-10-08 16:14:41.000138 | controller |   "ischr": false,
2025-10-08 16:14:41.000153 | controller |   "isdir": false,
2025-10-08 16:14:41.000168 | controller |   "isfifo": false,
2025-10-08 16:14:41.000183 | controller |   "isgid": false,
2025-10-08 16:14:41.000198 | controller |   "islnk": false,
2025-10-08 16:14:41.000213 | controller |   "isreg": true,
2025-10-08 16:14:41.000229 | controller |   "issock": false,
2025-10-08 16:14:41.000245 | controller |   "isuid": false,
2025-10-08 16:14:41.000260 | controller |   "mode": "0644",
2025-10-08 16:14:41.000275 | controller |   "mtime": 1759939985.5274398,
2025-10-08 16:14:41.000290 | controller |   "nlink": 1,
2025-10-08 16:14:41.000305 | controller |   "path": "/home/zuul/ansible.log",
2025-10-08 16:14:41.000321 | controller |   "pw_name": "zuul",
2025-10-08 16:14:41.000338 | controller |   "rgrp": true,
2025-10-08 16:14:41.000353 | controller |   "roth": true,
2025-10-08 16:14:41.000374 | controller |   "rusr": true,
2025-10-08 16:14:41.000391 | controller |   "size": 6749,
2025-10-08 16:14:41.000408 | controller |   "uid": 1000,
2025-10-08 16:14:41.000424 | controller |   "wgrp": false,
2025-10-08 16:14:41.000439 | controller |   "woth": false,
2025-10-08 16:14:41.000457 | controller |   "wusr": true,
2025-10-08 16:14:41.000474 | controller |   "xgrp": false,
2025-10-08 16:14:41.000489 | controller |   "xoth": false,
2025-10-08 16:14:41.000503 | controller |   "xusr": false
2025-10-08 16:14:41.000518 | controller | }
2025-10-08 16:14:41.014501 | 
2025-10-08 16:14:41.014606 | TASK [Copy crio stats log file]
2025-10-08 16:14:41.038490 | controller | skipping: Conditional result was False
2025-10-08 16:14:41.044669 | 
2025-10-08 16:14:41.044759 | TASK [Get SELinux related data]
2025-10-08 16:14:41.253204 | controller | <no matches>
2025-10-08 16:14:41.568856 | controller | ERROR
2025-10-08 16:14:41.569042 | controller | {
2025-10-08 16:14:41.569076 | controller |   "delta": "0:00:00.008448",
2025-10-08 16:14:41.569098 | controller |   "end": "2025-10-08 16:14:41.253763",
2025-10-08 16:14:41.569116 | controller |   "msg": "non-zero return code",
2025-10-08 16:14:41.569133 | controller |   "rc": 1,
2025-10-08 16:14:41.569149 | controller |   "start": "2025-10-08 16:14:41.245315"
2025-10-08 16:14:41.569182 | controller | }
2025-10-08 16:14:41.569207 | controller | ERROR: Ignoring Errors
2025-10-08 16:14:41.574421 | 
2025-10-08 16:14:41.574551 | TASK [Create system configuration directory]
2025-10-08 16:14:41.754999 | controller | changed
2025-10-08 16:14:41.760299 | 
2025-10-08 16:14:41.760363 | TASK [Get some of the system configurations]
2025-10-08 16:14:42.283961 | controller | changed
2025-10-08 16:14:42.296267 | 
2025-10-08 16:14:42.296352 | TASK [Copy generated documentation if available]
2025-10-08 16:14:42.310065 | controller | skipping: Conditional result was False
2025-10-08 16:14:42.316392 | 
2025-10-08 16:14:42.316475 | TASK [Copy generated AsciiDoc documentation if available]
2025-10-08 16:14:42.341657 | controller | skipping: Conditional result was False
2025-10-08 16:14:42.347861 | 
2025-10-08 16:14:42.347951 | TASK [Compress logs bigger than 2MB]
2025-10-08 16:14:42.875464 | controller | changed
2025-10-08 16:14:42.881085 | 
2025-10-08 16:14:42.881170 | TASK [Copy files from workspace on node]
2025-10-08 16:14:42.901619 | controller | ok
2025-10-08 16:14:42.925703 | 
2025-10-08 16:14:42.925799 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-08 16:14:42.939505 | controller | skipping: Conditional result was False
2025-10-08 16:14:42.945586 | 
2025-10-08 16:14:42.945664 | TASK [fetch-output : Set log path for single node]
2025-10-08 16:14:42.974067 | controller | ok
2025-10-08 16:14:42.980025 | 
2025-10-08 16:14:42.980095 | LOOP [fetch-output : Ensure local output dirs]
2025-10-08 16:14:43.202130 | controller -> localhost | ok: "/var/lib/zuul/builds/21f233acfca840e09eddb40ac7652094/work/logs"
2025-10-08 16:14:43.202336 | controller -> localhost | changed: All items complete
2025-10-08 16:14:43.202366 | 
2025-10-08 16:14:43.404090 | controller -> localhost | changed: "/var/lib/zuul/builds/21f233acfca840e09eddb40ac7652094/work/artifacts"
2025-10-08 16:14:43.601054 | controller -> localhost | changed: "/var/lib/zuul/builds/21f233acfca840e09eddb40ac7652094/work/docs"
2025-10-08 16:14:43.616042 | 
2025-10-08 16:14:43.616135 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-08 16:14:44.241546 | controller | changed:
2025-10-08 16:14:44.241739 | controller | .d..t...... ./
2025-10-08 16:14:44.241773 | controller | >f+++++++++ README.html
2025-10-08 16:14:44.241797 | controller | >f+++++++++ ansible-execution.log
2025-10-08 16:14:44.241819 | controller | >f+++++++++ ansible.log
2025-10-08 16:14:44.241838 | controller | >f+++++++++ dmesg.log
2025-10-08 16:14:44.241857 | controller | >f+++++++++ installed-pkgs.log
2025-10-08 16:14:44.241879 | controller | >f+++++++++ python.log
2025-10-08 16:14:44.241901 | controller | >f+++++++++ registries.conf
2025-10-08 16:14:44.241950 | controller | >f+++++++++ report.html
2025-10-08 16:14:44.241977 | controller | >f+++++++++ selinux-denials.log
2025-10-08 16:14:44.241996 | controller | >f+++++++++ selinux-listing.log
2025-10-08 16:14:44.242014 | controller | cd+++++++++ ci-framework-data/
2025-10-08 16:14:44.242033 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-10-08 16:14:44.242051 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-10-08 16:14:44.242068 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-10-08 16:14:44.242085 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-10-08 16:14:44.242101 | controller | cd+++++++++ ci-framework-data/artifacts/repositories/
2025-10-08 16:14:44.242118 | controller | >f+++++++++ ci-framework-data/artifacts/repositories/delorean.repo.md5
2025-10-08 16:14:44.242136 | controller | cd+++++++++ ci-framework-data/logs/
2025-10-08 16:14:44.242153 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-10-08 16:14:44.242169 | controller | cd+++++++++ registries.conf.d/
2025-10-08 16:14:44.242185 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-10-08 16:14:44.242201 | controller | cd+++++++++ system-config/
2025-10-08 16:14:44.242218 | controller | cd+++++++++ system-config/libvirt/
2025-10-08 16:14:44.242236 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-10-08 16:14:44.242252 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-10-08 16:14:44.762645 | controller | changed: .d..t...... ./
2025-10-08 16:14:45.152751 | controller | changed: .d..t...... ./
2025-10-08 16:14:45.171308 | 
2025-10-08 16:14:45.171401 | TASK [Return artifact to Zuul]
2025-10-08 16:14:45.200542 | controller | ok
2025-10-08 16:14:45.221081 | 
2025-10-08 16:14:45.221141 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-10-08 16:14:45.221233 | 
2025-10-08 16:14:45.221259 | PLAY RECAP
2025-10-08 16:14:45.221295 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-10-08 16:14:45.221315 | 
2025-10-08 16:14:45.309304 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-08 16:14:45.310080 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-08 16:14:45.842163 | 
2025-10-08 16:14:45.842266 | PLAY [all]
2025-10-08 16:14:45.860821 | 
2025-10-08 16:14:45.860900 | TASK [include_role : fetch-output]
2025-10-08 16:14:45.891325 | controller | ok
2025-10-08 16:14:45.908757 | 
2025-10-08 16:14:45.908850 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-08 16:14:45.953052 | controller | skipping: Conditional result was False
2025-10-08 16:14:45.958887 | 
2025-10-08 16:14:45.959053 | TASK [fetch-output : Set log path for single node]
2025-10-08 16:14:45.987228 | controller | ok
2025-10-08 16:14:45.992432 | 
2025-10-08 16:14:45.992516 | LOOP [fetch-output : Ensure local output dirs]
2025-10-08 16:14:46.325548 | controller -> localhost | ok: "/var/lib/zuul/builds/21f233acfca840e09eddb40ac7652094/work/logs"
2025-10-08 16:14:46.511264 | controller -> localhost | ok: "/var/lib/zuul/builds/21f233acfca840e09eddb40ac7652094/work/artifacts"
2025-10-08 16:14:46.703399 | controller -> localhost | ok: "/var/lib/zuul/builds/21f233acfca840e09eddb40ac7652094/work/docs"
2025-10-08 16:14:46.711577 | 
2025-10-08 16:14:46.711683 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-08 16:14:47.253572 | controller | ok
2025-10-08 16:14:47.253771 | controller | ok: All items complete
2025-10-08 16:14:47.253803 | 
2025-10-08 16:14:47.629109 | controller | ok
2025-10-08 16:14:48.044215 | controller | ok
2025-10-08 16:14:48.065715 | 
2025-10-08 16:14:48.065839 | TASK [include_role : fetch-output-openshift]
2025-10-08 16:14:48.079904 | controller | skipping: Conditional result was False
2025-10-08 16:14:48.086768 | 
2025-10-08 16:14:48.086841 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-08 16:14:48.522141 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.023099
2025-10-08 16:14:48.746197 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006315
2025-10-08 16:14:48.776994 | 
2025-10-08 16:14:48.777108 | PLAY [all]
2025-10-08 16:14:48.791133 | 
2025-10-08 16:14:48.791216 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-08 16:14:49.217347 | controller | changed
2025-10-08 16:14:49.240958 | 
2025-10-08 16:14:49.241019 | PLAY RECAP
2025-10-08 16:14:49.241061 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-08 16:14:49.241084 | 
2025-10-08 16:14:49.317075 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-08 16:14:49.317835 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-08 16:14:49.926290 | 
2025-10-08 16:14:49.926397 | PLAY [localhost]
2025-10-08 16:14:49.944621 | 
2025-10-08 16:14:49.944881 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-08 16:14:50.249785 | localhost | changed
2025-10-08 16:14:50.256150 | 
2025-10-08 16:14:50.256234 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-08 16:14:50.285373 | localhost | ok
2025-10-08 16:14:50.293716 | 
2025-10-08 16:14:50.293791 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-08 16:14:50.616381 | localhost | changed
2025-10-08 16:14:50.622155 | 
2025-10-08 16:14:50.622227 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-08 16:14:51.188118 | localhost | changed
2025-10-08 16:14:51.193274 | 
2025-10-08 16:14:51.193341 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-08 16:14:51.545980 | localhost | Identity added: /var/lib/zuul/builds/21f233acfca840e09eddb40ac7652094/work/tmp/ansible.wdr_3fnr (/var/lib/zuul/builds/21f233acfca840e09eddb40ac7652094/work/tmp/ansible.wdr_3fnr)
2025-10-08 16:14:51.546162 | localhost | ok: Runtime: 0:00:00.006204
2025-10-08 16:14:51.550388 | 
2025-10-08 16:14:51.550460 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-08 16:14:51.781586 | localhost | ok: Runtime: 0:00:00.004645
2025-10-08 16:14:51.786298 | 
2025-10-08 16:14:51.786367 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-08 16:14:51.857490 | localhost | changed
2025-10-08 16:14:51.861739 | 
2025-10-08 16:14:51.861830 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-08 16:14:52.196801 | localhost | changed
2025-10-08 16:14:52.217469 | 
2025-10-08 16:14:52.217539 | PLAY [localhost]
2025-10-08 16:14:52.229721 | 
2025-10-08 16:14:52.229784 | TASK [Generate bulk log download script]
2025-10-08 16:14:52.248205 | localhost | ok
2025-10-08 16:14:52.260585 | 
2025-10-08 16:14:52.260659 | TASK [local-log-download : Check API endpoint is defined]
2025-10-08 16:14:52.289152 | localhost | ok: All assertions passed
2025-10-08 16:14:52.294252 | 
2025-10-08 16:14:52.294318 | TASK [local-log-download : Create download script]
2025-10-08 16:14:52.666202 | localhost -> localhost | changed
2025-10-08 16:14:52.675130 | 
2025-10-08 16:14:52.675210 | TASK [Register quick-download link]
2025-10-08 16:14:52.692899 | localhost | ok
2025-10-08 16:14:52.730809 | 
2025-10-08 16:14:52.730894 | PLAY [logserver.rdoproject.org]
2025-10-08 16:14:52.740770 | 
2025-10-08 16:14:52.740833 | TASK [Set zuul-log-path fact]
2025-10-08 16:14:52.756566 | logserver.rdoproject.org | ok
2025-10-08 16:14:52.766366 | 
2025-10-08 16:14:52.766436 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-08 16:14:52.792881 | logserver.rdoproject.org | ok
2025-10-08 16:14:52.798749 | 
2025-10-08 16:14:52.798819 | TASK [upload-logs : Create log directories]
2025-10-08 16:14:54.494845 | logserver.rdoproject.org | changed
2025-10-08 16:14:54.498173 | 
2025-10-08 16:14:54.498254 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-08 16:14:54.736925 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004795
2025-10-08 16:14:54.741439 | 
2025-10-08 16:14:54.741696 | TASK [upload-logs : Upload logs to log server]
2025-10-08 16:14:56.311385 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-08 16:14:56.315009 | 
2025-10-08 16:14:56.315086 | LOOP [upload-logs : Compress console log and json output]
2025-10-08 16:14:56.355159 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 16:14:56.364582 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 16:14:56.373029 | 
2025-10-08 16:14:56.373105 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-08 16:14:56.411795 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 16:14:56.412056 | 
2025-10-08 16:14:56.416161 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 16:14:56.421337 | 
2025-10-08 16:14:56.421411 | LOOP [upload-logs : Upload console log and json output]