2025-09-30 05:00:17.639473 | Job console starting...
2025-09-30 05:00:17.893343 | Updating repositories
2025-09-30 05:00:18.602660 | Preparing job workspace
2025-09-30 05:00:27.845345 | Running Ansible setup...
2025-09-30 05:00:31.691232 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-09-30 05:00:32.526805 | 
2025-09-30 05:00:32.527001 | PLAY [localhost]
2025-09-30 05:00:32.567611 | 
2025-09-30 05:00:32.567717 | TASK [Gathering Facts]
2025-09-30 05:00:34.647045 | localhost | ok
2025-09-30 05:00:34.665426 | 
2025-09-30 05:00:34.665532 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-09-30 05:00:35.630305 | localhost -> localhost | changed
2025-09-30 05:00:35.638498 | 
2025-09-30 05:00:35.638575 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-09-30 05:00:36.991137 | localhost -> localhost | changed
2025-09-30 05:00:36.999088 | 
2025-09-30 05:00:36.999166 | TASK [Setup log path fact]
2025-09-30 05:00:37.019270 | localhost | ok
2025-09-30 05:00:37.035127 | 
2025-09-30 05:00:37.035190 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-09-30 05:00:37.101553 | localhost | ok
2025-09-30 05:00:37.129237 | 
2025-09-30 05:00:37.129324 | TASK [emit-job-header : Print job information]
2025-09-30 05:00:37.218791 | # Job Information
2025-09-30 05:00:37.218978 | Ansible Version: 2.15.12
2025-09-30 05:00:37.219009 | Job: cifmw-molecule-cifmw_ceph_client
2025-09-30 05:00:37.219031 | Pipeline: github-check
2025-09-30 05:00:37.219050 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-09-30 05:00:37.219067 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3333
2025-09-30 05:00:37.219087 | Log URL (when completed): https://logserver.rdoproject.org/af6/rdoproject.org/af6d9ce10a2041fcb4fa74a48398ac24/
2025-09-30 05:00:37.219118 | Event ID: 3089cae0-9dba-11f0-9d66-59f03df1d747
2025-09-30 05:00:37.227960 | 
2025-09-30 05:00:37.228032 | LOOP [emit-job-header : Print node information]
2025-09-30 05:00:37.540616 | localhost | ok:
2025-09-30 05:00:37.540821 | localhost | # Node Information
2025-09-30 05:00:37.540854 | localhost | Inventory Hostname: controller
2025-09-30 05:00:37.540879 | localhost | Hostname: np0005461580
2025-09-30 05:00:37.540900 | localhost | Username: zuul
2025-09-30 05:00:37.541006 | localhost | Distro: CentOS 9
2025-09-30 05:00:37.541031 | localhost | Provider: ibm-bm4-nodepool
2025-09-30 05:00:37.541050 | localhost | Region: regionOne
2025-09-30 05:00:37.541068 | localhost | Label: cloud-centos-9-stream-tripleo-ibm
2025-09-30 05:00:37.541086 | localhost | Product Name: OpenStack Compute
2025-09-30 05:00:37.541111 | localhost | Interface IP: 192.168.26.18
2025-09-30 05:00:37.599755 | 
2025-09-30 05:00:37.599819 | PLAY [all]
2025-09-30 05:00:37.613658 | 
2025-09-30 05:00:37.613731 | TASK [Gather network facts]
2025-09-30 05:00:38.083420 | controller | ok
2025-09-30 05:00:38.144179 | 
2025-09-30 05:00:38.144281 | TASK [include_role : start-zuul-console]
2025-09-30 05:00:38.204843 | controller | ok
2025-09-30 05:00:38.228988 | 
2025-09-30 05:00:38.229073 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-09-30 05:00:38.951262 | controller | ok
2025-09-30 05:00:38.978619 | 
2025-09-30 05:00:38.978726 | TASK [include_role : add-build-sshkey]
2025-09-30 05:00:39.123092 | controller | ok
2025-09-30 05:00:39.202255 | 
2025-09-30 05:00:39.202416 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-09-30 05:00:39.963701 | controller -> localhost | ok
2025-09-30 05:00:39.983022 | 
2025-09-30 05:00:39.983128 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-09-30 05:00:40.054687 | controller | ok
2025-09-30 05:00:40.086452 | controller | included: /var/lib/zuul/builds/af6d9ce10a2041fcb4fa74a48398ac24/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-09-30 05:00:40.097236 | 
2025-09-30 05:00:40.097314 | TASK [add-build-sshkey : Create Temp SSH key]
2025-09-30 05:00:42.462741 | controller -> localhost | Generating public/private rsa key pair.
2025-09-30 05:00:42.463000 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/af6d9ce10a2041fcb4fa74a48398ac24/work/af6d9ce10a2041fcb4fa74a48398ac24_id_rsa.
2025-09-30 05:00:42.463040 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/af6d9ce10a2041fcb4fa74a48398ac24/work/af6d9ce10a2041fcb4fa74a48398ac24_id_rsa.pub.
2025-09-30 05:00:42.463066 | controller -> localhost | The key fingerprint is:
2025-09-30 05:00:42.463089 | controller -> localhost | SHA256:SZJDBBAgvC/6Xe/8L0VCe+jb2YlXDzhE/+cH1bBMf+g zuul-build-sshkey
2025-09-30 05:00:42.463122 | controller -> localhost | The key's randomart image is:
2025-09-30 05:00:42.463144 | controller -> localhost | +---[RSA 3072]----+
2025-09-30 05:00:42.463165 | controller -> localhost | |+.oo.oo          |
2025-09-30 05:00:42.463187 | controller -> localhost | |..   . .  . . o  |
2025-09-30 05:00:42.463207 | controller -> localhost | |  .   + .. + + =.|
2025-09-30 05:00:42.463227 | controller -> localhost | | .     + .+ + = =|
2025-09-30 05:00:42.463247 | controller -> localhost | |  .     S. = o o.|
2025-09-30 05:00:42.463267 | controller -> localhost | | . .      . + E +|
2025-09-30 05:00:42.463286 | controller -> localhost | |. .   .    + = *o|
2025-09-30 05:00:42.463304 | controller -> localhost | |.  . . o  o + + +|
2025-09-30 05:00:42.463323 | controller -> localhost | | .. .  .+..o..  .|
2025-09-30 05:00:42.463342 | controller -> localhost | +----[SHA256]-----+
2025-09-30 05:00:42.463395 | controller -> localhost | ok: Runtime: 0:00:01.433920
2025-09-30 05:00:42.469395 | 
2025-09-30 05:00:42.469466 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-09-30 05:00:42.537845 | controller | ok
2025-09-30 05:00:42.583592 | controller | included: /var/lib/zuul/builds/af6d9ce10a2041fcb4fa74a48398ac24/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-09-30 05:00:42.630644 | 
2025-09-30 05:00:42.630730 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-09-30 05:00:42.699732 | controller | skipping: Conditional result was False
2025-09-30 05:00:42.706565 | 
2025-09-30 05:00:42.706738 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-09-30 05:00:43.696064 | controller | changed
2025-09-30 05:00:43.700800 | 
2025-09-30 05:00:43.700885 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-09-30 05:00:43.993752 | controller | ok
2025-09-30 05:00:44.005844 | 
2025-09-30 05:00:44.005952 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-09-30 05:00:44.928336 | controller | changed
2025-09-30 05:00:44.933492 | 
2025-09-30 05:00:44.933559 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-09-30 05:00:45.732170 | controller | changed
2025-09-30 05:00:45.742448 | 
2025-09-30 05:00:45.742528 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-09-30 05:00:45.782437 | controller | skipping: Conditional result was False
2025-09-30 05:00:45.788125 | 
2025-09-30 05:00:45.788192 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-09-30 05:00:46.296235 | controller -> localhost | changed
2025-09-30 05:00:46.333960 | 
2025-09-30 05:00:46.334049 | TASK [add-build-sshkey : Add back temp key]
2025-09-30 05:00:46.906413 | controller -> localhost | Identity added: /var/lib/zuul/builds/af6d9ce10a2041fcb4fa74a48398ac24/work/af6d9ce10a2041fcb4fa74a48398ac24_id_rsa (zuul-build-sshkey)
2025-09-30 05:00:46.906854 | controller -> localhost | ok: Runtime: 0:00:00.014235
2025-09-30 05:00:46.924568 | 
2025-09-30 05:00:46.924648 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-09-30 05:00:47.522083 | controller | ok
2025-09-30 05:00:47.527666 | 
2025-09-30 05:00:47.527773 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-09-30 05:00:47.681767 | controller | skipping: Conditional result was False
2025-09-30 05:00:47.699670 | 
2025-09-30 05:00:47.699772 | TASK [include_role : validate-host]
2025-09-30 05:00:47.797647 | controller | ok
2025-09-30 05:00:47.914938 | 
2025-09-30 05:00:47.915378 | TASK [validate-host : Define zuul_info_dir fact]
2025-09-30 05:00:48.031860 | controller | ok
2025-09-30 05:00:48.043013 | 
2025-09-30 05:00:48.043122 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-09-30 05:00:48.895033 | controller -> localhost | ok
2025-09-30 05:00:48.901823 | 
2025-09-30 05:00:48.901940 | TASK [validate-host : Collect information about the host]
2025-09-30 05:00:49.665487 | controller | ok
2025-09-30 05:00:49.725877 | 
2025-09-30 05:00:49.726024 | TASK [validate-host : Sanitize hostname]
2025-09-30 05:00:49.954618 | controller | ok
2025-09-30 05:00:49.964586 | 
2025-09-30 05:00:49.964817 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-09-30 05:00:51.228470 | controller -> localhost | changed
2025-09-30 05:00:51.235146 | 
2025-09-30 05:00:51.235359 | TASK [validate-host : Collect information about zuul worker]
2025-09-30 05:00:51.994999 | controller | ok
2025-09-30 05:00:52.008312 | 
2025-09-30 05:00:52.008423 | TASK [validate-host : Write out all zuul information for each host]
2025-09-30 05:00:53.456297 | controller -> localhost | changed
2025-09-30 05:00:53.466471 | 
2025-09-30 05:00:53.466553 | TASK [include_role : prepare-workspace-openshift]
2025-09-30 05:00:53.536428 | controller | skipping: Conditional result was False
2025-09-30 05:00:53.542319 | 
2025-09-30 05:00:53.542400 | TASK [include_role : remove-zuul-sshkey]
2025-09-30 05:00:53.608068 | controller | skipping: Conditional result was False
2025-09-30 05:00:53.614308 | 
2025-09-30 05:00:53.614426 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-09-30 05:00:53.935443 | controller | ok: "logs"
2025-09-30 05:00:53.935697 | controller | ok: All items complete
2025-09-30 05:00:53.935733 | 
2025-09-30 05:00:54.132623 | controller | ok: "artifacts"
2025-09-30 05:00:54.312710 | controller | ok: "docs"
2025-09-30 05:00:54.331153 | 
2025-09-30 05:00:54.331313 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-09-30 05:00:54.699590 | controller | changed: "logs"
2025-09-30 05:00:54.874020 | controller | changed: "artifacts"
2025-09-30 05:00:55.062060 | controller | changed: "docs"
2025-09-30 05:00:55.172184 | 
2025-09-30 05:00:55.172328 | PLAY RECAP
2025-09-30 05:00:55.172385 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-09-30 05:00:55.172420 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-09-30 05:00:55.172443 | 
2025-09-30 05:00:55.513870 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-09-30 05:00:55.514734 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-09-30 05:00:58.142471 | 
2025-09-30 05:00:58.142606 | PLAY [all]
2025-09-30 05:00:58.243657 | 
2025-09-30 05:00:58.243793 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-09-30 05:00:58.503492 | controller | ok
2025-09-30 05:00:58.515390 | 
2025-09-30 05:00:58.515474 | TASK [mirror-info-fork : Create /etc/ci]
2025-09-30 05:00:59.558238 | controller | changed
2025-09-30 05:00:59.567634 | 
2025-09-30 05:00:59.567730 | TASK [mirror-info-fork : Install ci_mirror script]
2025-09-30 05:01:01.298458 | controller | changed
2025-09-30 05:01:01.342249 | 
2025-09-30 05:01:01.342330 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-09-30 05:01:02.318217 | controller | changed:
2025-09-30 05:01:02.318393 | controller | {
2025-09-30 05:01:02.318430 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-09-30 05:01:02.318461 | controller | }
2025-09-30 05:01:02.555687 | controller | changed:
2025-09-30 05:01:02.555767 | controller | {
2025-09-30 05:01:02.555800 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-09-30 05:01:02.555825 | controller | }
2025-09-30 05:01:02.810794 | controller | changed:
2025-09-30 05:01:02.810873 | controller | {
2025-09-30 05:01:02.810901 | 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 05:01:02.812527 | controller | }
2025-09-30 05:01:03.051490 | controller | changed:
2025-09-30 05:01:03.051568 | controller | {
2025-09-30 05:01:03.051596 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-09-30 05:01:03.051618 | controller | }
2025-09-30 05:01:03.294390 | controller | changed:
2025-09-30 05:01:03.294483 | controller | {
2025-09-30 05:01:03.294510 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-09-30 05:01:03.294533 | controller | }
2025-09-30 05:01:03.544418 | controller | changed:
2025-09-30 05:01:03.544506 | controller | {
2025-09-30 05:01:03.544537 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-09-30 05:01:03.544561 | controller | }
2025-09-30 05:01:03.766846 | controller | changed:
2025-09-30 05:01:03.766949 | controller | {
2025-09-30 05:01:03.766981 | 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 05:01:03.767005 | controller | }
2025-09-30 05:01:04.109177 | controller | changed:
2025-09-30 05:01:04.109270 | controller | {
2025-09-30 05:01:04.109301 | 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 05:01:04.109324 | controller | }
2025-09-30 05:01:04.234014 | controller | changed:
2025-09-30 05:01:04.234111 | controller | {
2025-09-30 05:01:04.234142 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-09-30 05:01:04.234166 | controller | }
2025-09-30 05:01:04.454745 | controller | changed:
2025-09-30 05:01:04.454869 | controller | {
2025-09-30 05:01:04.454900 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-09-30 05:01:04.454955 | controller | }
2025-09-30 05:01:04.686995 | controller | changed:
2025-09-30 05:01:04.687079 | controller | {
2025-09-30 05:01:04.687117 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-09-30 05:01:04.687141 | controller | }
2025-09-30 05:01:04.966168 | controller | changed:
2025-09-30 05:01:04.966305 | controller | {
2025-09-30 05:01:04.966343 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-09-30 05:01:04.966367 | controller | }
2025-09-30 05:01:05.250556 | controller | changed:
2025-09-30 05:01:05.250636 | controller | {
2025-09-30 05:01:05.250664 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-09-30 05:01:05.250687 | controller | }
2025-09-30 05:01:05.453601 | controller | changed:
2025-09-30 05:01:05.453689 | controller | {
2025-09-30 05:01:05.453715 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-09-30 05:01:05.453737 | controller | }
2025-09-30 05:01:05.703520 | controller | changed:
2025-09-30 05:01:05.703602 | controller | {
2025-09-30 05:01:05.703632 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-09-30 05:01:05.703655 | controller | }
2025-09-30 05:01:05.930136 | controller | changed:
2025-09-30 05:01:05.930219 | controller | {
2025-09-30 05:01:05.930249 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-09-30 05:01:05.930270 | controller | }
2025-09-30 05:01:06.170504 | controller | changed:
2025-09-30 05:01:06.170580 | controller | {
2025-09-30 05:01:06.170609 | 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 05:01:06.170634 | controller | }
2025-09-30 05:01:06.394988 | controller | changed:
2025-09-30 05:01:06.395073 | controller | {
2025-09-30 05:01:06.395113 | 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 05:01:06.395147 | controller | }
2025-09-30 05:01:06.611601 | controller | changed:
2025-09-30 05:01:06.611676 | controller | {
2025-09-30 05:01:06.611703 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-09-30 05:01:06.611725 | controller | }
2025-09-30 05:01:06.841224 | controller | changed:
2025-09-30 05:01:06.841302 | controller | {
2025-09-30 05:01:06.841330 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-09-30 05:01:06.841353 | controller | }
2025-09-30 05:01:07.045008 | controller | changed:
2025-09-30 05:01:07.045087 | controller | {
2025-09-30 05:01:07.045126 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-09-30 05:01:07.045150 | controller | }
2025-09-30 05:01:07.280274 | controller | changed:
2025-09-30 05:01:07.280355 | controller | {
2025-09-30 05:01:07.280383 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-09-30 05:01:07.280404 | controller | }
2025-09-30 05:01:07.496802 | controller | changed:
2025-09-30 05:01:07.496881 | controller | {
2025-09-30 05:01:07.496927 | 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 05:01:07.496958 | controller | }
2025-09-30 05:01:07.723989 | controller | changed:
2025-09-30 05:01:07.724067 | controller | {
2025-09-30 05:01:07.724096 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-09-30 05:01:07.724128 | controller | }
2025-09-30 05:01:07.959468 | controller | changed:
2025-09-30 05:01:07.959557 | controller | {
2025-09-30 05:01:07.959585 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-09-30 05:01:07.959607 | controller | }
2025-09-30 05:01:08.187730 | controller | changed:
2025-09-30 05:01:08.187810 | controller | {
2025-09-30 05:01:08.187839 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-09-30 05:01:08.187861 | controller | }
2025-09-30 05:01:08.226877 | 
2025-09-30 05:01:08.227182 | TASK [Set timezone to UTC]
2025-09-30 05:01:09.329085 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-09-30 05:01:09.334621 | 
2025-09-30 05:01:09.334707 | TASK [Create nodepool directory]
2025-09-30 05:01:09.670586 | controller | changed
2025-09-30 05:01:09.678422 | 
2025-09-30 05:01:09.678491 | TASK [Create nodepool sub_nodes file]
2025-09-30 05:01:10.451525 | controller | changed
2025-09-30 05:01:10.474832 | 
2025-09-30 05:01:10.474944 | TASK [Create nodepool sub_nodes_private file]
2025-09-30 05:01:11.261887 | controller | changed
2025-09-30 05:01:11.279075 | 
2025-09-30 05:01:11.279193 | LOOP [Populate nodepool sub_nodes file]
2025-09-30 05:01:11.397956 | 
2025-09-30 05:01:11.398138 | LOOP [Populate nodepool sub_nodes_private file]
2025-09-30 05:01:11.542191 | 
2025-09-30 05:01:11.542342 | TASK [Create nodepool primary file]
2025-09-30 05:01:11.652624 | controller | skipping: Conditional result was False
2025-09-30 05:01:11.667360 | 
2025-09-30 05:01:11.667445 | TASK [Create nodepool node_private for this node]
2025-09-30 05:01:12.512530 | controller | changed
2025-09-30 05:01:12.518086 | 
2025-09-30 05:01:12.518160 | LOOP [Copy ssh keys to nodepool directory]
2025-09-30 05:01:13.652190 | controller | ok: Item: id_rsa Runtime: 0:00:00.006144
2025-09-30 05:01:13.652347 | 
2025-09-30 05:01:13.847778 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.004885
2025-09-30 05:01:13.862513 | 
2025-09-30 05:01:13.862619 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-09-30 05:01:14.694442 | controller | changed
2025-09-30 05:01:14.700061 | 
2025-09-30 05:01:14.700160 | TASK [Validate sudoers config after edits]
2025-09-30 05:01:15.214415 | controller | /etc/sudoers: parsed OK
2025-09-30 05:01:15.214487 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-09-30 05:01:15.214498 | controller | /etc/sudoers.d/zuul: parsed OK
2025-09-30 05:01:15.214505 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-09-30 05:01:15.350546 | controller | ok: Runtime: 0:00:00.005316
2025-09-30 05:01:15.356255 | 
2025-09-30 05:01:15.356324 | TASK [Show the environment passed in to job shell scripts]
2025-09-30 05:01:15.836132 | controller | SHELL=/bin/bash
2025-09-30 05:01:15.836181 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-09-30 05:01:15.836190 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-09-30 05:01:15.836197 | 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 05:01:15.836205 | controller | PWD=/home/zuul
2025-09-30 05:01:15.836211 | controller | ZUUL_PIPELINE=github-check
2025-09-30 05:01:15.836216 | controller | LOGNAME=zuul
2025-09-30 05:01:15.836222 | controller | XDG_SESSION_TYPE=tty
2025-09-30 05:01:15.836227 | controller | _=/usr/bin/env
2025-09-30 05:01:15.836242 | controller | MOTD_SHOWN=pam
2025-09-30 05:01:15.836304 | controller | HOME=/home/zuul
2025-09-30 05:01:15.836314 | controller | LANG=en_US.UTF-8
2025-09-30 05:01:15.836319 | controller | SSH_CONNECTION=192.168.26.12 57120 192.168.26.18 22
2025-09-30 05:01:15.836325 | 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 05:01:15.836331 | controller | ZUUL_CHANGE_IDS=3346,eb5b53fb17db92a72d33d052a56c8edd0d10ea78 3333,b461fc761ffaeed72eedc04b84a1fb92d251fe5d
2025-09-30 05:01:15.836336 | controller | WORKSPACE=/home/zuul/workspace
2025-09-30 05:01:15.836342 | controller | XDG_SESSION_CLASS=user
2025-09-30 05:01:15.836347 | controller | SELINUX_ROLE_REQUESTED=
2025-09-30 05:01:15.836353 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-09-30 05:01:15.836358 | controller | USER=zuul
2025-09-30 05:01:15.836363 | controller | ZUUL_VOTING=True
2025-09-30 05:01:15.836369 | controller | BUILD_TIMEOUT=1800000
2025-09-30 05:01:15.836374 | controller | SELINUX_USE_CURRENT_RANGE=
2025-09-30 05:01:15.836379 | controller | SHLVL=1
2025-09-30 05:01:15.836385 | controller | ZUUL_PATCHSET=b461fc761ffaeed72eedc04b84a1fb92d251fe5d
2025-09-30 05:01:15.836390 | controller | XDG_SESSION_ID=1
2025-09-30 05:01:15.836395 | controller | ZUUL_BRANCH=main
2025-09-30 05:01:15.836401 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-09-30 05:01:15.836406 | controller | SSH_CLIENT=192.168.26.12 57120 22
2025-09-30 05:01:15.836411 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-09-30 05:01:15.836417 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-09-30 05:01:15.836422 | controller | which_declare=declare -f
2025-09-30 05:01:15.836428 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-09-30 05:01:15.836434 | controller | SELINUX_LEVEL_REQUESTED=
2025-09-30 05:01:15.836440 | controller | ZUUL_CHANGE=3333
2025-09-30 05:01:15.836445 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-09-30 05:01:15.836450 | controller | ZUUL_UUID=af6d9ce10a2041fcb4fa74a48398ac24
2025-09-30 05:01:15.836457 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-09-30 05:01:15.836463 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-09-30 05:01:15.836468 | controller | }
2025-09-30 05:01:15.966506 | controller | ok: Runtime: 0:00:00.006215
2025-09-30 05:01:15.972621 | 
2025-09-30 05:01:15.972708 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-09-30 05:01:16.063674 | controller | skipping: Conditional result was False
2025-09-30 05:01:16.070602 | 
2025-09-30 05:01:16.070697 | TASK [Symlink /home/zuul-worker/workspace]
2025-09-30 05:01:16.845677 | controller | skipping: Conditional result was False
2025-09-30 05:01:16.851624 | 
2025-09-30 05:01:16.851690 | TASK [Ensure legacy workspace directory]
2025-09-30 05:01:17.136304 | controller | changed
2025-09-30 05:01:17.244059 | 
2025-09-30 05:01:17.244151 | PLAY RECAP
2025-09-30 05:01:17.244201 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-09-30 05:01:17.244226 | 
2025-09-30 05:01:17.800733 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-09-30 05:01:17.801444 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/read_global_vars.yml@main]
2025-09-30 05:01:21.147040 | 
2025-09-30 05:01:21.147181 | PLAY [Load global variables]
2025-09-30 05:01:21.252356 | 
2025-09-30 05:01:21.254667 | TASK [Read group_vars all file]
2025-09-30 05:01:21.312991 | controller | ok
2025-09-30 05:01:21.407588 | 
2025-09-30 05:01:21.407716 | TASK [cifmw_helpers : Check if file is available]
2025-09-30 05:01:22.124964 | controller | ok
2025-09-30 05:01:22.133884 | 
2025-09-30 05:01:22.133989 | TASK [cifmw_helpers : Read vars]
2025-09-30 05:01:22.210193 | 
2025-09-30 05:01:22.210343 | LOOP [cifmw_helpers : Set vars as fact]
2025-09-30 05:01:22.440029 | 
2025-09-30 05:01:22.440162 | PLAY RECAP
2025-09-30 05:01:22.440210 | controller | ok: 1 changed: 0 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-09-30 05:01:22.440233 | 
2025-09-30 05:01:22.891122 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/read_global_vars.yml@main]
2025-09-30 05:01:22.892063 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-09-30 05:01:25.961580 | 
2025-09-30 05:01:25.961688 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-09-30 05:01:26.050437 | 
2025-09-30 05:01:26.050531 | TASK [Create zuul-output directory]
2025-09-30 05:01:27.036660 | controller | changed
2025-09-30 05:01:27.047086 | 
2025-09-30 05:01:27.047195 | TASK [Slurp Zuul inventory test]
2025-09-30 05:01:28.699365 | controller -> localhost | ok
2025-09-30 05:01:28.706764 | 
2025-09-30 05:01:28.706833 | TASK [Save zuul inventory]
2025-09-30 05:01:30.744595 | controller | changed
2025-09-30 05:01:30.751429 | 
2025-09-30 05:01:30.751497 | TASK [Save zuul vars without the change_message]
2025-09-30 05:01:31.998029 | controller | changed
2025-09-30 05:01:32.114053 | 
2025-09-30 05:01:32.114150 | PLAY RECAP
2025-09-30 05:01:32.114199 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-09-30 05:01:32.114224 | 
2025-09-30 05:01:32.898739 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-09-30 05:01:32.899533 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-09-30 05:01:35.813619 | 
2025-09-30 05:01:35.813746 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-09-30 05:01:35.897317 | 
2025-09-30 05:01:35.897447 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-09-30 05:01:35.966005 | controller | ok
2025-09-30 05:01:36.047693 | 
2025-09-30 05:01:36.047818 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-09-30 05:01:36.198741 | controller | skipping: Conditional result was False
2025-09-30 05:01:36.210020 | 
2025-09-30 05:01:36.210117 | TASK [mirror-info-fork : Create /etc/ci]
2025-09-30 05:01:37.492995 | controller | ok
2025-09-30 05:01:37.499090 | 
2025-09-30 05:01:37.499201 | TASK [mirror-info-fork : Install ci_mirror script]
2025-09-30 05:01:38.895062 | controller | ok
2025-09-30 05:01:38.946164 | 
2025-09-30 05:01:38.946880 | TASK [Prepare workspace]
2025-09-30 05:01:39.006268 | controller | ok
2025-09-30 05:01:39.086537 | 
2025-09-30 05:01:39.086652 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-09-30 05:01:39.977596 | controller | ok
2025-09-30 05:01:39.983496 | 
2025-09-30 05:01:39.983566 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-09-30 05:01:46.232018 | controller | Output suppressed because no_log was given
2025-09-30 05:01:46.263545 | 
2025-09-30 05:01:46.264067 | LOOP [Create zuul-output directory]
2025-09-30 05:01:46.483173 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-09-30 05:01:46.651505 | controller | ok: "/home/zuul/zuul-output/logs"
2025-09-30 05:01:46.664848 | 
2025-09-30 05:01:46.664966 | TASK [Install required packages]
2025-09-30 05:02:45.809987 | controller | changed
2025-09-30 05:02:45.817570 | 
2025-09-30 05:02:45.817700 | TASK [Install venv]
2025-09-30 05:03:49.059401 | controller | changed
2025-09-30 05:03:49.103756 | 
2025-09-30 05:03:49.103834 | PLAY RECAP
2025-09-30 05:03:49.103875 | controller | ok: 7 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-09-30 05:03:49.103897 | 
2025-09-30 05:03:49.163149 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-09-30 05:03:49.163972 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-09-30 05:03:49.688855 | 
2025-09-30 05:03:49.688971 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-09-30 05:03:49.709456 | 
2025-09-30 05:03:49.709529 | TASK [Gather required facts]
2025-09-30 05:03:50.203827 | controller | ok
2025-09-30 05:03:50.209077 | 
2025-09-30 05:03:50.209152 | TASK [Load environment var if instructed to]
2025-09-30 05:03:50.232891 | controller | skipping: Conditional result was False
2025-09-30 05:03:50.238107 | 
2025-09-30 05:03:50.238176 | TASK [Run molecule]
2025-09-30 05:03:51.236075 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-09-30 05:03:51.308627 | controller | INFO     Performing prerun with role_name_check=0...
2025-09-30 05:04:08.946695 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/0ebe5d/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 05:04:08.947118 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/0ebe5d/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 05:04:08.947593 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/0ebe5d/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 05:04:08.948052 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/0ebe5d/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 05:04:08.948540 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+e2f9c552 was found installed in /home/zuul/.cache/ansible-compat/0ebe5d/collections/ansible_collections, only the first one will be used, 1.0.0+e2f9c552 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 05:04:08.948996 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/0ebe5d/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 05:04:08.949447 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/0ebe5d/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 05:04:08.949893 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/0ebe5d/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 05:04:08.950347 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/0ebe5d/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 05:04:08.950782 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/0ebe5d/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 05:04:08.951235 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/0ebe5d/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 05:04:08.951689 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/0ebe5d/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 05:04:08.952163 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/0ebe5d/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 05:04:08.952621 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/0ebe5d/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 05:04:08.953079 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/0ebe5d/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-09-30 05:04:08.963056 | controller | INFO     Running default > prepare
2025-09-30 05:04:09.696415 | controller |
2025-09-30 05:04:09.696486 | controller | PLAY [Prepare] *****************************************************************
2025-09-30 05:04:09.696570 | controller |
2025-09-30 05:04:09.696671 | controller | TASK [Gathering Facts] *********************************************************
2025-09-30 05:04:09.696773 | controller | Tuesday 30 September 2025  05:04:09 +0000 (0:00:00.014)       0:00:00.014 *****
2025-09-30 05:04:10.589986 | controller | ok: [instance]
2025-09-30 05:04:10.590059 | controller |
2025-09-30 05:04:10.590142 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-09-30 05:04:10.590253 | controller | Tuesday 30 September 2025  05:04:10 +0000 (0:00:00.893)       0:00:00.908 *****
2025-09-30 05:04:10.614512 | controller | skipping: [instance]
2025-09-30 05:04:10.614613 | controller |
2025-09-30 05:04:10.614742 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-09-30 05:04:10.614912 | controller | Tuesday 30 September 2025  05:04:10 +0000 (0:00:00.025)       0:00:00.933 *****
2025-09-30 05:04:10.664999 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-09-30 05:04:10.665052 | controller |
2025-09-30 05:04:10.665194 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-09-30 05:04:10.665322 | controller | Tuesday 30 September 2025  05:04:10 +0000 (0:00:00.050)       0:00:00.983 *****
2025-09-30 05:04:10.987373 | controller | ok: [instance]
2025-09-30 05:04:10.987428 | controller |
2025-09-30 05:04:10.987545 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-09-30 05:04:10.987647 | controller | Tuesday 30 September 2025  05:04:10 +0000 (0:00:00.322)       0:00:01.305 *****
2025-09-30 05:04:11.338909 | controller | ok: [instance]
2025-09-30 05:04:11.339178 | controller |
2025-09-30 05:04:11.339187 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-09-30 05:04:11.339198 | controller | Tuesday 30 September 2025  05:04:11 +0000 (0:00:00.350)       0:00:01.656 *****
2025-09-30 05:04:12.068807 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-09-30 05:04:12.068898 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-09-30 05:04:12.069005 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-09-30 05:04:12.069105 | controller |
2025-09-30 05:04:12.069209 | controller | TASK [Deploy repo-setup] *******************************************************
2025-09-30 05:04:12.069329 | controller | Tuesday 30 September 2025  05:04:12 +0000 (0:00:00.731)       0:00:02.387 *****
2025-09-30 05:04:12.141999 | controller |
2025-09-30 05:04:12.741813 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-09-30 05:04:12.742036 | controller | Tuesday 30 September 2025  05:04:12 +0000 (0:00:00.071)       0:00:02.459 *****
2025-09-30 05:04:12.742055 | controller | changed: [instance] => (item=tmp)
2025-09-30 05:04:12.742883 | controller | changed: [instance] => (item=artifacts/repositories)
2025-09-30 05:04:13.594479 | controller | changed: [instance] => (item=venv/repo_setup)
2025-09-30 05:04:13.595309 | controller |
2025-09-30 05:04:13.595325 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-09-30 05:04:13.595333 | controller | Tuesday 30 September 2025  05:04:12 +0000 (0:00:00.598)       0:00:03.057 *****
2025-09-30 05:04:13.595347 | controller | ok: [instance]
2025-09-30 05:04:14.849362 | controller |
2025-09-30 05:04:14.849427 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-09-30 05:04:14.849437 | controller | Tuesday 30 September 2025  05:04:13 +0000 (0:00:00.853)       0:00:03.911 *****
2025-09-30 05:04:14.849453 | controller | changed: [instance]
2025-09-30 05:04:14.849533 | controller |
2025-09-30 05:04:14.849589 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-09-30 05:04:23.235825 | controller | Tuesday 30 September 2025  05:04:14 +0000 (0:00:01.256)       0:00:05.167 *****
2025-09-30 05:04:23.235885 | controller | changed: [instance]
2025-09-30 05:04:23.983593 | controller |
2025-09-30 05:04:23.983635 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-09-30 05:04:23.983644 | controller | Tuesday 30 September 2025  05:04:23 +0000 (0:00:08.386)       0:00:13.554 *****
2025-09-30 05:04:23.983654 | controller | changed: [instance]
2025-09-30 05:04:24.007165 | controller |
2025-09-30 05:04:24.007196 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-09-30 05:04:24.007205 | controller | Tuesday 30 September 2025  05:04:23 +0000 (0:00:00.747)       0:00:14.302 *****
2025-09-30 05:04:24.007218 | controller | skipping: [instance]
2025-09-30 05:04:24.865869 | controller |
2025-09-30 05:04:24.865946 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-09-30 05:04:24.865956 | controller | Tuesday 30 September 2025  05:04:24 +0000 (0:00:00.023)       0:00:14.325 *****
2025-09-30 05:04:24.865971 | controller | changed: [instance]
2025-09-30 05:04:24.915562 | controller |
2025-09-30 05:04:24.915627 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-09-30 05:04:24.915637 | controller | Tuesday 30 September 2025  05:04:24 +0000 (0:00:00.857)       0:00:15.183 *****
2025-09-30 05:04:24.915650 | controller | skipping: [instance]
2025-09-30 05:04:24.966092 | controller |
2025-09-30 05:04:24.966155 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-09-30 05:04:24.966165 | controller | Tuesday 30 September 2025  05:04:24 +0000 (0:00:00.049)       0:00:15.233 *****
2025-09-30 05:04:24.966178 | controller | skipping: [instance]
2025-09-30 05:04:24.966348 | controller |
2025-09-30 05:04:24.966501 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-09-30 05:04:24.967313 | controller | Tuesday 30 September 2025  05:04:24 +0000 (0:00:00.050)       0:00:15.284 *****
2025-09-30 05:04:25.018432 | controller | skipping: [instance]
2025-09-30 05:04:25.018639 | controller |
2025-09-30 05:04:25.018793 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-09-30 05:04:25.018975 | controller | Tuesday 30 September 2025  05:04:25 +0000 (0:00:00.052)       0:00:15.336 *****
2025-09-30 05:04:25.625036 | controller | changed: [instance]
2025-09-30 05:04:26.096794 | controller |
2025-09-30 05:04:26.096846 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-09-30 05:04:26.096876 | controller | Tuesday 30 September 2025  05:04:25 +0000 (0:00:00.606)       0:00:15.942 *****
2025-09-30 05:04:26.096889 | controller | changed: [instance]
2025-09-30 05:04:26.127976 | controller |
2025-09-30 05:04:26.128044 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-09-30 05:04:26.128053 | controller | Tuesday 30 September 2025  05:04:26 +0000 (0:00:00.472)       0:00:16.415 *****
2025-09-30 05:04:26.128067 | controller | skipping: [instance]
2025-09-30 05:04:26.158162 | controller |
2025-09-30 05:04:26.158211 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-09-30 05:04:26.158219 | controller | Tuesday 30 September 2025  05:04:26 +0000 (0:00:00.030)       0:00:16.445 *****
2025-09-30 05:04:26.158247 | controller | skipping: [instance]
2025-09-30 05:04:26.189423 | controller |
2025-09-30 05:04:26.189492 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-09-30 05:04:26.189501 | controller | Tuesday 30 September 2025  05:04:26 +0000 (0:00:00.030)       0:00:16.476 *****
2025-09-30 05:04:26.189516 | controller | skipping: [instance]
2025-09-30 05:04:26.189675 | controller |
2025-09-30 05:04:26.189842 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-09-30 05:04:26.190028 | controller | Tuesday 30 September 2025  05:04:26 +0000 (0:00:00.030)       0:00:16.507 *****
2025-09-30 05:04:26.229385 | controller | ok: [instance]
2025-09-30 05:04:26.229625 | controller |
2025-09-30 05:04:26.229773 | controller | TASK [repo_setup : Create download directory] **********************************
2025-09-30 05:04:26.229955 | controller | Tuesday 30 September 2025  05:04:26 +0000 (0:00:00.040)       0:00:16.547 *****
2025-09-30 05:04:26.258362 | controller | skipping: [instance]
2025-09-30 05:04:26.258595 | controller |
2025-09-30 05:04:26.258743 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-09-30 05:04:26.258913 | controller | Tuesday 30 September 2025  05:04:26 +0000 (0:00:00.028)       0:00:16.576 *****
2025-09-30 05:04:26.287989 | controller | skipping: [instance]
2025-09-30 05:04:26.288037 | controller |
2025-09-30 05:04:26.288202 | controller | TASK [Download the RPM] ********************************************************
2025-09-30 05:04:26.288354 | controller | Tuesday 30 September 2025  05:04:26 +0000 (0:00:00.029)       0:00:16.606 *****
2025-09-30 05:04:26.317097 | controller | skipping: [instance]
2025-09-30 05:04:26.317221 | controller |
2025-09-30 05:04:26.317368 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-09-30 05:04:26.317495 | controller | Tuesday 30 September 2025  05:04:26 +0000 (0:00:00.029)       0:00:16.636 *****
2025-09-30 05:04:26.348313 | controller | skipping: [instance]
2025-09-30 05:04:26.348490 | controller |
2025-09-30 05:04:26.348623 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-09-30 05:04:26.348744 | controller | Tuesday 30 September 2025  05:04:26 +0000 (0:00:00.031)       0:00:16.667 *****
2025-09-30 05:04:26.375975 | controller | skipping: [instance]
2025-09-30 05:04:26.376143 | controller |
2025-09-30 05:04:26.376320 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-09-30 05:04:26.376473 | controller | Tuesday 30 September 2025  05:04:26 +0000 (0:00:00.027)       0:00:16.695 *****
2025-09-30 05:04:26.405209 | controller | skipping: [instance]
2025-09-30 05:04:26.405408 | controller |
2025-09-30 05:04:26.405562 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-09-30 05:04:26.405700 | controller | Tuesday 30 September 2025  05:04:26 +0000 (0:00:00.029)       0:00:16.724 *****
2025-09-30 05:04:26.434881 | controller | skipping: [instance]
2025-09-30 05:04:26.435070 | controller |
2025-09-30 05:04:26.435218 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-09-30 05:04:26.435375 | controller | Tuesday 30 September 2025  05:04:26 +0000 (0:00:00.029)       0:00:16.753 *****
2025-09-30 05:04:26.660689 | controller | ok: [instance]
2025-09-30 05:04:26.895758 | controller |
2025-09-30 05:04:26.895820 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-09-30 05:04:26.895829 | controller | Tuesday 30 September 2025  05:04:26 +0000 (0:00:00.224)       0:00:16.978 *****
2025-09-30 05:04:26.895843 | controller | changed: [instance]
2025-09-30 05:04:27.176007 | controller |
2025-09-30 05:04:27.176063 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-09-30 05:04:27.176072 | controller | Tuesday 30 September 2025  05:04:26 +0000 (0:00:00.235)       0:00:17.213 *****
2025-09-30 05:04:27.176086 | controller | changed: [instance]
2025-09-30 05:04:27.197014 | controller |
2025-09-30 05:04:27.197032 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-09-30 05:04:27.197039 | controller | Tuesday 30 September 2025  05:04:27 +0000 (0:00:00.280)       0:00:17.493 *****
2025-09-30 05:04:27.197048 | controller | skipping: [instance]
2025-09-30 05:04:27.219323 | controller |
2025-09-30 05:04:27.219347 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-09-30 05:04:27.219354 | controller | Tuesday 30 September 2025  05:04:27 +0000 (0:00:00.022)       0:00:17.515 *****
2025-09-30 05:04:27.219363 | controller | skipping: [instance]
2025-09-30 05:04:27.240776 | controller |
2025-09-30 05:04:27.240797 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-09-30 05:04:27.240805 | controller | Tuesday 30 September 2025  05:04:27 +0000 (0:00:00.022)       0:00:17.538 *****
2025-09-30 05:04:27.240816 | controller | skipping: [instance]
2025-09-30 05:04:27.261742 | controller |
2025-09-30 05:04:27.261763 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-09-30 05:04:27.261772 | controller | Tuesday 30 September 2025  05:04:27 +0000 (0:00:00.021)       0:00:17.559 *****
2025-09-30 05:04:27.261783 | controller | skipping: [instance]
2025-09-30 05:04:27.261984 | controller |
2025-09-30 05:04:27.262171 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-09-30 05:04:27.262355 | controller | Tuesday 30 September 2025  05:04:27 +0000 (0:00:00.021)       0:00:17.580 *****
2025-09-30 05:04:27.283722 | controller | skipping: [instance]
2025-09-30 05:04:27.283995 | controller |
2025-09-30 05:04:27.284177 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-09-30 05:04:27.284394 | controller | Tuesday 30 September 2025  05:04:27 +0000 (0:00:00.021)       0:00:17.602 *****
2025-09-30 05:04:27.305472 | controller | skipping: [instance]
2025-09-30 05:04:27.305646 | controller |
2025-09-30 05:04:27.305791 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-09-30 05:04:27.306005 | controller | Tuesday 30 September 2025  05:04:27 +0000 (0:00:00.021)       0:00:17.624 *****
2025-09-30 05:04:27.322125 | controller | skipping: [instance]
2025-09-30 05:04:27.322290 | controller |
2025-09-30 05:04:27.322445 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-09-30 05:04:27.322597 | controller | Tuesday 30 September 2025  05:04:27 +0000 (0:00:00.016)       0:00:17.641 *****
2025-09-30 05:04:27.350820 | controller | skipping: [instance]
2025-09-30 05:04:27.351037 | controller |
2025-09-30 05:04:27.351215 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-09-30 05:04:27.351411 | controller | Tuesday 30 September 2025  05:04:27 +0000 (0:00:00.028)       0:00:17.669 *****
2025-09-30 05:04:27.369658 | controller | skipping: [instance]
2025-09-30 05:04:27.390955 | controller |
2025-09-30 05:04:27.390977 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-09-30 05:04:27.390987 | controller | Tuesday 30 September 2025  05:04:27 +0000 (0:00:00.018)       0:00:17.688 *****
2025-09-30 05:04:27.390998 | controller | skipping: [instance]
2025-09-30 05:04:27.423710 | controller |
2025-09-30 05:04:27.423756 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-09-30 05:04:27.423765 | controller | Tuesday 30 September 2025  05:04:27 +0000 (0:00:00.021)       0:00:17.709 *****
2025-09-30 05:04:27.423777 | controller | skipping: [instance]
2025-09-30 05:04:27.453358 | controller |
2025-09-30 05:04:27.453389 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-09-30 05:04:27.453397 | controller | Tuesday 30 September 2025  05:04:27 +0000 (0:00:00.032)       0:00:17.742 *****
2025-09-30 05:04:27.453408 | controller | skipping: [instance]
2025-09-30 05:04:27.483007 | controller |
2025-09-30 05:04:27.483033 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-09-30 05:04:27.483041 | controller | Tuesday 30 September 2025  05:04:27 +0000 (0:00:00.030)       0:00:17.772 *****
2025-09-30 05:04:27.483051 | controller | skipping: [instance]
2025-09-30 05:04:27.512539 | controller |
2025-09-30 05:04:27.512568 | controller | TASK [test_deps : Install additional packages] *********************************
2025-09-30 05:04:27.512577 | controller | Tuesday 30 September 2025  05:04:27 +0000 (0:00:00.029)       0:00:17.801 *****
2025-09-30 05:04:27.512588 | controller | skipping: [instance]
2025-09-30 05:05:13.403126 | controller |
2025-09-30 05:05:13.403159 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-09-30 05:05:13.403168 | controller | Tuesday 30 September 2025  05:04:27 +0000 (0:00:00.029)       0:00:17.831 *****
2025-09-30 05:05:13.403178 | controller | ok: [instance]
2025-09-30 05:05:14.555176 | controller |
2025-09-30 05:05:14.555205 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-09-30 05:05:14.555213 | controller | Tuesday 30 September 2025  05:05:13 +0000 (0:00:45.890)       0:01:03.721 *****
2025-09-30 05:05:14.555223 | controller | ok: [instance]
2025-09-30 05:05:14.595286 | controller |
2025-09-30 05:05:14.595332 | controller | TASK [test_deps : Install extra packages] **************************************
2025-09-30 05:05:14.595340 | controller | Tuesday 30 September 2025  05:05:14 +0000 (0:00:01.152)       0:01:04.873 *****
2025-09-30 05:05:14.595350 | controller | skipping: [instance]
2025-09-30 05:05:14.808132 | controller |
2025-09-30 05:05:14.808202 | controller | TASK [Ensure cifmw_ceph_client_config_home exists on all clients] **************
2025-09-30 05:05:14.808211 | controller | Tuesday 30 September 2025  05:05:14 +0000 (0:00:00.040)       0:01:04.913 *****
2025-09-30 05:05:14.808226 | controller | changed: [instance]
2025-09-30 05:05:14.810020 | controller |
2025-09-30 05:05:14.810071 | controller | PLAY RECAP *********************************************************************
2025-09-30 05:05:14.810080 | controller | instance                   : ok=20   changed=10   unreachable=0    failed=0    skipped=30   rescued=0    ignored=0
2025-09-30 05:05:14.810087 | controller |
2025-09-30 05:05:14.810100 | controller | Tuesday 30 September 2025  05:05:14 +0000 (0:00:00.212)       0:01:05.125 *****
2025-09-30 05:05:14.810107 | controller | ===============================================================================
2025-09-30 05:05:14.810113 | controller | test_deps : Install selinux python libs -------------------------------- 45.89s
2025-09-30 05:05:14.810126 | controller | repo_setup : Initialize python venv and install requirements ------------ 8.39s
2025-09-30 05:05:14.872050 | controller | repo_setup : Get repo-setup repository ---------------------------------- 1.26s
2025-09-30 05:05:14.872080 | controller | test_deps : Install python yaml libs ------------------------------------ 1.15s
2025-09-30 05:05:14.872088 | controller | Gathering Facts --------------------------------------------------------- 0.89s
2025-09-30 05:05:14.872094 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.86s
2025-09-30 05:05:14.872099 | controller | repo_setup : Make sure git-core package is installed -------------------- 0.85s
2025-09-30 05:05:14.872104 | controller | repo_setup : Install repo-setup package --------------------------------- 0.75s
2025-09-30 05:05:14.872110 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.73s
2025-09-30 05:05:14.872115 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.61s
2025-09-30 05:05:14.872120 | controller | repo_setup : Ensure directories are present ----------------------------- 0.60s
2025-09-30 05:05:14.872126 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.47s
2025-09-30 05:05:14.872131 | controller | test_deps : Disable ubi host subscription-manager integration ----------- 0.35s
2025-09-30 05:05:14.872136 | controller | test_deps : Detect mirrors file ----------------------------------------- 0.32s
2025-09-30 05:05:14.872142 | controller | repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist) --- 0.28s
2025-09-30 05:05:14.872147 | controller | repo_setup : Use RDO proxy mirrors -------------------------------------- 0.24s
2025-09-30 05:05:14.872153 | controller | repo_setup : Check for /etc/ci/mirror_info.sh --------------------------- 0.22s
2025-09-30 05:05:14.872158 | controller | Ensure cifmw_ceph_client_config_home exists on all clients -------------- 0.21s
2025-09-30 05:05:14.872164 | controller | Deploy repo-setup ------------------------------------------------------- 0.07s
2025-09-30 05:05:14.872169 | controller | repo_setup : Disable component repo in current-podified dlrn repo ------- 0.05s
2025-09-30 05:05:14.872180 | controller | INFO     Running default > converge
2025-09-30 05:05:15.309799 | controller |
2025-09-30 05:05:16.096947 | controller | PLAY [Converge] ****************************************************************
2025-09-30 05:05:16.096986 | controller |
2025-09-30 05:05:16.096994 | controller | TASK [Gathering Facts] *********************************************************
2025-09-30 05:05:16.097000 | controller | Tuesday 30 September 2025  05:05:15 +0000 (0:00:00.013)       0:00:00.013 *****
2025-09-30 05:05:16.097011 | controller | ok: [instance]
2025-09-30 05:05:16.097030 | controller |
2025-09-30 05:05:16.097270 | controller | TASK [cifmw_ceph_client : Check if the input variables exist] ******************
2025-09-30 05:05:16.119903 | controller | Tuesday 30 September 2025  05:05:16 +0000 (0:00:00.787)       0:00:00.801 *****
2025-09-30 05:05:16.119939 | controller | skipping: [instance]
2025-09-30 05:05:16.142130 | controller |
2025-09-30 05:05:16.142161 | controller | TASK [cifmw_ceph_client : Load variables produced by the cephadm provisioning process] ***
2025-09-30 05:05:16.142169 | controller | Tuesday 30 September 2025  05:05:16 +0000 (0:00:00.022)       0:00:00.824 *****
2025-09-30 05:05:16.142179 | controller | skipping: [instance]
2025-09-30 05:05:16.170334 | controller |
2025-09-30 05:05:16.170365 | controller | TASK [cifmw_ceph_client : Render keys provided for the Ceph cluster] ***********
2025-09-30 05:05:16.170373 | controller | Tuesday 30 September 2025  05:05:16 +0000 (0:00:00.022)       0:00:00.846 *****
2025-09-30 05:05:16.170384 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/cifmw_ceph_client/tasks/create_keys.yml for instance
2025-09-30 05:05:17.075109 | controller |
2025-09-30 05:05:17.075139 | controller | TASK [cifmw_ceph_client : Create cephx key(s)] *********************************
2025-09-30 05:05:17.075153 | controller | Tuesday 30 September 2025  05:05:16 +0000 (0:00:00.028)       0:00:00.874 *****
2025-09-30 05:05:17.075164 | controller | changed: [instance] => (item={'caps': {'mgr': 'allow *', 'mon': 'profile rbd', 'osd': 'profile rbd pool=vms, profile rbd pool=volumes, profile rbd pool=metrics, profile rbd pool=backups, profile rbd pool=pool2, profile rbd pool=pool3, profile rbd pool=altrbd'}, 'key': 'AQC+vYNXgDAgAhAAc8UoYt+OTz5uhV7ItLdwUw==', 'mode': '0600', 'name': 'client.glance'})
2025-09-30 05:05:17.094001 | controller | changed: [instance] => (item={'caps': {'mgr': 'allow *', 'mon': 'profile rbd', 'osd': 'profile rbd pool=images'}, 'key': 'AQBRgQ9eAAAAABAAv84zEilJYZPNuJ0Iwn9Ndg==', 'mode': '0600', 'name': 'client.manila'})
2025-09-30 05:05:17.094037 | controller |
2025-09-30 05:05:17.094047 | controller | TASK [cifmw_ceph_client : Render ceph config for the Ceph Clients] *************
2025-09-30 05:05:17.094055 | controller | Tuesday 30 September 2025  05:05:17 +0000 (0:00:00.904)       0:00:01.779 *****
2025-09-30 05:05:17.094067 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/cifmw_ceph_client/tasks/create_ceph_conf.yml for instance
2025-09-30 05:05:17.094097 | controller |
2025-09-30 05:05:17.094108 | controller | TASK [cifmw_ceph_client : Create ceph.conf] ************************************
2025-09-30 05:05:17.094165 | controller | Tuesday 30 September 2025  05:05:17 +0000 (0:00:00.019)       0:00:01.798 *****
2025-09-30 05:05:17.479452 | controller | changed: [instance]
2025-09-30 05:05:17.500008 | controller |
2025-09-30 05:05:17.500031 | controller | TASK [cifmw_ceph_client : Create edpm-values-post-ceph ConfigMap if sample path provided] ***
2025-09-30 05:05:17.500040 | controller | Tuesday 30 September 2025  05:05:17 +0000 (0:00:00.385)       0:00:02.184 *****
2025-09-30 05:05:17.500049 | controller | skipping: [instance]
2025-09-30 05:05:17.523738 | controller |
2025-09-30 05:05:17.523755 | controller | TASK [cifmw_ceph_client : Create edpm-service-values-post-ceph ConfigMap if sample path provided] ***
2025-09-30 05:05:17.523763 | controller | Tuesday 30 September 2025  05:05:17 +0000 (0:00:00.020)       0:00:02.204 *****
2025-09-30 05:05:17.523771 | controller | skipping: [instance]
2025-09-30 05:05:18.060167 | controller |
2025-09-30 05:05:18.060197 | controller | TASK [Check current file] ******************************************************
2025-09-30 05:05:18.060206 | controller | Tuesday 30 September 2025  05:05:17 +0000 (0:00:00.023)       0:00:02.228 *****
2025-09-30 05:05:18.060216 | controller | ok: [instance] => (item=ceph.client.glance.keyring)
2025-09-30 05:05:18.089930 | controller | ok: [instance] => (item=ceph.client.manila.keyring)
2025-09-30 05:05:18.089962 | controller | ok: [instance] => (item=ceph.conf)
2025-09-30 05:05:18.089970 | controller |
2025-09-30 05:05:18.089976 | controller | TASK [Fail if file not found] **************************************************
2025-09-30 05:05:18.089982 | controller | Tuesday 30 September 2025  05:05:18 +0000 (0:00:00.535)       0:00:02.764 *****
2025-09-30 05:05:18.089994 | controller | skipping: [instance] => (item={'changed': False, 'stat': {'exists': True, 'path': '/tmp/ceph.client.glance.keyring', 'mode': '0600', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 302, 'inode': 58738661, 'dev': 64513, 'nlink': 1, 'atime': 1759208716.710756, 'mtime': 1759208716.4557538, 'ctime': 1759208716.712756, 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': False, 'xgrp': False, 'woth': False, 'roth': False, 'xoth': False, 'isuid': False, 'isgid': False, 'blocks': 8, 'block_size': 4096, 'device_type': 0, 'readable': True, 'writeable': True, 'executable': False, 'pw_name': 'zuul', 'gr_name': 'zuul', 'checksum': 'e7164142ee2f357bf32771e16ce9bcaf223d404e', 'mimetype': 'text/plain', 'charset': 'us-ascii', 'version': '2417295209', 'attributes': [], 'attr_flags': ''}, 'invocation': {'module_args': {'path': '/tmp/ceph.client.glance.keyring', 'follow': False, 'get_md5': False, 'get_checksum': True, 'get_mime': True, 'get_attributes': True, 'checksum_algorithm': 'sha1'}}, 'failed': False, 'item': 'ceph.client.glance.keyring', 'ansible_loop_var': 'item'})
2025-09-30 05:05:18.090033 | controller | skipping: [instance] => (item={'changed': False, 'stat': {'exists': True, 'path': '/tmp/ceph.client.manila.keyring', 'mode': '0600', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 1000, 'gid': 1000, 'size': 154, 'inode': 75505335, 'dev': 64513, 'nlink': 1, 'atime': 1759208717.039759, 'mtime': 1759208716.8967576, 'ctime': 1759208717.041759, 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': False, 'xgrp': False, 'woth': False, 'roth': False, 'xoth': False, 'isuid': False, 'isgid': False, 'blocks': 8, 'block_size': 4096, 'device_type': 0, 'readable': True, 'writeable': True, 'executable': False, 'pw_name': 'zuul', 'gr_name': 'zuul', 'checksum': 'd6d4783ea1936e82934ab1c7b21cc940553e7bd8', 'mimetype': 'text/plain', 'charset': 'us-ascii', 'version': '3928039100', 'attributes': [], 'attr_flags': ''}, 'invocation': {'module_args': {'path': '/tmp/ceph.client.manila.keyring', 'follow': False, 'get_md5': False, 'get_checksum': True, 'get_mime': True, 'get_attributes': True, 'checksum_algorithm': 'sha1'}}, 'failed': False, 'item': 'ceph.client.manila.keyring', 'ansible_loop_var': 'item'})
2025-09-30 05:05:18.090621 | controller | skipping: [instance] => (item={'changed': False, 'stat': {'exists': True, 'path': '/tmp/ceph.conf', 'mode': '0644', 'isdir': False, 'ischr': False, 'isblk': False, 'isreg': True, 'isfifo': False, 'islnk': False, 'issock': False, 'uid': 0, 'gid': 0, 'size': 386, 'inode': 92314312, 'dev': 64513, 'nlink': 1, 'atime': 1759208717.4447625, 'mtime': 1759208717.2947612, 'ctime': 1759208717.4477625, 'wusr': True, 'rusr': True, 'xusr': False, 'wgrp': False, 'rgrp': True, 'xgrp': False, 'woth': False, 'roth': True, 'xoth': False, 'isuid': False, 'isgid': False, 'blocks': 8, 'block_size': 4096, 'device_type': 0, 'readable': True, 'writeable': False, 'executable': False, 'pw_name': 'root', 'gr_name': 'root', 'checksum': 'e31ff745c34475be37b341f51eb9c14b9adbb4f9', 'mimetype': 'text/plain', 'charset': 'us-ascii', 'version': '1940288444', 'attributes': [], 'attr_flags': ''}, 'invocation': {'module_args': {'path': '/tmp/ceph.conf', 'follow': False, 'get_md5': False, 'get_checksum': True, 'get_mime': True, 'get_attributes': True, 'checksum_algorithm': 'sha1'}}, 'failed': False, 'item': 'ceph.conf', 'ansible_loop_var': 'item'})
2025-09-30 05:05:18.360925 | controller | skipping: [instance]
2025-09-30 05:05:18.360954 | controller |
2025-09-30 05:05:18.360961 | controller | TASK [Show the content of the generated Ceph config file] **********************
2025-09-30 05:05:18.360974 | controller | Tuesday 30 September 2025  05:05:18 +0000 (0:00:00.030)       0:00:02.794 *****
2025-09-30 05:05:18.360985 | controller | ok: [instance]
2025-09-30 05:05:18.361152 | controller |
2025-09-30 05:05:18.361171 | controller | TASK [Debug ceph config] *******************************************************
2025-09-30 05:05:18.404954 | controller | Tuesday 30 September 2025  05:05:18 +0000 (0:00:00.270)       0:00:03.065 *****
2025-09-30 05:05:18.404989 | controller | ok: [instance] =>
2025-09-30 05:05:18.405016 | controller |   msg: |-
2025-09-30 05:05:18.405025 | controller |     # Ansible managed: Do NOT edit this file manually!
2025-09-30 05:05:18.405032 | controller |
2025-09-30 05:05:18.405039 | controller |     [global]
2025-09-30 05:05:18.405046 | controller |
2025-09-30 05:05:18.405053 | controller |     fsid = 1dee28aa-2eba-11eb-b30b-244200b898e6
2025-09-30 05:05:18.405062 | controller |     mon host = 172.16.3.10,172.16.3.11,172.16.3.12
2025-09-30 05:05:18.405086 | controller |     [client]
2025-09-30 05:05:18.407790 | controller |     rbd_cache = True
2025-09-30 05:05:18.465216 | controller |     rbd_cache_writethrough_until_flush = True
2025-09-30 05:05:18.465238 | controller |     rbd_concurrent_management_ops = 20
2025-09-30 05:05:18.465246 | controller |
2025-09-30 05:05:18.465252 | controller |
2025-09-30 05:05:18.465257 | controller |     [client.libvirt]
2025-09-30 05:05:18.465263 | controller |     admin socket = /var/run/ceph/$cluster-$type.$id.$pid.$cctid.asok
2025-09-30 05:05:18.465269 | controller |     log file = /var/log/ceph/qemu-guest-$pid.log
2025-09-30 05:05:18.465274 | controller |
2025-09-30 05:05:18.465280 | controller | PLAY RECAP *********************************************************************
2025-09-30 05:05:18.465285 | controller | instance                   : ok=8    changed=2    unreachable=0    failed=0    skipped=5    rescued=0    ignored=0
2025-09-30 05:05:18.465297 | controller |
2025-09-30 05:05:18.465325 | controller | Tuesday 30 September 2025  05:05:18 +0000 (0:00:00.043)       0:00:03.109 *****
2025-09-30 05:05:18.465331 | controller | ===============================================================================
2025-09-30 05:05:18.465336 | controller | cifmw_ceph_client : Create cephx key(s) --------------------------------- 0.90s
2025-09-30 05:05:18.465342 | controller | Gathering Facts --------------------------------------------------------- 0.79s
2025-09-30 05:05:18.465347 | controller | Check current file ------------------------------------------------------ 0.54s
2025-09-30 05:05:18.465352 | controller | cifmw_ceph_client : Create ceph.conf ------------------------------------ 0.39s
2025-09-30 05:05:18.465358 | controller | Show the content of the generated Ceph config file ---------------------- 0.27s
2025-09-30 05:05:18.465363 | controller | Debug ceph config ------------------------------------------------------- 0.04s
2025-09-30 05:05:18.465368 | controller | Fail if file not found -------------------------------------------------- 0.03s
2025-09-30 05:05:18.465374 | controller | cifmw_ceph_client : Render keys provided for the Ceph cluster ----------- 0.03s
2025-09-30 05:05:18.465379 | controller | cifmw_ceph_client : Create edpm-service-values-post-ceph ConfigMap if sample path provided --- 0.02s
2025-09-30 05:05:18.465385 | controller | cifmw_ceph_client : Check if the input variables exist ------------------ 0.02s
2025-09-30 05:05:18.465390 | controller | cifmw_ceph_client : Load variables produced by the cephadm provisioning process --- 0.02s
2025-09-30 05:05:18.465396 | controller | cifmw_ceph_client : Create edpm-values-post-ceph ConfigMap if sample path provided --- 0.02s
2025-09-30 05:05:18.465401 | controller | cifmw_ceph_client : Render ceph config for the Ceph Clients ------------- 0.02s
2025-09-30 05:05:18.465410 | controller | INFO     Running default > cleanup
2025-09-30 05:05:18.465896 | controller | WARNING  Skipping, cleanup playbook not configured.
2025-09-30 05:05:18.466532 | controller | INFO     Writing /tmp/report.html report.
2025-09-30 05:05:18.886546 | controller | changed
2025-09-30 05:05:18.907301 | 
2025-09-30 05:05:18.907356 | PLAY RECAP
2025-09-30 05:05:18.907399 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-09-30 05:05:18.907422 | 
2025-09-30 05:05:18.980577 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-09-30 05:05:18.981462 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-09-30 05:05:19.574436 | 
2025-09-30 05:05:19.574555 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-09-30 05:05:19.595427 | 
2025-09-30 05:05:19.595518 | TASK [Filter out host if needed]
2025-09-30 05:05:19.604412 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-09-30 05:05:19.609676 | 
2025-09-30 05:05:19.609755 | TASK [Ensure file is present]
2025-09-30 05:05:19.933481 | controller | ok
2025-09-30 05:05:19.940136 | 
2025-09-30 05:05:19.940207 | TASK [Manage molecule report file]
2025-09-30 05:05:20.467216 | controller | changed
2025-09-30 05:05:20.473646 | 
2025-09-30 05:05:20.473722 | TASK [Check if we get ci-framework-data basedir]
2025-09-30 05:05:20.655602 | controller | ok
2025-09-30 05:05:20.660810 | 
2025-09-30 05:05:20.660888 | TASK [Create ci-framework-data log directory for zuul]
2025-09-30 05:05:20.978370 | controller | changed
2025-09-30 05:05:20.985085 | 
2025-09-30 05:05:20.985179 | TASK [Copy ci-framework interesting files]
2025-09-30 05:05:21.182396 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2025-09-30 05:05:21.514786 | controller | changed
2025-09-30 05:05:21.520290 | 
2025-09-30 05:05:21.520360 | TASK [Get SELinux listing]
2025-09-30 05:05:22.046435 | controller | changed
2025-09-30 05:05:22.052149 | 
2025-09-30 05:05:22.052332 | TASK [Generate log index]
2025-09-30 05:05:22.694695 | controller | changed
2025-09-30 05:05:22.699632 | 
2025-09-30 05:05:22.699696 | TASK [Get some env related data]
2025-09-30 05:05:23.233584 | controller | /home/zuul/.local/bin/ansible
2025-09-30 05:05:24.223925 | controller | changed
2025-09-30 05:05:24.230260 | 
2025-09-30 05:05:24.230347 | TASK [Generate list of logs to collect in home directory]
2025-09-30 05:05:24.534177 | controller | ok: All paths examined
2025-09-30 05:05:24.539744 | 
2025-09-30 05:05:24.539838 | LOOP [Copy logs from home directory]
2025-09-30 05:05:24.860978 | controller | changed:
2025-09-30 05:05:24.861095 | controller | {
2025-09-30 05:05:24.861123 | controller |   "atime": 1759208612.4338377,
2025-09-30 05:05:24.861143 | controller |   "ctime": 1759208628.6129794,
2025-09-30 05:05:24.861160 | controller |   "dev": 64513,
2025-09-30 05:05:24.861177 | controller |   "gid": 1000,
2025-09-30 05:05:24.861192 | controller |   "gr_name": "zuul",
2025-09-30 05:05:24.861208 | controller |   "inode": 4411470,
2025-09-30 05:05:24.861223 | controller |   "isblk": false,
2025-09-30 05:05:24.861238 | controller |   "ischr": false,
2025-09-30 05:05:24.861272 | controller |   "isdir": false,
2025-09-30 05:05:24.861288 | controller |   "isfifo": false,
2025-09-30 05:05:24.861302 | controller |   "isgid": false,
2025-09-30 05:05:24.861322 | controller |   "islnk": false,
2025-09-30 05:05:24.861337 | controller |   "isreg": true,
2025-09-30 05:05:24.861351 | controller |   "issock": false,
2025-09-30 05:05:24.861365 | controller |   "isuid": false,
2025-09-30 05:05:24.861380 | controller |   "mode": "0644",
2025-09-30 05:05:24.861394 | controller |   "mtime": 1759208628.6129794,
2025-09-30 05:05:24.861411 | controller |   "nlink": 1,
2025-09-30 05:05:24.861427 | controller |   "path": "/home/zuul/ansible.log",
2025-09-30 05:05:24.861444 | controller |   "pw_name": "zuul",
2025-09-30 05:05:24.861459 | controller |   "rgrp": true,
2025-09-30 05:05:24.861474 | controller |   "roth": true,
2025-09-30 05:05:24.861488 | controller |   "rusr": true,
2025-09-30 05:05:24.861503 | controller |   "size": 6749,
2025-09-30 05:05:24.861517 | controller |   "uid": 1000,
2025-09-30 05:05:24.861531 | controller |   "wgrp": false,
2025-09-30 05:05:24.861544 | controller |   "woth": false,
2025-09-30 05:05:24.861560 | controller |   "wusr": true,
2025-09-30 05:05:24.861575 | controller |   "xgrp": false,
2025-09-30 05:05:24.861589 | controller |   "xoth": false,
2025-09-30 05:05:24.861603 | controller |   "xusr": false
2025-09-30 05:05:24.861616 | controller | }
2025-09-30 05:05:24.875380 | 
2025-09-30 05:05:24.875489 | TASK [Copy crio stats log file]
2025-09-30 05:05:24.889440 | controller | skipping: Conditional result was False
2025-09-30 05:05:24.896368 | 
2025-09-30 05:05:24.896440 | TASK [Get SELinux related data]
2025-09-30 05:05:25.113006 | controller | <no matches>
2025-09-30 05:05:25.421174 | controller | ERROR
2025-09-30 05:05:25.421417 | controller | {
2025-09-30 05:05:25.421466 | controller |   "delta": "0:00:00.008404",
2025-09-30 05:05:25.421497 | controller |   "end": "2025-09-30 05:05:25.113569",
2025-09-30 05:05:25.421517 | controller |   "msg": "non-zero return code",
2025-09-30 05:05:25.421536 | controller |   "rc": 1,
2025-09-30 05:05:25.421553 | controller |   "start": "2025-09-30 05:05:25.105165"
2025-09-30 05:05:25.421570 | controller | }
2025-09-30 05:05:25.421593 | controller | ERROR: Ignoring Errors
2025-09-30 05:05:25.427332 | 
2025-09-30 05:05:25.427403 | TASK [Create system configuration directory]
2025-09-30 05:05:25.618573 | controller | changed
2025-09-30 05:05:25.623648 | 
2025-09-30 05:05:25.623725 | TASK [Get some of the system configurations]
2025-09-30 05:05:26.149566 | controller | changed
2025-09-30 05:05:26.155025 | 
2025-09-30 05:05:26.155100 | TASK [Copy generated documentation if available]
2025-09-30 05:05:26.169006 | controller | skipping: Conditional result was False
2025-09-30 05:05:26.174741 | 
2025-09-30 05:05:26.174813 | TASK [Copy generated AsciiDoc documentation if available]
2025-09-30 05:05:26.198341 | controller | skipping: Conditional result was False
2025-09-30 05:05:26.204137 | 
2025-09-30 05:05:26.204213 | TASK [Compress logs bigger than 2MB]
2025-09-30 05:05:26.730818 | controller | changed
2025-09-30 05:05:26.736522 | 
2025-09-30 05:05:26.736585 | TASK [Copy files from workspace on node]
2025-09-30 05:05:26.754655 | controller | ok
2025-09-30 05:05:26.777933 | 
2025-09-30 05:05:26.778023 | TASK [fetch-output : Set log path for multiple nodes]
2025-09-30 05:05:26.801466 | controller | skipping: Conditional result was False
2025-09-30 05:05:26.807016 | 
2025-09-30 05:05:26.807084 | TASK [fetch-output : Set log path for single node]
2025-09-30 05:05:26.837303 | controller | ok
2025-09-30 05:05:26.842478 | 
2025-09-30 05:05:26.842546 | LOOP [fetch-output : Ensure local output dirs]
2025-09-30 05:05:27.061280 | controller -> localhost | ok: "/var/lib/zuul/builds/af6d9ce10a2041fcb4fa74a48398ac24/work/logs"
2025-09-30 05:05:27.061521 | controller -> localhost | changed: All items complete
2025-09-30 05:05:27.061554 | 
2025-09-30 05:05:27.258998 | controller -> localhost | changed: "/var/lib/zuul/builds/af6d9ce10a2041fcb4fa74a48398ac24/work/artifacts"
2025-09-30 05:05:27.444193 | controller -> localhost | changed: "/var/lib/zuul/builds/af6d9ce10a2041fcb4fa74a48398ac24/work/docs"
2025-09-30 05:05:27.452146 | 
2025-09-30 05:05:27.452218 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-09-30 05:05:28.005040 | controller | changed:
2025-09-30 05:05:28.005264 | controller | .d..t...... ./
2025-09-30 05:05:28.005302 | controller | >f+++++++++ README.html
2025-09-30 05:05:28.005326 | controller | >f+++++++++ ansible-execution.log
2025-09-30 05:05:28.005346 | controller | >f+++++++++ ansible.log
2025-09-30 05:05:28.005365 | controller | >f+++++++++ dmesg.log
2025-09-30 05:05:28.005383 | controller | >f+++++++++ installed-pkgs.log
2025-09-30 05:05:28.005402 | controller | >f+++++++++ python.log
2025-09-30 05:05:28.005421 | controller | >f+++++++++ registries.conf
2025-09-30 05:05:28.005438 | controller | >f+++++++++ report.html
2025-09-30 05:05:28.005457 | controller | >f+++++++++ selinux-denials.log
2025-09-30 05:05:28.005473 | controller | >f+++++++++ selinux-listing.log
2025-09-30 05:05:28.005489 | controller | cd+++++++++ ci-framework-data/
2025-09-30 05:05:28.005504 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-09-30 05:05:28.005520 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-09-30 05:05:28.005535 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-09-30 05:05:28.005550 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-09-30 05:05:28.005565 | controller | cd+++++++++ ci-framework-data/artifacts/repositories/
2025-09-30 05:05:28.005579 | controller | >f+++++++++ ci-framework-data/artifacts/repositories/delorean.repo.md5
2025-09-30 05:05:28.005594 | controller | cd+++++++++ ci-framework-data/logs/
2025-09-30 05:05:28.005609 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-09-30 05:05:28.005623 | controller | cd+++++++++ registries.conf.d/
2025-09-30 05:05:28.005639 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-09-30 05:05:28.005654 | controller | cd+++++++++ system-config/
2025-09-30 05:05:28.005669 | controller | cd+++++++++ system-config/libvirt/
2025-09-30 05:05:28.005684 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-09-30 05:05:28.005698 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-09-30 05:05:28.375769 | controller | changed: .d..t...... ./
2025-09-30 05:05:28.746719 | controller | changed: .d..t...... ./
2025-09-30 05:05:28.760517 | 
2025-09-30 05:05:28.760601 | TASK [Return artifact to Zuul]
2025-09-30 05:05:28.789447 | controller | ok
2025-09-30 05:05:28.809199 | 
2025-09-30 05:05:28.809295 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-09-30 05:05:28.809405 | 
2025-09-30 05:05:28.809432 | PLAY RECAP
2025-09-30 05:05:28.809470 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-09-30 05:05:28.809492 | 
2025-09-30 05:05:28.893007 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-09-30 05:05:28.893773 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-09-30 05:05:29.419693 | 
2025-09-30 05:05:29.419827 | PLAY [all]
2025-09-30 05:05:29.437826 | 
2025-09-30 05:05:29.437898 | TASK [include_role : fetch-output]
2025-09-30 05:05:29.465990 | controller | ok
2025-09-30 05:05:29.482385 | 
2025-09-30 05:05:29.482467 | TASK [fetch-output : Set log path for multiple nodes]
2025-09-30 05:05:29.525800 | controller | skipping: Conditional result was False
2025-09-30 05:05:29.531304 | 
2025-09-30 05:05:29.531382 | TASK [fetch-output : Set log path for single node]
2025-09-30 05:05:29.559902 | controller | ok
2025-09-30 05:05:29.564832 | 
2025-09-30 05:05:29.564903 | LOOP [fetch-output : Ensure local output dirs]
2025-09-30 05:05:29.932965 | controller -> localhost | ok: "/var/lib/zuul/builds/af6d9ce10a2041fcb4fa74a48398ac24/work/logs"
2025-09-30 05:05:30.131934 | controller -> localhost | ok: "/var/lib/zuul/builds/af6d9ce10a2041fcb4fa74a48398ac24/work/artifacts"
2025-09-30 05:05:30.343963 | controller -> localhost | ok: "/var/lib/zuul/builds/af6d9ce10a2041fcb4fa74a48398ac24/work/docs"
2025-09-30 05:05:30.357458 | 
2025-09-30 05:05:30.357542 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-09-30 05:05:30.905303 | controller | ok
2025-09-30 05:05:30.905494 | controller | ok: All items complete
2025-09-30 05:05:30.905526 | 
2025-09-30 05:05:31.268760 | controller | ok
2025-09-30 05:05:31.631364 | controller | ok
2025-09-30 05:05:31.643753 | 
2025-09-30 05:05:31.643855 | TASK [include_role : fetch-output-openshift]
2025-09-30 05:05:31.657536 | controller | skipping: Conditional result was False
2025-09-30 05:05:31.663331 | 
2025-09-30 05:05:31.663407 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-09-30 05:05:32.010464 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006313
2025-09-30 05:05:32.212709 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.007336
2025-09-30 05:05:32.255238 | 
2025-09-30 05:05:32.255347 | PLAY [all]
2025-09-30 05:05:32.270527 | 
2025-09-30 05:05:32.270610 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-09-30 05:05:32.686263 | controller | changed
2025-09-30 05:05:32.708358 | 
2025-09-30 05:05:32.708432 | PLAY RECAP
2025-09-30 05:05:32.708477 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-09-30 05:05:32.708500 | 
2025-09-30 05:05:32.778578 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-09-30 05:05:32.779349 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-09-30 05:05:33.346307 | 
2025-09-30 05:05:33.346408 | PLAY [localhost]
2025-09-30 05:05:33.363801 | 
2025-09-30 05:05:33.363876 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-09-30 05:05:33.684795 | localhost | changed
2025-09-30 05:05:33.689682 | 
2025-09-30 05:05:33.689764 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-09-30 05:05:33.716820 | localhost | ok
2025-09-30 05:05:33.725204 | 
2025-09-30 05:05:33.725285 | TASK [add-fileserver : Create SSH private key tempfile]
2025-09-30 05:05:34.026202 | localhost | changed
2025-09-30 05:05:34.031864 | 
2025-09-30 05:05:34.031956 | TASK [add-fileserver : Create SSH private key from secret]
2025-09-30 05:05:34.585869 | localhost | changed
2025-09-30 05:05:34.590828 | 
2025-09-30 05:05:34.590897 | TASK [add-fileserver : Add fileserver ssh key]
2025-09-30 05:05:34.943102 | localhost | Identity added: /var/lib/zuul/builds/af6d9ce10a2041fcb4fa74a48398ac24/work/tmp/ansible.iy2wglvi (/var/lib/zuul/builds/af6d9ce10a2041fcb4fa74a48398ac24/work/tmp/ansible.iy2wglvi)
2025-09-30 05:05:34.943283 | localhost | ok: Runtime: 0:00:00.006553
2025-09-30 05:05:34.947713 | 
2025-09-30 05:05:34.947788 | TASK [add-fileserver : Remove SSH private key from disk]
2025-09-30 05:05:35.178213 | localhost | ok: Runtime: 0:00:00.004769
2025-09-30 05:05:35.183336 | 
2025-09-30 05:05:35.183418 | TASK [add-fileserver : Add fileserver to inventory]
2025-09-30 05:05:35.232242 | localhost | changed
2025-09-30 05:05:35.236400 | 
2025-09-30 05:05:35.236483 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-09-30 05:05:35.589373 | localhost | changed
2025-09-30 05:05:35.609990 | 
2025-09-30 05:05:35.610078 | PLAY [localhost]
2025-09-30 05:05:35.621648 | 
2025-09-30 05:05:35.621715 | TASK [Generate bulk log download script]
2025-09-30 05:05:35.651076 | localhost | ok
2025-09-30 05:05:35.663229 | 
2025-09-30 05:05:35.663331 | TASK [local-log-download : Check API endpoint is defined]
2025-09-30 05:05:35.691113 | localhost | ok: All assertions passed
2025-09-30 05:05:35.695589 | 
2025-09-30 05:05:35.695670 | TASK [local-log-download : Create download script]
2025-09-30 05:05:36.063053 | localhost -> localhost | changed
2025-09-30 05:05:36.072211 | 
2025-09-30 05:05:36.072292 | TASK [Register quick-download link]
2025-09-30 05:05:36.089621 | localhost | ok
2025-09-30 05:05:36.124067 | 
2025-09-30 05:05:36.124147 | PLAY [logserver.rdoproject.org]
2025-09-30 05:05:36.134133 | 
2025-09-30 05:05:36.134195 | TASK [Set zuul-log-path fact]
2025-09-30 05:05:36.150031 | logserver.rdoproject.org | ok
2025-09-30 05:05:36.159871 | 
2025-09-30 05:05:36.159959 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-09-30 05:05:36.185946 | logserver.rdoproject.org | ok
2025-09-30 05:05:36.191473 | 
2025-09-30 05:05:36.191536 | TASK [upload-logs : Create log directories]
2025-09-30 05:05:37.869488 | logserver.rdoproject.org | changed
2025-09-30 05:05:37.872994 | 
2025-09-30 05:05:37.873075 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-09-30 05:05:38.109636 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004717
2025-09-30 05:05:38.114430 | 
2025-09-30 05:05:38.114512 | TASK [upload-logs : Upload logs to log server]
2025-09-30 05:05:39.689699 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-09-30 05:05:39.692810 | 
2025-09-30 05:05:39.692874 | LOOP [upload-logs : Compress console log and json output]
2025-09-30 05:05:39.730664 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-30 05:05:39.739672 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-30 05:05:39.750290 | 
2025-09-30 05:05:39.750402 | LOOP [upload-logs : Upload compressed console log and json output]
2025-09-30 05:05:39.786050 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-30 05:05:39.786265 | 
2025-09-30 05:05:39.789070 | logserver.rdoproject.org | skipping: Conditional result was False
2025-09-30 05:05:39.797505 | 
2025-09-30 05:05:39.797602 | LOOP [upload-logs : Upload console log and json output]