2025-10-08 15:06:22.399052 | Job console starting...
2025-10-08 15:06:22.646789 | Updating repositories
2025-10-08 15:06:23.377483 | Preparing job workspace
2025-10-08 15:06:31.032692 | Running Ansible setup...
2025-10-08 15:06:34.743585 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-08 15:06:35.314009 | 
2025-10-08 15:06:35.314111 | PLAY [localhost]
2025-10-08 15:06:35.325482 | 
2025-10-08 15:06:35.325569 | TASK [Gathering Facts]
2025-10-08 15:06:36.202369 | localhost | ok
2025-10-08 15:06:36.215648 | 
2025-10-08 15:06:36.215956 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-08 15:06:36.553925 | localhost -> localhost | changed
2025-10-08 15:06:36.562074 | 
2025-10-08 15:06:36.562197 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-08 15:06:37.278600 | localhost -> localhost | changed
2025-10-08 15:06:37.286634 | 
2025-10-08 15:06:37.286702 | TASK [Setup log path fact]
2025-10-08 15:06:37.303782 | localhost | ok
2025-10-08 15:06:37.314941 | 
2025-10-08 15:06:37.315014 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-08 15:06:37.341792 | localhost | ok
2025-10-08 15:06:37.349063 | 
2025-10-08 15:06:37.349129 | TASK [emit-job-header : Print job information]
2025-10-08 15:06:37.376432 | # Job Information
2025-10-08 15:06:37.376591 | Ansible Version: 2.15.12
2025-10-08 15:06:37.376623 | Job: cifmw-molecule-openshift_setup
2025-10-08 15:06:37.376645 | Pipeline: github-check
2025-10-08 15:06:37.376664 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-10-08 15:06:37.376682 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3368
2025-10-08 15:06:37.376701 | Log URL (when completed): https://logserver.rdoproject.org/d64/rdoproject.org/d6470fb11ad14c358e968e29ba9fd183/
2025-10-08 15:06:37.376719 | Event ID: dc080060-a456-11f0-897c-380a1fc1fefa
2025-10-08 15:06:37.380294 | 
2025-10-08 15:06:37.380360 | LOOP [emit-job-header : Print node information]
2025-10-08 15:06:37.468320 | localhost | ok:
2025-10-08 15:06:37.468519 | localhost | # Node Information
2025-10-08 15:06:37.468561 | localhost | Inventory Hostname: controller
2025-10-08 15:06:37.468588 | localhost | Hostname: np0005477011
2025-10-08 15:06:37.468612 | localhost | Username: zuul
2025-10-08 15:06:37.468633 | localhost | Distro: CentOS 9
2025-10-08 15:06:37.468651 | localhost | Provider: ibm-bm4-nodepool
2025-10-08 15:06:37.468669 | localhost | Region: regionOne
2025-10-08 15:06:37.468685 | localhost | Label: centos-9-stream-crc-2-48-0-xl-ibm
2025-10-08 15:06:37.468702 | localhost | Product Name: OpenStack Compute
2025-10-08 15:06:37.468718 | localhost | Interface IP: 192.168.26.59
2025-10-08 15:06:37.495537 | 
2025-10-08 15:06:37.495607 | PLAY [all]
2025-10-08 15:06:37.502074 | 
2025-10-08 15:06:37.502140 | TASK [Gather network facts]
2025-10-08 15:06:37.916490 | controller | ok
2025-10-08 15:06:37.931459 | 
2025-10-08 15:06:37.931530 | TASK [include_role : start-zuul-console]
2025-10-08 15:06:37.949806 | controller | ok
2025-10-08 15:06:37.961839 | 
2025-10-08 15:06:37.961931 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-08 15:06:38.335892 | controller | ok
2025-10-08 15:06:38.347274 | 
2025-10-08 15:06:38.347355 | TASK [include_role : add-build-sshkey]
2025-10-08 15:06:38.367437 | controller | ok
2025-10-08 15:06:38.383034 | 
2025-10-08 15:06:38.383346 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-08 15:06:38.590460 | controller -> localhost | ok
2025-10-08 15:06:38.595990 | 
2025-10-08 15:06:38.596058 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-08 15:06:38.614438 | controller | ok
2025-10-08 15:06:38.627776 | controller | included: /var/lib/zuul/builds/d6470fb11ad14c358e968e29ba9fd183/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-08 15:06:38.633721 | 
2025-10-08 15:06:38.633790 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-08 15:06:39.055873 | controller -> localhost | Generating public/private rsa key pair.
2025-10-08 15:06:39.056319 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/d6470fb11ad14c358e968e29ba9fd183/work/d6470fb11ad14c358e968e29ba9fd183_id_rsa.
2025-10-08 15:06:39.056374 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/d6470fb11ad14c358e968e29ba9fd183/work/d6470fb11ad14c358e968e29ba9fd183_id_rsa.pub.
2025-10-08 15:06:39.056403 | controller -> localhost | The key fingerprint is:
2025-10-08 15:06:39.056425 | controller -> localhost | SHA256:4Ke/oPqdNCf3pHf06A3rOEinSQmHL8QBOPLMOmFvnro zuul-build-sshkey
2025-10-08 15:06:39.056444 | controller -> localhost | The key's randomart image is:
2025-10-08 15:06:39.056463 | controller -> localhost | +---[RSA 3072]----+
2025-10-08 15:06:39.056480 | controller -> localhost | |   ...           |
2025-10-08 15:06:39.056499 | controller -> localhost | |. o   .          |
2025-10-08 15:06:39.056516 | controller -> localhost | | = . ..o         |
2025-10-08 15:06:39.056535 | controller -> localhost | |..+  .=..        |
2025-10-08 15:06:39.056563 | controller -> localhost | |.o.  ..+S.       |
2025-10-08 15:06:39.056581 | controller -> localhost | |o  o  .o= . .    |
2025-10-08 15:06:39.056598 | controller -> localhost | | .o . *+o=...o   |
2025-10-08 15:06:39.056617 | controller -> localhost | |   o + O++o.o+.  |
2025-10-08 15:06:39.056634 | controller -> localhost | | E+oo o +oo=+ .  |
2025-10-08 15:06:39.056649 | controller -> localhost | +----[SHA256]-----+
2025-10-08 15:06:39.056696 | controller -> localhost | ok: Runtime: 0:00:00.083646
2025-10-08 15:06:39.063338 | 
2025-10-08 15:06:39.063417 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-08 15:06:39.092631 | controller | ok
2025-10-08 15:06:39.116500 | controller | included: /var/lib/zuul/builds/d6470fb11ad14c358e968e29ba9fd183/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-08 15:06:39.128876 | 
2025-10-08 15:06:39.128999 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-08 15:06:39.153354 | controller | skipping: Conditional result was False
2025-10-08 15:06:39.159191 | 
2025-10-08 15:06:39.159279 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-08 15:06:39.615885 | controller | changed
2025-10-08 15:06:39.621657 | 
2025-10-08 15:06:39.621736 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-08 15:06:39.876444 | controller | ok
2025-10-08 15:06:39.882111 | 
2025-10-08 15:06:39.882209 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-08 15:06:40.968487 | controller | changed
2025-10-08 15:06:40.973394 | 
2025-10-08 15:06:40.973458 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-08 15:06:42.005616 | controller | changed
2025-10-08 15:06:42.011590 | 
2025-10-08 15:06:42.011656 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-08 15:06:42.024868 | controller | skipping: Conditional result was False
2025-10-08 15:06:42.030946 | 
2025-10-08 15:06:42.031013 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-08 15:06:42.349056 | controller -> localhost | changed
2025-10-08 15:06:42.358969 | 
2025-10-08 15:06:42.359050 | TASK [add-build-sshkey : Add back temp key]
2025-10-08 15:06:42.595858 | controller -> localhost | Identity added: /var/lib/zuul/builds/d6470fb11ad14c358e968e29ba9fd183/work/d6470fb11ad14c358e968e29ba9fd183_id_rsa (zuul-build-sshkey)
2025-10-08 15:06:42.596053 | controller -> localhost | ok: Runtime: 0:00:00.007153
2025-10-08 15:06:42.601656 | 
2025-10-08 15:06:42.601727 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-08 15:06:42.965139 | controller | ok
2025-10-08 15:06:42.971394 | 
2025-10-08 15:06:42.971464 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-08 15:06:42.994989 | controller | skipping: Conditional result was False
2025-10-08 15:06:43.005132 | 
2025-10-08 15:06:43.005201 | TASK [include_role : validate-host]
2025-10-08 15:06:43.023474 | controller | ok
2025-10-08 15:06:43.042600 | 
2025-10-08 15:06:43.042688 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-08 15:06:43.070483 | controller | ok
2025-10-08 15:06:43.075760 | 
2025-10-08 15:06:43.075843 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-08 15:06:43.315687 | controller -> localhost | ok
2025-10-08 15:06:43.321232 | 
2025-10-08 15:06:43.321297 | TASK [validate-host : Collect information about the host]
2025-10-08 15:06:44.011621 | controller | ok
2025-10-08 15:06:44.025089 | 
2025-10-08 15:06:44.025165 | TASK [validate-host : Sanitize hostname]
2025-10-08 15:06:44.070763 | controller | ok
2025-10-08 15:06:44.075593 | 
2025-10-08 15:06:44.075664 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-08 15:06:44.474963 | controller -> localhost | changed
2025-10-08 15:06:44.480418 | 
2025-10-08 15:06:44.480487 | TASK [validate-host : Collect information about zuul worker]
2025-10-08 15:06:44.852424 | controller | ok
2025-10-08 15:06:44.857193 | 
2025-10-08 15:06:44.857278 | TASK [validate-host : Write out all zuul information for each host]
2025-10-08 15:06:45.216601 | controller -> localhost | changed
2025-10-08 15:06:45.226306 | 
2025-10-08 15:06:45.226459 | TASK [include_role : prepare-workspace-openshift]
2025-10-08 15:06:45.239385 | controller | skipping: Conditional result was False
2025-10-08 15:06:45.245049 | 
2025-10-08 15:06:45.245118 | TASK [include_role : remove-zuul-sshkey]
2025-10-08 15:06:45.259091 | controller | skipping: Conditional result was False
2025-10-08 15:06:45.267311 | 
2025-10-08 15:06:45.267390 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-08 15:06:45.513641 | controller | ok: "logs"
2025-10-08 15:06:45.513944 | controller | ok: All items complete
2025-10-08 15:06:45.513985 | 
2025-10-08 15:06:45.735313 | controller | ok: "artifacts"
2025-10-08 15:06:45.953260 | controller | ok: "docs"
2025-10-08 15:06:45.965569 | 
2025-10-08 15:06:45.965663 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-08 15:06:46.216607 | controller | changed: "logs"
2025-10-08 15:06:46.446825 | controller | changed: "artifacts"
2025-10-08 15:06:46.678286 | controller | changed: "docs"
2025-10-08 15:06:46.700775 | 
2025-10-08 15:06:46.700863 | PLAY RECAP
2025-10-08 15:06:46.700940 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-08 15:06:46.700979 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-08 15:06:46.701001 | 
2025-10-08 15:06:46.775726 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-08 15:06:46.776443 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-08 15:06:47.379117 | 
2025-10-08 15:06:47.379235 | PLAY [all]
2025-10-08 15:06:47.401104 | 
2025-10-08 15:06:47.401195 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-08 15:06:47.460842 | controller | ok
2025-10-08 15:06:47.466145 | 
2025-10-08 15:06:47.466249 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-08 15:06:47.861680 | controller | changed
2025-10-08 15:06:47.867473 | 
2025-10-08 15:06:47.867575 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-08 15:06:49.071771 | controller | changed
2025-10-08 15:06:49.082647 | 
2025-10-08 15:06:49.082750 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-10-08 15:06:49.538119 | controller | changed:
2025-10-08 15:06:49.538293 | controller | {
2025-10-08 15:06:49.538328 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-10-08 15:06:49.538360 | controller | }
2025-10-08 15:06:49.812045 | controller | changed:
2025-10-08 15:06:49.812132 | controller | {
2025-10-08 15:06:49.812163 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-10-08 15:06:49.812187 | controller | }
2025-10-08 15:06:50.089243 | controller | changed:
2025-10-08 15:06:50.089327 | controller | {
2025-10-08 15:06:50.089427 | 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 15:06:50.089456 | controller | }
2025-10-08 15:06:50.361098 | controller | changed:
2025-10-08 15:06:50.361189 | controller | {
2025-10-08 15:06:50.361221 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-10-08 15:06:50.361244 | controller | }
2025-10-08 15:06:50.640433 | controller | changed:
2025-10-08 15:06:50.640525 | controller | {
2025-10-08 15:06:50.640567 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-10-08 15:06:50.640591 | controller | }
2025-10-08 15:06:50.911764 | controller | changed:
2025-10-08 15:06:50.911858 | controller | {
2025-10-08 15:06:50.911887 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-10-08 15:06:50.911941 | controller | }
2025-10-08 15:06:51.184165 | controller | changed:
2025-10-08 15:06:51.184247 | controller | {
2025-10-08 15:06:51.184276 | 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 15:06:51.184299 | controller | }
2025-10-08 15:06:51.463746 | controller | changed:
2025-10-08 15:06:51.463823 | controller | {
2025-10-08 15:06:51.463852 | 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 15:06:51.463875 | controller | }
2025-10-08 15:06:51.739482 | controller | changed:
2025-10-08 15:06:51.739588 | controller | {
2025-10-08 15:06:51.739620 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-10-08 15:06:51.739642 | controller | }
2025-10-08 15:06:52.064364 | controller | changed:
2025-10-08 15:06:52.064440 | controller | {
2025-10-08 15:06:52.064468 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-10-08 15:06:52.064490 | controller | }
2025-10-08 15:06:52.318601 | controller | changed:
2025-10-08 15:06:52.318691 | controller | {
2025-10-08 15:06:52.318721 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-10-08 15:06:52.318744 | controller | }
2025-10-08 15:06:52.616032 | controller | changed:
2025-10-08 15:06:52.616125 | controller | {
2025-10-08 15:06:52.616155 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-10-08 15:06:52.616176 | controller | }
2025-10-08 15:06:52.901448 | controller | changed:
2025-10-08 15:06:52.901532 | controller | {
2025-10-08 15:06:52.901582 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-10-08 15:06:52.901605 | controller | }
2025-10-08 15:06:53.185000 | controller | changed:
2025-10-08 15:06:53.185093 | controller | {
2025-10-08 15:06:53.185122 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-10-08 15:06:53.185145 | controller | }
2025-10-08 15:06:53.464546 | controller | changed:
2025-10-08 15:06:53.464783 | controller | {
2025-10-08 15:06:53.464812 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-10-08 15:06:53.464834 | controller | }
2025-10-08 15:06:53.770869 | controller | changed:
2025-10-08 15:06:53.770982 | controller | {
2025-10-08 15:06:53.771013 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-10-08 15:06:53.771035 | controller | }
2025-10-08 15:06:54.072362 | controller | changed:
2025-10-08 15:06:54.072435 | controller | {
2025-10-08 15:06:54.072463 | 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 15:06:54.072486 | controller | }
2025-10-08 15:06:54.402413 | controller | changed:
2025-10-08 15:06:54.402494 | controller | {
2025-10-08 15:06:54.402522 | 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 15:06:54.402568 | controller | }
2025-10-08 15:06:54.715300 | controller | changed:
2025-10-08 15:06:54.715390 | controller | {
2025-10-08 15:06:54.715421 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-10-08 15:06:54.715442 | controller | }
2025-10-08 15:06:55.004026 | controller | changed:
2025-10-08 15:06:55.004136 | controller | {
2025-10-08 15:06:55.004163 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-10-08 15:06:55.004184 | controller | }
2025-10-08 15:06:55.288048 | controller | changed:
2025-10-08 15:06:55.288295 | controller | {
2025-10-08 15:06:55.288339 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-10-08 15:06:55.288364 | controller | }
2025-10-08 15:06:55.596858 | controller | changed:
2025-10-08 15:06:55.596985 | controller | {
2025-10-08 15:06:55.597018 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-10-08 15:06:55.597042 | controller | }
2025-10-08 15:06:55.888342 | controller | changed:
2025-10-08 15:06:55.888440 | controller | {
2025-10-08 15:06:55.888471 | 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 15:06:55.888494 | controller | }
2025-10-08 15:06:56.183821 | controller | changed:
2025-10-08 15:06:56.183904 | controller | {
2025-10-08 15:06:56.183953 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-10-08 15:06:56.183977 | controller | }
2025-10-08 15:06:56.477990 | controller | changed:
2025-10-08 15:06:56.478092 | controller | {
2025-10-08 15:06:56.478123 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-10-08 15:06:56.478146 | controller | }
2025-10-08 15:06:56.766061 | controller | changed:
2025-10-08 15:06:56.766140 | controller | {
2025-10-08 15:06:56.766168 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-10-08 15:06:56.766190 | controller | }
2025-10-08 15:06:56.792707 | 
2025-10-08 15:06:56.792813 | TASK [Set timezone to UTC]
2025-10-08 15:06:57.312426 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-10-08 15:06:57.326741 | 
2025-10-08 15:06:57.326826 | TASK [Create nodepool directory]
2025-10-08 15:06:57.623174 | controller | changed
2025-10-08 15:06:57.629852 | 
2025-10-08 15:06:57.629966 | TASK [Create nodepool sub_nodes file]
2025-10-08 15:06:58.665837 | controller | changed
2025-10-08 15:06:58.671130 | 
2025-10-08 15:06:58.671207 | TASK [Create nodepool sub_nodes_private file]
2025-10-08 15:06:59.632863 | controller | changed
2025-10-08 15:06:59.638537 | 
2025-10-08 15:06:59.638634 | LOOP [Populate nodepool sub_nodes file]
2025-10-08 15:06:59.668767 | 
2025-10-08 15:06:59.669212 | LOOP [Populate nodepool sub_nodes_private file]
2025-10-08 15:06:59.699270 | 
2025-10-08 15:06:59.699408 | TASK [Create nodepool primary file]
2025-10-08 15:06:59.723439 | controller | skipping: Conditional result was False
2025-10-08 15:06:59.729221 | 
2025-10-08 15:06:59.729308 | TASK [Create nodepool node_private for this node]
2025-10-08 15:07:00.699718 | controller | changed
2025-10-08 15:07:00.705746 | 
2025-10-08 15:07:00.705859 | LOOP [Copy ssh keys to nodepool directory]
2025-10-08 15:07:01.115490 | controller | ok: Item: id_rsa Runtime: 0:00:00.003985
2025-10-08 15:07:01.115781 | 
2025-10-08 15:07:01.336621 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.004519
2025-10-08 15:07:01.347953 | 
2025-10-08 15:07:01.348123 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-10-08 15:07:02.356290 | controller | changed
2025-10-08 15:07:02.365140 | 
2025-10-08 15:07:02.365231 | TASK [Validate sudoers config after edits]
2025-10-08 15:07:02.667417 | controller | /etc/sudoers: parsed OK
2025-10-08 15:07:02.667491 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-10-08 15:07:02.667502 | controller | /etc/sudoers.d/zuul: parsed OK
2025-10-08 15:07:02.667509 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-10-08 15:07:02.895993 | controller | ok: Runtime: 0:00:00.005598
2025-10-08 15:07:02.901771 | 
2025-10-08 15:07:02.901856 | TASK [Show the environment passed in to job shell scripts]
2025-10-08 15:07:03.166676 | controller | SHELL=/bin/bash
2025-10-08 15:07:03.166727 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-10-08 15:07:03.166737 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-10-08 15:07:03.166744 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/68/3368/aa3d6015903436a1e30822664d9bf9e0f671d4a4
2025-10-08 15:07:03.166750 | controller | PWD=/home/zuul
2025-10-08 15:07:03.166796 | controller | ZUUL_PIPELINE=github-check
2025-10-08 15:07:03.166803 | controller | LOGNAME=zuul
2025-10-08 15:07:03.166809 | controller | XDG_SESSION_TYPE=tty
2025-10-08 15:07:03.166814 | controller | _=/usr/bin/env
2025-10-08 15:07:03.166820 | controller | MOTD_SHOWN=pam
2025-10-08 15:07:03.166825 | controller | HOME=/home/zuul
2025-10-08 15:07:03.166830 | controller | LANG=en_US.UTF-8
2025-10-08 15:07:03.166835 | controller | SSH_CONNECTION=192.168.26.12 34434 192.168.26.59 22
2025-10-08 15:07:03.166841 | 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 15:07:03.166849 | controller | ZUUL_CHANGE_IDS=3368,aa3d6015903436a1e30822664d9bf9e0f671d4a4
2025-10-08 15:07:03.166854 | controller | WORKSPACE=/home/zuul/workspace
2025-10-08 15:07:03.166860 | controller | XDG_SESSION_CLASS=user
2025-10-08 15:07:03.166865 | controller | SELINUX_ROLE_REQUESTED=
2025-10-08 15:07:03.166871 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-10-08 15:07:03.166876 | controller | USER=zuul
2025-10-08 15:07:03.166881 | controller | ZUUL_VOTING=True
2025-10-08 15:07:03.166886 | controller | BUILD_TIMEOUT=1800000
2025-10-08 15:07:03.166892 | controller | SELINUX_USE_CURRENT_RANGE=
2025-10-08 15:07:03.166897 | controller | SHLVL=1
2025-10-08 15:07:03.166902 | controller | ZUUL_PATCHSET=aa3d6015903436a1e30822664d9bf9e0f671d4a4
2025-10-08 15:07:03.166908 | controller | XDG_SESSION_ID=1
2025-10-08 15:07:03.166913 | controller | ZUUL_BRANCH=main
2025-10-08 15:07:03.166919 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-10-08 15:07:03.166924 | controller | SSH_CLIENT=192.168.26.12 34434 22
2025-10-08 15:07:03.166929 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-10-08 15:07:03.166935 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-10-08 15:07:03.166942 | controller | which_declare=declare -f
2025-10-08 15:07:03.166948 | controller | PATH=/home/zuul/.crc/bin/oc:/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-10-08 15:07:03.166953 | controller | SELINUX_LEVEL_REQUESTED=
2025-10-08 15:07:03.166958 | controller | ZUUL_CHANGE=3368
2025-10-08 15:07:03.166964 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-10-08 15:07:03.166969 | controller | ZUUL_UUID=d6470fb11ad14c358e968e29ba9fd183
2025-10-08 15:07:03.166975 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-10-08 15:07:03.166980 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-10-08 15:07:03.166985 | controller | }
2025-10-08 15:07:03.432113 | controller | ok: Runtime: 0:00:00.005244
2025-10-08 15:07:03.438042 | 
2025-10-08 15:07:03.438108 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-10-08 15:07:03.463299 | controller | skipping: Conditional result was False
2025-10-08 15:07:03.468975 | 
2025-10-08 15:07:03.469048 | TASK [Symlink /home/zuul-worker/workspace]
2025-10-08 15:07:04.018343 | controller | skipping: Conditional result was False
2025-10-08 15:07:04.024164 | 
2025-10-08 15:07:04.024650 | TASK [Ensure legacy workspace directory]
2025-10-08 15:07:04.277764 | controller | changed
2025-10-08 15:07:04.298428 | 
2025-10-08 15:07:04.298506 | PLAY RECAP
2025-10-08 15:07:04.298569 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-08 15:07:04.298597 | 
2025-10-08 15:07:04.401680 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-08 15:07:04.402416 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-08 15:07:04.923379 | 
2025-10-08 15:07:04.923477 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-10-08 15:07:04.959342 | 
2025-10-08 15:07:04.959448 | TASK [Create zuul-output directory]
2025-10-08 15:07:05.363691 | controller | changed
2025-10-08 15:07:05.368929 | 
2025-10-08 15:07:05.369009 | TASK [Slurp Zuul inventory test]
2025-10-08 15:07:05.726685 | controller -> localhost | ok
2025-10-08 15:07:05.733401 | 
2025-10-08 15:07:05.733501 | TASK [Save zuul inventory]
2025-10-08 15:07:06.971397 | controller | changed
2025-10-08 15:07:06.977260 | 
2025-10-08 15:07:06.977340 | TASK [Save zuul vars without the change_message]
2025-10-08 15:07:07.998633 | controller | changed
2025-10-08 15:07:08.043231 | 
2025-10-08 15:07:08.043301 | PLAY RECAP
2025-10-08 15:07:08.043348 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-08 15:07:08.043374 | 
2025-10-08 15:07:08.138569 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-08 15:07:08.139320 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-08 15:07:08.709867 | 
2025-10-08 15:07:08.709990 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-10-08 15:07:08.730073 | 
2025-10-08 15:07:08.730142 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-10-08 15:07:08.748258 | controller | ok
2025-10-08 15:07:08.765091 | 
2025-10-08 15:07:08.765178 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-08 15:07:08.800201 | controller | skipping: Conditional result was False
2025-10-08 15:07:08.806422 | 
2025-10-08 15:07:08.806499 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-08 15:07:09.192403 | controller | ok
2025-10-08 15:07:09.198305 | 
2025-10-08 15:07:09.198375 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-08 15:07:10.164289 | controller | ok
2025-10-08 15:07:10.175227 | 
2025-10-08 15:07:10.175330 | TASK [Prepare workspace]
2025-10-08 15:07:10.194286 | controller | ok
2025-10-08 15:07:10.213492 | 
2025-10-08 15:07:10.213589 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-08 15:07:10.631755 | controller | ok
2025-10-08 15:07:10.638069 | 
2025-10-08 15:07:10.638156 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-08 15:07:13.159111 | controller | Output suppressed because no_log was given
2025-10-08 15:07:13.168653 | 
2025-10-08 15:07:13.168731 | LOOP [Create zuul-output directory]
2025-10-08 15:07:13.427632 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-10-08 15:07:13.644520 | controller | ok: "/home/zuul/zuul-output/logs"
2025-10-08 15:07:13.660467 | 
2025-10-08 15:07:13.660543 | TASK [Install required packages]
2025-10-08 15:07:48.329373 | controller | ok: Nothing to do
2025-10-08 15:07:48.335165 | 
2025-10-08 15:07:48.335233 | TASK [Install venv]
2025-10-08 15:08:47.120668 | controller | changed
2025-10-08 15:08:47.164313 | 
2025-10-08 15:08:47.164400 | PLAY RECAP
2025-10-08 15:08:47.164444 | controller | ok: 7 changed: 3 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-08 15:08:47.164467 | 
2025-10-08 15:08:47.266446 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-08 15:08:47.267164 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-08 15:08:47.901023 | 
2025-10-08 15:08:47.901152 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-10-08 15:08:47.927044 | 
2025-10-08 15:08:47.927187 | TASK [Gather required facts]
2025-10-08 15:08:48.485349 | controller | ok
2025-10-08 15:08:48.496081 | 
2025-10-08 15:08:48.496183 | TASK [Load environment var if instructed to]
2025-10-08 15:08:48.519946 | controller | skipping: Conditional result was False
2025-10-08 15:08:48.525471 | 
2025-10-08 15:08:48.525539 | TASK [Run molecule]
2025-10-08 15:08:49.565454 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-10-08 15:08:49.638288 | controller | INFO     Performing prerun with role_name_check=0...
2025-10-08 15:09:07.428925 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/c9682b/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 15:09:07.429368 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/c9682b/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 15:09:07.429833 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/c9682b/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 15:09:07.430289 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/c9682b/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 15:09:07.430766 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+9ece53e1 was found installed in /home/zuul/.cache/ansible-compat/c9682b/collections/ansible_collections, only the first one will be used, 1.0.0+9ece53e1 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 15:09:07.431237 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/c9682b/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 15:09:07.431682 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/c9682b/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 15:09:07.432117 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/c9682b/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 15:09:07.432569 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/c9682b/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 15:09:07.432985 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/c9682b/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 15:09:07.433426 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/c9682b/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 15:09:07.433884 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/c9682b/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 15:09:07.434335 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/c9682b/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 15:09:07.434775 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/c9682b/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 15:09:07.435226 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/c9682b/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-08 15:09:07.444512 | controller | INFO     Running default > prepare
2025-10-08 15:09:08.114506 | controller |
2025-10-08 15:09:08.114637 | controller | PLAY [Prepare] *****************************************************************
2025-10-08 15:09:08.114745 | controller |
2025-10-08 15:09:08.114846 | controller | TASK [Gathering Facts] *********************************************************
2025-10-08 15:09:08.114941 | controller | Wednesday 08 October 2025  15:09:08 +0000 (0:00:00.013)       0:00:00.013 *****
2025-10-08 15:09:08.967057 | controller | ok: [instance]
2025-10-08 15:09:08.967148 | controller |
2025-10-08 15:09:08.967278 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-10-08 15:09:08.967386 | controller | Wednesday 08 October 2025  15:09:08 +0000 (0:00:00.853)       0:00:00.866 *****
2025-10-08 15:09:08.984615 | controller | skipping: [instance]
2025-10-08 15:09:08.984710 | controller |
2025-10-08 15:09:08.984813 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-10-08 15:09:08.984917 | controller | Wednesday 08 October 2025  15:09:08 +0000 (0:00:00.017)       0:00:00.884 *****
2025-10-08 15:09:09.025909 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-10-08 15:09:09.026017 | controller |
2025-10-08 15:09:09.026156 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-10-08 15:09:09.026279 | controller | Wednesday 08 October 2025  15:09:09 +0000 (0:00:00.041)       0:00:00.925 *****
2025-10-08 15:09:09.306459 | controller | ok: [instance]
2025-10-08 15:09:09.306530 | controller |
2025-10-08 15:09:09.306663 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-10-08 15:09:09.306775 | controller | Wednesday 08 October 2025  15:09:09 +0000 (0:00:00.280)       0:00:01.205 *****
2025-10-08 15:09:09.621262 | controller | ok: [instance]
2025-10-08 15:09:09.621324 | controller |
2025-10-08 15:09:09.621427 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-10-08 15:09:09.621530 | controller | Wednesday 08 October 2025  15:09:09 +0000 (0:00:00.314)       0:00:01.520 *****
2025-10-08 15:09:10.304893 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-10-08 15:09:10.304980 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-10-08 15:09:10.305098 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-10-08 15:09:10.305200 | controller |
2025-10-08 15:09:10.305302 | controller | TASK [Deploy repo-setup] *******************************************************
2025-10-08 15:09:10.305396 | controller | Wednesday 08 October 2025  15:09:10 +0000 (0:00:00.683)       0:00:02.204 *****
2025-10-08 15:09:10.364516 | controller |
2025-10-08 15:09:10.364637 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-10-08 15:09:10.364741 | controller | Wednesday 08 October 2025  15:09:10 +0000 (0:00:00.059)       0:00:02.264 *****
2025-10-08 15:09:10.906271 | controller | changed: [instance] => (item=tmp)
2025-10-08 15:09:10.906349 | controller | changed: [instance] => (item=artifacts/repositories)
2025-10-08 15:09:10.906451 | controller | changed: [instance] => (item=venv/repo_setup)
2025-10-08 15:09:10.906587 | controller |
2025-10-08 15:09:10.906701 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-10-08 15:09:10.906795 | controller | Wednesday 08 October 2025  15:09:10 +0000 (0:00:00.541)       0:00:02.805 *****
2025-10-08 15:09:11.715012 | controller | ok: [instance]
2025-10-08 15:09:11.715326 | controller |
2025-10-08 15:09:12.870645 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-10-08 15:09:12.870684 | controller | Wednesday 08 October 2025  15:09:11 +0000 (0:00:00.808)       0:00:03.614 *****
2025-10-08 15:09:12.870699 | controller | changed: [instance]
2025-10-08 15:09:12.870728 | controller |
2025-10-08 15:09:12.870744 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-10-08 15:09:12.870857 | controller | Wednesday 08 October 2025  15:09:12 +0000 (0:00:01.155)       0:00:04.769 *****
2025-10-08 15:09:20.864285 | controller | changed: [instance]
2025-10-08 15:09:21.610806 | controller |
2025-10-08 15:09:21.610846 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-10-08 15:09:21.610855 | controller | Wednesday 08 October 2025  15:09:20 +0000 (0:00:07.993)       0:00:12.763 *****
2025-10-08 15:09:21.610865 | controller | changed: [instance]
2025-10-08 15:09:21.633437 | controller |
2025-10-08 15:09:21.633460 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-10-08 15:09:21.633467 | controller | Wednesday 08 October 2025  15:09:21 +0000 (0:00:00.746)       0:00:13.509 *****
2025-10-08 15:09:21.633477 | controller | skipping: [instance]
2025-10-08 15:09:22.508679 | controller |
2025-10-08 15:09:22.508713 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-10-08 15:09:22.508722 | controller | Wednesday 08 October 2025  15:09:21 +0000 (0:00:00.022)       0:00:13.532 *****
2025-10-08 15:09:22.508732 | controller | changed: [instance]
2025-10-08 15:09:22.545679 | controller |
2025-10-08 15:09:22.545751 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-10-08 15:09:22.545760 | controller | Wednesday 08 October 2025  15:09:22 +0000 (0:00:00.874)       0:00:14.407 *****
2025-10-08 15:09:22.545773 | controller | skipping: [instance]
2025-10-08 15:09:22.545813 | controller |
2025-10-08 15:09:22.545836 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-10-08 15:09:22.546017 | controller | Wednesday 08 October 2025  15:09:22 +0000 (0:00:00.037)       0:00:14.445 *****
2025-10-08 15:09:22.581647 | controller | skipping: [instance]
2025-10-08 15:09:22.581715 | controller |
2025-10-08 15:09:22.582297 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-10-08 15:09:22.618478 | controller | Wednesday 08 October 2025  15:09:22 +0000 (0:00:00.036)       0:00:14.481 *****
2025-10-08 15:09:22.618508 | controller | skipping: [instance]
2025-10-08 15:09:23.169146 | controller |
2025-10-08 15:09:23.169176 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-10-08 15:09:23.169184 | controller | Wednesday 08 October 2025  15:09:22 +0000 (0:00:00.036)       0:00:14.517 *****
2025-10-08 15:09:23.169194 | controller | changed: [instance]
2025-10-08 15:09:23.612149 | controller |
2025-10-08 15:09:23.612178 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-10-08 15:09:23.612186 | controller | Wednesday 08 October 2025  15:09:23 +0000 (0:00:00.550)       0:00:15.068 *****
2025-10-08 15:09:23.612196 | controller | changed: [instance]
2025-10-08 15:09:23.644678 | controller |
2025-10-08 15:09:23.644714 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-10-08 15:09:23.644724 | controller | Wednesday 08 October 2025  15:09:23 +0000 (0:00:00.442)       0:00:15.511 *****
2025-10-08 15:09:23.644736 | controller | skipping: [instance]
2025-10-08 15:09:23.644767 | controller |
2025-10-08 15:09:23.644777 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-10-08 15:09:23.644890 | controller | Wednesday 08 October 2025  15:09:23 +0000 (0:00:00.032)       0:00:15.543 *****
2025-10-08 15:09:23.676602 | controller | skipping: [instance]
2025-10-08 15:09:23.706677 | controller |
2025-10-08 15:09:23.706699 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-10-08 15:09:23.706707 | controller | Wednesday 08 October 2025  15:09:23 +0000 (0:00:00.031)       0:00:15.575 *****
2025-10-08 15:09:23.706717 | controller | skipping: [instance]
2025-10-08 15:09:23.746427 | controller |
2025-10-08 15:09:23.746461 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-10-08 15:09:23.746469 | controller | Wednesday 08 October 2025  15:09:23 +0000 (0:00:00.030)       0:00:15.605 *****
2025-10-08 15:09:23.746479 | controller | ok: [instance]
2025-10-08 15:09:23.774333 | controller |
2025-10-08 15:09:23.774362 | controller | TASK [repo_setup : Create download directory] **********************************
2025-10-08 15:09:23.774370 | controller | Wednesday 08 October 2025  15:09:23 +0000 (0:00:00.039)       0:00:15.645 *****
2025-10-08 15:09:23.774380 | controller | skipping: [instance]
2025-10-08 15:09:23.803282 | controller |
2025-10-08 15:09:23.803313 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-10-08 15:09:23.803321 | controller | Wednesday 08 October 2025  15:09:23 +0000 (0:00:00.027)       0:00:15.673 *****
2025-10-08 15:09:23.803339 | controller | skipping: [instance]
2025-10-08 15:09:23.803487 | controller |
2025-10-08 15:09:23.803663 | controller | TASK [Download the RPM] ********************************************************
2025-10-08 15:09:23.803814 | controller | Wednesday 08 October 2025  15:09:23 +0000 (0:00:00.029)       0:00:15.702 *****
2025-10-08 15:09:23.832362 | controller | skipping: [instance]
2025-10-08 15:09:23.832527 | controller |
2025-10-08 15:09:23.832708 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-10-08 15:09:23.832854 | controller | Wednesday 08 October 2025  15:09:23 +0000 (0:00:00.029)       0:00:15.731 *****
2025-10-08 15:09:23.860409 | controller | skipping: [instance]
2025-10-08 15:09:23.860599 | controller |
2025-10-08 15:09:23.860752 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-10-08 15:09:23.860892 | controller | Wednesday 08 October 2025  15:09:23 +0000 (0:00:00.028)       0:00:15.760 *****
2025-10-08 15:09:23.888363 | controller | skipping: [instance]
2025-10-08 15:09:23.888540 | controller |
2025-10-08 15:09:23.888727 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-10-08 15:09:23.888868 | controller | Wednesday 08 October 2025  15:09:23 +0000 (0:00:00.027)       0:00:15.788 *****
2025-10-08 15:09:23.917699 | controller | skipping: [instance]
2025-10-08 15:09:23.917896 | controller |
2025-10-08 15:09:23.918101 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-10-08 15:09:23.918273 | controller | Wednesday 08 October 2025  15:09:23 +0000 (0:00:00.029)       0:00:15.817 *****
2025-10-08 15:09:23.944701 | controller | skipping: [instance]
2025-10-08 15:09:23.944885 | controller |
2025-10-08 15:09:23.945080 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-10-08 15:09:23.945248 | controller | Wednesday 08 October 2025  15:09:23 +0000 (0:00:00.027)       0:00:15.844 *****
2025-10-08 15:09:24.131229 | controller | ok: [instance]
2025-10-08 15:09:24.344861 | controller |
2025-10-08 15:09:24.344891 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-10-08 15:09:24.344899 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.185)       0:00:16.030 *****
2025-10-08 15:09:24.344909 | controller | changed: [instance]
2025-10-08 15:09:24.570652 | controller |
2025-10-08 15:09:24.570687 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-10-08 15:09:24.570697 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.213)       0:00:16.244 *****
2025-10-08 15:09:24.570710 | controller | changed: [instance]
2025-10-08 15:09:24.570742 | controller |
2025-10-08 15:09:24.570977 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-10-08 15:09:24.591634 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.225)       0:00:16.470 *****
2025-10-08 15:09:24.591665 | controller | skipping: [instance]
2025-10-08 15:09:24.591692 | controller |
2025-10-08 15:09:24.591701 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-10-08 15:09:24.591846 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.021)       0:00:16.491 *****
2025-10-08 15:09:24.613518 | controller | skipping: [instance]
2025-10-08 15:09:24.635647 | controller |
2025-10-08 15:09:24.635692 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-10-08 15:09:24.635701 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.021)       0:00:16.512 *****
2025-10-08 15:09:24.635719 | controller | skipping: [instance]
2025-10-08 15:09:24.657689 | controller |
2025-10-08 15:09:24.657732 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-10-08 15:09:24.657742 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.021)       0:00:16.534 *****
2025-10-08 15:09:24.657760 | controller | skipping: [instance]
2025-10-08 15:09:24.679998 | controller |
2025-10-08 15:09:24.680027 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-10-08 15:09:24.680035 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.022)       0:00:16.557 *****
2025-10-08 15:09:24.680045 | controller | skipping: [instance]
2025-10-08 15:09:24.680074 | controller |
2025-10-08 15:09:24.680082 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-10-08 15:09:24.680160 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.021)       0:00:16.579 *****
2025-10-08 15:09:24.702654 | controller | skipping: [instance]
2025-10-08 15:09:24.702806 | controller |
2025-10-08 15:09:24.702952 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-10-08 15:09:24.703113 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.023)       0:00:16.602 *****
2025-10-08 15:09:24.720170 | controller | skipping: [instance]
2025-10-08 15:09:24.720341 | controller |
2025-10-08 15:09:24.720510 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-10-08 15:09:24.720707 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.017)       0:00:16.619 *****
2025-10-08 15:09:24.749604 | controller | skipping: [instance]
2025-10-08 15:09:24.749747 | controller |
2025-10-08 15:09:24.749911 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-10-08 15:09:24.750077 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.029)       0:00:16.649 *****
2025-10-08 15:09:24.766984 | controller | skipping: [instance]
2025-10-08 15:09:24.767136 | controller |
2025-10-08 15:09:24.767266 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-10-08 15:09:24.767386 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.017)       0:00:16.666 *****
2025-10-08 15:09:24.788450 | controller | skipping: [instance]
2025-10-08 15:09:24.788634 | controller |
2025-10-08 15:09:24.788803 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-10-08 15:09:24.788948 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.021)       0:00:16.687 *****
2025-10-08 15:09:24.818408 | controller | skipping: [instance]
2025-10-08 15:09:24.818566 | controller |
2025-10-08 15:09:24.818745 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-10-08 15:09:24.818899 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.030)       0:00:16.718 *****
2025-10-08 15:09:24.847976 | controller | skipping: [instance]
2025-10-08 15:09:24.848139 | controller |
2025-10-08 15:09:24.848289 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-10-08 15:09:24.848414 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.029)       0:00:16.747 *****
2025-10-08 15:09:24.877965 | controller | skipping: [instance]
2025-10-08 15:09:24.878120 | controller |
2025-10-08 15:09:24.878269 | controller | TASK [test_deps : Install additional packages] *********************************
2025-10-08 15:09:24.878406 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.029)       0:00:16.777 *****
2025-10-08 15:09:24.911282 | controller | skipping: [instance]
2025-10-08 15:09:24.911441 | controller |
2025-10-08 15:09:24.911565 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-10-08 15:09:24.911708 | controller | Wednesday 08 October 2025  15:09:24 +0000 (0:00:00.033)       0:00:16.810 *****
2025-10-08 15:10:29.316165 | controller | ok: [instance]
2025-10-08 15:10:30.561635 | controller |
2025-10-08 15:10:30.561669 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-10-08 15:10:30.561677 | controller | Wednesday 08 October 2025  15:10:29 +0000 (0:01:04.403)       0:01:21.214 *****
2025-10-08 15:10:30.561687 | controller | ok: [instance]
2025-10-08 15:10:30.562028 | controller |
2025-10-08 15:10:30.594301 | controller | TASK [test_deps : Install extra packages] **************************************
2025-10-08 15:10:30.594332 | controller | Wednesday 08 October 2025  15:10:30 +0000 (0:00:01.246)       0:01:22.461 *****
2025-10-08 15:10:30.594344 | controller | skipping: [instance]
2025-10-08 15:13:16.215597 | controller |
2025-10-08 15:13:16.215640 | controller | TASK [Ensure CRC is started] ***************************************************
2025-10-08 15:13:16.215649 | controller | Wednesday 08 October 2025  15:10:30 +0000 (0:00:00.032)       0:01:22.493 *****
2025-10-08 15:13:16.215660 | controller | changed: [instance]
2025-10-08 15:13:16.216160 | controller |
2025-10-08 15:13:16.216173 | controller | PLAY RECAP *********************************************************************
2025-10-08 15:13:16.216259 | controller | instance                   : ok=20   changed=10   unreachable=0    failed=0    skipped=30   rescued=0    ignored=0
2025-10-08 15:13:16.216267 | controller |
2025-10-08 15:13:16.216279 | controller | Wednesday 08 October 2025  15:13:16 +0000 (0:02:45.621)       0:04:08.114 *****
2025-10-08 15:13:16.216285 | controller | ===============================================================================
2025-10-08 15:13:16.216305 | controller | Ensure CRC is started ------------------------------------------------- 165.62s
2025-10-08 15:13:16.216334 | controller | test_deps : Install selinux python libs -------------------------------- 64.40s
2025-10-08 15:13:16.216476 | controller | repo_setup : Initialize python venv and install requirements ------------ 7.99s
2025-10-08 15:13:16.216589 | controller | test_deps : Install python yaml libs ------------------------------------ 1.25s
2025-10-08 15:13:16.216621 | controller | repo_setup : Get repo-setup repository ---------------------------------- 1.16s
2025-10-08 15:13:16.216816 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.87s
2025-10-08 15:13:16.216975 | controller | Gathering Facts --------------------------------------------------------- 0.85s
2025-10-08 15:13:16.216987 | controller | repo_setup : Make sure git-core package is installed -------------------- 0.81s
2025-10-08 15:13:16.217010 | controller | repo_setup : Install repo-setup package --------------------------------- 0.75s
2025-10-08 15:13:16.217246 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.68s
2025-10-08 15:13:16.217353 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.55s
2025-10-08 15:13:16.217365 | controller | repo_setup : Ensure directories are present ----------------------------- 0.54s
2025-10-08 15:13:16.217450 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.44s
2025-10-08 15:13:16.217589 | controller | test_deps : Disable ubi host subscription-manager integration ----------- 0.31s
2025-10-08 15:13:16.217685 | controller | test_deps : Detect mirrors file ----------------------------------------- 0.28s
2025-10-08 15:13:16.218004 | controller | repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist) --- 0.23s
2025-10-08 15:13:16.218029 | controller | repo_setup : Use RDO proxy mirrors -------------------------------------- 0.21s
2025-10-08 15:13:16.218035 | controller | repo_setup : Check for /etc/ci/mirror_info.sh --------------------------- 0.19s
2025-10-08 15:13:16.218042 | controller | Deploy repo-setup ------------------------------------------------------- 0.06s
2025-10-08 15:13:16.218154 | controller | test_deps : Gather variables for each operating system ------------------ 0.04s
2025-10-08 15:13:16.275824 | controller | INFO     Running default > converge
2025-10-08 15:13:16.751373 | controller |
2025-10-08 15:13:17.614732 | controller | PLAY [Converge] ****************************************************************
2025-10-08 15:13:17.614766 | controller |
2025-10-08 15:13:17.614774 | controller | TASK [Gathering Facts] *********************************************************
2025-10-08 15:13:17.614780 | controller | Wednesday 08 October 2025  15:13:16 +0000 (0:00:00.018)       0:00:00.018 *****
2025-10-08 15:13:17.614790 | controller | ok: [instance]
2025-10-08 15:13:17.614850 | controller |
2025-10-08 15:13:17.614860 | controller | TASK [openshift_setup : Ensure output directory exists] ************************
2025-10-08 15:13:17.614958 | controller | Wednesday 08 October 2025  15:13:17 +0000 (0:00:00.864)       0:00:00.882 *****
2025-10-08 15:13:17.924379 | controller | ok: [instance]
2025-10-08 15:13:17.924454 | controller |
2025-10-08 15:13:17.924583 | controller | TASK [openshift_setup : Fetch namespaces to create] ****************************
2025-10-08 15:13:17.924721 | controller | Wednesday 08 October 2025  15:13:17 +0000 (0:00:00.309)       0:00:01.192 *****
2025-10-08 15:13:17.965825 | controller | ok: [instance]
2025-10-08 15:13:17.965883 | controller |
2025-10-08 15:13:17.966006 | controller | TASK [openshift_setup : Create required namespaces] ****************************
2025-10-08 15:13:17.966142 | controller | Wednesday 08 October 2025  15:13:17 +0000 (0:00:00.041)       0:00:01.233 *****
2025-10-08 15:13:19.450696 | controller | changed: [instance] => (item=openstack)
2025-10-08 15:13:19.450759 | controller | changed: [instance] => (item=openstack-operators)
2025-10-08 15:13:19.450858 | controller |
2025-10-08 15:13:19.450975 | controller | TASK [openshift_setup : Get internal OpenShift registry route] *****************
2025-10-08 15:13:19.451101 | controller | Wednesday 08 October 2025  15:13:19 +0000 (0:00:01.484)       0:00:02.718 *****
2025-10-08 15:13:21.583018 | controller | ok: [instance]
2025-10-08 15:13:21.583102 | controller |
2025-10-08 15:13:21.583231 | controller | TASK [openshift_setup : Allow anonymous image-pulls in CRC registry for targeted namespaces] ***
2025-10-08 15:13:21.583339 | controller | Wednesday 08 October 2025  15:13:21 +0000 (0:00:02.132)       0:00:04.850 *****
2025-10-08 15:13:21.626857 | controller | skipping: [instance] => (item=openstack)
2025-10-08 15:13:21.626932 | controller | skipping: [instance] => (item=openstack-operators)
2025-10-08 15:13:21.627036 | controller | skipping: [instance]
2025-10-08 15:13:21.627143 | controller |
2025-10-08 15:13:21.627247 | controller | TASK [openshift_setup : Wait for the image registry to be ready] ***************
2025-10-08 15:13:21.627352 | controller | Wednesday 08 October 2025  15:13:21 +0000 (0:00:00.043)       0:00:04.894 *****
2025-10-08 15:13:21.652133 | controller | skipping: [instance]
2025-10-08 15:13:21.652227 | controller |
2025-10-08 15:13:21.652330 | controller | TASK [openshift_setup : Login into OpenShift internal registry] ****************
2025-10-08 15:13:21.652439 | controller | Wednesday 08 October 2025  15:13:21 +0000 (0:00:00.025)       0:00:04.919 *****
2025-10-08 15:13:21.674259 | controller | skipping: [instance]
2025-10-08 15:13:21.674344 | controller |
2025-10-08 15:13:21.674464 | controller | TASK [Ensure we have custom CA installed on host] ******************************
2025-10-08 15:13:21.674585 | controller | Wednesday 08 October 2025  15:13:21 +0000 (0:00:00.022)       0:00:04.942 *****
2025-10-08 15:13:21.722571 | controller |
2025-10-08 15:13:21.722694 | controller | TASK [install_ca : Ensure target directory exists] *****************************
2025-10-08 15:13:21.722821 | controller | Wednesday 08 October 2025  15:13:21 +0000 (0:00:00.048)       0:00:04.990 *****
2025-10-08 15:13:21.938172 | controller | ok: [instance]
2025-10-08 15:13:21.938245 | controller |
2025-10-08 15:13:21.938351 | controller | TASK [install_ca : Install internal CA from url] *******************************
2025-10-08 15:13:21.938460 | controller | Wednesday 08 October 2025  15:13:21 +0000 (0:00:00.215)       0:00:05.205 *****
2025-10-08 15:13:21.962644 | controller | skipping: [instance]
2025-10-08 15:13:21.962742 | controller |
2025-10-08 15:13:21.962954 | controller | TASK [install_ca : Install custom CA bundle from inline] ***********************
2025-10-08 15:13:21.963093 | controller | Wednesday 08 October 2025  15:13:21 +0000 (0:00:00.024)       0:00:05.230 *****
2025-10-08 15:13:21.989080 | controller | skipping: [instance]
2025-10-08 15:13:21.989198 | controller |
2025-10-08 15:13:21.989315 | controller | TASK [install_ca : Install custom CA bundle from file] *************************
2025-10-08 15:13:21.989419 | controller | Wednesday 08 October 2025  15:13:21 +0000 (0:00:00.026)       0:00:05.256 *****
2025-10-08 15:13:22.013598 | controller | skipping: [instance]
2025-10-08 15:13:22.013701 | controller |
2025-10-08 15:13:22.013801 | controller | TASK [install_ca : Update ca bundle] *******************************************
2025-10-08 15:13:22.013909 | controller | Wednesday 08 October 2025  15:13:22 +0000 (0:00:00.024)       0:00:05.281 *****
2025-10-08 15:13:23.191640 | controller | changed: [instance]
2025-10-08 15:13:23.191696 | controller |
2025-10-08 15:13:23.191912 | controller | TASK [openshift_setup : Update ca bundle] **************************************
2025-10-08 15:13:24.277127 | controller | Wednesday 08 October 2025  15:13:23 +0000 (0:00:01.177)       0:00:06.459 *****
2025-10-08 15:13:24.277166 | controller | changed: [instance]
2025-10-08 15:13:24.277194 | controller |
2025-10-08 15:13:24.277377 | controller | TASK [openshift_setup : Slurp CAs file] ****************************************
2025-10-08 15:13:24.572738 | controller | Wednesday 08 October 2025  15:13:24 +0000 (0:00:01.085)       0:00:07.544 *****
2025-10-08 15:13:24.572776 | controller | ok: [instance]
2025-10-08 15:13:24.572896 | controller |
2025-10-08 15:13:24.572996 | controller | TASK [openshift_setup : Create config map with registry CAs] *******************
2025-10-08 15:13:24.573015 | controller | Wednesday 08 October 2025  15:13:24 +0000 (0:00:00.295)       0:00:07.840 *****
2025-10-08 15:13:25.291126 | controller | changed: [instance]
2025-10-08 15:13:25.291599 | controller |
2025-10-08 15:13:25.291614 | controller | TASK [openshift_setup : Install Red Hat CA for pulling images from internal registry] ***
2025-10-08 15:13:25.291624 | controller | Wednesday 08 October 2025  15:13:25 +0000 (0:00:00.718)       0:00:08.558 *****
2025-10-08 15:13:25.935612 | controller | changed: [instance]
2025-10-08 15:13:25.935974 | controller |
2025-10-08 15:13:25.959741 | controller | TASK [openshift_setup : Add insecure registry] *********************************
2025-10-08 15:13:25.959781 | controller | Wednesday 08 October 2025  15:13:25 +0000 (0:00:00.644)       0:00:09.203 *****
2025-10-08 15:13:25.959794 | controller | skipping: [instance]
2025-10-08 15:13:25.959802 | controller |
2025-10-08 15:13:25.959932 | controller | TASK [openshift_setup : Create a ICSP with repository digest mirrors] **********
2025-10-08 15:13:25.960028 | controller | Wednesday 08 October 2025  15:13:25 +0000 (0:00:00.024)       0:00:09.227 *****
2025-10-08 15:13:26.631476 | controller | changed: [instance]
2025-10-08 15:13:26.631542 | controller |
2025-10-08 15:13:26.631669 | controller | TASK [openshift_setup : Metal3 tweaks] *****************************************
2025-10-08 15:13:26.631777 | controller | Wednesday 08 October 2025  15:13:26 +0000 (0:00:00.671)       0:00:09.899 *****
2025-10-08 15:13:26.659513 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/openshift_setup/tasks/metal3_config.yml for instance
2025-10-08 15:13:26.659636 | controller |
2025-10-08 15:13:26.659771 | controller | TASK [openshift_setup : Fetch Metal3 configuration name] ***********************
2025-10-08 15:13:26.659893 | controller | Wednesday 08 October 2025  15:13:26 +0000 (0:00:00.028)       0:00:09.927 *****
2025-10-08 15:13:26.687067 | controller | skipping: [instance]
2025-10-08 15:13:26.687154 | controller |
2025-10-08 15:13:26.687261 | controller | TASK [openshift_setup : Apply the patch to Metal3 Provisioning] ****************
2025-10-08 15:13:26.687366 | controller | Wednesday 08 October 2025  15:13:26 +0000 (0:00:00.027)       0:00:09.954 *****
2025-10-08 15:13:26.714177 | controller | skipping: [instance]
2025-10-08 15:13:26.714240 | controller |
2025-10-08 15:13:26.714342 | controller | TASK [openshift_setup : Gather network.operator info] **************************
2025-10-08 15:13:26.714456 | controller | Wednesday 08 October 2025  15:13:26 +0000 (0:00:00.027)       0:00:09.982 *****
2025-10-08 15:13:27.325417 | controller | ok: [instance]
2025-10-08 15:13:27.325469 | controller |
2025-10-08 15:13:27.325477 | controller | TASK [openshift_setup : Patch network operator] ********************************
2025-10-08 15:13:27.325486 | controller | Wednesday 08 October 2025  15:13:27 +0000 (0:00:00.610)       0:00:10.592 *****
2025-10-08 15:13:28.106740 | controller | changed: [instance]
2025-10-08 15:13:28.107022 | controller |
2025-10-08 15:13:28.738463 | controller | TASK [openshift_setup : Patch samples registry configuration] ******************
2025-10-08 15:13:28.738494 | controller | Wednesday 08 October 2025  15:13:28 +0000 (0:00:00.781)       0:00:11.374 *****
2025-10-08 15:13:28.738506 | controller | changed: [instance]
2025-10-08 15:13:28.758513 | controller |
2025-10-08 15:13:28.758539 | controller | TASK [openshift_setup : Delete the pods from openshift-marketplace namespace] ***
2025-10-08 15:13:28.758567 | controller | Wednesday 08 October 2025  15:13:28 +0000 (0:00:00.631)       0:00:12.005 *****
2025-10-08 15:13:28.758600 | controller | skipping: [instance]
2025-10-08 15:13:28.782379 | controller |
2025-10-08 15:13:28.782403 | controller | TASK [openshift_setup : Wait for openshift-marketplace pods to be running] *****
2025-10-08 15:13:28.782411 | controller | Wednesday 08 October 2025  15:13:28 +0000 (0:00:00.020)       0:00:12.025 *****
2025-10-08 15:13:28.782420 | controller | skipping: [instance]
2025-10-08 15:13:29.419901 | controller |
2025-10-08 15:13:29.419953 | controller | TASK [Check that config map is created] ****************************************
2025-10-08 15:13:29.419962 | controller | Wednesday 08 October 2025  15:13:28 +0000 (0:00:00.023)       0:00:12.049 *****
2025-10-08 15:13:29.419973 | controller | ok: [instance]
2025-10-08 15:13:29.420100 | controller |
2025-10-08 15:13:29.420118 | controller | TASK [Assert that configmap was created] ***************************************
2025-10-08 15:13:29.441166 | controller | Wednesday 08 October 2025  15:13:29 +0000 (0:00:00.637)       0:00:12.687 *****
2025-10-08 15:13:29.441203 | controller | ok: [instance] => changed=false
2025-10-08 15:13:30.076464 | controller |   msg: All assertions passed
2025-10-08 15:13:30.076518 | controller |
2025-10-08 15:13:30.076527 | controller | TASK [Check that Image cluster is patched] *************************************
2025-10-08 15:13:30.076533 | controller | Wednesday 08 October 2025  15:13:29 +0000 (0:00:00.021)       0:00:12.708 *****
2025-10-08 15:13:30.076543 | controller | ok: [instance]
2025-10-08 15:13:30.096619 | controller |
2025-10-08 15:13:30.096695 | controller | TASK [Assert that cluster was patched] *****************************************
2025-10-08 15:13:30.096704 | controller | Wednesday 08 October 2025  15:13:30 +0000 (0:00:00.635)       0:00:13.343 *****
2025-10-08 15:13:30.096721 | controller | ok: [instance] => changed=false
2025-10-08 15:13:30.096807 | controller |   msg: All assertions passed
2025-10-08 15:13:30.096822 | controller |
2025-10-08 15:13:30.096934 | controller | TASK [Check that registry mirror resource is created] **************************
2025-10-08 15:13:30.097022 | controller | Wednesday 08 October 2025  15:13:30 +0000 (0:00:00.020)       0:00:13.364 *****
2025-10-08 15:13:30.733252 | controller | ok: [instance]
2025-10-08 15:13:30.733605 | controller |
2025-10-08 15:13:30.770528 | controller | TASK [Assert that digest mirrors are correct] **********************************
2025-10-08 15:13:30.770575 | controller | Wednesday 08 October 2025  15:13:30 +0000 (0:00:00.636)       0:00:14.000 *****
2025-10-08 15:13:30.770588 | controller | ok: [instance] => changed=false
2025-10-08 15:13:30.770662 | controller |   msg: All assertions passed
2025-10-08 15:13:30.770763 | controller |
2025-10-08 15:13:30.770887 | controller | PLAY RECAP *********************************************************************
2025-10-08 15:13:30.771001 | controller | instance                   : ok=22   changed=8    unreachable=0    failed=0    skipped=11   rescued=0    ignored=0
2025-10-08 15:13:30.771105 | controller |
2025-10-08 15:13:30.771218 | controller | Wednesday 08 October 2025  15:13:30 +0000 (0:00:00.037)       0:00:14.038 *****
2025-10-08 15:13:30.771317 | controller | ===============================================================================
2025-10-08 15:13:30.771412 | controller | openshift_setup : Get internal OpenShift registry route ----------------- 2.13s
2025-10-08 15:13:30.771520 | controller | openshift_setup : Create required namespaces ---------------------------- 1.48s
2025-10-08 15:13:30.771628 | controller | install_ca : Update ca bundle ------------------------------------------- 1.18s
2025-10-08 15:13:30.771728 | controller | openshift_setup : Update ca bundle -------------------------------------- 1.09s
2025-10-08 15:13:30.771815 | controller | Gathering Facts --------------------------------------------------------- 0.86s
2025-10-08 15:13:30.771915 | controller | openshift_setup : Patch network operator -------------------------------- 0.78s
2025-10-08 15:13:30.772026 | controller | openshift_setup : Create config map with registry CAs ------------------- 0.72s
2025-10-08 15:13:30.772136 | controller | openshift_setup : Create a ICSP with repository digest mirrors ---------- 0.67s
2025-10-08 15:13:30.772246 | controller | openshift_setup : Install Red Hat CA for pulling images from internal registry --- 0.64s
2025-10-08 15:13:30.772333 | controller | Check that config map is created ---------------------------------------- 0.64s
2025-10-08 15:13:30.772437 | controller | Check that registry mirror resource is created -------------------------- 0.64s
2025-10-08 15:13:30.772532 | controller | Check that Image cluster is patched ------------------------------------- 0.64s
2025-10-08 15:13:30.772637 | controller | openshift_setup : Patch samples registry configuration ------------------ 0.63s
2025-10-08 15:13:30.772743 | controller | openshift_setup : Gather network.operator info -------------------------- 0.61s
2025-10-08 15:13:30.772822 | controller | openshift_setup : Ensure output directory exists ------------------------ 0.31s
2025-10-08 15:13:30.772924 | controller | openshift_setup : Slurp CAs file ---------------------------------------- 0.30s
2025-10-08 15:13:30.773014 | controller | install_ca : Ensure target directory exists ----------------------------- 0.22s
2025-10-08 15:13:30.773124 | controller | Ensure we have custom CA installed on host ------------------------------ 0.05s
2025-10-08 15:13:30.773234 | controller | openshift_setup : Allow anonymous image-pulls in CRC registry for targeted namespaces --- 0.04s
2025-10-08 15:13:30.773314 | controller | openshift_setup : Fetch namespaces to create ---------------------------- 0.04s
2025-10-08 15:13:30.838913 | controller | INFO     Running default > cleanup
2025-10-08 15:13:30.839384 | controller | WARNING  Skipping, cleanup playbook not configured.
2025-10-08 15:13:30.839981 | controller | INFO     Writing /tmp/report.html report.
2025-10-08 15:13:30.921509 | controller | changed
2025-10-08 15:13:30.942371 | 
2025-10-08 15:13:30.942435 | PLAY RECAP
2025-10-08 15:13:30.942483 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-08 15:13:30.942511 | 
2025-10-08 15:13:31.060835 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-08 15:13:31.061653 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-08 15:13:31.624038 | 
2025-10-08 15:13:31.624143 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-10-08 15:13:31.672672 | 
2025-10-08 15:13:31.672790 | TASK [Filter out host if needed]
2025-10-08 15:13:31.681633 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-10-08 15:13:31.686114 | 
2025-10-08 15:13:31.686187 | TASK [Ensure file is present]
2025-10-08 15:13:32.073848 | controller | ok
2025-10-08 15:13:32.080365 | 
2025-10-08 15:13:32.080436 | TASK [Manage molecule report file]
2025-10-08 15:13:32.605316 | controller | changed
2025-10-08 15:13:32.610472 | 
2025-10-08 15:13:32.610538 | TASK [Check if we get ci-framework-data basedir]
2025-10-08 15:13:32.861558 | controller | ok
2025-10-08 15:13:32.868679 | 
2025-10-08 15:13:32.868751 | TASK [Create ci-framework-data log directory for zuul]
2025-10-08 15:13:33.251893 | controller | changed
2025-10-08 15:13:33.257371 | 
2025-10-08 15:13:33.257461 | TASK [Copy ci-framework interesting files]
2025-10-08 15:13:33.524943 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2025-10-08 15:13:33.785600 | controller | changed
2025-10-08 15:13:33.791216 | 
2025-10-08 15:13:33.791309 | TASK [Get SELinux listing]
2025-10-08 15:13:34.332408 | controller | changed
2025-10-08 15:13:34.339150 | 
2025-10-08 15:13:34.339234 | TASK [Generate log index]
2025-10-08 15:13:36.163848 | controller | changed
2025-10-08 15:13:36.173460 | 
2025-10-08 15:13:36.173640 | TASK [Get some env related data]
2025-10-08 15:13:36.971838 | controller | /home/zuul/.local/bin/ansible
2025-10-08 15:13:37.726264 | controller | changed
2025-10-08 15:13:37.753245 | 
2025-10-08 15:13:37.753367 | TASK [Generate list of logs to collect in home directory]
2025-10-08 15:13:38.159318 | controller | ok: All paths examined
2025-10-08 15:13:38.165334 | 
2025-10-08 15:13:38.165400 | LOOP [Copy logs from home directory]
2025-10-08 15:13:39.033610 | controller | changed:
2025-10-08 15:13:39.035091 | controller | {
2025-10-08 15:13:39.035267 | controller |   "atime": 1743544925.4788878,
2025-10-08 15:13:39.035306 | controller |   "ctime": 1743545329.1409318,
2025-10-08 15:13:39.035329 | controller |   "dev": 64513,
2025-10-08 15:13:39.035348 | controller |   "gid": 1000,
2025-10-08 15:13:39.035366 | controller |   "gr_name": "zuul",
2025-10-08 15:13:39.035384 | controller |   "inode": 4518807,
2025-10-08 15:13:39.035399 | controller |   "isblk": false,
2025-10-08 15:13:39.035415 | controller |   "ischr": false,
2025-10-08 15:13:39.035429 | controller |   "isdir": false,
2025-10-08 15:13:39.035444 | controller |   "isfifo": false,
2025-10-08 15:13:39.035663 | controller |   "isgid": false,
2025-10-08 15:13:39.035688 | controller |   "islnk": false,
2025-10-08 15:13:39.035706 | controller |   "isreg": true,
2025-10-08 15:13:39.035723 | controller |   "issock": false,
2025-10-08 15:13:39.035739 | controller |   "isuid": false,
2025-10-08 15:13:39.035754 | controller |   "mode": "0644",
2025-10-08 15:13:39.035770 | controller |   "mtime": 1743545329.1409318,
2025-10-08 15:13:39.035785 | controller |   "nlink": 1,
2025-10-08 15:13:39.035800 | controller |   "path": "/home/zuul/crc-setup.log",
2025-10-08 15:13:39.035822 | controller |   "pw_name": "zuul",
2025-10-08 15:13:39.035836 | controller |   "rgrp": true,
2025-10-08 15:13:39.035850 | controller |   "roth": true,
2025-10-08 15:13:39.035864 | controller |   "rusr": true,
2025-10-08 15:13:39.035878 | controller |   "size": 4108,
2025-10-08 15:13:39.035892 | controller |   "uid": 1000,
2025-10-08 15:13:39.035905 | controller |   "wgrp": false,
2025-10-08 15:13:39.035949 | controller |   "woth": false,
2025-10-08 15:13:39.035971 | controller |   "wusr": true,
2025-10-08 15:13:39.035988 | controller |   "xgrp": false,
2025-10-08 15:13:39.036003 | controller |   "xoth": false,
2025-10-08 15:13:39.036017 | controller |   "xusr": false
2025-10-08 15:13:39.036104 | controller | }
2025-10-08 15:13:39.905059 | controller | changed:
2025-10-08 15:13:39.905154 | controller | {
2025-10-08 15:13:39.905183 | controller |   "atime": 1743545331.0429637,
2025-10-08 15:13:39.905204 | controller |   "ctime": 1743545842.0111232,
2025-10-08 15:13:39.905222 | controller |   "dev": 64513,
2025-10-08 15:13:39.905239 | controller |   "gid": 1000,
2025-10-08 15:13:39.905254 | controller |   "gr_name": "zuul",
2025-10-08 15:13:39.905271 | controller |   "inode": 4194437,
2025-10-08 15:13:39.905287 | controller |   "isblk": false,
2025-10-08 15:13:39.905302 | controller |   "ischr": false,
2025-10-08 15:13:39.905319 | controller |   "isdir": false,
2025-10-08 15:13:39.905336 | controller |   "isfifo": false,
2025-10-08 15:13:39.905352 | controller |   "isgid": false,
2025-10-08 15:13:39.905367 | controller |   "islnk": false,
2025-10-08 15:13:39.905382 | controller |   "isreg": true,
2025-10-08 15:13:39.905397 | controller |   "issock": false,
2025-10-08 15:13:39.905412 | controller |   "isuid": false,
2025-10-08 15:13:39.905427 | controller |   "mode": "0644",
2025-10-08 15:13:39.905447 | controller |   "mtime": 1743545842.0111232,
2025-10-08 15:13:39.905465 | controller |   "nlink": 1,
2025-10-08 15:13:39.905482 | controller |   "path": "/home/zuul/crc-start.log",
2025-10-08 15:13:39.905498 | controller |   "pw_name": "zuul",
2025-10-08 15:13:39.905514 | controller |   "rgrp": true,
2025-10-08 15:13:39.905530 | controller |   "roth": true,
2025-10-08 15:13:39.905545 | controller |   "rusr": true,
2025-10-08 15:13:39.905811 | controller |   "size": 4023,
2025-10-08 15:13:39.905842 | controller |   "uid": 1000,
2025-10-08 15:13:39.905863 | controller |   "wgrp": false,
2025-10-08 15:13:39.905882 | controller |   "woth": false,
2025-10-08 15:13:39.905898 | controller |   "wusr": true,
2025-10-08 15:13:39.905942 | controller |   "xgrp": false,
2025-10-08 15:13:39.905961 | controller |   "xoth": false,
2025-10-08 15:13:39.905978 | controller |   "xusr": false
2025-10-08 15:13:39.905994 | controller | }
2025-10-08 15:13:40.870965 | controller | changed:
2025-10-08 15:13:40.871123 | controller | {
2025-10-08 15:13:40.871156 | controller |   "atime": 1759936110.666319,
2025-10-08 15:13:40.871178 | controller |   "ctime": 1759936126.6923764,
2025-10-08 15:13:40.871196 | controller |   "dev": 64513,
2025-10-08 15:13:40.871213 | controller |   "gid": 1000,
2025-10-08 15:13:40.871229 | controller |   "gr_name": "zuul",
2025-10-08 15:13:40.871246 | controller |   "inode": 4685788,
2025-10-08 15:13:40.871262 | controller |   "isblk": false,
2025-10-08 15:13:40.871277 | controller |   "ischr": false,
2025-10-08 15:13:40.871292 | controller |   "isdir": false,
2025-10-08 15:13:40.871307 | controller |   "isfifo": false,
2025-10-08 15:13:40.871320 | controller |   "isgid": false,
2025-10-08 15:13:40.871335 | controller |   "islnk": false,
2025-10-08 15:13:40.871350 | controller |   "isreg": true,
2025-10-08 15:13:40.871365 | controller |   "issock": false,
2025-10-08 15:13:40.871379 | controller |   "isuid": false,
2025-10-08 15:13:40.871393 | controller |   "mode": "0644",
2025-10-08 15:13:40.871406 | controller |   "mtime": 1759936126.6923764,
2025-10-08 15:13:40.871420 | controller |   "nlink": 1,
2025-10-08 15:13:40.871435 | controller |   "path": "/home/zuul/ansible.log",
2025-10-08 15:13:40.871450 | controller |   "pw_name": "zuul",
2025-10-08 15:13:40.871465 | controller |   "rgrp": true,
2025-10-08 15:13:40.871480 | controller |   "roth": true,
2025-10-08 15:13:40.871496 | controller |   "rusr": true,
2025-10-08 15:13:40.871512 | controller |   "size": 6749,
2025-10-08 15:13:40.871526 | controller |   "uid": 1000,
2025-10-08 15:13:40.871541 | controller |   "wgrp": false,
2025-10-08 15:13:40.871555 | controller |   "woth": false,
2025-10-08 15:13:40.871569 | controller |   "wusr": true,
2025-10-08 15:13:40.871583 | controller |   "xgrp": false,
2025-10-08 15:13:40.871597 | controller |   "xoth": false,
2025-10-08 15:13:40.871610 | controller |   "xusr": false
2025-10-08 15:13:40.871623 | controller | }
2025-10-08 15:13:40.888188 | 
2025-10-08 15:13:40.888272 | TASK [Copy crio stats log file]
2025-10-08 15:13:40.912142 | controller | skipping: Conditional result was False
2025-10-08 15:13:40.917643 | 
2025-10-08 15:13:40.917724 | TASK [Get SELinux related data]
2025-10-08 15:13:41.233962 | controller | <no matches>
2025-10-08 15:13:41.445487 | controller | ERROR
2025-10-08 15:13:41.445621 | controller | {
2025-10-08 15:13:41.445677 | controller |   "delta": "0:00:00.008765",
2025-10-08 15:13:41.445705 | controller |   "end": "2025-10-08 15:13:41.235133",
2025-10-08 15:13:41.445728 | controller |   "msg": "non-zero return code",
2025-10-08 15:13:41.445749 | controller |   "rc": 1,
2025-10-08 15:13:41.445769 | controller |   "start": "2025-10-08 15:13:41.226368"
2025-10-08 15:13:41.445789 | controller | }
2025-10-08 15:13:41.445816 | controller | ERROR: Ignoring Errors
2025-10-08 15:13:41.452771 | 
2025-10-08 15:13:41.452839 | TASK [Create system configuration directory]
2025-10-08 15:13:41.758774 | controller | changed
2025-10-08 15:13:41.768762 | 
2025-10-08 15:13:41.768847 | TASK [Get some of the system configurations]
2025-10-08 15:13:42.303214 | controller | changed
2025-10-08 15:13:42.308979 | 
2025-10-08 15:13:42.309049 | TASK [Copy generated documentation if available]
2025-10-08 15:13:42.322504 | controller | skipping: Conditional result was False
2025-10-08 15:13:42.328585 | 
2025-10-08 15:13:42.328668 | TASK [Copy generated AsciiDoc documentation if available]
2025-10-08 15:13:42.342754 | controller | skipping: Conditional result was False
2025-10-08 15:13:42.348729 | 
2025-10-08 15:13:42.348795 | TASK [Compress logs bigger than 2MB]
2025-10-08 15:13:42.887029 | controller | changed
2025-10-08 15:13:42.892793 | 
2025-10-08 15:13:42.892863 | TASK [Copy files from workspace on node]
2025-10-08 15:13:42.911587 | controller | ok
2025-10-08 15:13:42.935261 | 
2025-10-08 15:13:42.935352 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-08 15:13:42.950006 | controller | skipping: Conditional result was False
2025-10-08 15:13:42.956304 | 
2025-10-08 15:13:42.956382 | TASK [fetch-output : Set log path for single node]
2025-10-08 15:13:42.985840 | controller | ok
2025-10-08 15:13:42.992846 | 
2025-10-08 15:13:42.992972 | LOOP [fetch-output : Ensure local output dirs]
2025-10-08 15:13:43.197943 | controller -> localhost | ok: "/var/lib/zuul/builds/d6470fb11ad14c358e968e29ba9fd183/work/logs"
2025-10-08 15:13:43.198187 | controller -> localhost | changed: All items complete
2025-10-08 15:13:43.198218 | 
2025-10-08 15:13:43.396319 | controller -> localhost | changed: "/var/lib/zuul/builds/d6470fb11ad14c358e968e29ba9fd183/work/artifacts"
2025-10-08 15:13:43.582129 | controller -> localhost | changed: "/var/lib/zuul/builds/d6470fb11ad14c358e968e29ba9fd183/work/docs"
2025-10-08 15:13:43.592368 | 
2025-10-08 15:13:43.592478 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-08 15:13:44.381669 | controller | changed:
2025-10-08 15:13:44.381852 | controller | .d..t...... ./
2025-10-08 15:13:44.381890 | controller | >f+++++++++ README.html
2025-10-08 15:13:44.381937 | controller | >f+++++++++ ansible-execution.log
2025-10-08 15:13:44.381966 | controller | >f+++++++++ ansible.log
2025-10-08 15:13:44.381991 | controller | >f+++++++++ crc-setup.log
2025-10-08 15:13:44.382014 | controller | >f+++++++++ crc-start.log
2025-10-08 15:13:44.382037 | controller | >f+++++++++ dmesg.log
2025-10-08 15:13:44.382065 | controller | >f+++++++++ installed-pkgs.log
2025-10-08 15:13:44.382089 | controller | >f+++++++++ python.log
2025-10-08 15:13:44.382110 | controller | >f+++++++++ registries.conf
2025-10-08 15:13:44.382131 | controller | >f+++++++++ report.html
2025-10-08 15:13:44.382152 | controller | >f+++++++++ selinux-denials.log
2025-10-08 15:13:44.382172 | controller | >f+++++++++ selinux-listing.log
2025-10-08 15:13:44.382191 | controller | cd+++++++++ ci-framework-data/
2025-10-08 15:13:44.382211 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-10-08 15:13:44.382230 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-10-08 15:13:44.382250 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-10-08 15:13:44.382270 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-10-08 15:13:44.382293 | controller | cd+++++++++ ci-framework-data/artifacts/repositories/
2025-10-08 15:13:44.382314 | controller | >f+++++++++ ci-framework-data/artifacts/repositories/delorean.repo.md5
2025-10-08 15:13:44.382335 | controller | cd+++++++++ ci-framework-data/logs/
2025-10-08 15:13:44.382355 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-10-08 15:13:44.382375 | controller | cd+++++++++ registries.conf.d/
2025-10-08 15:13:44.382396 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-10-08 15:13:44.382416 | controller | cd+++++++++ system-config/
2025-10-08 15:13:44.382437 | controller | cd+++++++++ system-config/libvirt/
2025-10-08 15:13:44.382458 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-10-08 15:13:44.382478 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-10-08 15:13:44.382944 | controller | >f+++++++++ system-config/libvirt/libvirtd.conf
2025-10-08 15:13:44.382990 | controller | >f+++++++++ system-config/libvirt/network.conf
2025-10-08 15:13:44.383013 | controller | >f+++++++++ system-config/libvirt/qemu-lockd.conf
2025-10-08 15:13:44.383032 | controller | >f+++++++++ system-config/libvirt/qemu.conf
2025-10-08 15:13:44.383049 | controller | >f+++++++++ system-config/libvirt/virtinterfaced.conf
2025-10-08 15:13:44.383066 | controller | >f+++++++++ system-config/libvirt/virtlockd.conf
2025-10-08 15:13:44.383083 | controller | >f+++++++++ system-config/libvirt/virtlogd.conf
2025-10-08 15:13:44.383099 | controller | >f+++++++++ system-config/libvirt/virtnetworkd.conf
2025-10-08 15:13:44.383114 | controller | >f+++++++++ system-config/libvirt/virtnodedevd.conf
2025-10-08 15:13:44.383131 | controller | >f+++++++++ system-config/libvirt/virtnwfilterd.conf
2025-10-08 15:13:44.383146 | controller | >f+++++++++ system-config/libvirt/virtproxyd.conf
2025-10-08 15:13:44.383162 | controller | >f+++++++++ system-config/libvirt/virtqemud.conf
2025-10-08 15:13:44.383178 | controller | >f+++++++++ system-config/libvirt/virtsecretd.conf
2025-10-08 15:13:44.383193 | controller | >f+++++++++ system-config/libvirt/virtstoraged.conf
2025-10-08 15:13:44.958437 | controller | changed: .d..t...... ./
2025-10-08 15:13:45.580328 | controller | changed: .d..t...... ./
2025-10-08 15:13:45.607797 | 
2025-10-08 15:13:45.607894 | TASK [Return artifact to Zuul]
2025-10-08 15:13:45.636816 | controller | ok
2025-10-08 15:13:45.657262 | 
2025-10-08 15:13:45.657347 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-10-08 15:13:45.657448 | 
2025-10-08 15:13:45.657475 | PLAY RECAP
2025-10-08 15:13:45.657512 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-10-08 15:13:45.657534 | 
2025-10-08 15:13:45.748106 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-08 15:13:45.748808 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-08 15:13:46.328749 | 
2025-10-08 15:13:46.328865 | PLAY [all]
2025-10-08 15:13:46.348791 | 
2025-10-08 15:13:46.348945 | TASK [include_role : fetch-output]
2025-10-08 15:13:46.389231 | controller | ok
2025-10-08 15:13:46.407220 | 
2025-10-08 15:13:46.407324 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-08 15:13:46.450947 | controller | skipping: Conditional result was False
2025-10-08 15:13:46.456879 | 
2025-10-08 15:13:46.457001 | TASK [fetch-output : Set log path for single node]
2025-10-08 15:13:46.484955 | controller | ok
2025-10-08 15:13:46.490384 | 
2025-10-08 15:13:46.490459 | LOOP [fetch-output : Ensure local output dirs]
2025-10-08 15:13:46.850621 | controller -> localhost | ok: "/var/lib/zuul/builds/d6470fb11ad14c358e968e29ba9fd183/work/logs"
2025-10-08 15:13:47.055549 | controller -> localhost | ok: "/var/lib/zuul/builds/d6470fb11ad14c358e968e29ba9fd183/work/artifacts"
2025-10-08 15:13:47.258621 | controller -> localhost | ok: "/var/lib/zuul/builds/d6470fb11ad14c358e968e29ba9fd183/work/docs"
2025-10-08 15:13:47.266964 | 
2025-10-08 15:13:47.267071 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-08 15:13:47.894785 | controller | ok
2025-10-08 15:13:47.895015 | controller | ok: All items complete
2025-10-08 15:13:47.895048 | 
2025-10-08 15:13:48.394207 | controller | ok
2025-10-08 15:13:48.906231 | controller | ok
2025-10-08 15:13:48.924723 | 
2025-10-08 15:13:48.924831 | TASK [include_role : fetch-output-openshift]
2025-10-08 15:13:48.941394 | controller | skipping: Conditional result was False
2025-10-08 15:13:48.947268 | 
2025-10-08 15:13:48.947351 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-08 15:13:49.364326 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.008387
2025-10-08 15:13:49.609863 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.008495
2025-10-08 15:13:49.650789 | 
2025-10-08 15:13:49.650881 | PLAY [all]
2025-10-08 15:13:49.668118 | 
2025-10-08 15:13:49.668204 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-08 15:13:50.222046 | controller | changed
2025-10-08 15:13:50.246947 | 
2025-10-08 15:13:50.247035 | PLAY RECAP
2025-10-08 15:13:50.247081 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-08 15:13:50.247104 | 
2025-10-08 15:13:50.345336 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-08 15:13:50.346114 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-08 15:13:50.968654 | 
2025-10-08 15:13:50.968770 | PLAY [localhost]
2025-10-08 15:13:50.987208 | 
2025-10-08 15:13:50.987321 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-08 15:13:51.321749 | localhost | changed
2025-10-08 15:13:51.326730 | 
2025-10-08 15:13:51.326811 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-08 15:13:51.355198 | localhost | ok
2025-10-08 15:13:51.363531 | 
2025-10-08 15:13:51.363602 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-08 15:13:51.685450 | localhost | changed
2025-10-08 15:13:51.691501 | 
2025-10-08 15:13:51.691571 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-08 15:13:52.360096 | localhost | changed
2025-10-08 15:13:52.366536 | 
2025-10-08 15:13:52.366623 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-08 15:13:52.800606 | localhost | Identity added: /var/lib/zuul/builds/d6470fb11ad14c358e968e29ba9fd183/work/tmp/ansible.eqw1pdme (/var/lib/zuul/builds/d6470fb11ad14c358e968e29ba9fd183/work/tmp/ansible.eqw1pdme)
2025-10-08 15:13:52.800795 | localhost | ok: Runtime: 0:00:00.009501
2025-10-08 15:13:52.805530 | 
2025-10-08 15:13:52.805641 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-08 15:13:53.090793 | localhost | ok: Runtime: 0:00:00.008377
2025-10-08 15:13:53.108670 | 
2025-10-08 15:13:53.108763 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-08 15:13:53.173931 | localhost | changed
2025-10-08 15:13:53.180344 | 
2025-10-08 15:13:53.180437 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-08 15:13:53.624695 | localhost | changed
2025-10-08 15:13:53.645645 | 
2025-10-08 15:13:53.645717 | PLAY [localhost]
2025-10-08 15:13:53.658518 | 
2025-10-08 15:13:53.658579 | TASK [Generate bulk log download script]
2025-10-08 15:13:53.676460 | localhost | ok
2025-10-08 15:13:53.689202 | 
2025-10-08 15:13:53.689275 | TASK [local-log-download : Check API endpoint is defined]
2025-10-08 15:13:53.718470 | localhost | ok: All assertions passed
2025-10-08 15:13:53.723283 | 
2025-10-08 15:13:53.723352 | TASK [local-log-download : Create download script]
2025-10-08 15:13:54.123121 | localhost -> localhost | changed
2025-10-08 15:13:54.132250 | 
2025-10-08 15:13:54.132319 | TASK [Register quick-download link]
2025-10-08 15:13:54.150063 | localhost | ok
2025-10-08 15:13:54.185404 | 
2025-10-08 15:13:54.185491 | PLAY [logserver.rdoproject.org]
2025-10-08 15:13:54.196034 | 
2025-10-08 15:13:54.196102 | TASK [Set zuul-log-path fact]
2025-10-08 15:13:54.211975 | logserver.rdoproject.org | ok
2025-10-08 15:13:54.221816 | 
2025-10-08 15:13:54.221894 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-08 15:13:54.248477 | logserver.rdoproject.org | ok
2025-10-08 15:13:54.254810 | 
2025-10-08 15:13:54.254932 | TASK [upload-logs : Create log directories]
2025-10-08 15:13:56.222069 | logserver.rdoproject.org | changed
2025-10-08 15:13:56.225261 | 
2025-10-08 15:13:56.225347 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-08 15:13:56.527832 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.005706
2025-10-08 15:13:56.533204 | 
2025-10-08 15:13:56.533269 | TASK [upload-logs : Upload logs to log server]
2025-10-08 15:13:58.272548 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-08 15:13:58.277709 | 
2025-10-08 15:13:58.277796 | LOOP [upload-logs : Compress console log and json output]
2025-10-08 15:13:58.337136 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 15:13:58.338092 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 15:13:58.352098 | 
2025-10-08 15:13:58.352209 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-08 15:13:58.407694 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 15:13:58.407990 | 
2025-10-08 15:13:58.411516 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-08 15:13:58.421472 | 
2025-10-08 15:13:58.421546 | LOOP [upload-logs : Upload console log and json output]