2025-09-30 02:57:26.675622 | Job console starting...
2025-09-30 02:57:26.915112 | Updating repositories
2025-09-30 02:57:27.606714 | Preparing job workspace
2025-09-30 02:57:36.647391 | Running Ansible setup...
2025-09-30 02:57:39.745972 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-09-30 02:57:40.288251 | 
2025-09-30 02:57:40.288349 | PLAY [localhost]
2025-09-30 02:57:40.297257 | 
2025-09-30 02:57:40.297328 | TASK [Gathering Facts]
2025-09-30 02:57:41.122939 | localhost | ok
2025-09-30 02:57:41.136378 | 
2025-09-30 02:57:41.136552 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-09-30 02:57:41.464927 | localhost -> localhost | changed
2025-09-30 02:57:41.470752 | 
2025-09-30 02:57:41.470837 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-09-30 02:57:42.213753 | localhost -> localhost | changed
2025-09-30 02:57:42.222705 | 
2025-09-30 02:57:42.222886 | TASK [Setup log path fact]
2025-09-30 02:57:42.240237 | localhost | ok
2025-09-30 02:57:42.251754 | 
2025-09-30 02:57:42.251841 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-09-30 02:57:42.279133 | localhost | ok
2025-09-30 02:57:42.287315 | 
2025-09-30 02:57:42.287407 | TASK [emit-job-header : Print job information]
2025-09-30 02:57:42.315459 | # Job Information
2025-09-30 02:57:42.315632 | Ansible Version: 2.15.12
2025-09-30 02:57:42.315663 | Job: cifmw-molecule-test_deps
2025-09-30 02:57:42.315687 | Pipeline: github-check
2025-09-30 02:57:42.315707 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-09-30 02:57:42.315726 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3333
2025-09-30 02:57:42.315745 | Log URL (when completed): https://logserver.rdoproject.org/d36/rdoproject.org/d36d0ace6ffa4cda9009f319c6427288/
2025-09-30 02:57:42.315763 | Event ID: 1dc977c0-9da6-11f0-92a8-2c1c6d0a259d
2025-09-30 02:57:42.319322 | 
2025-09-30 02:57:42.319390 | LOOP [emit-job-header : Print node information]
2025-09-30 02:57:42.408092 | localhost | ok:
2025-09-30 02:57:42.408250 | localhost | # Node Information
2025-09-30 02:57:42.408281 | localhost | Inventory Hostname: controller
2025-09-30 02:57:42.408403 | localhost | Hostname: np0005461430
2025-09-30 02:57:42.408433 | localhost | Username: zuul
2025-09-30 02:57:42.408456 | localhost | Distro: CentOS 9
2025-09-30 02:57:42.408474 | localhost | Provider: ibm-bm4-nodepool
2025-09-30 02:57:42.408490 | localhost | Region: regionOne
2025-09-30 02:57:42.408591 | localhost | Label: cloud-centos-9-stream-tripleo-ibm
2025-09-30 02:57:42.408630 | localhost | Product Name: OpenStack Compute
2025-09-30 02:57:42.408651 | localhost | Interface IP: 192.168.26.9
2025-09-30 02:57:42.433656 | 
2025-09-30 02:57:42.433784 | PLAY [all]
2025-09-30 02:57:42.439885 | 
2025-09-30 02:57:42.439967 | TASK [Gather network facts]
2025-09-30 02:57:42.824393 | controller | ok
2025-09-30 02:57:42.838684 | 
2025-09-30 02:57:42.838757 | TASK [include_role : start-zuul-console]
2025-09-30 02:57:42.856455 | controller | ok
2025-09-30 02:57:42.868927 | 
2025-09-30 02:57:42.869003 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-09-30 02:57:43.180564 | controller | ok
2025-09-30 02:57:43.189257 | 
2025-09-30 02:57:43.189329 | TASK [include_role : add-build-sshkey]
2025-09-30 02:57:43.207499 | controller | ok
2025-09-30 02:57:43.220856 | 
2025-09-30 02:57:43.220951 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-09-30 02:57:43.436961 | controller -> localhost | ok
2025-09-30 02:57:43.442679 | 
2025-09-30 02:57:43.442751 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-09-30 02:57:43.461120 | controller | ok
2025-09-30 02:57:43.475667 | controller | included: /var/lib/zuul/builds/d36d0ace6ffa4cda9009f319c6427288/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-09-30 02:57:43.481527 | 
2025-09-30 02:57:43.481596 | TASK [add-build-sshkey : Create Temp SSH key]
2025-09-30 02:57:43.922802 | controller -> localhost | Generating public/private rsa key pair.
2025-09-30 02:57:43.923028 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/d36d0ace6ffa4cda9009f319c6427288/work/d36d0ace6ffa4cda9009f319c6427288_id_rsa.
2025-09-30 02:57:43.923068 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/d36d0ace6ffa4cda9009f319c6427288/work/d36d0ace6ffa4cda9009f319c6427288_id_rsa.pub.
2025-09-30 02:57:43.923103 | controller -> localhost | The key fingerprint is:
2025-09-30 02:57:43.923127 | controller -> localhost | SHA256:avNZIOiOJUtgbrwMPUoouLH5iP2aA2/ap5LJHvRrpDs zuul-build-sshkey
2025-09-30 02:57:43.923148 | controller -> localhost | The key's randomart image is:
2025-09-30 02:57:43.923168 | controller -> localhost | +---[RSA 3072]----+
2025-09-30 02:57:43.923188 | controller -> localhost | |                 |
2025-09-30 02:57:43.923207 | controller -> localhost | |                 |
2025-09-30 02:57:43.923225 | controller -> localhost | |                 |
2025-09-30 02:57:43.923244 | controller -> localhost | |     .           |
2025-09-30 02:57:43.923263 | controller -> localhost | |.o  . . S        |
2025-09-30 02:57:43.923282 | controller -> localhost | |Oo.o   o .       |
2025-09-30 02:57:43.923299 | controller -> localhost | |B@B.o +   .      |
2025-09-30 02:57:43.923317 | controller -> localhost | |@E*Xo. o o       |
2025-09-30 02:57:43.923334 | controller -> localhost | |XX&Bo   o        |
2025-09-30 02:57:43.923352 | controller -> localhost | +----[SHA256]-----+
2025-09-30 02:57:43.923408 | controller -> localhost | ok: Runtime: 0:00:00.083040
2025-09-30 02:57:43.929392 | 
2025-09-30 02:57:43.929466 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-09-30 02:57:43.957669 | controller | ok
2025-09-30 02:57:43.967522 | controller | included: /var/lib/zuul/builds/d36d0ace6ffa4cda9009f319c6427288/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-09-30 02:57:43.976024 | 
2025-09-30 02:57:43.976092 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-09-30 02:57:43.989818 | controller | skipping: Conditional result was False
2025-09-30 02:57:43.995634 | 
2025-09-30 02:57:43.995702 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-09-30 02:57:44.378375 | controller | changed
2025-09-30 02:57:44.384646 | 
2025-09-30 02:57:44.384737 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-09-30 02:57:44.586080 | controller | ok
2025-09-30 02:57:44.591335 | 
2025-09-30 02:57:44.591404 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-09-30 02:57:45.149232 | controller | changed
2025-09-30 02:57:45.154449 | 
2025-09-30 02:57:45.154520 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-09-30 02:57:45.723340 | controller | changed
2025-09-30 02:57:45.728450 | 
2025-09-30 02:57:45.728523 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-09-30 02:57:45.742189 | controller | skipping: Conditional result was False
2025-09-30 02:57:45.748723 | 
2025-09-30 02:57:45.748796 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-09-30 02:57:46.125154 | controller -> localhost | changed
2025-09-30 02:57:46.134290 | 
2025-09-30 02:57:46.134359 | TASK [add-build-sshkey : Add back temp key]
2025-09-30 02:57:46.512869 | controller -> localhost | Identity added: /var/lib/zuul/builds/d36d0ace6ffa4cda9009f319c6427288/work/d36d0ace6ffa4cda9009f319c6427288_id_rsa (zuul-build-sshkey)
2025-09-30 02:57:46.513115 | controller -> localhost | ok: Runtime: 0:00:00.007641
2025-09-30 02:57:46.518766 | 
2025-09-30 02:57:46.518843 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-09-30 02:57:46.858985 | controller | ok
2025-09-30 02:57:46.865815 | 
2025-09-30 02:57:46.865887 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-09-30 02:57:46.890067 | controller | skipping: Conditional result was False
2025-09-30 02:57:46.900036 | 
2025-09-30 02:57:46.900114 | TASK [include_role : validate-host]
2025-09-30 02:57:46.918491 | controller | ok
2025-09-30 02:57:46.940868 | 
2025-09-30 02:57:46.940970 | TASK [validate-host : Define zuul_info_dir fact]
2025-09-30 02:57:46.981158 | controller | ok
2025-09-30 02:57:46.986626 | 
2025-09-30 02:57:46.986705 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-09-30 02:57:47.203246 | controller -> localhost | ok
2025-09-30 02:57:47.211580 | 
2025-09-30 02:57:47.211685 | TASK [validate-host : Collect information about the host]
2025-09-30 02:57:47.844951 | controller | ok
2025-09-30 02:57:47.854762 | 
2025-09-30 02:57:47.854850 | TASK [validate-host : Sanitize hostname]
2025-09-30 02:57:47.926625 | controller | ok
2025-09-30 02:57:47.970288 | 
2025-09-30 02:57:47.970495 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-09-30 02:57:48.405100 | controller -> localhost | changed
2025-09-30 02:57:48.410763 | 
2025-09-30 02:57:48.410827 | TASK [validate-host : Collect information about zuul worker]
2025-09-30 02:57:48.751418 | controller | ok
2025-09-30 02:57:48.756261 | 
2025-09-30 02:57:48.756330 | TASK [validate-host : Write out all zuul information for each host]
2025-09-30 02:57:49.137310 | controller -> localhost | changed
2025-09-30 02:57:49.148969 | 
2025-09-30 02:57:49.149040 | TASK [include_role : prepare-workspace-openshift]
2025-09-30 02:57:49.173227 | controller | skipping: Conditional result was False
2025-09-30 02:57:49.179270 | 
2025-09-30 02:57:49.179347 | TASK [include_role : remove-zuul-sshkey]
2025-09-30 02:57:49.193509 | controller | skipping: Conditional result was False
2025-09-30 02:57:49.200258 | 
2025-09-30 02:57:49.200356 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-09-30 02:57:49.404152 | controller | ok: "logs"
2025-09-30 02:57:49.404403 | controller | ok: All items complete
2025-09-30 02:57:49.404432 | 
2025-09-30 02:57:49.585773 | controller | ok: "artifacts"
2025-09-30 02:57:49.762900 | controller | ok: "docs"
2025-09-30 02:57:49.778489 | 
2025-09-30 02:57:49.778712 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-09-30 02:57:49.995476 | controller | changed: "logs"
2025-09-30 02:57:50.179169 | controller | changed: "artifacts"
2025-09-30 02:57:50.350382 | controller | changed: "docs"
2025-09-30 02:57:50.384194 | 
2025-09-30 02:57:50.384334 | PLAY RECAP
2025-09-30 02:57:50.384387 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-09-30 02:57:50.384415 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-09-30 02:57:50.384433 | 
2025-09-30 02:57:50.527430 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-09-30 02:57:50.528290 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-09-30 02:57:51.101540 | 
2025-09-30 02:57:51.101676 | PLAY [all]
2025-09-30 02:57:51.123331 | 
2025-09-30 02:57:51.123497 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-09-30 02:57:51.183040 | controller | ok
2025-09-30 02:57:51.188116 | 
2025-09-30 02:57:51.188219 | TASK [mirror-info-fork : Create /etc/ci]
2025-09-30 02:57:51.573731 | controller | changed
2025-09-30 02:57:51.579426 | 
2025-09-30 02:57:51.579502 | TASK [mirror-info-fork : Install ci_mirror script]
2025-09-30 02:57:52.430854 | controller | changed
2025-09-30 02:57:52.440844 | 
2025-09-30 02:57:52.440975 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-09-30 02:57:52.813161 | controller | changed:
2025-09-30 02:57:52.813414 | controller | {
2025-09-30 02:57:52.813448 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-09-30 02:57:52.813480 | controller | }
2025-09-30 02:57:53.030051 | controller | changed:
2025-09-30 02:57:53.030144 | controller | {
2025-09-30 02:57:53.030174 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-09-30 02:57:53.030198 | controller | }
2025-09-30 02:57:53.233904 | controller | changed:
2025-09-30 02:57:53.234030 | controller | {
2025-09-30 02:57:53.234059 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-09-30 02:57:53.234081 | controller | }
2025-09-30 02:57:53.437751 | controller | changed:
2025-09-30 02:57:53.437848 | controller | {
2025-09-30 02:57:53.437874 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-09-30 02:57:53.437894 | controller | }
2025-09-30 02:57:53.644770 | controller | changed:
2025-09-30 02:57:53.644873 | controller | {
2025-09-30 02:57:53.644903 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-09-30 02:57:53.645012 | controller | }
2025-09-30 02:57:53.853368 | controller | changed:
2025-09-30 02:57:53.853527 | controller | {
2025-09-30 02:57:53.853561 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-09-30 02:57:53.853583 | controller | }
2025-09-30 02:57:54.079198 | controller | changed:
2025-09-30 02:57:54.079293 | controller | {
2025-09-30 02:57:54.079319 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDLOQd4ZLtkZXQGY6UwAr/06ppWQK4fDO3HaqxPk98csyOCBXsliSKK39Bso828+5srIXiW7aI6aC9P5mwi4mUZlGPfJlQbfrcGvY+b/SocuvaGK+1RrHLoJCT52LBhwgrzlXio2jeksZeein8iaTrhsPrOAs7KggIL/rB9hEiB3NaOPWhhoCP4vlW6MEMExGcqB/1FVxXFBPnLkEyW0Lk7ycVflZl2ocRxbfjZi0+tI1Wlinp8PvSQSc/WVrAcDgKjc/mB4ODPOyYy3G8FHgfMsrXSDEyjBKgLKMsdCrAUcqJQWjkqXleXSYOV4q3pzL+9umK+q/e3P/bIoSFQzmJKTU1eDfuvPXmow9F5H54fii/Da7ezlMJ+wPGHJrRAkmzvMbALy7xwswLhZMkOGNtRcPqaKYRmIBKpw3o6bCTtcNUHOtOQnzwY8JzrM2eBWJBXAANYw+9/ho80JIiwhg29CFNpVBuHbql2YxJQNrnl90guN65rYNpDxdIluweyUf8= anbanerj@kaermorhen"
2025-09-30 02:57:54.079340 | controller | }
2025-09-30 02:57:54.298880 | controller | changed:
2025-09-30 02:57:54.298990 | controller | {
2025-09-30 02:57:54.299018 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC3VwV8Im9kRm49lt3tM36hj4Zv27FxGo4C1Q/0jqhzFmHY7RHbmeRr8ObhwWoHjXSozKWg8FL5ER0z3hTwL0W6lez3sL7hUaCmSuZmG5Hnl3x4vTSxDI9JZ/Y65rtYiiWQo2fC5xJhU/4+0e5e/pseCm8cKRSu+SaxhO+sd6FDojA2x1BzOzKiQRDy/1zWGp/cZkxcEuB1wHI5LMzN03c67vmbu+fhZRAUO4dQkvcnj2LrhQtpa+ytvnSjr8icMDosf1OsbSffwZFyHB/hfWGAfe0eIeSA2XPraxiPknXxiPKx2MJsaUTYbsZcm3EjFdHBBMumw5rBI74zLrMRvCO9GwBEmGT4rFng1nP+yw5DB8sn2zqpOsPg1LYRwCPOUveC13P6pgsZZPh812e8v5EKnETct+5XI3dVpdw6CnNiLwAyVAF15DJvBGT/u1k0Myg/bQn+Gv9k2MSj6LvQmf6WbZu2Wgjm30z3FyCneBqTL7mLF19YXzeC0ufHz5pnO1E= dasm@fedora"
2025-09-30 02:57:54.299039 | controller | }
2025-09-30 02:57:54.521354 | controller | changed:
2025-09-30 02:57:54.521446 | controller | {
2025-09-30 02:57:54.521472 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-09-30 02:57:54.521491 | controller | }
2025-09-30 02:57:54.727392 | controller | changed:
2025-09-30 02:57:54.727484 | controller | {
2025-09-30 02:57:54.727511 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-09-30 02:57:54.727533 | controller | }
2025-09-30 02:57:54.936146 | controller | changed:
2025-09-30 02:57:54.936301 | controller | {
2025-09-30 02:57:54.936333 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-09-30 02:57:54.936355 | controller | }
2025-09-30 02:57:55.161210 | controller | changed:
2025-09-30 02:57:55.161302 | controller | {
2025-09-30 02:57:55.161330 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-09-30 02:57:55.161351 | controller | }
2025-09-30 02:57:55.359960 | controller | changed:
2025-09-30 02:57:55.360046 | controller | {
2025-09-30 02:57:55.360071 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-09-30 02:57:55.360091 | controller | }
2025-09-30 02:57:55.574633 | controller | changed:
2025-09-30 02:57:55.574738 | controller | {
2025-09-30 02:57:55.574765 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-09-30 02:57:55.574786 | controller | }
2025-09-30 02:57:55.796441 | controller | changed:
2025-09-30 02:57:55.796537 | controller | {
2025-09-30 02:57:55.796563 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-09-30 02:57:55.796583 | controller | }
2025-09-30 02:57:56.017736 | controller | changed:
2025-09-30 02:57:56.017834 | controller | {
2025-09-30 02:57:56.017861 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-09-30 02:57:56.017883 | controller | }
2025-09-30 02:57:56.225920 | controller | changed:
2025-09-30 02:57:56.226025 | controller | {
2025-09-30 02:57:56.226052 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQCfNtF7NvKl915TGsGGoseUb06Hj8L/S4toWf0hExeY+F00woL6NvBlJD0nDct+P5a22I4EhvoQCRQ8reaPCm1lybR3uiRIJsj+8zkVvLwby9LXzfZorlNG9ofjd00FEmB09uW/YvTl6Q9XwwwX6tInzIOv3TMqTHHGOL74ibbj8J/FJR0cFEyj0z4WQRvtkh32xAHl83gbuINryMt0sqRI+clj2381NKL55DRLQrVw0gsfqqxiHAnXg21qWmc4J+b9e9kiuAFQjcjwTVkwJCcg3xbPwC/qokYRby/Y5S40UUd7/jEARGXT7RZgpzTuDd1oZiCVrnrqJNPaMNdVv5MLeFdf1B7iIe5aa/fGouX7AO4SdKhZUdnJmCFAGvjC6S3JMZ2wAcUl+OHnssfmdj7XL50cLo27vjuzMtLAgSqi6N99m92WCF2s8J9aVzszX7Xz9OKZCeGsiVJp3/NdABKzSEAyM9xBD/5Vho894Sav+otpySHe3p6RUTgbB5Zu8VyZRZ/UtB3ueXxyo764yrc6qWIDqrehm84Xm9g+/jpIBzGPl07NUNJpdt/6Sgf9RIKXw/7XypO5yZfUcuFNGTxLfqjTNrtgLZNcjfav6sSdVXVcMPL//XNuRdKmVFaO76eV/oGMQGr1fGcCD+N+CpI7+Q+fCNB6VFWG4nZFuI/Iuw== averdagu@redhat.com"
2025-09-30 02:57:56.226073 | controller | }
2025-09-30 02:57:56.443378 | controller | changed:
2025-09-30 02:57:56.443518 | controller | {
2025-09-30 02:57:56.443548 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDq8l27xI+QlQVdS4djp9ogSoyrNE2+Ox6vKPdhSNL1J3PE5w+WCSvMz9A5gnNuH810zwbekEApbxTze/gLQJwBHA52CChfURpXrFaxY7ePXRElwKAL3mJfzBWY/c5jnNL9TCVmFJTGZkFZP3Nh+BMgZvL6xBkt3WKm6Uq18qzd9XeKcZusrA+O+uLv1fVeQnadY9RIqOCyeFYCzLWrUfTyE8x/XG0hAWIM7qpnF2cALQS2h9n4hW5ybiUN790H08wf9hFwEf5nxY9Z9dVkPFQiTSGKNBzmnCXU9skxS/xhpFjJ5duGSZdtAHe9O+nGZm9c67hxgtf8e5PDuqAdXEv2cf6e3VBAt+Bz8EKI3yosTj0oZHfwr42Yzb1l/SKy14Rggsrc9KAQlrGXan6+u2jcQqqx7l+SWmnpFiWTV9u5cWj2IgOhApOitmRBPYqk9rE2usfO0hLn/Pj/R/Nau4803e1/EikdLE7Ps95s9mX5jRDjAoUa2JwFF5RsVFyL910= ashigupt@ashigupt.remote.csb"
2025-09-30 02:57:56.443578 | controller | }
2025-09-30 02:57:56.651263 | controller | changed:
2025-09-30 02:57:56.651357 | controller | {
2025-09-30 02:57:56.651382 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-09-30 02:57:56.651402 | controller | }
2025-09-30 02:57:56.861671 | controller | changed:
2025-09-30 02:57:56.861763 | controller | {
2025-09-30 02:57:56.861789 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-09-30 02:57:56.861810 | controller | }
2025-09-30 02:57:57.071220 | controller | changed:
2025-09-30 02:57:57.071319 | controller | {
2025-09-30 02:57:57.071346 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-09-30 02:57:57.071368 | controller | }
2025-09-30 02:57:57.280306 | controller | changed:
2025-09-30 02:57:57.280394 | controller | {
2025-09-30 02:57:57.280420 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-09-30 02:57:57.280441 | controller | }
2025-09-30 02:57:57.495993 | controller | changed:
2025-09-30 02:57:57.496078 | controller | {
2025-09-30 02:57:57.496104 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQDZdI7t1cxYx65heVI24HTV4F7oQLW1zyfxHreL2TIJKxjyrUUKIFEUmTutcBlJRLNT2Eoix6x1sOw9YrchloCLcn//SGfTElr9mSc5jbjb7QXEU+zJMhtxyEJ1Po3CUGnj7ckiIXw7wcawZtrEOAQ9pH3ExYCJcEMiyNjRQZCxT3tPK+S4B95EWh5Fsrz9CkwpjNRPPH7LigCeQTM3Wc7r97utAslBUUvYceDSLA7rMgkitJE38b7rZBeYzsGQ8YYUBjTCtehqQXxCRjizbHWaaZkBU+N3zkKB6n/iCNGIO690NK7A/qb6msTijiz1PeuM8ThOsi9qXnbX5v0PoTpcFSojV7NHAQ71f0XXuS43FhZctT+Dcx44dT8Fb5vJu2cJGrk+qF8ZgJYNpRS7gPg0EG2EqjK7JMf9ULdjSu0r+KlqIAyLvtzT4eOnQipoKlb/WG5D/0ohKv7OMQ352ggfkBFIQsRXyyTCT98Ft9juqPuahi3CAQmP4H9dyE+7+Kz437PEtsxLmfm6naNmWi7Ee1DqWPwS8rEajsm4sNM4wW9gdBboJQtc0uZw0DfLj1I9r3Mc8Ol0jYtz0yNQDSzVLrGCaJlC311trU70tZ+ZkAVV6Mn8lOhSbj1cK0lvSr6ZK4dgqGl3I1eTZJJhbLNdg7UOVaiRx9543+C/p/As7w== brjackma@redhat.com"
2025-09-30 02:57:57.496125 | controller | }
2025-09-30 02:57:57.709177 | controller | changed:
2025-09-30 02:57:57.709279 | controller | {
2025-09-30 02:57:57.709306 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-09-30 02:57:57.709326 | controller | }
2025-09-30 02:57:57.929978 | controller | changed:
2025-09-30 02:57:57.930054 | controller | {
2025-09-30 02:57:57.930081 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-09-30 02:57:57.930101 | controller | }
2025-09-30 02:57:58.134592 | controller | changed:
2025-09-30 02:57:58.134684 | controller | {
2025-09-30 02:57:58.134712 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-09-30 02:57:58.134732 | controller | }
2025-09-30 02:57:58.151004 | 
2025-09-30 02:57:58.151102 | TASK [Set timezone to UTC]
2025-09-30 02:57:58.533319 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-09-30 02:57:58.538852 | 
2025-09-30 02:57:58.538941 | TASK [Create nodepool directory]
2025-09-30 02:57:58.749565 | controller | changed
2025-09-30 02:57:58.755352 | 
2025-09-30 02:57:58.755420 | TASK [Create nodepool sub_nodes file]
2025-09-30 02:57:59.253764 | controller | changed
2025-09-30 02:57:59.258850 | 
2025-09-30 02:57:59.258948 | TASK [Create nodepool sub_nodes_private file]
2025-09-30 02:57:59.736061 | controller | changed
2025-09-30 02:57:59.741184 | 
2025-09-30 02:57:59.741253 | LOOP [Populate nodepool sub_nodes file]
2025-09-30 02:57:59.771018 | 
2025-09-30 02:57:59.771176 | LOOP [Populate nodepool sub_nodes_private file]
2025-09-30 02:57:59.801166 | 
2025-09-30 02:57:59.801320 | TASK [Create nodepool primary file]
2025-09-30 02:57:59.824834 | controller | skipping: Conditional result was False
2025-09-30 02:57:59.830249 | 
2025-09-30 02:57:59.830327 | TASK [Create nodepool node_private for this node]
2025-09-30 02:58:00.335451 | controller | changed
2025-09-30 02:58:00.342676 | 
2025-09-30 02:58:00.342761 | LOOP [Copy ssh keys to nodepool directory]
2025-09-30 02:58:00.682979 | controller | ok: Item: id_rsa Runtime: 0:00:00.005335
2025-09-30 02:58:00.683178 | 
2025-09-30 02:58:00.850369 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.004500
2025-09-30 02:58:00.865534 | 
2025-09-30 02:58:00.865667 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-09-30 02:58:01.461645 | controller | changed
2025-09-30 02:58:01.467901 | 
2025-09-30 02:58:01.467991 | TASK [Validate sudoers config after edits]
2025-09-30 02:58:01.704648 | controller | /etc/sudoers: parsed OK
2025-09-30 02:58:01.704741 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-09-30 02:58:01.704752 | controller | /etc/sudoers.d/zuul: parsed OK
2025-09-30 02:58:01.704759 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-09-30 02:58:01.996497 | controller | ok: Runtime: 0:00:00.008318
2025-09-30 02:58:02.002533 | 
2025-09-30 02:58:02.002600 | TASK [Show the environment passed in to job shell scripts]
2025-09-30 02:58:02.217623 | controller | SHELL=/bin/bash
2025-09-30 02:58:02.217679 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-09-30 02:58:02.217689 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-09-30 02:58:02.217696 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/46/3346/eb5b53fb17db92a72d33d052a56c8edd0d10ea78^openstack-k8s-operators/ci-framework:main:refs/changes/33/3333/b461fc761ffaeed72eedc04b84a1fb92d251fe5d
2025-09-30 02:58:02.217747 | controller | PWD=/home/zuul
2025-09-30 02:58:02.217756 | controller | ZUUL_PIPELINE=github-check
2025-09-30 02:58:02.217761 | controller | LOGNAME=zuul
2025-09-30 02:58:02.217767 | controller | XDG_SESSION_TYPE=tty
2025-09-30 02:58:02.217772 | controller | _=/usr/bin/env
2025-09-30 02:58:02.217778 | controller | MOTD_SHOWN=pam
2025-09-30 02:58:02.217783 | controller | HOME=/home/zuul
2025-09-30 02:58:02.217788 | controller | LANG=en_US.UTF-8
2025-09-30 02:58:02.217794 | controller | SSH_CONNECTION=192.168.26.12 54896 192.168.26.9 22
2025-09-30 02:58:02.217800 | controller | TOX_TESTENV_PASSENV=ZUUL_UUID ZUUL_PROJECT ZUUL_SHORT_PROJECT_NAME ZUUL_PIPELINE ZUUL_VOTING WORKSPACE BUILD_TIMEOUT ZUUL_BRANCH ZUUL_CHANGES ZUUL_CHANGE_IDS ZUUL_CHANGE ZUUL_PATCHSET
2025-09-30 02:58:02.217805 | controller | ZUUL_CHANGE_IDS=3346,eb5b53fb17db92a72d33d052a56c8edd0d10ea78 3333,b461fc761ffaeed72eedc04b84a1fb92d251fe5d
2025-09-30 02:58:02.217811 | controller | WORKSPACE=/home/zuul/workspace
2025-09-30 02:58:02.217816 | controller | XDG_SESSION_CLASS=user
2025-09-30 02:58:02.217822 | controller | SELINUX_ROLE_REQUESTED=
2025-09-30 02:58:02.217827 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-09-30 02:58:02.217832 | controller | USER=zuul
2025-09-30 02:58:02.217838 | controller | ZUUL_VOTING=True
2025-09-30 02:58:02.217843 | controller | BUILD_TIMEOUT=1800000
2025-09-30 02:58:02.217848 | controller | SELINUX_USE_CURRENT_RANGE=
2025-09-30 02:58:02.217853 | controller | SHLVL=1
2025-09-30 02:58:02.217859 | controller | ZUUL_PATCHSET=b461fc761ffaeed72eedc04b84a1fb92d251fe5d
2025-09-30 02:58:02.217864 | controller | XDG_SESSION_ID=1
2025-09-30 02:58:02.217869 | controller | ZUUL_BRANCH=main
2025-09-30 02:58:02.217875 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-09-30 02:58:02.217880 | controller | SSH_CLIENT=192.168.26.12 54896 22
2025-09-30 02:58:02.217885 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-09-30 02:58:02.217891 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-09-30 02:58:02.217896 | controller | which_declare=declare -f
2025-09-30 02:58:02.217902 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-09-30 02:58:02.217908 | controller | SELINUX_LEVEL_REQUESTED=
2025-09-30 02:58:02.217913 | controller | ZUUL_CHANGE=3333
2025-09-30 02:58:02.217919 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-09-30 02:58:02.217924 | controller | ZUUL_UUID=d36d0ace6ffa4cda9009f319c6427288
2025-09-30 02:58:02.217930 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-09-30 02:58:02.217937 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-09-30 02:58:02.217942 | controller | }
2025-09-30 02:58:02.530572 | controller | ok: Runtime: 0:00:00.006534
2025-09-30 02:58:02.537039 | 
2025-09-30 02:58:02.537108 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-09-30 02:58:02.560658 | controller | skipping: Conditional result was False
2025-09-30 02:58:02.566828 | 
2025-09-30 02:58:02.566935 | TASK [Symlink /home/zuul-worker/workspace]
2025-09-30 02:58:03.095578 | controller | skipping: Conditional result was False
2025-09-30 02:58:03.101892 | 
2025-09-30 02:58:03.101986 | TASK [Ensure legacy workspace directory]
2025-09-30 02:58:03.304165 | controller | changed
2025-09-30 02:58:03.324527 | 
2025-09-30 02:58:03.324733 | PLAY RECAP
2025-09-30 02:58:03.324791 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-09-30 02:58:03.324818 | 
2025-09-30 02:58:03.415967 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-09-30 02:58:03.417022 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/read_global_vars.yml@main]
2025-09-30 02:58:03.949978 | 
2025-09-30 02:58:03.950087 | PLAY [Load global variables]
2025-09-30 02:58:03.972803 | 
2025-09-30 02:58:03.972902 | TASK [Read group_vars all file]
2025-09-30 02:58:03.991373 | controller | ok
2025-09-30 02:58:04.006855 | 
2025-09-30 02:58:04.006969 | TASK [cifmw_helpers : Check if file is available]
2025-09-30 02:58:04.320451 | controller | ok
2025-09-30 02:58:04.326791 | 
2025-09-30 02:58:04.326932 | TASK [cifmw_helpers : Read vars]
2025-09-30 02:58:04.356667 | 
2025-09-30 02:58:04.356804 | LOOP [cifmw_helpers : Set vars as fact]
2025-09-30 02:58:04.436043 | 
2025-09-30 02:58:04.436161 | PLAY RECAP
2025-09-30 02:58:04.436208 | controller | ok: 1 changed: 0 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-09-30 02:58:04.436233 | 
2025-09-30 02:58:04.519814 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/read_global_vars.yml@main]
2025-09-30 02:58:04.520580 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-09-30 02:58:05.112109 | 
2025-09-30 02:58:05.112206 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-09-30 02:58:05.135590 | 
2025-09-30 02:58:05.135685 | TASK [Create zuul-output directory]
2025-09-30 02:58:05.481390 | controller | changed
2025-09-30 02:58:05.486695 | 
2025-09-30 02:58:05.486773 | TASK [Slurp Zuul inventory test]
2025-09-30 02:58:05.794680 | controller -> localhost | ok
2025-09-30 02:58:05.801306 | 
2025-09-30 02:58:05.801392 | TASK [Save zuul inventory]
2025-09-30 02:58:06.612142 | controller | changed
2025-09-30 02:58:06.617129 | 
2025-09-30 02:58:06.617196 | TASK [Save zuul vars without the change_message]
2025-09-30 02:58:07.231984 | controller | changed
2025-09-30 02:58:07.249789 | 
2025-09-30 02:58:07.249866 | PLAY RECAP
2025-09-30 02:58:07.249945 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-09-30 02:58:07.249977 | 
2025-09-30 02:58:07.335705 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-09-30 02:58:07.336506 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-09-30 02:58:07.915892 | 
2025-09-30 02:58:07.916029 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-09-30 02:58:07.948437 | 
2025-09-30 02:58:07.948555 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-09-30 02:58:07.978589 | controller | ok
2025-09-30 02:58:07.998612 | 
2025-09-30 02:58:07.998708 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-09-30 02:58:08.021948 | controller | skipping: Conditional result was False
2025-09-30 02:58:08.027770 | 
2025-09-30 02:58:08.027847 | TASK [mirror-info-fork : Create /etc/ci]
2025-09-30 02:58:08.420703 | controller | ok
2025-09-30 02:58:08.428234 | 
2025-09-30 02:58:08.428325 | TASK [mirror-info-fork : Install ci_mirror script]
2025-09-30 02:58:09.114000 | controller | ok
2025-09-30 02:58:09.124383 | 
2025-09-30 02:58:09.124454 | TASK [Prepare workspace]
2025-09-30 02:58:09.142782 | controller | ok
2025-09-30 02:58:09.159773 | 
2025-09-30 02:58:09.159845 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-09-30 02:58:09.486729 | controller | ok
2025-09-30 02:58:09.494252 | 
2025-09-30 02:58:09.494336 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-09-30 02:58:11.529421 | controller | Output suppressed because no_log was given
2025-09-30 02:58:11.540000 | 
2025-09-30 02:58:11.540570 | LOOP [Create zuul-output directory]
2025-09-30 02:58:11.739005 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-09-30 02:58:11.908044 | controller | ok: "/home/zuul/zuul-output/logs"
2025-09-30 02:58:11.924688 | 
2025-09-30 02:58:11.924804 | TASK [Install required packages]
2025-09-30 02:59:13.057217 | controller | changed
2025-09-30 02:59:13.063972 | 
2025-09-30 02:59:13.064505 | TASK [Install venv]
2025-09-30 03:00:15.423723 | controller | changed
2025-09-30 03:00:15.450073 | 
2025-09-30 03:00:15.450202 | PLAY RECAP
2025-09-30 03:00:15.450260 | controller | ok: 7 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-09-30 03:00:15.450286 | 
2025-09-30 03:00:15.547462 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-09-30 03:00:15.548413 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-09-30 03:00:16.145655 | 
2025-09-30 03:00:16.145789 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-09-30 03:00:16.166670 | 
2025-09-30 03:00:16.166779 | TASK [Gather required facts]
2025-09-30 03:00:16.674857 | controller | ok
2025-09-30 03:00:16.680409 | 
2025-09-30 03:00:16.680512 | TASK [Load environment var if instructed to]
2025-09-30 03:00:16.704492 | controller | skipping: Conditional result was False
2025-09-30 03:00:16.710966 | 
2025-09-30 03:00:16.711060 | TASK [Run molecule]
2025-09-30 03:00:17.669000 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-09-30 03:00:17.739744 | controller | INFO     Performing prerun with role_name_check=0...
2025-09-30 03:00:35.906826 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/9d1eb3/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 03:00:35.907289 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/9d1eb3/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 03:00:35.907764 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/9d1eb3/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 03:00:35.908226 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/9d1eb3/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 03:00:35.908702 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+ad20938b was found installed in /home/zuul/.cache/ansible-compat/9d1eb3/collections/ansible_collections, only the first one will be used, 1.0.0+ad20938b (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 03:00:35.909165 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/9d1eb3/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 03:00:35.909612 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/9d1eb3/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 03:00:35.910070 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/9d1eb3/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 03:00:35.910529 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/9d1eb3/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 03:00:35.910966 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/9d1eb3/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 03:00:35.911451 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/9d1eb3/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 03:00:35.911898 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/9d1eb3/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 03:00:35.912378 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/9d1eb3/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 03:00:35.912828 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/9d1eb3/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 03:00:35.913296 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/9d1eb3/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 03:00:35.923027 | controller | INFO     Running default > prepare
2025-09-30 03:00:36.597731 | controller |
2025-09-30 03:00:36.597792 | controller | PLAY [Prepare] *****************************************************************
2025-09-30 03:00:36.597899 | controller |
2025-09-30 03:00:36.598016 | controller | TASK [Gathering Facts] *********************************************************
2025-09-30 03:00:36.598128 | controller | Tuesday 30 September 2025  03:00:36 +0000 (0:00:00.012)       0:00:00.012 *****
2025-09-30 03:00:37.447946 | controller | ok: [instance]
2025-09-30 03:00:37.448051 | controller |
2025-09-30 03:00:37.448186 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-09-30 03:00:37.448358 | controller | Tuesday 30 September 2025  03:00:37 +0000 (0:00:00.850)       0:00:00.863 *****
2025-09-30 03:00:37.466125 | controller | skipping: [instance]
2025-09-30 03:00:37.466175 | controller |
2025-09-30 03:00:37.466289 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-09-30 03:00:37.466411 | controller | Tuesday 30 September 2025  03:00:37 +0000 (0:00:00.018)       0:00:00.881 *****
2025-09-30 03:00:37.509468 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-09-30 03:00:37.509565 | controller |
2025-09-30 03:00:37.509694 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-09-30 03:00:37.509818 | controller | Tuesday 30 September 2025  03:00:37 +0000 (0:00:00.043)       0:00:00.924 *****
2025-09-30 03:00:37.817111 | controller | ok: [instance]
2025-09-30 03:00:37.817192 | controller |
2025-09-30 03:00:37.817348 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-09-30 03:00:37.817463 | controller | Tuesday 30 September 2025  03:00:37 +0000 (0:00:00.307)       0:00:01.232 *****
2025-09-30 03:00:38.148356 | controller | ok: [instance]
2025-09-30 03:00:38.148438 | controller |
2025-09-30 03:00:38.148545 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-09-30 03:00:38.148651 | controller | Tuesday 30 September 2025  03:00:38 +0000 (0:00:00.331)       0:00:01.563 *****
2025-09-30 03:00:38.864349 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-09-30 03:00:38.864400 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-09-30 03:00:38.864475 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-09-30 03:00:38.864574 | controller |
2025-09-30 03:00:38.864676 | controller | TASK [Deploy repo-setup] *******************************************************
2025-09-30 03:00:38.864776 | controller | Tuesday 30 September 2025  03:00:38 +0000 (0:00:00.715)       0:00:02.279 *****
2025-09-30 03:00:38.931838 | controller |
2025-09-30 03:00:38.931899 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-09-30 03:00:38.932000 | controller | Tuesday 30 September 2025  03:00:38 +0000 (0:00:00.067)       0:00:02.346 *****
2025-09-30 03:00:39.491566 | controller | changed: [instance] => (item=tmp)
2025-09-30 03:00:39.491663 | controller | changed: [instance] => (item=artifacts/repositories)
2025-09-30 03:00:39.491780 | controller | changed: [instance] => (item=venv/repo_setup)
2025-09-30 03:00:39.491876 | controller |
2025-09-30 03:00:39.491994 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-09-30 03:00:39.492107 | controller | Tuesday 30 September 2025  03:00:39 +0000 (0:00:00.560)       0:00:02.906 *****
2025-09-30 03:00:40.295429 | controller | ok: [instance]
2025-09-30 03:00:40.295485 | controller |
2025-09-30 03:00:40.295743 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-09-30 03:00:41.480660 | controller | Tuesday 30 September 2025  03:00:40 +0000 (0:00:00.803)       0:00:03.710 *****
2025-09-30 03:00:41.480694 | controller | changed: [instance]
2025-09-30 03:00:49.510302 | controller |
2025-09-30 03:00:49.510358 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-09-30 03:00:49.510369 | controller | Tuesday 30 September 2025  03:00:41 +0000 (0:00:01.184)       0:00:04.895 *****
2025-09-30 03:00:49.510380 | controller | changed: [instance]
2025-09-30 03:00:50.244412 | controller |
2025-09-30 03:00:50.244460 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-09-30 03:00:50.244469 | controller | Tuesday 30 September 2025  03:00:49 +0000 (0:00:08.029)       0:00:12.925 *****
2025-09-30 03:00:50.244481 | controller | changed: [instance]
2025-09-30 03:00:50.266037 | controller |
2025-09-30 03:00:50.266076 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-09-30 03:00:50.266086 | controller | Tuesday 30 September 2025  03:00:50 +0000 (0:00:00.734)       0:00:13.659 *****
2025-09-30 03:00:50.266099 | controller | skipping: [instance]
2025-09-30 03:00:51.114234 | controller |
2025-09-30 03:00:51.114267 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-09-30 03:00:51.114275 | controller | Tuesday 30 September 2025  03:00:50 +0000 (0:00:00.021)       0:00:13.681 *****
2025-09-30 03:00:51.114285 | controller | changed: [instance]
2025-09-30 03:00:51.151398 | controller |
2025-09-30 03:00:51.151431 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-09-30 03:00:51.151439 | controller | Tuesday 30 September 2025  03:00:51 +0000 (0:00:00.848)       0:00:14.529 *****
2025-09-30 03:00:51.151449 | controller | skipping: [instance]
2025-09-30 03:00:51.151532 | controller |
2025-09-30 03:00:51.151561 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-09-30 03:00:51.151573 | controller | Tuesday 30 September 2025  03:00:51 +0000 (0:00:00.036)       0:00:14.566 *****
2025-09-30 03:00:51.189267 | controller | skipping: [instance]
2025-09-30 03:00:51.227396 | controller |
2025-09-30 03:00:51.227430 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-09-30 03:00:51.227438 | controller | Tuesday 30 September 2025  03:00:51 +0000 (0:00:00.037)       0:00:14.603 *****
2025-09-30 03:00:51.227447 | controller | skipping: [instance]
2025-09-30 03:00:51.227490 | controller |
2025-09-30 03:00:51.227500 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-09-30 03:00:51.227620 | controller | Tuesday 30 September 2025  03:00:51 +0000 (0:00:00.038)       0:00:14.642 *****
2025-09-30 03:00:51.814230 | controller | changed: [instance]
2025-09-30 03:00:52.258757 | controller |
2025-09-30 03:00:52.258791 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-09-30 03:00:52.258799 | controller | Tuesday 30 September 2025  03:00:51 +0000 (0:00:00.586)       0:00:15.229 *****
2025-09-30 03:00:52.258809 | controller | changed: [instance]
2025-09-30 03:00:52.288666 | controller |
2025-09-30 03:00:52.288698 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-09-30 03:00:52.288706 | controller | Tuesday 30 September 2025  03:00:52 +0000 (0:00:00.444)       0:00:15.673 *****
2025-09-30 03:00:52.288716 | controller | skipping: [instance]
2025-09-30 03:00:52.317707 | controller |
2025-09-30 03:00:52.317742 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-09-30 03:00:52.317750 | controller | Tuesday 30 September 2025  03:00:52 +0000 (0:00:00.029)       0:00:15.703 *****
2025-09-30 03:00:52.317760 | controller | skipping: [instance]
2025-09-30 03:00:52.347040 | controller |
2025-09-30 03:00:52.347067 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-09-30 03:00:52.347076 | controller | Tuesday 30 September 2025  03:00:52 +0000 (0:00:00.029)       0:00:15.732 *****
2025-09-30 03:00:52.347094 | controller | skipping: [instance]
2025-09-30 03:00:52.385742 | controller |
2025-09-30 03:00:52.385763 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-09-30 03:00:52.385771 | controller | Tuesday 30 September 2025  03:00:52 +0000 (0:00:00.029)       0:00:15.762 *****
2025-09-30 03:00:52.385780 | controller | ok: [instance]
2025-09-30 03:00:52.385924 | controller |
2025-09-30 03:00:52.386087 | controller | TASK [repo_setup : Create download directory] **********************************
2025-09-30 03:00:52.386226 | controller | Tuesday 30 September 2025  03:00:52 +0000 (0:00:00.039)       0:00:15.801 *****
2025-09-30 03:00:52.413833 | controller | skipping: [instance]
2025-09-30 03:00:52.414046 | controller |
2025-09-30 03:00:52.414211 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-09-30 03:00:52.414387 | controller | Tuesday 30 September 2025  03:00:52 +0000 (0:00:00.027)       0:00:15.829 *****
2025-09-30 03:00:52.440104 | controller | skipping: [instance]
2025-09-30 03:00:52.440284 | controller |
2025-09-30 03:00:52.440461 | controller | TASK [Download the RPM] ********************************************************
2025-09-30 03:00:52.440625 | controller | Tuesday 30 September 2025  03:00:52 +0000 (0:00:00.026)       0:00:15.855 *****
2025-09-30 03:00:52.466294 | controller | skipping: [instance]
2025-09-30 03:00:52.466519 | controller |
2025-09-30 03:00:52.466667 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-09-30 03:00:52.466809 | controller | Tuesday 30 September 2025  03:00:52 +0000 (0:00:00.026)       0:00:15.881 *****
2025-09-30 03:00:52.492324 | controller | skipping: [instance]
2025-09-30 03:00:52.492490 | controller |
2025-09-30 03:00:52.492634 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-09-30 03:00:52.492772 | controller | Tuesday 30 September 2025  03:00:52 +0000 (0:00:00.026)       0:00:15.908 *****
2025-09-30 03:00:52.518204 | controller | skipping: [instance]
2025-09-30 03:00:52.518379 | controller |
2025-09-30 03:00:52.518527 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-09-30 03:00:52.518665 | controller | Tuesday 30 September 2025  03:00:52 +0000 (0:00:00.025)       0:00:15.933 *****
2025-09-30 03:00:52.547247 | controller | skipping: [instance]
2025-09-30 03:00:52.547491 | controller |
2025-09-30 03:00:52.547694 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-09-30 03:00:52.547852 | controller | Tuesday 30 September 2025  03:00:52 +0000 (0:00:00.028)       0:00:15.962 *****
2025-09-30 03:00:52.573731 | controller | skipping: [instance]
2025-09-30 03:00:52.760534 | controller |
2025-09-30 03:00:52.760565 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-09-30 03:00:52.760573 | controller | Tuesday 30 September 2025  03:00:52 +0000 (0:00:00.026)       0:00:15.989 *****
2025-09-30 03:00:52.760583 | controller | ok: [instance]
2025-09-30 03:00:52.976358 | controller |
2025-09-30 03:00:52.976390 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-09-30 03:00:52.976399 | controller | Tuesday 30 September 2025  03:00:52 +0000 (0:00:00.186)       0:00:16.175 *****
2025-09-30 03:00:52.976409 | controller | changed: [instance]
2025-09-30 03:00:53.206743 | controller |
2025-09-30 03:00:53.206778 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-09-30 03:00:53.206786 | controller | Tuesday 30 September 2025  03:00:52 +0000 (0:00:00.215)       0:00:16.391 *****
2025-09-30 03:00:53.206796 | controller | changed: [instance]
2025-09-30 03:00:53.228084 | controller |
2025-09-30 03:00:53.228108 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-09-30 03:00:53.228115 | controller | Tuesday 30 September 2025  03:00:53 +0000 (0:00:00.230)       0:00:16.621 *****
2025-09-30 03:00:53.228125 | controller | skipping: [instance]
2025-09-30 03:00:53.250420 | controller |
2025-09-30 03:00:53.250462 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-09-30 03:00:53.250471 | controller | Tuesday 30 September 2025  03:00:53 +0000 (0:00:00.021)       0:00:16.643 *****
2025-09-30 03:00:53.250481 | controller | skipping: [instance]
2025-09-30 03:00:53.272909 | controller |
2025-09-30 03:00:53.272943 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-09-30 03:00:53.272953 | controller | Tuesday 30 September 2025  03:00:53 +0000 (0:00:00.022)       0:00:16.665 *****
2025-09-30 03:00:53.272965 | controller | skipping: [instance]
2025-09-30 03:00:53.295993 | controller |
2025-09-30 03:00:53.296023 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-09-30 03:00:53.296032 | controller | Tuesday 30 September 2025  03:00:53 +0000 (0:00:00.022)       0:00:16.688 *****
2025-09-30 03:00:53.296043 | controller | skipping: [instance]
2025-09-30 03:00:53.318406 | controller |
2025-09-30 03:00:53.318438 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-09-30 03:00:53.318455 | controller | Tuesday 30 September 2025  03:00:53 +0000 (0:00:00.022)       0:00:16.711 *****
2025-09-30 03:00:53.318468 | controller | skipping: [instance]
2025-09-30 03:00:53.318499 | controller |
2025-09-30 03:00:53.318764 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-09-30 03:00:53.341297 | controller | Tuesday 30 September 2025  03:00:53 +0000 (0:00:00.022)       0:00:16.733 *****
2025-09-30 03:00:53.341346 | controller | skipping: [instance]
2025-09-30 03:00:53.358375 | controller |
2025-09-30 03:00:53.358404 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-09-30 03:00:53.358412 | controller | Tuesday 30 September 2025  03:00:53 +0000 (0:00:00.022)       0:00:16.756 *****
2025-09-30 03:00:53.358422 | controller | skipping: [instance]
2025-09-30 03:00:53.388287 | controller |
2025-09-30 03:00:53.388327 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-09-30 03:00:53.388338 | controller | Tuesday 30 September 2025  03:00:53 +0000 (0:00:00.017)       0:00:16.773 *****
2025-09-30 03:00:53.388347 | controller | skipping: [instance]
2025-09-30 03:00:53.405184 | controller |
2025-09-30 03:00:53.405205 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-09-30 03:00:53.405212 | controller | Tuesday 30 September 2025  03:00:53 +0000 (0:00:00.029)       0:00:16.803 *****
2025-09-30 03:00:53.405221 | controller | skipping: [instance]
2025-09-30 03:00:53.426121 | controller |
2025-09-30 03:00:53.426144 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-09-30 03:00:53.426152 | controller | Tuesday 30 September 2025  03:00:53 +0000 (0:00:00.016)       0:00:16.820 *****
2025-09-30 03:00:53.426163 | controller | skipping: [instance]
2025-09-30 03:00:53.458093 | controller |
2025-09-30 03:00:53.458120 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-09-30 03:00:53.458128 | controller | Tuesday 30 September 2025  03:00:53 +0000 (0:00:00.020)       0:00:16.841 *****
2025-09-30 03:00:53.458138 | controller | skipping: [instance]
2025-09-30 03:00:53.489040 | controller |
2025-09-30 03:00:53.489075 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-09-30 03:00:53.489083 | controller | Tuesday 30 September 2025  03:00:53 +0000 (0:00:00.031)       0:00:16.873 *****
2025-09-30 03:00:53.489093 | controller | skipping: [instance]
2025-09-30 03:00:53.518835 | controller |
2025-09-30 03:00:53.518865 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-09-30 03:00:53.518872 | controller | Tuesday 30 September 2025  03:00:53 +0000 (0:00:00.030)       0:00:16.904 *****
2025-09-30 03:00:53.518882 | controller | skipping: [instance]
2025-09-30 03:00:53.549421 | controller |
2025-09-30 03:00:53.549455 | controller | TASK [test_deps : Install additional packages] *********************************
2025-09-30 03:00:53.549463 | controller | Tuesday 30 September 2025  03:00:53 +0000 (0:00:00.029)       0:00:16.934 *****
2025-09-30 03:00:53.549477 | controller | skipping: [instance]
2025-09-30 03:00:53.549503 | controller |
2025-09-30 03:00:53.549510 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-09-30 03:00:53.549518 | controller | Tuesday 30 September 2025  03:00:53 +0000 (0:00:00.030)       0:00:16.964 *****
2025-09-30 03:01:33.374206 | controller | ok: [instance]
2025-09-30 03:01:34.603155 | controller |
2025-09-30 03:01:34.603188 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-09-30 03:01:34.603196 | controller | Tuesday 30 September 2025  03:01:33 +0000 (0:00:39.824)       0:00:56.789 *****
2025-09-30 03:01:34.603206 | controller | ok: [instance]
2025-09-30 03:01:34.648901 | controller |
2025-09-30 03:01:34.648932 | controller | TASK [test_deps : Install extra packages] **************************************
2025-09-30 03:01:34.648940 | controller | Tuesday 30 September 2025  03:01:34 +0000 (0:00:01.228)       0:00:58.018 *****
2025-09-30 03:01:34.648950 | controller | skipping: [instance]
2025-09-30 03:01:34.709729 | controller |
2025-09-30 03:01:34.709761 | controller | PLAY RECAP *********************************************************************
2025-09-30 03:01:34.709770 | controller | instance                   : ok=19   changed=9    unreachable=0    failed=0    skipped=30   rescued=0    ignored=0
2025-09-30 03:01:34.709776 | controller |
2025-09-30 03:01:34.709782 | controller | Tuesday 30 September 2025  03:01:34 +0000 (0:00:00.043)       0:00:58.061 *****
2025-09-30 03:01:34.709787 | controller | ===============================================================================
2025-09-30 03:01:34.709793 | controller | test_deps : Install selinux python libs -------------------------------- 39.82s
2025-09-30 03:01:34.709805 | controller | repo_setup : Initialize python venv and install requirements ------------ 8.03s
2025-09-30 03:01:34.709810 | controller | test_deps : Install python yaml libs ------------------------------------ 1.23s
2025-09-30 03:01:34.709816 | controller | repo_setup : Get repo-setup repository ---------------------------------- 1.18s
2025-09-30 03:01:34.709826 | controller | Gathering Facts --------------------------------------------------------- 0.85s
2025-09-30 03:01:34.709831 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.85s
2025-09-30 03:01:34.709837 | controller | repo_setup : Make sure git-core package is installed -------------------- 0.80s
2025-09-30 03:01:34.709842 | controller | repo_setup : Install repo-setup package --------------------------------- 0.73s
2025-09-30 03:01:34.709847 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.72s
2025-09-30 03:01:34.709852 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.59s
2025-09-30 03:01:34.709857 | controller | repo_setup : Ensure directories are present ----------------------------- 0.56s
2025-09-30 03:01:34.709863 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.44s
2025-09-30 03:01:34.709868 | controller | test_deps : Disable ubi host subscription-manager integration ----------- 0.33s
2025-09-30 03:01:34.709873 | controller | test_deps : Detect mirrors file ----------------------------------------- 0.31s
2025-09-30 03:01:34.709878 | controller | repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist) --- 0.23s
2025-09-30 03:01:34.709884 | controller | repo_setup : Use RDO proxy mirrors -------------------------------------- 0.22s
2025-09-30 03:01:34.709889 | controller | repo_setup : Check for /etc/ci/mirror_info.sh --------------------------- 0.19s
2025-09-30 03:01:34.709894 | controller | Deploy repo-setup ------------------------------------------------------- 0.07s
2025-09-30 03:01:34.709899 | controller | test_deps : Install extra packages -------------------------------------- 0.04s
2025-09-30 03:01:34.709904 | controller | test_deps : Gather variables for each operating system ------------------ 0.04s
2025-09-30 03:01:34.709915 | controller | INFO     Running default > converge
2025-09-30 03:01:35.166357 | controller |
2025-09-30 03:01:35.166591 | controller | PLAY [Converge] ****************************************************************
2025-09-30 03:01:35.166737 | controller |
2025-09-30 03:01:35.166883 | controller | TASK [Gathering Facts] *********************************************************
2025-09-30 03:01:35.167048 | controller | Tuesday 30 September 2025  03:01:35 +0000 (0:00:00.017)       0:00:00.017 *****
2025-09-30 03:01:35.993877 | controller | ok: [instance]
2025-09-30 03:01:36.011902 | controller |
2025-09-30 03:01:36.011931 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-09-30 03:01:36.011939 | controller | Tuesday 30 September 2025  03:01:35 +0000 (0:00:00.824)       0:00:00.842 *****
2025-09-30 03:01:36.011949 | controller | skipping: [instance]
2025-09-30 03:01:36.053958 | controller |
2025-09-30 03:01:36.054012 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-09-30 03:01:36.054021 | controller | Tuesday 30 September 2025  03:01:36 +0000 (0:00:00.021)       0:00:00.864 *****
2025-09-30 03:01:36.054031 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-09-30 03:01:36.343600 | controller |
2025-09-30 03:01:36.343632 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-09-30 03:01:36.343640 | controller | Tuesday 30 September 2025  03:01:36 +0000 (0:00:00.041)       0:00:00.905 *****
2025-09-30 03:01:36.343650 | controller | ok: [instance]
2025-09-30 03:01:36.658399 | controller |
2025-09-30 03:01:36.658432 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-09-30 03:01:36.658440 | controller | Tuesday 30 September 2025  03:01:36 +0000 (0:00:00.289)       0:00:01.195 *****
2025-09-30 03:01:36.658450 | controller | ok: [instance]
2025-09-30 03:01:36.658474 | controller |
2025-09-30 03:01:36.658653 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-09-30 03:01:37.362417 | controller | Tuesday 30 September 2025  03:01:36 +0000 (0:00:00.315)       0:00:01.510 *****
2025-09-30 03:01:37.362460 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-09-30 03:01:37.362822 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-09-30 03:01:37.362843 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-09-30 03:01:37.422415 | controller |
2025-09-30 03:01:37.422445 | controller | TASK [Deploy repo-setup] *******************************************************
2025-09-30 03:01:37.422453 | controller | Tuesday 30 September 2025  03:01:37 +0000 (0:00:00.703)       0:00:02.214 *****
2025-09-30 03:01:37.422462 | controller |
2025-09-30 03:01:37.422534 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-09-30 03:01:37.422561 | controller | Tuesday 30 September 2025  03:01:37 +0000 (0:00:00.060)       0:00:02.274 *****
2025-09-30 03:01:37.967727 | controller | ok: [instance] => (item=tmp)
2025-09-30 03:01:39.286442 | controller | ok: [instance] => (item=artifacts/repositories)
2025-09-30 03:01:39.286472 | controller | ok: [instance] => (item=venv/repo_setup)
2025-09-30 03:01:39.286480 | controller |
2025-09-30 03:01:39.286487 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-09-30 03:01:39.286493 | controller | Tuesday 30 September 2025  03:01:37 +0000 (0:00:00.544)       0:00:02.819 *****
2025-09-30 03:01:39.286502 | controller | ok: [instance]
2025-09-30 03:01:39.877633 | controller |
2025-09-30 03:01:39.877665 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-09-30 03:01:39.877673 | controller | Tuesday 30 September 2025  03:01:39 +0000 (0:00:01.318)       0:00:04.138 *****
2025-09-30 03:01:39.877683 | controller | ok: [instance]
2025-09-30 03:01:41.229137 | controller |
2025-09-30 03:01:41.229170 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-09-30 03:01:41.229179 | controller | Tuesday 30 September 2025  03:01:39 +0000 (0:00:00.591)       0:00:04.729 *****
2025-09-30 03:01:41.229189 | controller | ok: [instance]
2025-09-30 03:01:41.531127 | controller |
2025-09-30 03:01:41.531161 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-09-30 03:01:41.531169 | controller | Tuesday 30 September 2025  03:01:41 +0000 (0:00:01.351)       0:00:06.081 *****
2025-09-30 03:01:41.531179 | controller | ok: [instance]
2025-09-30 03:01:41.554177 | controller |
2025-09-30 03:01:41.554209 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-09-30 03:01:41.554218 | controller | Tuesday 30 September 2025  03:01:41 +0000 (0:00:00.301)       0:00:06.382 *****
2025-09-30 03:01:41.554230 | controller | skipping: [instance]
2025-09-30 03:01:42.455946 | controller |
2025-09-30 03:01:42.455979 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-09-30 03:01:42.456001 | controller | Tuesday 30 September 2025  03:01:41 +0000 (0:00:00.023)       0:00:06.406 *****
2025-09-30 03:01:42.456012 | controller | changed: [instance]
2025-09-30 03:01:42.493863 | controller |
2025-09-30 03:01:42.493896 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-09-30 03:01:42.493905 | controller | Tuesday 30 September 2025  03:01:42 +0000 (0:00:00.901)       0:00:07.307 *****
2025-09-30 03:01:42.493917 | controller | skipping: [instance]
2025-09-30 03:01:42.532237 | controller |
2025-09-30 03:01:42.532266 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-09-30 03:01:42.532273 | controller | Tuesday 30 September 2025  03:01:42 +0000 (0:00:00.037)       0:00:07.345 *****
2025-09-30 03:01:42.532283 | controller | skipping: [instance]
2025-09-30 03:01:42.570421 | controller |
2025-09-30 03:01:42.570457 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-09-30 03:01:42.570465 | controller | Tuesday 30 September 2025  03:01:42 +0000 (0:00:00.038)       0:00:07.384 *****
2025-09-30 03:01:42.570475 | controller | skipping: [instance]
2025-09-30 03:01:42.570501 | controller |
2025-09-30 03:01:42.570716 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-09-30 03:01:43.132747 | controller | Tuesday 30 September 2025  03:01:42 +0000 (0:00:00.038)       0:00:07.422 *****
2025-09-30 03:01:43.132784 | controller | changed: [instance]
2025-09-30 03:01:43.492404 | controller |
2025-09-30 03:01:43.492437 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-09-30 03:01:43.492454 | controller | Tuesday 30 September 2025  03:01:43 +0000 (0:00:00.561)       0:00:07.984 *****
2025-09-30 03:01:43.492465 | controller | ok: [instance]
2025-09-30 03:01:43.492488 | controller |
2025-09-30 03:01:43.492496 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-09-30 03:01:43.492517 | controller | Tuesday 30 September 2025  03:01:43 +0000 (0:00:00.359)       0:00:08.344 *****
2025-09-30 03:01:43.522337 | controller | skipping: [instance]
2025-09-30 03:01:43.551374 | controller |
2025-09-30 03:01:43.551406 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-09-30 03:01:43.551414 | controller | Tuesday 30 September 2025  03:01:43 +0000 (0:00:00.029)       0:00:08.374 *****
2025-09-30 03:01:43.551424 | controller | skipping: [instance]
2025-09-30 03:01:43.580463 | controller |
2025-09-30 03:01:43.580493 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-09-30 03:01:43.580500 | controller | Tuesday 30 September 2025  03:01:43 +0000 (0:00:00.029)       0:00:08.403 *****
2025-09-30 03:01:43.580510 | controller | skipping: [instance]
2025-09-30 03:01:43.619142 | controller |
2025-09-30 03:01:43.619176 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-09-30 03:01:43.619185 | controller | Tuesday 30 September 2025  03:01:43 +0000 (0:00:00.029)       0:00:08.432 *****
2025-09-30 03:01:43.619200 | controller | ok: [instance]
2025-09-30 03:01:43.647277 | controller |
2025-09-30 03:01:43.647324 | controller | TASK [repo_setup : Create download directory] **********************************
2025-09-30 03:01:43.647335 | controller | Tuesday 30 September 2025  03:01:43 +0000 (0:00:00.038)       0:00:08.471 *****
2025-09-30 03:01:43.647346 | controller | skipping: [instance]
2025-09-30 03:01:43.675741 | controller |
2025-09-30 03:01:43.675793 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-09-30 03:01:43.675802 | controller | Tuesday 30 September 2025  03:01:43 +0000 (0:00:00.028)       0:00:08.499 *****
2025-09-30 03:01:43.675814 | controller | skipping: [instance]
2025-09-30 03:01:43.676043 | controller |
2025-09-30 03:01:43.676217 | controller | TASK [Download the RPM] ********************************************************
2025-09-30 03:01:43.676402 | controller | Tuesday 30 September 2025  03:01:43 +0000 (0:00:00.028)       0:00:08.527 *****
2025-09-30 03:01:43.703855 | controller | skipping: [instance]
2025-09-30 03:01:43.704063 | controller |
2025-09-30 03:01:43.704209 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-09-30 03:01:43.704378 | controller | Tuesday 30 September 2025  03:01:43 +0000 (0:00:00.028)       0:00:08.555 *****
2025-09-30 03:01:43.734705 | controller | skipping: [instance]
2025-09-30 03:01:43.734895 | controller |
2025-09-30 03:01:43.735500 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-09-30 03:01:43.735661 | controller | Tuesday 30 September 2025  03:01:43 +0000 (0:00:00.030)       0:00:08.586 *****
2025-09-30 03:01:43.763797 | controller | skipping: [instance]
2025-09-30 03:01:43.764005 | controller |
2025-09-30 03:01:43.764156 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-09-30 03:01:43.764297 | controller | Tuesday 30 September 2025  03:01:43 +0000 (0:00:00.028)       0:00:08.615 *****
2025-09-30 03:01:43.794152 | controller | skipping: [instance]
2025-09-30 03:01:43.794384 | controller |
2025-09-30 03:01:43.794548 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-09-30 03:01:43.794688 | controller | Tuesday 30 September 2025  03:01:43 +0000 (0:00:00.030)       0:00:08.646 *****
2025-09-30 03:01:43.822206 | controller | skipping: [instance]
2025-09-30 03:01:43.822418 | controller |
2025-09-30 03:01:43.822566 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-09-30 03:01:43.822711 | controller | Tuesday 30 September 2025  03:01:43 +0000 (0:00:00.028)       0:00:08.674 *****
2025-09-30 03:01:44.033326 | controller | ok: [instance]
2025-09-30 03:01:44.252254 | controller |
2025-09-30 03:01:44.252286 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-09-30 03:01:44.252294 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.210)       0:00:08.884 *****
2025-09-30 03:01:44.252304 | controller | changed: [instance]
2025-09-30 03:01:44.493642 | controller |
2025-09-30 03:01:44.493695 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-09-30 03:01:44.493722 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.219)       0:00:09.104 *****
2025-09-30 03:01:44.493734 | controller | changed: [instance]
2025-09-30 03:01:44.513654 | controller |
2025-09-30 03:01:44.513686 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-09-30 03:01:44.513695 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.240)       0:00:09.345 *****
2025-09-30 03:01:44.513706 | controller | skipping: [instance]
2025-09-30 03:01:44.534390 | controller |
2025-09-30 03:01:44.534420 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-09-30 03:01:44.534428 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.020)       0:00:09.365 *****
2025-09-30 03:01:44.534438 | controller | skipping: [instance]
2025-09-30 03:01:44.555266 | controller |
2025-09-30 03:01:44.555297 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-09-30 03:01:44.555329 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.020)       0:00:09.386 *****
2025-09-30 03:01:44.555342 | controller | skipping: [instance]
2025-09-30 03:01:44.577110 | controller |
2025-09-30 03:01:44.577163 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-09-30 03:01:44.577173 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.020)       0:00:09.407 *****
2025-09-30 03:01:44.577185 | controller | skipping: [instance]
2025-09-30 03:01:44.577370 | controller |
2025-09-30 03:01:44.577528 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-09-30 03:01:44.577675 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.021)       0:00:09.429 *****
2025-09-30 03:01:44.598399 | controller | skipping: [instance]
2025-09-30 03:01:44.598501 | controller |
2025-09-30 03:01:44.598643 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-09-30 03:01:44.598769 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.021)       0:00:09.450 *****
2025-09-30 03:01:44.623627 | controller | skipping: [instance]
2025-09-30 03:01:44.623740 | controller |
2025-09-30 03:01:44.623880 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-09-30 03:01:44.624021 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.025)       0:00:09.476 *****
2025-09-30 03:01:44.641366 | controller | skipping: [instance]
2025-09-30 03:01:44.641525 | controller |
2025-09-30 03:01:44.641659 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-09-30 03:01:44.641791 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.017)       0:00:09.493 *****
2025-09-30 03:01:44.671137 | controller | skipping: [instance]
2025-09-30 03:01:44.671238 | controller |
2025-09-30 03:01:44.671422 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-09-30 03:01:44.671580 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.029)       0:00:09.523 *****
2025-09-30 03:01:44.688905 | controller | skipping: [instance]
2025-09-30 03:01:44.689034 | controller |
2025-09-30 03:01:44.689161 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-09-30 03:01:44.689279 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.017)       0:00:09.541 *****
2025-09-30 03:01:44.711328 | controller | skipping: [instance]
2025-09-30 03:01:44.711452 | controller |
2025-09-30 03:01:44.711577 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-09-30 03:01:44.711695 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.022)       0:00:09.563 *****
2025-09-30 03:01:44.742666 | controller | skipping: [instance]
2025-09-30 03:01:44.742789 | controller |
2025-09-30 03:01:44.742924 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-09-30 03:01:44.743073 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.031)       0:00:09.595 *****
2025-09-30 03:01:44.774443 | controller | skipping: [instance]
2025-09-30 03:01:44.774579 | controller |
2025-09-30 03:01:44.774712 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-09-30 03:01:44.774844 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.031)       0:00:09.626 *****
2025-09-30 03:01:44.805653 | controller | skipping: [instance]
2025-09-30 03:01:44.805748 | controller |
2025-09-30 03:01:44.805863 | controller | TASK [test_deps : Install additional packages] *********************************
2025-09-30 03:01:44.805983 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.031)       0:00:09.657 *****
2025-09-30 03:01:44.836273 | controller | skipping: [instance]
2025-09-30 03:01:44.836421 | controller |
2025-09-30 03:01:44.836553 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-09-30 03:01:44.836706 | controller | Tuesday 30 September 2025  03:01:44 +0000 (0:00:00.030)       0:00:09.688 *****
2025-09-30 03:02:54.973376 | controller | ok: [instance]
2025-09-30 03:02:56.191420 | controller |
2025-09-30 03:02:56.191456 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-09-30 03:02:56.191465 | controller | Tuesday 30 September 2025  03:02:54 +0000 (0:01:10.134)       0:01:19.823 *****
2025-09-30 03:02:56.191475 | controller | ok: [instance]
2025-09-30 03:02:56.239565 | controller |
2025-09-30 03:02:56.239620 | controller | TASK [test_deps : Install extra packages] **************************************
2025-09-30 03:02:56.239630 | controller | Tuesday 30 September 2025  03:02:56 +0000 (0:00:01.219)       0:01:21.043 *****
2025-09-30 03:02:56.239644 | controller | skipping: [instance]
2025-09-30 03:02:56.239678 | controller |
2025-09-30 03:02:56.239686 | controller | PLAY RECAP *********************************************************************
2025-09-30 03:02:56.239694 | controller | instance                   : ok=19   changed=4    unreachable=0    failed=0    skipped=30   rescued=0    ignored=0
2025-09-30 03:02:56.239701 | controller |
2025-09-30 03:02:56.239710 | controller | Tuesday 30 September 2025  03:02:56 +0000 (0:00:00.048)       0:01:21.091 *****
2025-09-30 03:02:56.241679 | controller | ===============================================================================
2025-09-30 03:02:56.241728 | controller | test_deps : Install selinux python libs -------------------------------- 70.13s
2025-09-30 03:02:56.307636 | controller | repo_setup : Initialize python venv and install requirements ------------ 1.35s
2025-09-30 03:02:56.307672 | controller | repo_setup : Make sure git-core package is installed -------------------- 1.32s
2025-09-30 03:02:56.307680 | controller | test_deps : Install python yaml libs ------------------------------------ 1.22s
2025-09-30 03:02:56.307686 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.90s
2025-09-30 03:02:56.307692 | controller | Gathering Facts --------------------------------------------------------- 0.82s
2025-09-30 03:02:56.307698 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.70s
2025-09-30 03:02:56.307703 | controller | repo_setup : Get repo-setup repository ---------------------------------- 0.59s
2025-09-30 03:02:56.307708 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.56s
2025-09-30 03:02:56.307720 | controller | repo_setup : Ensure directories are present ----------------------------- 0.54s
2025-09-30 03:02:56.307726 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.36s
2025-09-30 03:02:56.307731 | controller | test_deps : Disable ubi host subscription-manager integration ----------- 0.32s
2025-09-30 03:02:56.307737 | controller | repo_setup : Install repo-setup package --------------------------------- 0.30s
2025-09-30 03:02:56.307742 | controller | test_deps : Detect mirrors file ----------------------------------------- 0.29s
2025-09-30 03:02:56.307747 | controller | repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist) --- 0.24s
2025-09-30 03:02:56.307753 | controller | repo_setup : Use RDO proxy mirrors -------------------------------------- 0.22s
2025-09-30 03:02:56.307758 | controller | repo_setup : Check for /etc/ci/mirror_info.sh --------------------------- 0.21s
2025-09-30 03:02:56.307764 | controller | Deploy repo-setup ------------------------------------------------------- 0.06s
2025-09-30 03:02:56.307769 | controller | test_deps : Install extra packages -------------------------------------- 0.05s
2025-09-30 03:02:56.307774 | controller | test_deps : Gather variables for each operating system ------------------ 0.04s
2025-09-30 03:02:56.307786 | controller | INFO     Running default > cleanup
2025-09-30 03:02:56.308254 | controller | WARNING  Skipping, cleanup playbook not configured.
2025-09-30 03:02:56.308860 | controller | INFO     Writing /tmp/report.html report.
2025-09-30 03:02:56.424122 | controller | changed
2025-09-30 03:02:56.465175 | 
2025-09-30 03:02:56.465263 | PLAY RECAP
2025-09-30 03:02:56.465307 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-09-30 03:02:56.465332 | 
2025-09-30 03:02:56.589299 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-09-30 03:02:56.590149 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-09-30 03:02:57.213413 | 
2025-09-30 03:02:57.213523 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-09-30 03:02:57.235727 | 
2025-09-30 03:02:57.235820 | TASK [Filter out host if needed]
2025-09-30 03:02:57.244755 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-09-30 03:02:57.249710 | 
2025-09-30 03:02:57.249781 | TASK [Ensure file is present]
2025-09-30 03:02:57.657096 | controller | ok
2025-09-30 03:02:57.668996 | 
2025-09-30 03:02:57.669083 | TASK [Manage molecule report file]
2025-09-30 03:02:58.200864 | controller | changed
2025-09-30 03:02:58.206964 | 
2025-09-30 03:02:58.207035 | TASK [Check if we get ci-framework-data basedir]
2025-09-30 03:02:58.398255 | controller | ok
2025-09-30 03:02:58.404333 | 
2025-09-30 03:02:58.404402 | TASK [Create ci-framework-data log directory for zuul]
2025-09-30 03:02:58.724306 | controller | changed
2025-09-30 03:02:58.729603 | 
2025-09-30 03:02:58.729693 | TASK [Copy ci-framework interesting files]
2025-09-30 03:02:58.931523 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2025-09-30 03:02:59.255687 | controller | changed
2025-09-30 03:02:59.261257 | 
2025-09-30 03:02:59.261356 | TASK [Get SELinux listing]
2025-09-30 03:02:59.805827 | controller | changed
2025-09-30 03:02:59.812381 | 
2025-09-30 03:02:59.812462 | TASK [Generate log index]
2025-09-30 03:03:00.495169 | controller | changed
2025-09-30 03:03:00.500019 | 
2025-09-30 03:03:00.500081 | TASK [Get some env related data]
2025-09-30 03:03:01.039614 | controller | /home/zuul/.local/bin/ansible
2025-09-30 03:03:02.028359 | controller | changed
2025-09-30 03:03:02.034037 | 
2025-09-30 03:03:02.034107 | TASK [Generate list of logs to collect in home directory]
2025-09-30 03:03:02.347957 | controller | ok: All paths examined
2025-09-30 03:03:02.354196 | 
2025-09-30 03:03:02.354284 | LOOP [Copy logs from home directory]
2025-09-30 03:03:02.697758 | controller | changed:
2025-09-30 03:03:02.697874 | controller | {
2025-09-30 03:03:02.697901 | controller |   "atime": 1759201199.243966,
2025-09-30 03:03:02.697946 | controller |   "ctime": 1759201214.991138,
2025-09-30 03:03:02.697966 | controller |   "dev": 64513,
2025-09-30 03:03:02.697983 | controller |   "gid": 1000,
2025-09-30 03:03:02.697998 | controller |   "gr_name": "zuul",
2025-09-30 03:03:02.698013 | controller |   "inode": 4331581,
2025-09-30 03:03:02.698029 | controller |   "isblk": false,
2025-09-30 03:03:02.698044 | controller |   "ischr": false,
2025-09-30 03:03:02.698059 | controller |   "isdir": false,
2025-09-30 03:03:02.698074 | controller |   "isfifo": false,
2025-09-30 03:03:02.698089 | controller |   "isgid": false,
2025-09-30 03:03:02.698103 | controller |   "islnk": false,
2025-09-30 03:03:02.698117 | controller |   "isreg": true,
2025-09-30 03:03:02.698137 | controller |   "issock": false,
2025-09-30 03:03:02.698151 | controller |   "isuid": false,
2025-09-30 03:03:02.698164 | controller |   "mode": "0644",
2025-09-30 03:03:02.698177 | controller |   "mtime": 1759201214.991138,
2025-09-30 03:03:02.698190 | controller |   "nlink": 1,
2025-09-30 03:03:02.698204 | controller |   "path": "/home/zuul/ansible.log",
2025-09-30 03:03:02.698219 | controller |   "pw_name": "zuul",
2025-09-30 03:03:02.698234 | controller |   "rgrp": true,
2025-09-30 03:03:02.698249 | controller |   "roth": true,
2025-09-30 03:03:02.698263 | controller |   "rusr": true,
2025-09-30 03:03:02.698277 | controller |   "size": 6749,
2025-09-30 03:03:02.698291 | controller |   "uid": 1000,
2025-09-30 03:03:02.698305 | controller |   "wgrp": false,
2025-09-30 03:03:02.698319 | controller |   "woth": false,
2025-09-30 03:03:02.698336 | controller |   "wusr": true,
2025-09-30 03:03:02.698350 | controller |   "xgrp": false,
2025-09-30 03:03:02.698364 | controller |   "xoth": false,
2025-09-30 03:03:02.698377 | controller |   "xusr": false
2025-09-30 03:03:02.698391 | controller | }
2025-09-30 03:03:02.711221 | 
2025-09-30 03:03:02.711312 | TASK [Copy crio stats log file]
2025-09-30 03:03:02.735490 | controller | skipping: Conditional result was False
2025-09-30 03:03:02.741163 | 
2025-09-30 03:03:02.741239 | TASK [Get SELinux related data]
2025-09-30 03:03:02.963848 | controller | <no matches>
2025-09-30 03:03:03.270053 | controller | ERROR
2025-09-30 03:03:03.270228 | controller | {
2025-09-30 03:03:03.270260 | controller |   "delta": "0:00:00.010495",
2025-09-30 03:03:03.270283 | controller |   "end": "2025-09-30 03:03:02.964953",
2025-09-30 03:03:03.270303 | controller |   "msg": "non-zero return code",
2025-09-30 03:03:03.270320 | controller |   "rc": 1,
2025-09-30 03:03:03.270337 | controller |   "start": "2025-09-30 03:03:02.954458"
2025-09-30 03:03:03.270353 | controller | }
2025-09-30 03:03:03.270376 | controller | ERROR: Ignoring Errors
2025-09-30 03:03:03.275515 | 
2025-09-30 03:03:03.275592 | TASK [Create system configuration directory]
2025-09-30 03:03:03.485657 | controller | changed
2025-09-30 03:03:03.496703 | 
2025-09-30 03:03:03.496789 | TASK [Get some of the system configurations]
2025-09-30 03:03:04.057295 | controller | changed
2025-09-30 03:03:04.064701 | 
2025-09-30 03:03:04.064785 | TASK [Copy generated documentation if available]
2025-09-30 03:03:04.078958 | controller | skipping: Conditional result was False
2025-09-30 03:03:04.085494 | 
2025-09-30 03:03:04.085570 | TASK [Copy generated AsciiDoc documentation if available]
2025-09-30 03:03:04.100173 | controller | skipping: Conditional result was False
2025-09-30 03:03:04.107065 | 
2025-09-30 03:03:04.107137 | TASK [Compress logs bigger than 2MB]
2025-09-30 03:03:04.635990 | controller | changed
2025-09-30 03:03:04.651375 | 
2025-09-30 03:03:04.651469 | TASK [Copy files from workspace on node]
2025-09-30 03:03:04.711354 | controller | ok
2025-09-30 03:03:04.761630 | 
2025-09-30 03:03:04.761737 | TASK [fetch-output : Set log path for multiple nodes]
2025-09-30 03:03:04.809848 | controller | skipping: Conditional result was False
2025-09-30 03:03:04.816212 | 
2025-09-30 03:03:04.816299 | TASK [fetch-output : Set log path for single node]
2025-09-30 03:03:04.859674 | controller | ok
2025-09-30 03:03:04.865171 | 
2025-09-30 03:03:04.865242 | LOOP [fetch-output : Ensure local output dirs]
2025-09-30 03:03:05.206815 | controller -> localhost | ok: "/var/lib/zuul/builds/d36d0ace6ffa4cda9009f319c6427288/work/logs"
2025-09-30 03:03:05.207068 | controller -> localhost | changed: All items complete
2025-09-30 03:03:05.207100 | 
2025-09-30 03:03:05.638836 | controller -> localhost | changed: "/var/lib/zuul/builds/d36d0ace6ffa4cda9009f319c6427288/work/artifacts"
2025-09-30 03:03:05.830962 | controller -> localhost | changed: "/var/lib/zuul/builds/d36d0ace6ffa4cda9009f319c6427288/work/docs"
2025-09-30 03:03:05.854204 | 
2025-09-30 03:03:05.854305 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-09-30 03:03:06.451082 | controller | changed:
2025-09-30 03:03:06.451296 | controller | .d..t...... ./
2025-09-30 03:03:06.451336 | controller | >f+++++++++ README.html
2025-09-30 03:03:06.451359 | controller | >f+++++++++ ansible-execution.log
2025-09-30 03:03:06.451382 | controller | >f+++++++++ ansible.log
2025-09-30 03:03:06.451404 | controller | >f+++++++++ dmesg.log
2025-09-30 03:03:06.451427 | controller | >f+++++++++ installed-pkgs.log
2025-09-30 03:03:06.451495 | controller | >f+++++++++ python.log
2025-09-30 03:03:06.451542 | controller | >f+++++++++ registries.conf
2025-09-30 03:03:06.451565 | controller | >f+++++++++ report.html
2025-09-30 03:03:06.451604 | controller | >f+++++++++ selinux-denials.log
2025-09-30 03:03:06.451625 | controller | >f+++++++++ selinux-listing.log
2025-09-30 03:03:06.451645 | controller | cd+++++++++ ci-framework-data/
2025-09-30 03:03:06.451670 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-09-30 03:03:06.451688 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-09-30 03:03:06.451705 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-09-30 03:03:06.451724 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-09-30 03:03:06.451740 | controller | cd+++++++++ ci-framework-data/artifacts/repositories/
2025-09-30 03:03:06.451757 | controller | >f+++++++++ ci-framework-data/artifacts/repositories/delorean.repo.md5
2025-09-30 03:03:06.451774 | controller | cd+++++++++ ci-framework-data/logs/
2025-09-30 03:03:06.451790 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-09-30 03:03:06.451807 | controller | cd+++++++++ registries.conf.d/
2025-09-30 03:03:06.451824 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-09-30 03:03:06.451841 | controller | cd+++++++++ system-config/
2025-09-30 03:03:06.451858 | controller | cd+++++++++ system-config/libvirt/
2025-09-30 03:03:06.451874 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-09-30 03:03:06.451891 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-09-30 03:03:06.854119 | controller | changed: .d..t...... ./
2025-09-30 03:03:07.252456 | controller | changed: .d..t...... ./
2025-09-30 03:03:07.266327 | 
2025-09-30 03:03:07.266435 | TASK [Return artifact to Zuul]
2025-09-30 03:03:07.306469 | controller | ok
2025-09-30 03:03:07.334947 | 
2025-09-30 03:03:07.335033 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-09-30 03:03:07.335134 | 
2025-09-30 03:03:07.335161 | PLAY RECAP
2025-09-30 03:03:07.335199 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-09-30 03:03:07.335220 | 
2025-09-30 03:03:07.420272 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-09-30 03:03:07.421094 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-09-30 03:03:07.997331 | 
2025-09-30 03:03:07.997439 | PLAY [all]
2025-09-30 03:03:08.016764 | 
2025-09-30 03:03:08.016870 | TASK [include_role : fetch-output]
2025-09-30 03:03:08.066486 | controller | ok
2025-09-30 03:03:08.089636 | 
2025-09-30 03:03:08.089778 | TASK [fetch-output : Set log path for multiple nodes]
2025-09-30 03:03:08.155267 | controller | skipping: Conditional result was False
2025-09-30 03:03:08.162187 | 
2025-09-30 03:03:08.162303 | TASK [fetch-output : Set log path for single node]
2025-09-30 03:03:08.207108 | controller | ok
2025-09-30 03:03:08.213298 | 
2025-09-30 03:03:08.213424 | LOOP [fetch-output : Ensure local output dirs]
2025-09-30 03:03:08.687158 | controller -> localhost | ok: "/var/lib/zuul/builds/d36d0ace6ffa4cda9009f319c6427288/work/logs"
2025-09-30 03:03:08.892860 | controller -> localhost | ok: "/var/lib/zuul/builds/d36d0ace6ffa4cda9009f319c6427288/work/artifacts"
2025-09-30 03:03:09.276492 | controller -> localhost | ok: "/var/lib/zuul/builds/d36d0ace6ffa4cda9009f319c6427288/work/docs"
2025-09-30 03:03:09.289420 | 
2025-09-30 03:03:09.289505 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-09-30 03:03:10.030236 | controller | ok
2025-09-30 03:03:10.030419 | controller | ok: All items complete
2025-09-30 03:03:10.030455 | 
2025-09-30 03:03:10.534703 | controller | ok
2025-09-30 03:03:11.121192 | controller | ok
2025-09-30 03:03:11.140190 | 
2025-09-30 03:03:11.140294 | TASK [include_role : fetch-output-openshift]
2025-09-30 03:03:11.154080 | controller | skipping: Conditional result was False
2025-09-30 03:03:11.159902 | 
2025-09-30 03:03:11.159995 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-09-30 03:03:11.559751 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007247
2025-09-30 03:03:11.778409 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006587
2025-09-30 03:03:11.814275 | 
2025-09-30 03:03:11.814370 | PLAY [all]
2025-09-30 03:03:11.829072 | 
2025-09-30 03:03:11.829148 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-09-30 03:03:12.261817 | controller | changed
2025-09-30 03:03:12.321306 | 
2025-09-30 03:03:12.321425 | PLAY RECAP
2025-09-30 03:03:12.321475 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-09-30 03:03:12.321504 | 
2025-09-30 03:03:12.532947 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-09-30 03:03:12.533768 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-09-30 03:03:13.602454 | 
2025-09-30 03:03:13.602573 | PLAY [localhost]
2025-09-30 03:03:13.626500 | 
2025-09-30 03:03:13.626635 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-09-30 03:03:14.061596 | localhost | changed
2025-09-30 03:03:14.066093 | 
2025-09-30 03:03:14.066177 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-09-30 03:03:14.139048 | localhost | ok
2025-09-30 03:03:14.154102 | 
2025-09-30 03:03:14.154225 | TASK [add-fileserver : Create SSH private key tempfile]
2025-09-30 03:03:14.579416 | localhost | changed
2025-09-30 03:03:14.584483 | 
2025-09-30 03:03:14.584565 | TASK [add-fileserver : Create SSH private key from secret]
2025-09-30 03:03:15.506120 | localhost | changed
2025-09-30 03:03:15.511488 | 
2025-09-30 03:03:15.511563 | TASK [add-fileserver : Add fileserver ssh key]
2025-09-30 03:03:15.905069 | localhost | Identity added: /var/lib/zuul/builds/d36d0ace6ffa4cda9009f319c6427288/work/tmp/ansible.h1s79aw6 (/var/lib/zuul/builds/d36d0ace6ffa4cda9009f319c6427288/work/tmp/ansible.h1s79aw6)
2025-09-30 03:03:15.905249 | localhost | ok: Runtime: 0:00:00.006892
2025-09-30 03:03:15.909873 | 
2025-09-30 03:03:15.909966 | TASK [add-fileserver : Remove SSH private key from disk]
2025-09-30 03:03:16.174638 | localhost | ok: Runtime: 0:00:00.004484
2025-09-30 03:03:16.179777 | 
2025-09-30 03:03:16.179850 | TASK [add-fileserver : Add fileserver to inventory]
2025-09-30 03:03:16.228652 | localhost | changed
2025-09-30 03:03:16.241472 | 
2025-09-30 03:03:16.241557 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-09-30 03:03:16.677511 | localhost | changed
2025-09-30 03:03:16.699439 | 
2025-09-30 03:03:16.699528 | PLAY [localhost]
2025-09-30 03:03:16.711663 | 
2025-09-30 03:03:16.711726 | TASK [Generate bulk log download script]
2025-09-30 03:03:16.728545 | localhost | ok
2025-09-30 03:03:16.740832 | 
2025-09-30 03:03:16.740900 | TASK [local-log-download : Check API endpoint is defined]
2025-09-30 03:03:16.769737 | localhost | ok: All assertions passed
2025-09-30 03:03:16.775471 | 
2025-09-30 03:03:16.775545 | TASK [local-log-download : Create download script]
2025-09-30 03:03:17.327840 | localhost -> localhost | changed
2025-09-30 03:03:17.337348 | 
2025-09-30 03:03:17.337497 | TASK [Register quick-download link]
2025-09-30 03:03:17.374499 | localhost | ok
2025-09-30 03:03:17.390128 | 
2025-09-30 03:03:17.390195 | PLAY [logserver.rdoproject.org]
2025-09-30 03:03:17.399755 | 
2025-09-30 03:03:17.399813 | TASK [Set zuul-log-path fact]
2025-09-30 03:03:17.416106 | logserver.rdoproject.org | ok
2025-09-30 03:03:17.428197 | 
2025-09-30 03:03:17.428265 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-09-30 03:03:17.453695 | logserver.rdoproject.org | ok
2025-09-30 03:03:17.459296 | 
2025-09-30 03:03:17.459363 | TASK [upload-logs : Create log directories]
2025-09-30 03:03:19.258797 | logserver.rdoproject.org | changed
2025-09-30 03:03:19.262293 | 
2025-09-30 03:03:19.262369 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-09-30 03:03:19.499585 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004775
2025-09-30 03:03:19.504053 | 
2025-09-30 03:03:19.504131 | TASK [upload-logs : Upload logs to log server]
2025-09-30 03:03:21.058764 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-09-30 03:03:21.061547 | 
2025-09-30 03:03:21.061626 | LOOP [upload-logs : Compress console log and json output]
2025-09-30 03:03:21.097192 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-30 03:03:21.105487 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-30 03:03:21.118368 | 
2025-09-30 03:03:21.118440 | LOOP [upload-logs : Upload compressed console log and json output]
2025-09-30 03:03:21.155102 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-30 03:03:21.155326 | 
2025-09-30 03:03:21.159438 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-30 03:03:21.164718 | 
2025-09-30 03:03:21.164788 | LOOP [upload-logs : Upload console log and json output]