2025-10-03 10:12:43.285321 | Job console starting...
2025-10-03 10:12:43.526143 | Updating repositories
2025-10-03 10:12:44.245303 | Preparing job workspace
2025-10-03 10:12:51.529961 | Running Ansible setup...
2025-10-03 10:12:54.707272 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 10:12:55.250887 | 
2025-10-03 10:12:55.251021 | PLAY [localhost]
2025-10-03 10:12:55.266586 | 
2025-10-03 10:12:55.266678 | TASK [Gathering Facts]
2025-10-03 10:12:56.155277 | localhost | ok
2025-10-03 10:12:56.169372 | 
2025-10-03 10:12:56.169490 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-10-03 10:12:56.540960 | localhost -> localhost | changed
2025-10-03 10:12:56.546677 | 
2025-10-03 10:12:56.546770 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-10-03 10:12:57.339755 | localhost -> localhost | changed
2025-10-03 10:12:57.348772 | 
2025-10-03 10:12:57.348855 | TASK [Setup log path fact]
2025-10-03 10:12:57.366087 | localhost | ok
2025-10-03 10:12:57.377660 | 
2025-10-03 10:12:57.377747 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 10:12:57.404806 | localhost | ok
2025-10-03 10:12:57.413150 | 
2025-10-03 10:12:57.413226 | TASK [emit-job-header : Print job information]
2025-10-03 10:12:57.440460 | # Job Information
2025-10-03 10:12:57.440586 | Ansible Version: 2.15.12
2025-10-03 10:12:57.440617 | Job: cifmw-molecule-ssh_jumper
2025-10-03 10:12:57.440639 | Pipeline: github-check
2025-10-03 10:12:57.440660 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-10-03 10:12:57.440680 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3362
2025-10-03 10:12:57.440701 | Log URL (when completed): https://logserver.rdoproject.org/223/rdoproject.org/223947a67f58454eb874644eabb7a2c2/
2025-10-03 10:12:57.440738 | Event ID: 79314020-a03f-11f0-87f2-6df8ed647fba
2025-10-03 10:12:57.444547 | 
2025-10-03 10:12:57.444616 | LOOP [emit-job-header : Print node information]
2025-10-03 10:12:57.538558 | localhost | ok:
2025-10-03 10:12:57.538820 | localhost | # Node Information
2025-10-03 10:12:57.538863 | localhost | Inventory Hostname: controller
2025-10-03 10:12:57.538891 | localhost | Hostname: np0005468643
2025-10-03 10:12:57.538941 | localhost | Username: zuul
2025-10-03 10:12:57.538967 | localhost | Distro: CentOS 9
2025-10-03 10:12:57.538988 | localhost | Provider: ibm-bm4-nodepool
2025-10-03 10:12:57.539007 | localhost | Region: regionOne
2025-10-03 10:12:57.539025 | localhost | Label: cloud-centos-9-stream-tripleo-ibm
2025-10-03 10:12:57.539284 | localhost | Product Name: OpenStack Compute
2025-10-03 10:12:57.539331 | localhost | Interface IP: 192.168.26.235
2025-10-03 10:12:57.561229 | 
2025-10-03 10:12:57.561316 | PLAY [all]
2025-10-03 10:12:57.567499 | 
2025-10-03 10:12:57.567562 | TASK [Gather network facts]
2025-10-03 10:12:57.922009 | controller | ok
2025-10-03 10:12:57.937516 | 
2025-10-03 10:12:57.937597 | TASK [include_role : start-zuul-console]
2025-10-03 10:12:57.956449 | controller | ok
2025-10-03 10:12:57.968181 | 
2025-10-03 10:12:57.968258 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-10-03 10:12:58.301088 | controller | ok
2025-10-03 10:12:58.310598 | 
2025-10-03 10:12:58.310690 | TASK [include_role : add-build-sshkey]
2025-10-03 10:12:58.329431 | controller | ok
2025-10-03 10:12:58.343073 | 
2025-10-03 10:12:58.343175 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-10-03 10:12:58.560274 | controller -> localhost | ok
2025-10-03 10:12:58.565892 | 
2025-10-03 10:12:58.565994 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-10-03 10:12:58.585925 | controller | ok
2025-10-03 10:12:58.599539 | controller | included: /var/lib/zuul/builds/223947a67f58454eb874644eabb7a2c2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-10-03 10:12:58.605421 | 
2025-10-03 10:12:58.605498 | TASK [add-build-sshkey : Create Temp SSH key]
2025-10-03 10:12:59.097045 | controller -> localhost | Generating public/private rsa key pair.
2025-10-03 10:12:59.097278 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/223947a67f58454eb874644eabb7a2c2/work/223947a67f58454eb874644eabb7a2c2_id_rsa.
2025-10-03 10:12:59.097322 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/223947a67f58454eb874644eabb7a2c2/work/223947a67f58454eb874644eabb7a2c2_id_rsa.pub.
2025-10-03 10:12:59.097348 | controller -> localhost | The key fingerprint is:
2025-10-03 10:12:59.097372 | controller -> localhost | SHA256:0CRFLdK9HrE5zuvxN5+7u7i7mL2hRwNfB8hb1vidZdo zuul-build-sshkey
2025-10-03 10:12:59.097394 | controller -> localhost | The key's randomart image is:
2025-10-03 10:12:59.097414 | controller -> localhost | +---[RSA 3072]----+
2025-10-03 10:12:59.097437 | controller -> localhost | |      .++o . . o |
2025-10-03 10:12:59.097460 | controller -> localhost | |      .+o + o = +|
2025-10-03 10:12:59.097480 | controller -> localhost | |      .... = + *+|
2025-10-03 10:12:59.097499 | controller -> localhost | |       .  *.. .oE|
2025-10-03 10:12:59.097518 | controller -> localhost | |        S+ oo . .|
2025-10-03 10:12:59.097535 | controller -> localhost | |          +  +   |
2025-10-03 10:12:59.097552 | controller -> localhost | |          .....  |
2025-10-03 10:12:59.097573 | controller -> localhost | |          .o=.= .|
2025-10-03 10:12:59.097590 | controller -> localhost | |         ..+oO=O*|
2025-10-03 10:12:59.097609 | controller -> localhost | +----[SHA256]-----+
2025-10-03 10:12:59.097666 | controller -> localhost | ok: Runtime: 0:00:00.064145
2025-10-03 10:12:59.103576 | 
2025-10-03 10:12:59.103647 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-10-03 10:12:59.132133 | controller | ok
2025-10-03 10:12:59.142285 | controller | included: /var/lib/zuul/builds/223947a67f58454eb874644eabb7a2c2/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-10-03 10:12:59.150735 | 
2025-10-03 10:12:59.150817 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-10-03 10:12:59.174949 | controller | skipping: Conditional result was False
2025-10-03 10:12:59.181156 | 
2025-10-03 10:12:59.181247 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-10-03 10:12:59.609020 | controller | changed
2025-10-03 10:12:59.614635 | 
2025-10-03 10:12:59.614703 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-10-03 10:12:59.814662 | controller | ok
2025-10-03 10:12:59.819346 | 
2025-10-03 10:12:59.819411 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-10-03 10:13:00.420088 | controller | changed
2025-10-03 10:13:00.425334 | 
2025-10-03 10:13:00.425408 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-10-03 10:13:00.998565 | controller | changed
2025-10-03 10:13:01.005001 | 
2025-10-03 10:13:01.005515 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-10-03 10:13:01.019307 | controller | skipping: Conditional result was False
2025-10-03 10:13:01.026759 | 
2025-10-03 10:13:01.026842 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-10-03 10:13:01.405887 | controller -> localhost | changed
2025-10-03 10:13:01.416798 | 
2025-10-03 10:13:01.416886 | TASK [add-build-sshkey : Add back temp key]
2025-10-03 10:13:01.687017 | controller -> localhost | Identity added: /var/lib/zuul/builds/223947a67f58454eb874644eabb7a2c2/work/223947a67f58454eb874644eabb7a2c2_id_rsa (zuul-build-sshkey)
2025-10-03 10:13:01.687209 | controller -> localhost | ok: Runtime: 0:00:00.009254
2025-10-03 10:13:01.693639 | 
2025-10-03 10:13:01.693722 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-10-03 10:13:02.054864 | controller | ok
2025-10-03 10:13:02.061395 | 
2025-10-03 10:13:02.061464 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-10-03 10:13:02.085085 | controller | skipping: Conditional result was False
2025-10-03 10:13:02.094904 | 
2025-10-03 10:13:02.094994 | TASK [include_role : validate-host]
2025-10-03 10:13:02.113302 | controller | ok
2025-10-03 10:13:02.134751 | 
2025-10-03 10:13:02.134834 | TASK [validate-host : Define zuul_info_dir fact]
2025-10-03 10:13:02.162957 | controller | ok
2025-10-03 10:13:02.167837 | 
2025-10-03 10:13:02.167925 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-10-03 10:13:02.373506 | controller -> localhost | ok
2025-10-03 10:13:02.379234 | 
2025-10-03 10:13:02.379303 | TASK [validate-host : Collect information about the host]
2025-10-03 10:13:02.975788 | controller | ok
2025-10-03 10:13:02.984481 | 
2025-10-03 10:13:02.984549 | TASK [validate-host : Sanitize hostname]
2025-10-03 10:13:03.074372 | controller | ok
2025-10-03 10:13:03.078856 | 
2025-10-03 10:13:03.078957 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-10-03 10:13:03.468245 | controller -> localhost | changed
2025-10-03 10:13:03.473987 | 
2025-10-03 10:13:03.474078 | TASK [validate-host : Collect information about zuul worker]
2025-10-03 10:13:03.815149 | controller | ok
2025-10-03 10:13:03.820697 | 
2025-10-03 10:13:03.820808 | TASK [validate-host : Write out all zuul information for each host]
2025-10-03 10:13:04.189320 | controller -> localhost | changed
2025-10-03 10:13:04.200816 | 
2025-10-03 10:13:04.200902 | TASK [include_role : prepare-workspace-openshift]
2025-10-03 10:13:04.216585 | controller | skipping: Conditional result was False
2025-10-03 10:13:04.223504 | 
2025-10-03 10:13:04.223579 | TASK [include_role : remove-zuul-sshkey]
2025-10-03 10:13:04.236899 | controller | skipping: Conditional result was False
2025-10-03 10:13:04.242535 | 
2025-10-03 10:13:04.242730 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-10-03 10:13:04.433122 | controller | ok: "logs"
2025-10-03 10:13:04.433335 | controller | ok: All items complete
2025-10-03 10:13:04.433370 | 
2025-10-03 10:13:04.594819 | controller | ok: "artifacts"
2025-10-03 10:13:04.755853 | controller | ok: "docs"
2025-10-03 10:13:04.766822 | 
2025-10-03 10:13:04.766915 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-10-03 10:13:04.959552 | controller | changed: "logs"
2025-10-03 10:13:05.134383 | controller | changed: "artifacts"
2025-10-03 10:13:05.329420 | controller | changed: "docs"
2025-10-03 10:13:05.361696 | 
2025-10-03 10:13:05.361809 | PLAY RECAP
2025-10-03 10:13:05.361858 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-03 10:13:05.361888 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 10:13:05.361931 | 
2025-10-03 10:13:05.445866 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-10-03 10:13:05.446888 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-03 10:13:06.066758 | 
2025-10-03 10:13:06.066932 | PLAY [all]
2025-10-03 10:13:06.088172 | 
2025-10-03 10:13:06.088261 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-03 10:13:06.147845 | controller | ok
2025-10-03 10:13:06.152775 | 
2025-10-03 10:13:06.152864 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-03 10:13:06.516760 | controller | changed
2025-10-03 10:13:06.526083 | 
2025-10-03 10:13:06.526166 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-03 10:13:07.334232 | controller | changed
2025-10-03 10:13:07.344661 | 
2025-10-03 10:13:07.344765 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-10-03 10:13:07.711079 | controller | changed:
2025-10-03 10:13:07.711251 | controller | {
2025-10-03 10:13:07.711281 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-10-03 10:13:07.711310 | controller | }
2025-10-03 10:13:07.907630 | controller | changed:
2025-10-03 10:13:07.907764 | controller | {
2025-10-03 10:13:07.907795 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-10-03 10:13:07.907819 | controller | }
2025-10-03 10:13:08.111404 | controller | changed:
2025-10-03 10:13:08.111546 | controller | {
2025-10-03 10:13:08.111578 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-10-03 10:13:08.111600 | controller | }
2025-10-03 10:13:08.308398 | controller | changed:
2025-10-03 10:13:08.308493 | controller | {
2025-10-03 10:13:08.308521 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-10-03 10:13:08.308542 | controller | }
2025-10-03 10:13:08.508372 | controller | changed:
2025-10-03 10:13:08.508550 | controller | {
2025-10-03 10:13:08.508582 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-10-03 10:13:08.508603 | controller | }
2025-10-03 10:13:08.715770 | controller | changed:
2025-10-03 10:13:08.715930 | controller | {
2025-10-03 10:13:08.715963 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-10-03 10:13:08.715987 | controller | }
2025-10-03 10:13:08.934233 | controller | changed:
2025-10-03 10:13:08.934360 | controller | {
2025-10-03 10:13:08.934389 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDLOQd4ZLtkZXQGY6UwAr/06ppWQK4fDO3HaqxPk98csyOCBXsliSKK39Bso828+5srIXiW7aI6aC9P5mwi4mUZlGPfJlQbfrcGvY+b/SocuvaGK+1RrHLoJCT52LBhwgrzlXio2jeksZeein8iaTrhsPrOAs7KggIL/rB9hEiB3NaOPWhhoCP4vlW6MEMExGcqB/1FVxXFBPnLkEyW0Lk7ycVflZl2ocRxbfjZi0+tI1Wlinp8PvSQSc/WVrAcDgKjc/mB4ODPOyYy3G8FHgfMsrXSDEyjBKgLKMsdCrAUcqJQWjkqXleXSYOV4q3pzL+9umK+q/e3P/bIoSFQzmJKTU1eDfuvPXmow9F5H54fii/Da7ezlMJ+wPGHJrRAkmzvMbALy7xwswLhZMkOGNtRcPqaKYRmIBKpw3o6bCTtcNUHOtOQnzwY8JzrM2eBWJBXAANYw+9/ho80JIiwhg29CFNpVBuHbql2YxJQNrnl90guN65rYNpDxdIluweyUf8= anbanerj@kaermorhen"
2025-10-03 10:13:08.934411 | controller | }
2025-10-03 10:13:09.141411 | controller | changed:
2025-10-03 10:13:09.141516 | controller | {
2025-10-03 10:13:09.141554 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQC3VwV8Im9kRm49lt3tM36hj4Zv27FxGo4C1Q/0jqhzFmHY7RHbmeRr8ObhwWoHjXSozKWg8FL5ER0z3hTwL0W6lez3sL7hUaCmSuZmG5Hnl3x4vTSxDI9JZ/Y65rtYiiWQo2fC5xJhU/4+0e5e/pseCm8cKRSu+SaxhO+sd6FDojA2x1BzOzKiQRDy/1zWGp/cZkxcEuB1wHI5LMzN03c67vmbu+fhZRAUO4dQkvcnj2LrhQtpa+ytvnSjr8icMDosf1OsbSffwZFyHB/hfWGAfe0eIeSA2XPraxiPknXxiPKx2MJsaUTYbsZcm3EjFdHBBMumw5rBI74zLrMRvCO9GwBEmGT4rFng1nP+yw5DB8sn2zqpOsPg1LYRwCPOUveC13P6pgsZZPh812e8v5EKnETct+5XI3dVpdw6CnNiLwAyVAF15DJvBGT/u1k0Myg/bQn+Gv9k2MSj6LvQmf6WbZu2Wgjm30z3FyCneBqTL7mLF19YXzeC0ufHz5pnO1E= dasm@fedora"
2025-10-03 10:13:09.141584 | controller | }
2025-10-03 10:13:09.365474 | controller | changed:
2025-10-03 10:13:09.367183 | controller | {
2025-10-03 10:13:09.367239 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-10-03 10:13:09.367266 | controller | }
2025-10-03 10:13:09.594426 | controller | changed:
2025-10-03 10:13:09.594605 | controller | {
2025-10-03 10:13:09.594642 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-10-03 10:13:09.594665 | controller | }
2025-10-03 10:13:09.801444 | controller | changed:
2025-10-03 10:13:09.801538 | controller | {
2025-10-03 10:13:09.801566 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-10-03 10:13:09.801586 | controller | }
2025-10-03 10:13:10.032743 | controller | changed:
2025-10-03 10:13:10.032831 | controller | {
2025-10-03 10:13:10.032858 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-10-03 10:13:10.032879 | controller | }
2025-10-03 10:13:10.215020 | controller | changed:
2025-10-03 10:13:10.215114 | controller | {
2025-10-03 10:13:10.215144 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-10-03 10:13:10.215166 | controller | }
2025-10-03 10:13:10.426884 | controller | changed:
2025-10-03 10:13:10.426999 | controller | {
2025-10-03 10:13:10.427027 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-10-03 10:13:10.427047 | controller | }
2025-10-03 10:13:10.629705 | controller | changed:
2025-10-03 10:13:10.629871 | controller | {
2025-10-03 10:13:10.629928 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-10-03 10:13:10.629959 | controller | }
2025-10-03 10:13:10.836964 | controller | changed:
2025-10-03 10:13:10.837054 | controller | {
2025-10-03 10:13:10.837080 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-10-03 10:13:10.837100 | controller | }
2025-10-03 10:13:11.058231 | controller | changed:
2025-10-03 10:13:11.058327 | controller | {
2025-10-03 10:13:11.058354 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQCfNtF7NvKl915TGsGGoseUb06Hj8L/S4toWf0hExeY+F00woL6NvBlJD0nDct+P5a22I4EhvoQCRQ8reaPCm1lybR3uiRIJsj+8zkVvLwby9LXzfZorlNG9ofjd00FEmB09uW/YvTl6Q9XwwwX6tInzIOv3TMqTHHGOL74ibbj8J/FJR0cFEyj0z4WQRvtkh32xAHl83gbuINryMt0sqRI+clj2381NKL55DRLQrVw0gsfqqxiHAnXg21qWmc4J+b9e9kiuAFQjcjwTVkwJCcg3xbPwC/qokYRby/Y5S40UUd7/jEARGXT7RZgpzTuDd1oZiCVrnrqJNPaMNdVv5MLeFdf1B7iIe5aa/fGouX7AO4SdKhZUdnJmCFAGvjC6S3JMZ2wAcUl+OHnssfmdj7XL50cLo27vjuzMtLAgSqi6N99m92WCF2s8J9aVzszX7Xz9OKZCeGsiVJp3/NdABKzSEAyM9xBD/5Vho894Sav+otpySHe3p6RUTgbB5Zu8VyZRZ/UtB3ueXxyo764yrc6qWIDqrehm84Xm9g+/jpIBzGPl07NUNJpdt/6Sgf9RIKXw/7XypO5yZfUcuFNGTxLfqjTNrtgLZNcjfav6sSdVXVcMPL//XNuRdKmVFaO76eV/oGMQGr1fGcCD+N+CpI7+Q+fCNB6VFWG4nZFuI/Iuw== averdagu@redhat.com"
2025-10-03 10:13:11.058375 | controller | }
2025-10-03 10:13:11.262398 | controller | changed:
2025-10-03 10:13:11.262493 | controller | {
2025-10-03 10:13:11.262520 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABgQDq8l27xI+QlQVdS4djp9ogSoyrNE2+Ox6vKPdhSNL1J3PE5w+WCSvMz9A5gnNuH810zwbekEApbxTze/gLQJwBHA52CChfURpXrFaxY7ePXRElwKAL3mJfzBWY/c5jnNL9TCVmFJTGZkFZP3Nh+BMgZvL6xBkt3WKm6Uq18qzd9XeKcZusrA+O+uLv1fVeQnadY9RIqOCyeFYCzLWrUfTyE8x/XG0hAWIM7qpnF2cALQS2h9n4hW5ybiUN790H08wf9hFwEf5nxY9Z9dVkPFQiTSGKNBzmnCXU9skxS/xhpFjJ5duGSZdtAHe9O+nGZm9c67hxgtf8e5PDuqAdXEv2cf6e3VBAt+Bz8EKI3yosTj0oZHfwr42Yzb1l/SKy14Rggsrc9KAQlrGXan6+u2jcQqqx7l+SWmnpFiWTV9u5cWj2IgOhApOitmRBPYqk9rE2usfO0hLn/Pj/R/Nau4803e1/EikdLE7Ps95s9mX5jRDjAoUa2JwFF5RsVFyL910= ashigupt@ashigupt.remote.csb"
2025-10-03 10:13:11.262548 | controller | }
2025-10-03 10:13:11.464777 | controller | changed:
2025-10-03 10:13:11.464868 | controller | {
2025-10-03 10:13:11.464893 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-10-03 10:13:11.464932 | controller | }
2025-10-03 10:13:11.681145 | controller | changed:
2025-10-03 10:13:11.681227 | controller | {
2025-10-03 10:13:11.681254 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-10-03 10:13:11.681275 | controller | }
2025-10-03 10:13:11.880137 | controller | changed:
2025-10-03 10:13:11.880226 | controller | {
2025-10-03 10:13:11.880252 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-10-03 10:13:11.880273 | controller | }
2025-10-03 10:13:12.080547 | controller | changed:
2025-10-03 10:13:12.080632 | controller | {
2025-10-03 10:13:12.080659 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-10-03 10:13:12.080680 | controller | }
2025-10-03 10:13:12.280631 | controller | changed:
2025-10-03 10:13:12.280731 | controller | {
2025-10-03 10:13:12.280761 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAACAQDZdI7t1cxYx65heVI24HTV4F7oQLW1zyfxHreL2TIJKxjyrUUKIFEUmTutcBlJRLNT2Eoix6x1sOw9YrchloCLcn//SGfTElr9mSc5jbjb7QXEU+zJMhtxyEJ1Po3CUGnj7ckiIXw7wcawZtrEOAQ9pH3ExYCJcEMiyNjRQZCxT3tPK+S4B95EWh5Fsrz9CkwpjNRPPH7LigCeQTM3Wc7r97utAslBUUvYceDSLA7rMgkitJE38b7rZBeYzsGQ8YYUBjTCtehqQXxCRjizbHWaaZkBU+N3zkKB6n/iCNGIO690NK7A/qb6msTijiz1PeuM8ThOsi9qXnbX5v0PoTpcFSojV7NHAQ71f0XXuS43FhZctT+Dcx44dT8Fb5vJu2cJGrk+qF8ZgJYNpRS7gPg0EG2EqjK7JMf9ULdjSu0r+KlqIAyLvtzT4eOnQipoKlb/WG5D/0ohKv7OMQ352ggfkBFIQsRXyyTCT98Ft9juqPuahi3CAQmP4H9dyE+7+Kz437PEtsxLmfm6naNmWi7Ee1DqWPwS8rEajsm4sNM4wW9gdBboJQtc0uZw0DfLj1I9r3Mc8Ol0jYtz0yNQDSzVLrGCaJlC311trU70tZ+ZkAVV6Mn8lOhSbj1cK0lvSr6ZK4dgqGl3I1eTZJJhbLNdg7UOVaiRx9543+C/p/As7w== brjackma@redhat.com"
2025-10-03 10:13:12.280783 | controller | }
2025-10-03 10:13:12.478761 | controller | changed:
2025-10-03 10:13:12.478850 | controller | {
2025-10-03 10:13:12.478878 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-10-03 10:13:12.478899 | controller | }
2025-10-03 10:13:12.693888 | controller | changed:
2025-10-03 10:13:12.693991 | controller | {
2025-10-03 10:13:12.694021 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-10-03 10:13:12.694042 | controller | }
2025-10-03 10:13:12.899092 | controller | changed:
2025-10-03 10:13:12.899313 | controller | {
2025-10-03 10:13:12.899343 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-10-03 10:13:12.899366 | controller | }
2025-10-03 10:13:12.916237 | 
2025-10-03 10:13:12.916319 | TASK [Set timezone to UTC]
2025-10-03 10:13:13.329822 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-10-03 10:13:13.335055 | 
2025-10-03 10:13:13.335142 | TASK [Create nodepool directory]
2025-10-03 10:13:13.557080 | controller | changed
2025-10-03 10:13:13.562592 | 
2025-10-03 10:13:13.562689 | TASK [Create nodepool sub_nodes file]
2025-10-03 10:13:14.050053 | controller | changed
2025-10-03 10:13:14.056501 | 
2025-10-03 10:13:14.056592 | TASK [Create nodepool sub_nodes_private file]
2025-10-03 10:13:14.553643 | controller | changed
2025-10-03 10:13:14.558745 | 
2025-10-03 10:13:14.558828 | LOOP [Populate nodepool sub_nodes file]
2025-10-03 10:13:14.587871 | 
2025-10-03 10:13:14.588012 | LOOP [Populate nodepool sub_nodes_private file]
2025-10-03 10:13:14.617089 | 
2025-10-03 10:13:14.617216 | TASK [Create nodepool primary file]
2025-10-03 10:13:14.640747 | controller | skipping: Conditional result was False
2025-10-03 10:13:14.646630 | 
2025-10-03 10:13:14.646721 | TASK [Create nodepool node_private for this node]
2025-10-03 10:13:15.184452 | controller | changed
2025-10-03 10:13:15.191825 | 
2025-10-03 10:13:15.191898 | LOOP [Copy ssh keys to nodepool directory]
2025-10-03 10:13:15.519276 | controller | ok: Item: id_rsa Runtime: 0:00:00.005343
2025-10-03 10:13:15.519443 | 
2025-10-03 10:13:15.680227 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.004414
2025-10-03 10:13:15.687261 | 
2025-10-03 10:13:15.687357 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-10-03 10:13:16.213189 | controller | changed
2025-10-03 10:13:16.218936 | 
2025-10-03 10:13:16.219004 | TASK [Validate sudoers config after edits]
2025-10-03 10:13:16.435269 | controller | /etc/sudoers: parsed OK
2025-10-03 10:13:16.435347 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-10-03 10:13:16.435356 | controller | /etc/sudoers.d/zuul: parsed OK
2025-10-03 10:13:16.435362 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-10-03 10:13:16.744665 | controller | ok: Runtime: 0:00:00.005213
2025-10-03 10:13:16.751010 | 
2025-10-03 10:13:16.751094 | TASK [Show the environment passed in to job shell scripts]
2025-10-03 10:13:16.983122 | controller | SHELL=/bin/bash
2025-10-03 10:13:16.983163 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-10-03 10:13:16.983172 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-10-03 10:13:16.983178 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/62/3362/41f2edaa0ac45cd85919f70775e84cf472326a6e
2025-10-03 10:13:16.983184 | controller | PWD=/home/zuul
2025-10-03 10:13:16.983190 | controller | ZUUL_PIPELINE=github-check
2025-10-03 10:13:16.983195 | controller | LOGNAME=zuul
2025-10-03 10:13:16.983201 | controller | XDG_SESSION_TYPE=tty
2025-10-03 10:13:16.983206 | controller | _=/usr/bin/env
2025-10-03 10:13:16.983212 | controller | MOTD_SHOWN=pam
2025-10-03 10:13:16.983217 | controller | HOME=/home/zuul
2025-10-03 10:13:16.983222 | controller | LANG=en_US.UTF-8
2025-10-03 10:13:16.983260 | controller | SSH_CONNECTION=192.168.26.12 58830 192.168.26.235 22
2025-10-03 10:13:16.983269 | controller | TOX_TESTENV_PASSENV=ZUUL_UUID ZUUL_PROJECT ZUUL_SHORT_PROJECT_NAME ZUUL_PIPELINE ZUUL_VOTING WORKSPACE BUILD_TIMEOUT ZUUL_BRANCH ZUUL_CHANGES ZUUL_CHANGE_IDS ZUUL_CHANGE ZUUL_PATCHSET
2025-10-03 10:13:16.983277 | controller | ZUUL_CHANGE_IDS=3362,41f2edaa0ac45cd85919f70775e84cf472326a6e
2025-10-03 10:13:16.983283 | controller | WORKSPACE=/home/zuul/workspace
2025-10-03 10:13:16.983288 | controller | XDG_SESSION_CLASS=user
2025-10-03 10:13:16.983294 | controller | SELINUX_ROLE_REQUESTED=
2025-10-03 10:13:16.983299 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-10-03 10:13:16.983304 | controller | USER=zuul
2025-10-03 10:13:16.983309 | controller | ZUUL_VOTING=True
2025-10-03 10:13:16.983314 | controller | BUILD_TIMEOUT=1800000
2025-10-03 10:13:16.983320 | controller | SELINUX_USE_CURRENT_RANGE=
2025-10-03 10:13:16.983325 | controller | SHLVL=1
2025-10-03 10:13:16.983330 | controller | ZUUL_PATCHSET=41f2edaa0ac45cd85919f70775e84cf472326a6e
2025-10-03 10:13:16.983335 | controller | XDG_SESSION_ID=1
2025-10-03 10:13:16.983341 | controller | ZUUL_BRANCH=main
2025-10-03 10:13:16.983346 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-10-03 10:13:16.983351 | controller | SSH_CLIENT=192.168.26.12 58830 22
2025-10-03 10:13:16.983357 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-10-03 10:13:16.983362 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-10-03 10:13:16.983387 | controller | which_declare=declare -f
2025-10-03 10:13:16.983393 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-10-03 10:13:16.983399 | controller | SELINUX_LEVEL_REQUESTED=
2025-10-03 10:13:16.983404 | controller | ZUUL_CHANGE=3362
2025-10-03 10:13:16.983409 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-10-03 10:13:16.983414 | controller | ZUUL_UUID=223947a67f58454eb874644eabb7a2c2
2025-10-03 10:13:16.983421 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-10-03 10:13:16.983427 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-10-03 10:13:16.983432 | controller | }
2025-10-03 10:13:17.281803 | controller | ok: Runtime: 0:00:00.005837
2025-10-03 10:13:17.287311 | 
2025-10-03 10:13:17.287380 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-10-03 10:13:17.301194 | controller | skipping: Conditional result was False
2025-10-03 10:13:17.306841 | 
2025-10-03 10:13:17.306946 | TASK [Symlink /home/zuul-worker/workspace]
2025-10-03 10:13:17.834326 | controller | skipping: Conditional result was False
2025-10-03 10:13:17.840435 | 
2025-10-03 10:13:17.840508 | TASK [Ensure legacy workspace directory]
2025-10-03 10:13:18.031538 | controller | changed
2025-10-03 10:13:18.050307 | 
2025-10-03 10:13:18.050372 | PLAY RECAP
2025-10-03 10:13:18.050417 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-10-03 10:13:18.050440 | 
2025-10-03 10:13:18.144698 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-10-03 10:13:18.145482 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-03 10:13:18.722323 | 
2025-10-03 10:13:18.722472 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-10-03 10:13:18.743886 | 
2025-10-03 10:13:18.744007 | TASK [Create zuul-output directory]
2025-10-03 10:13:19.079190 | controller | changed
2025-10-03 10:13:19.084765 | 
2025-10-03 10:13:19.084852 | TASK [Slurp Zuul inventory test]
2025-10-03 10:13:19.373806 | controller -> localhost | ok
2025-10-03 10:13:19.380333 | 
2025-10-03 10:13:19.380408 | TASK [Save zuul inventory]
2025-10-03 10:13:20.118353 | controller | changed
2025-10-03 10:13:20.124051 | 
2025-10-03 10:13:20.124125 | TASK [Save zuul vars without the change_message]
2025-10-03 10:13:20.717573 | controller | changed
2025-10-03 10:13:20.737137 | 
2025-10-03 10:13:20.737193 | PLAY RECAP
2025-10-03 10:13:20.737238 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-10-03 10:13:20.737262 | 
2025-10-03 10:13:20.810284 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-10-03 10:13:20.811082 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-03 10:13:21.402599 | 
2025-10-03 10:13:21.402725 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-10-03 10:13:21.424239 | 
2025-10-03 10:13:21.424351 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-10-03 10:13:21.443388 | controller | ok
2025-10-03 10:13:21.461885 | 
2025-10-03 10:13:21.462008 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-10-03 10:13:21.486099 | controller | skipping: Conditional result was False
2025-10-03 10:13:21.492181 | 
2025-10-03 10:13:21.492275 | TASK [mirror-info-fork : Create /etc/ci]
2025-10-03 10:13:21.817125 | controller | ok
2025-10-03 10:13:21.822831 | 
2025-10-03 10:13:21.822944 | TASK [mirror-info-fork : Install ci_mirror script]
2025-10-03 10:13:22.439123 | controller | ok
2025-10-03 10:13:22.449460 | 
2025-10-03 10:13:22.449549 | TASK [Prepare workspace]
2025-10-03 10:13:22.468755 | controller | ok
2025-10-03 10:13:22.485672 | 
2025-10-03 10:13:22.485765 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-10-03 10:13:22.788315 | controller | ok
2025-10-03 10:13:22.794282 | 
2025-10-03 10:13:22.794375 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-10-03 10:13:24.907760 | controller | Output suppressed because no_log was given
2025-10-03 10:13:24.916948 | 
2025-10-03 10:13:24.917038 | LOOP [Create zuul-output directory]
2025-10-03 10:13:25.104829 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-10-03 10:13:25.262534 | controller | ok: "/home/zuul/zuul-output/logs"
2025-10-03 10:13:25.272528 | 
2025-10-03 10:13:25.272635 | TASK [Install required packages]
2025-10-03 10:14:16.144094 | controller | changed
2025-10-03 10:14:16.149808 | 
2025-10-03 10:14:16.149987 | TASK [Install venv]
2025-10-03 10:15:17.716531 | controller | changed
2025-10-03 10:15:17.743772 | 
2025-10-03 10:15:17.743865 | PLAY RECAP
2025-10-03 10:15:17.743930 | controller | ok: 7 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-03 10:15:17.743962 | 
2025-10-03 10:15:17.851365 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-10-03 10:15:17.852451 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-03 10:15:18.401794 | 
2025-10-03 10:15:18.401903 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-10-03 10:15:18.422339 | 
2025-10-03 10:15:18.422428 | TASK [Gather required facts]
2025-10-03 10:15:18.938864 | controller | ok
2025-10-03 10:15:18.945269 | 
2025-10-03 10:15:18.945380 | TASK [Load environment var if instructed to]
2025-10-03 10:15:18.969760 | controller | skipping: Conditional result was False
2025-10-03 10:15:18.975679 | 
2025-10-03 10:15:18.975802 | TASK [Run molecule]
2025-10-03 10:15:19.933563 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-10-03 10:15:20.003990 | controller | INFO     Performing prerun with role_name_check=0...
2025-10-03 10:15:36.558997 | controller | WARNING  Another version of '@NAMESPACE@.@NAME@' 3.1.4 was found installed in /home/zuul/.cache/ansible-compat/4656e4/collections/ansible_collections, only the first one will be used, 3.1.4 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-03 10:15:36.559470 | controller | WARNING  Another version of 'ansible.netcommon' 7.1.0 was found installed in /home/zuul/.cache/ansible-compat/4656e4/collections/ansible_collections, only the first one will be used, 7.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-03 10:15:36.559922 | controller | WARNING  Another version of 'ansible.posix' 1.6.2 was found installed in /home/zuul/.cache/ansible-compat/4656e4/collections/ansible_collections, only the first one will be used, 1.6.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-03 10:15:36.560379 | controller | WARNING  Another version of 'ansible.utils' 5.1.2 was found installed in /home/zuul/.cache/ansible-compat/4656e4/collections/ansible_collections, only the first one will be used, 5.1.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-03 10:15:36.560863 | controller | WARNING  Another version of 'cifmw.general' 1.0.0+41f2edaa was found installed in /home/zuul/.cache/ansible-compat/4656e4/collections/ansible_collections, only the first one will be used, 1.0.0+41f2edaa (/home/zuul/.ansible/collections/ansible_collections).
2025-10-03 10:15:36.561307 | controller | WARNING  Another version of 'cisco.ios' 9.0.3 was found installed in /home/zuul/.cache/ansible-compat/4656e4/collections/ansible_collections, only the first one will be used, 9.0.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-03 10:15:36.561756 | controller | WARNING  Another version of 'community.crypto' 2.22.3 was found installed in /home/zuul/.cache/ansible-compat/4656e4/collections/ansible_collections, only the first one will be used, 2.22.3 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-03 10:15:36.562211 | controller | WARNING  Another version of 'community.general' 10.0.1 was found installed in /home/zuul/.cache/ansible-compat/4656e4/collections/ansible_collections, only the first one will be used, 10.0.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-03 10:15:36.562655 | controller | WARNING  Another version of 'community.libvirt' 1.3.0 was found installed in /home/zuul/.cache/ansible-compat/4656e4/collections/ansible_collections, only the first one will be used, 1.3.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-03 10:15:36.563128 | controller | WARNING  Another version of 'community.okd' 4.0.0 was found installed in /home/zuul/.cache/ansible-compat/4656e4/collections/ansible_collections, only the first one will be used, 4.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-03 10:15:36.563583 | controller | WARNING  Another version of 'containers.podman' 1.16.2 was found installed in /home/zuul/.cache/ansible-compat/4656e4/collections/ansible_collections, only the first one will be used, 1.16.2 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-03 10:15:36.564022 | controller | WARNING  Another version of 'junipernetworks.junos' 9.1.0 was found installed in /home/zuul/.cache/ansible-compat/4656e4/collections/ansible_collections, only the first one will be used, 9.1.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-03 10:15:36.564474 | controller | WARNING  Another version of 'kubernetes.core' 5.0.0 was found installed in /home/zuul/.cache/ansible-compat/4656e4/collections/ansible_collections, only the first one will be used, 5.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-03 10:15:36.564905 | controller | WARNING  Another version of 'mellanox.onyx' 1.0.0 was found installed in /home/zuul/.cache/ansible-compat/4656e4/collections/ansible_collections, only the first one will be used, 1.0.0 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-03 10:15:36.565360 | controller | WARNING  Another version of 'openstack.config_template' 2.1.1 was found installed in /home/zuul/.cache/ansible-compat/4656e4/collections/ansible_collections, only the first one will be used, 2.1.1 (/home/zuul/.ansible/collections/ansible_collections).
2025-10-03 10:15:36.574585 | controller | INFO     Running default > prepare
2025-10-03 10:15:37.224960 | controller |
2025-10-03 10:15:37.225079 | controller | PLAY [Prepare] *****************************************************************
2025-10-03 10:15:37.225175 | controller |
2025-10-03 10:15:37.225276 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 10:15:37.225390 | controller | Friday 03 October 2025  10:15:37 +0000 (0:00:00.012)       0:00:00.012 ********
2025-10-03 10:15:38.022631 | controller | ok: [instance]
2025-10-03 10:15:38.022734 | controller |
2025-10-03 10:15:38.022892 | controller | TASK [Create custom basedir] ***************************************************
2025-10-03 10:15:38.023045 | controller | Friday 03 October 2025  10:15:38 +0000 (0:00:00.798)       0:00:00.810 ********
2025-10-03 10:15:38.330795 | controller | changed: [instance]
2025-10-03 10:15:38.330849 | controller |
2025-10-03 10:15:38.330980 | controller | TASK [test_deps : Gather facts if they don't exist] ****************************
2025-10-03 10:15:38.331083 | controller | Friday 03 October 2025  10:15:38 +0000 (0:00:00.308)       0:00:01.118 ********
2025-10-03 10:15:38.347832 | controller | skipping: [instance]
2025-10-03 10:15:38.347954 | controller |
2025-10-03 10:15:38.348071 | controller | TASK [test_deps : Gather variables for each operating system] ******************
2025-10-03 10:15:38.348188 | controller | Friday 03 October 2025  10:15:38 +0000 (0:00:00.017)       0:00:01.135 ********
2025-10-03 10:15:38.386794 | controller | ok: [instance] => (item=/home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/test_deps/vars/centos-9.yml)
2025-10-03 10:15:38.386872 | controller |
2025-10-03 10:15:38.386991 | controller | TASK [test_deps : Detect mirrors file] *****************************************
2025-10-03 10:15:38.387093 | controller | Friday 03 October 2025  10:15:38 +0000 (0:00:00.038)       0:00:01.174 ********
2025-10-03 10:15:38.657247 | controller | ok: [instance]
2025-10-03 10:15:38.657339 | controller |
2025-10-03 10:15:38.657483 | controller | TASK [test_deps : Disable ubi host subscription-manager integration] ***********
2025-10-03 10:15:38.657593 | controller | Friday 03 October 2025  10:15:38 +0000 (0:00:00.270)       0:00:01.445 ********
2025-10-03 10:15:38.860445 | controller | ok: [instance]
2025-10-03 10:15:38.860534 | controller |
2025-10-03 10:15:38.860642 | controller | TASK [test_deps : Disable ubi 9 repos] *****************************************
2025-10-03 10:15:38.860739 | controller | Friday 03 October 2025  10:15:38 +0000 (0:00:00.203)       0:00:01.648 ********
2025-10-03 10:15:39.541765 | controller | ok: [instance] => (item=ubi-9-appstream)
2025-10-03 10:15:39.541837 | controller | ok: [instance] => (item=ubi-9-baseos)
2025-10-03 10:15:39.541947 | controller | ok: [instance] => (item=ubi-9-codeready-builder)
2025-10-03 10:15:39.542042 | controller |
2025-10-03 10:15:39.542141 | controller | TASK [Deploy repo-setup] *******************************************************
2025-10-03 10:15:39.542241 | controller | Friday 03 October 2025  10:15:39 +0000 (0:00:00.681)       0:00:02.329 ********
2025-10-03 10:15:39.600315 | controller |
2025-10-03 10:15:39.600450 | controller | TASK [repo_setup : Ensure directories are present] *****************************
2025-10-03 10:15:39.600581 | controller | Friday 03 October 2025  10:15:39 +0000 (0:00:00.058)       0:00:02.388 ********
2025-10-03 10:15:40.138293 | controller | changed: [instance] => (item=tmp)
2025-10-03 10:15:40.138404 | controller | changed: [instance] => (item=artifacts/repositories)
2025-10-03 10:15:40.138507 | controller | changed: [instance] => (item=venv/repo_setup)
2025-10-03 10:15:40.138602 | controller |
2025-10-03 10:15:40.138702 | controller | TASK [repo_setup : Make sure git-core package is installed] ********************
2025-10-03 10:15:40.138800 | controller | Friday 03 October 2025  10:15:40 +0000 (0:00:00.537)       0:00:02.926 ********
2025-10-03 10:15:40.922486 | controller | ok: [instance]
2025-10-03 10:15:40.922809 | controller |
2025-10-03 10:15:42.092051 | controller | TASK [repo_setup : Get repo-setup repository] **********************************
2025-10-03 10:15:42.092083 | controller | Friday 03 October 2025  10:15:40 +0000 (0:00:00.784)       0:00:03.710 ********
2025-10-03 10:15:42.092095 | controller | changed: [instance]
2025-10-03 10:15:50.092484 | controller |
2025-10-03 10:15:50.092521 | controller | TASK [repo_setup : Initialize python venv and install requirements] ************
2025-10-03 10:15:50.092530 | controller | Friday 03 October 2025  10:15:42 +0000 (0:00:01.169)       0:00:04.879 ********
2025-10-03 10:15:50.092540 | controller | changed: [instance]
2025-10-03 10:15:50.800013 | controller |
2025-10-03 10:15:50.800044 | controller | TASK [repo_setup : Install repo-setup package] *********************************
2025-10-03 10:15:50.800052 | controller | Friday 03 October 2025  10:15:50 +0000 (0:00:08.000)       0:00:12.879 ********
2025-10-03 10:15:50.800062 | controller | changed: [instance]
2025-10-03 10:15:50.821514 | controller |
2025-10-03 10:15:50.821537 | controller | TASK [repo_setup : Set cifmw_repo_setup_dlrn_hash_tag from content provider] ***
2025-10-03 10:15:50.821545 | controller | Friday 03 October 2025  10:15:50 +0000 (0:00:00.707)       0:00:13.587 ********
2025-10-03 10:15:50.821555 | controller | skipping: [instance]
2025-10-03 10:15:51.646178 | controller |
2025-10-03 10:15:51.646208 | controller | TASK [repo_setup : Run repo-setup] *********************************************
2025-10-03 10:15:51.646216 | controller | Friday 03 October 2025  10:15:50 +0000 (0:00:00.021)       0:00:13.609 ********
2025-10-03 10:15:51.646225 | controller | changed: [instance]
2025-10-03 10:15:51.681025 | controller |
2025-10-03 10:15:51.681055 | controller | TASK [repo_setup : Get component repo] *****************************************
2025-10-03 10:15:51.681064 | controller | Friday 03 October 2025  10:15:51 +0000 (0:00:00.824)       0:00:14.433 ********
2025-10-03 10:15:51.681073 | controller | skipping: [instance]
2025-10-03 10:15:51.715221 | controller |
2025-10-03 10:15:51.715248 | controller | TASK [repo_setup : Rename component repo] **************************************
2025-10-03 10:15:51.715255 | controller | Friday 03 October 2025  10:15:51 +0000 (0:00:00.034)       0:00:14.468 ********
2025-10-03 10:15:51.715265 | controller | skipping: [instance]
2025-10-03 10:15:51.750417 | controller |
2025-10-03 10:15:51.750445 | controller | TASK [repo_setup : Disable component repo in current-podified dlrn repo] *******
2025-10-03 10:15:51.750453 | controller | Friday 03 October 2025  10:15:51 +0000 (0:00:00.034)       0:00:14.502 ********
2025-10-03 10:15:51.750463 | controller | skipping: [instance]
2025-10-03 10:15:52.333044 | controller |
2025-10-03 10:15:52.333073 | controller | TASK [repo_setup : Run repo-setup-get-hash] ************************************
2025-10-03 10:15:52.333081 | controller | Friday 03 October 2025  10:15:51 +0000 (0:00:00.035)       0:00:14.537 ********
2025-10-03 10:15:52.333091 | controller | changed: [instance]
2025-10-03 10:15:52.758005 | controller |
2025-10-03 10:15:52.758038 | controller | TASK [repo_setup : Dump full hash in delorean.repo.md5 file] *******************
2025-10-03 10:15:52.758046 | controller | Friday 03 October 2025  10:15:52 +0000 (0:00:00.582)       0:00:15.120 ********
2025-10-03 10:15:52.758061 | controller | changed: [instance]
2025-10-03 10:15:52.785449 | controller |
2025-10-03 10:15:52.785480 | controller | TASK [repo_setup : Dump current-podified hash] *********************************
2025-10-03 10:15:52.785488 | controller | Friday 03 October 2025  10:15:52 +0000 (0:00:00.424)       0:00:15.545 ********
2025-10-03 10:15:52.785497 | controller | skipping: [instance]
2025-10-03 10:15:52.785523 | controller |
2025-10-03 10:15:52.785533 | controller | TASK [repo_setup : Slurp current podified hash] ********************************
2025-10-03 10:15:52.785643 | controller | Friday 03 October 2025  10:15:52 +0000 (0:00:00.027)       0:00:15.573 ********
2025-10-03 10:15:52.813178 | controller | skipping: [instance]
2025-10-03 10:15:52.840993 | controller |
2025-10-03 10:15:52.841022 | controller | TASK [repo_setup : Update the value of full_hash] ******************************
2025-10-03 10:15:52.841030 | controller | Friday 03 October 2025  10:15:52 +0000 (0:00:00.027)       0:00:15.600 ********
2025-10-03 10:15:52.841040 | controller | skipping: [instance]
2025-10-03 10:15:52.878452 | controller |
2025-10-03 10:15:52.878483 | controller | TASK [repo_setup : Export hashes facts for further use] ************************
2025-10-03 10:15:52.878491 | controller | Friday 03 October 2025  10:15:52 +0000 (0:00:00.027)       0:00:15.628 ********
2025-10-03 10:15:52.878501 | controller | ok: [instance]
2025-10-03 10:15:52.878526 | controller |
2025-10-03 10:15:52.878533 | controller | TASK [repo_setup : Create download directory] **********************************
2025-10-03 10:15:52.878540 | controller | Friday 03 October 2025  10:15:52 +0000 (0:00:00.037)       0:00:15.666 ********
2025-10-03 10:15:52.904451 | controller | skipping: [instance]
2025-10-03 10:15:52.930174 | controller |
2025-10-03 10:15:52.930207 | controller | TASK [repo_setup : Print the URL to request] ***********************************
2025-10-03 10:15:52.930215 | controller | Friday 03 October 2025  10:15:52 +0000 (0:00:00.025)       0:00:15.692 ********
2025-10-03 10:15:52.930225 | controller | skipping: [instance]
2025-10-03 10:15:52.955851 | controller |
2025-10-03 10:15:52.955876 | controller | TASK [Download the RPM] ********************************************************
2025-10-03 10:15:52.955884 | controller | Friday 03 October 2025  10:15:52 +0000 (0:00:00.025)       0:00:15.717 ********
2025-10-03 10:15:52.955894 | controller | skipping: [instance]
2025-10-03 10:15:52.981490 | controller |
2025-10-03 10:15:52.981520 | controller | TASK [repo_setup : Install RHOS Release tool] **********************************
2025-10-03 10:15:52.981530 | controller | Friday 03 October 2025  10:15:52 +0000 (0:00:00.025)       0:00:15.743 ********
2025-10-03 10:15:52.981542 | controller | skipping: [instance]
2025-10-03 10:15:53.007230 | controller |
2025-10-03 10:15:53.007253 | controller | TASK [repo_setup : Get rhos-release tool version] ******************************
2025-10-03 10:15:53.007260 | controller | Friday 03 October 2025  10:15:52 +0000 (0:00:00.025)       0:00:15.769 ********
2025-10-03 10:15:53.007270 | controller | skipping: [instance]
2025-10-03 10:15:53.034892 | controller |
2025-10-03 10:15:53.034915 | controller | TASK [repo_setup : Print rhos-release tool version] ****************************
2025-10-03 10:15:53.034939 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.025)       0:00:15.794 ********
2025-10-03 10:15:53.034949 | controller | skipping: [instance]
2025-10-03 10:15:53.060385 | controller |
2025-10-03 10:15:53.060409 | controller | TASK [repo_setup : Generate repos using rhos-release {{ cifmw_repo_setup_rhos_release_args }}] ***
2025-10-03 10:15:53.060417 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.027)       0:00:15.822 ********
2025-10-03 10:15:53.060431 | controller | skipping: [instance]
2025-10-03 10:15:53.243376 | controller |
2025-10-03 10:15:53.243407 | controller | TASK [repo_setup : Check for /etc/ci/mirror_info.sh] ***************************
2025-10-03 10:15:53.243415 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.025)       0:00:15.848 ********
2025-10-03 10:15:53.243425 | controller | ok: [instance]
2025-10-03 10:15:53.455994 | controller |
2025-10-03 10:15:53.456024 | controller | TASK [repo_setup : Use RDO proxy mirrors] **************************************
2025-10-03 10:15:53.456032 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.182)       0:00:16.030 ********
2025-10-03 10:15:53.456042 | controller | changed: [instance]
2025-10-03 10:15:53.671023 | controller |
2025-10-03 10:15:53.671056 | controller | TASK [repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist)] ***
2025-10-03 10:15:53.671064 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.212)       0:00:16.243 ********
2025-10-03 10:15:53.671074 | controller | changed: [instance]
2025-10-03 10:15:53.691005 | controller |
2025-10-03 10:15:53.691029 | controller | TASK [repo_setup : Check for gating.repo file on content provider] *************
2025-10-03 10:15:53.691036 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.214)       0:00:16.458 ********
2025-10-03 10:15:53.691046 | controller | skipping: [instance]
2025-10-03 10:15:53.711434 | controller |
2025-10-03 10:15:53.711462 | controller | TASK [repo_setup : Populate gating repo from content provider ip] **************
2025-10-03 10:15:53.711470 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.020)       0:00:16.478 ********
2025-10-03 10:15:53.711480 | controller | skipping: [instance]
2025-10-03 10:15:53.732436 | controller |
2025-10-03 10:15:53.732461 | controller | TASK [repo_setup : Check for DLRN repo at the destination] *********************
2025-10-03 10:15:53.732469 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.020)       0:00:16.499 ********
2025-10-03 10:15:53.732479 | controller | skipping: [instance]
2025-10-03 10:15:53.753348 | controller |
2025-10-03 10:15:53.753388 | controller | TASK [repo_setup : Lower the priority of DLRN repos to allow installation from gating repo] ***
2025-10-03 10:15:53.753399 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.020)       0:00:16.520 ********
2025-10-03 10:15:53.753415 | controller | skipping: [instance]
2025-10-03 10:15:53.773910 | controller |
2025-10-03 10:15:53.773953 | controller | TASK [repo_setup : Check for DLRN component repo] ******************************
2025-10-03 10:15:53.773970 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.020)       0:00:16.540 ********
2025-10-03 10:15:53.773982 | controller | skipping: [instance]
2025-10-03 10:15:53.793784 | controller |
2025-10-03 10:15:53.793803 | controller | TASK [repo_setup : Lower the priority of componennt repos to allow installation from gating repo] ***
2025-10-03 10:15:53.793810 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.020)       0:00:16.561 ********
2025-10-03 10:15:53.793820 | controller | skipping: [instance]
2025-10-03 10:15:53.807914 | controller |
2025-10-03 10:15:53.807957 | controller | TASK [repo_setup : Find existing repos from /etc/yum.repos.d directory] ********
2025-10-03 10:15:53.807966 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.020)       0:00:16.581 ********
2025-10-03 10:15:53.807977 | controller | skipping: [instance]
2025-10-03 10:15:53.808154 | controller |
2025-10-03 10:15:53.808330 | controller | TASK [repo_setup : Remove existing repos from /etc/yum.repos.d directory] ******
2025-10-03 10:15:53.808522 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.014)       0:00:16.595 ********
2025-10-03 10:15:53.834008 | controller | skipping: [instance]
2025-10-03 10:15:53.834197 | controller |
2025-10-03 10:15:53.834397 | controller | TASK [repo_setup : Cleanup existing metadata] **********************************
2025-10-03 10:15:53.834582 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.025)       0:00:16.621 ********
2025-10-03 10:15:53.849220 | controller | skipping: [instance]
2025-10-03 10:15:53.849416 | controller |
2025-10-03 10:15:53.849576 | controller | TASK [repo_setup : Copy generated repos to /etc/yum.repos.d directory] *********
2025-10-03 10:15:53.849720 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.014)       0:00:16.636 ********
2025-10-03 10:15:53.868839 | controller | skipping: [instance]
2025-10-03 10:15:53.869036 | controller |
2025-10-03 10:15:53.869224 | controller | TASK [test_deps : Look for redhat-release rpm] *********************************
2025-10-03 10:15:53.869432 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.019)       0:00:16.656 ********
2025-10-03 10:15:53.896076 | controller | skipping: [instance]
2025-10-03 10:15:53.896218 | controller |
2025-10-03 10:15:53.896357 | controller | TASK [test_deps : Remove redhat-release] ***************************************
2025-10-03 10:15:53.896552 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.027)       0:00:16.684 ********
2025-10-03 10:15:53.924905 | controller | skipping: [instance]
2025-10-03 10:15:53.954167 | controller |
2025-10-03 10:15:53.954191 | controller | TASK [test_deps : Install centos-stream-release] *******************************
2025-10-03 10:15:53.954199 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.028)       0:00:16.712 ********
2025-10-03 10:15:53.954209 | controller | skipping: [instance]
2025-10-03 10:15:53.982412 | controller |
2025-10-03 10:15:53.982432 | controller | TASK [test_deps : Install additional packages] *********************************
2025-10-03 10:15:53.982440 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.029)       0:00:16.741 ********
2025-10-03 10:15:53.982449 | controller | skipping: [instance]
2025-10-03 10:15:53.982665 | controller |
2025-10-03 10:15:53.982678 | controller | TASK [test_deps : Install selinux python libs] *********************************
2025-10-03 10:16:38.809548 | controller | Friday 03 October 2025  10:15:53 +0000 (0:00:00.028)       0:00:16.770 ********
2025-10-03 10:16:38.809587 | controller | ok: [instance]
2025-10-03 10:16:39.977604 | controller |
2025-10-03 10:16:39.977635 | controller | TASK [test_deps : Install python yaml libs] ************************************
2025-10-03 10:16:39.977643 | controller | Friday 03 October 2025  10:16:38 +0000 (0:00:44.826)       0:01:01.596 ********
2025-10-03 10:16:39.977653 | controller | ok: [instance]
2025-10-03 10:16:40.020486 | controller |
2025-10-03 10:16:40.020521 | controller | TASK [test_deps : Install extra packages] **************************************
2025-10-03 10:16:40.020529 | controller | Friday 03 October 2025  10:16:39 +0000 (0:00:01.168)       0:01:02.765 ********
2025-10-03 10:16:40.020540 | controller | skipping: [instance]
2025-10-03 10:16:40.020563 | controller |
2025-10-03 10:16:40.020570 | controller | PLAY RECAP *********************************************************************
2025-10-03 10:16:40.020576 | controller | instance                   : ok=20   changed=10   unreachable=0    failed=0    skipped=30   rescued=0    ignored=0
2025-10-03 10:16:40.020583 | controller |
2025-10-03 10:16:40.020613 | controller | Friday 03 October 2025  10:16:40 +0000 (0:00:00.042)       0:01:02.807 ********
2025-10-03 10:16:40.022427 | controller | ===============================================================================
2025-10-03 10:16:40.022542 | controller | test_deps : Install selinux python libs -------------------------------- 44.83s
2025-10-03 10:16:40.022550 | controller | repo_setup : Initialize python venv and install requirements ------------ 8.00s
2025-10-03 10:16:40.022556 | controller | repo_setup : Get repo-setup repository ---------------------------------- 1.17s
2025-10-03 10:16:40.022568 | controller | test_deps : Install python yaml libs ------------------------------------ 1.17s
2025-10-03 10:16:40.022573 | controller | repo_setup : Run repo-setup --------------------------------------------- 0.82s
2025-10-03 10:16:40.022579 | controller | Gathering Facts --------------------------------------------------------- 0.80s
2025-10-03 10:16:40.022584 | controller | repo_setup : Make sure git-core package is installed -------------------- 0.78s
2025-10-03 10:16:40.022589 | controller | repo_setup : Install repo-setup package --------------------------------- 0.71s
2025-10-03 10:16:40.022595 | controller | test_deps : Disable ubi 9 repos ----------------------------------------- 0.68s
2025-10-03 10:16:40.022600 | controller | repo_setup : Run repo-setup-get-hash ------------------------------------ 0.58s
2025-10-03 10:16:40.022605 | controller | repo_setup : Ensure directories are present ----------------------------- 0.54s
2025-10-03 10:16:40.022611 | controller | repo_setup : Dump full hash in delorean.repo.md5 file ------------------- 0.42s
2025-10-03 10:16:40.022616 | controller | Create custom basedir --------------------------------------------------- 0.31s
2025-10-03 10:16:40.022621 | controller | test_deps : Detect mirrors file ----------------------------------------- 0.27s
2025-10-03 10:16:40.022627 | controller | repo_setup : Use RDO CentOS mirrors (remove CentOS 10 conditional when Nodepool mirrors exist) --- 0.21s
2025-10-03 10:16:40.022632 | controller | repo_setup : Use RDO proxy mirrors -------------------------------------- 0.21s
2025-10-03 10:16:40.022638 | controller | test_deps : Disable ubi host subscription-manager integration ----------- 0.20s
2025-10-03 10:16:40.022643 | controller | repo_setup : Check for /etc/ci/mirror_info.sh --------------------------- 0.18s
2025-10-03 10:16:40.022651 | controller | Deploy repo-setup ------------------------------------------------------- 0.06s
2025-10-03 10:16:40.077839 | controller | test_deps : Install extra packages -------------------------------------- 0.04s
2025-10-03 10:16:40.077893 | controller | INFO     Running default > converge
2025-10-03 10:16:40.511849 | controller |
2025-10-03 10:16:40.511985 | controller | PLAY [Converge] ****************************************************************
2025-10-03 10:16:40.512102 | controller |
2025-10-03 10:16:40.512241 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 10:16:40.512448 | controller | Friday 03 October 2025  10:16:40 +0000 (0:00:00.013)       0:00:00.013 ********
2025-10-03 10:16:41.336492 | controller | ok: [instance]
2025-10-03 10:16:41.336551 | controller |
2025-10-03 10:16:41.336564 | controller | TASK [Crate SSH keypair] *******************************************************
2025-10-03 10:16:41.336698 | controller | Friday 03 October 2025  10:16:41 +0000 (0:00:00.824)       0:00:00.837 ********
2025-10-03 10:16:41.704930 | controller | changed: [instance]
2025-10-03 10:16:41.729764 | controller |
2025-10-03 10:16:41.729795 | controller | TASK [Add SSH jumper entries] **************************************************
2025-10-03 10:16:41.729803 | controller | Friday 03 October 2025  10:16:41 +0000 (0:00:00.368)       0:00:01.206 ********
2025-10-03 10:16:41.729812 | controller |
2025-10-03 10:16:41.764442 | controller | TASK [ssh_jumper : Create ssh-jumper entries] **********************************
2025-10-03 10:16:41.764488 | controller | Friday 03 October 2025  10:16:41 +0000 (0:00:00.025)       0:00:01.231 ********
2025-10-03 10:16:41.764509 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/ssh_jumper/tasks/manage_ssh_jumper_entry.yml for instance => (item={'ssh_dir': '/opt/basedir/ssh', 'hostname': '192.168.250.10', 'proxy_host': 'proxy.example.com', 'proxy_user': 'cloud-user', 'patterns': ['test', 'test.node']})
2025-10-03 10:16:42.070438 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/ssh_jumper/tasks/manage_ssh_jumper_entry.yml for instance => (item={'hostname': 'minimal.example.com', 'ssh_dir': '/opt/basedir/ssh'})
2025-10-03 10:16:42.070474 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/ssh_jumper/tasks/manage_ssh_jumper_entry.yml for instance => (item={'target': 'instance', 'ssh_dir': '/opt/basedir/ssh', 'hostname': '192.168.250.11', 'identity_file': '/opt/basedir/ssh/id_test', 'patterns': ['test', 'test.node']})
2025-10-03 10:16:42.070482 | controller |
2025-10-03 10:16:42.070489 | controller | TASK [ssh_jumper : Make sure ~/.ssh/cifmw_ssh_config.d directory exists] *******
2025-10-03 10:16:42.070495 | controller | Friday 03 October 2025  10:16:41 +0000 (0:00:00.034)       0:00:01.265 ********
2025-10-03 10:16:42.070505 | controller | changed: [instance]
2025-10-03 10:16:42.070592 | controller |
2025-10-03 10:16:42.070605 | controller | TASK [ssh_jumper : Include ~/.ssh/cifmw_ssh_config.d/inventory_hostname/*.conf] ***
2025-10-03 10:16:42.070614 | controller | Friday 03 October 2025  10:16:42 +0000 (0:00:00.306)       0:00:01.571 ********
2025-10-03 10:16:42.366305 | controller | changed: [instance]
2025-10-03 10:16:42.955635 | controller |
2025-10-03 10:16:42.955665 | controller | TASK [ssh_jumper : Inject ssh jumpers for 192.168.250.10] **********************
2025-10-03 10:16:42.955679 | controller | Friday 03 October 2025  10:16:42 +0000 (0:00:00.294)       0:00:01.866 ********
2025-10-03 10:16:42.955690 | controller | changed: [instance]
2025-10-03 10:16:43.152932 | controller |
2025-10-03 10:16:43.152965 | controller | TASK [ssh_jumper : Make sure ~/.ssh/cifmw_ssh_config.d directory exists] *******
2025-10-03 10:16:43.152973 | controller | Friday 03 October 2025  10:16:42 +0000 (0:00:00.590)       0:00:02.456 ********
2025-10-03 10:16:43.152983 | controller | ok: [instance]
2025-10-03 10:16:43.346691 | controller |
2025-10-03 10:16:43.346722 | controller | TASK [ssh_jumper : Include ~/.ssh/cifmw_ssh_config.d/inventory_hostname/*.conf] ***
2025-10-03 10:16:43.346730 | controller | Friday 03 October 2025  10:16:43 +0000 (0:00:00.197)       0:00:02.654 ********
2025-10-03 10:16:43.346741 | controller | ok: [instance]
2025-10-03 10:16:43.712817 | controller |
2025-10-03 10:16:43.712851 | controller | TASK [ssh_jumper : Inject ssh jumpers for minimal.example.com] *****************
2025-10-03 10:16:43.712859 | controller | Friday 03 October 2025  10:16:43 +0000 (0:00:00.193)       0:00:02.848 ********
2025-10-03 10:16:43.712869 | controller | changed: [instance]
2025-10-03 10:16:43.917259 | controller |
2025-10-03 10:16:43.917292 | controller | TASK [ssh_jumper : Make sure ~/.ssh/cifmw_ssh_config.d directory exists] *******
2025-10-03 10:16:43.917300 | controller | Friday 03 October 2025  10:16:43 +0000 (0:00:00.366)       0:00:03.214 ********
2025-10-03 10:16:43.917309 | controller | ok: [instance]
2025-10-03 10:16:44.117033 | controller |
2025-10-03 10:16:44.117064 | controller | TASK [ssh_jumper : Include ~/.ssh/cifmw_ssh_config.d/inventory_hostname/*.conf] ***
2025-10-03 10:16:44.117078 | controller | Friday 03 October 2025  10:16:43 +0000 (0:00:00.204)       0:00:03.418 ********
2025-10-03 10:16:44.117089 | controller | ok: [instance]
2025-10-03 10:16:44.481485 | controller |
2025-10-03 10:16:44.481524 | controller | TASK [ssh_jumper : Inject ssh jumpers for 192.168.250.11] **********************
2025-10-03 10:16:44.481532 | controller | Friday 03 October 2025  10:16:44 +0000 (0:00:00.199)       0:00:03.618 ********
2025-10-03 10:16:44.481543 | controller | changed: [instance]
2025-10-03 10:16:44.481567 | controller |
2025-10-03 10:16:44.481749 | controller | TASK [Slurp ssh/config] ********************************************************
2025-10-03 10:16:44.753117 | controller | Friday 03 October 2025  10:16:44 +0000 (0:00:00.364)       0:00:03.983 ********
2025-10-03 10:16:44.753152 | controller | ok: [instance]
2025-10-03 10:16:44.923077 | controller |
2025-10-03 10:16:44.923113 | controller | TASK [Slurp ssh/cifmw_ssh_config.d/minimal.example.com.conf] *******************
2025-10-03 10:16:44.923122 | controller | Friday 03 October 2025  10:16:44 +0000 (0:00:00.271)       0:00:04.254 ********
2025-10-03 10:16:44.923132 | controller | ok: [instance]
2025-10-03 10:16:45.091488 | controller |
2025-10-03 10:16:45.091528 | controller | TASK [Slurp ssh/cifmw_ssh_config.d/192.168.250.10.conf] ************************
2025-10-03 10:16:45.091538 | controller | Friday 03 October 2025  10:16:44 +0000 (0:00:00.169)       0:00:04.424 ********
2025-10-03 10:16:45.091551 | controller | ok: [instance]
2025-10-03 10:16:45.091592 | controller |
2025-10-03 10:16:45.091732 | controller | TASK [Slurp ssh/cifmw_ssh_config.d/192.168.250.11.conf] ************************
2025-10-03 10:16:45.091766 | controller | Friday 03 October 2025  10:16:45 +0000 (0:00:00.168)       0:00:04.593 ********
2025-10-03 10:16:45.263194 | controller | ok: [instance]
2025-10-03 10:16:45.292484 | controller |
2025-10-03 10:16:45.292524 | controller | TASK [Assert Include in ssh_config] ********************************************
2025-10-03 10:16:45.292534 | controller | Friday 03 October 2025  10:16:45 +0000 (0:00:00.171)       0:00:04.764 ********
2025-10-03 10:16:45.292547 | controller | ok: [instance] => changed=false
2025-10-03 10:16:45.292579 | controller |   msg: All assertions passed
2025-10-03 10:16:45.292587 | controller |
2025-10-03 10:16:45.292596 | controller | TASK [Assert SSH host - minimal config] ****************************************
2025-10-03 10:16:45.322461 | controller | Friday 03 October 2025  10:16:45 +0000 (0:00:00.029)       0:00:04.794 ********
2025-10-03 10:16:45.322497 | controller | ok: [instance] => changed=false
2025-10-03 10:16:45.322524 | controller |   msg: All assertions passed
2025-10-03 10:16:45.322532 | controller |
2025-10-03 10:16:45.322541 | controller | TASK [Assert cifmw-192.168.250.10.conf] ****************************************
2025-10-03 10:16:45.322633 | controller | Friday 03 October 2025  10:16:45 +0000 (0:00:00.029)       0:00:04.824 ********
2025-10-03 10:16:45.352329 | controller | ok: [instance] => changed=false
2025-10-03 10:16:45.396431 | controller |   msg: All assertions passed
2025-10-03 10:16:45.396460 | controller |
2025-10-03 10:16:45.396468 | controller | TASK [Assert cifmw-192.168.250.11.conf] ****************************************
2025-10-03 10:16:45.396474 | controller | Friday 03 October 2025  10:16:45 +0000 (0:00:00.029)       0:00:04.853 ********
2025-10-03 10:16:45.396484 | controller | ok: [instance] => changed=false
2025-10-03 10:16:45.397738 | controller |   msg: All assertions passed
2025-10-03 10:16:45.397755 | controller |
2025-10-03 10:16:45.397762 | controller | PLAY RECAP *********************************************************************
2025-10-03 10:16:45.397767 | controller | instance                   : ok=22   changed=6    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-03 10:16:45.397773 | controller |
2025-10-03 10:16:45.397778 | controller | Friday 03 October 2025  10:16:45 +0000 (0:00:00.042)       0:00:04.896 ********
2025-10-03 10:16:45.397789 | controller | ===============================================================================
2025-10-03 10:16:45.397795 | controller | Gathering Facts --------------------------------------------------------- 0.82s
2025-10-03 10:16:45.397800 | controller | ssh_jumper : Inject ssh jumpers for 192.168.250.10 ---------------------- 0.59s
2025-10-03 10:16:45.397806 | controller | Crate SSH keypair ------------------------------------------------------- 0.37s
2025-10-03 10:16:45.397811 | controller | ssh_jumper : Inject ssh jumpers for minimal.example.com ----------------- 0.37s
2025-10-03 10:16:45.397816 | controller | ssh_jumper : Inject ssh jumpers for 192.168.250.11 ---------------------- 0.36s
2025-10-03 10:16:45.397821 | controller | ssh_jumper : Make sure ~/.ssh/cifmw_ssh_config.d directory exists ------- 0.31s
2025-10-03 10:16:45.397826 | controller | ssh_jumper : Include ~/.ssh/cifmw_ssh_config.d/inventory_hostname/*.conf --- 0.29s
2025-10-03 10:16:45.397832 | controller | Slurp ssh/config -------------------------------------------------------- 0.27s
2025-10-03 10:16:45.397837 | controller | ssh_jumper : Make sure ~/.ssh/cifmw_ssh_config.d directory exists ------- 0.20s
2025-10-03 10:16:45.397842 | controller | ssh_jumper : Include ~/.ssh/cifmw_ssh_config.d/inventory_hostname/*.conf --- 0.20s
2025-10-03 10:16:45.397850 | controller | ssh_jumper : Make sure ~/.ssh/cifmw_ssh_config.d directory exists ------- 0.20s
2025-10-03 10:16:45.454718 | controller | ssh_jumper : Include ~/.ssh/cifmw_ssh_config.d/inventory_hostname/*.conf --- 0.19s
2025-10-03 10:16:45.454749 | controller | Slurp ssh/cifmw_ssh_config.d/192.168.250.11.conf ------------------------ 0.17s
2025-10-03 10:16:45.454757 | controller | Slurp ssh/cifmw_ssh_config.d/minimal.example.com.conf ------------------- 0.17s
2025-10-03 10:16:45.454763 | controller | Slurp ssh/cifmw_ssh_config.d/192.168.250.10.conf ------------------------ 0.17s
2025-10-03 10:16:45.454768 | controller | Assert cifmw-192.168.250.11.conf ---------------------------------------- 0.04s
2025-10-03 10:16:45.454774 | controller | ssh_jumper : Create ssh-jumper entries ---------------------------------- 0.03s
2025-10-03 10:16:45.454784 | controller | Assert SSH host - minimal config ---------------------------------------- 0.03s
2025-10-03 10:16:45.454790 | controller | Assert cifmw-192.168.250.10.conf ---------------------------------------- 0.03s
2025-10-03 10:16:45.454795 | controller | Assert Include in ssh_config -------------------------------------------- 0.03s
2025-10-03 10:16:45.454805 | controller | INFO     Running default > cleanup
2025-10-03 10:16:45.866684 | controller |
2025-10-03 10:16:46.651439 | controller | PLAY [Cleanup] *****************************************************************
2025-10-03 10:16:46.651474 | controller |
2025-10-03 10:16:46.651484 | controller | TASK [Gathering Facts] *********************************************************
2025-10-03 10:16:46.651492 | controller | Friday 03 October 2025  10:16:45 +0000 (0:00:00.034)       0:00:00.034 ********
2025-10-03 10:16:46.651503 | controller | ok: [instance]
2025-10-03 10:16:46.674709 | controller |
2025-10-03 10:16:46.674731 | controller | TASK [Cleanup SSH jumper hosts] ************************************************
2025-10-03 10:16:46.674738 | controller | Friday 03 October 2025  10:16:46 +0000 (0:00:00.784)       0:00:00.819 ********
2025-10-03 10:16:46.674748 | controller |
2025-10-03 10:16:46.959470 | controller | TASK [ssh_jumper : Remove Include cifmw_ssh_config.d] **************************
2025-10-03 10:16:46.959500 | controller | Friday 03 October 2025  10:16:46 +0000 (0:00:00.023)       0:00:00.843 ********
2025-10-03 10:16:46.959512 | controller | changed: [instance]
2025-10-03 10:16:47.271461 | controller |
2025-10-03 10:16:47.271494 | controller | TASK [ssh_jumper : Remove cifmw_ssh_config.d directory] ************************
2025-10-03 10:16:47.271502 | controller | Friday 03 October 2025  10:16:46 +0000 (0:00:00.284)       0:00:01.127 ********
2025-10-03 10:16:47.271512 | controller | changed: [instance]
2025-10-03 10:16:47.314822 | controller |
2025-10-03 10:16:47.314857 | controller | PLAY RECAP *********************************************************************
2025-10-03 10:16:47.314865 | controller | instance                   : ok=3    changed=2    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-10-03 10:16:47.314871 | controller |
2025-10-03 10:16:47.314882 | controller | Friday 03 October 2025  10:16:47 +0000 (0:00:00.311)       0:00:01.439 ********
2025-10-03 10:16:47.314887 | controller | ===============================================================================
2025-10-03 10:16:47.314893 | controller | Gathering Facts --------------------------------------------------------- 0.78s
2025-10-03 10:16:47.314898 | controller | ssh_jumper : Remove cifmw_ssh_config.d directory ------------------------ 0.31s
2025-10-03 10:16:47.314903 | controller | ssh_jumper : Remove Include cifmw_ssh_config.d -------------------------- 0.28s
2025-10-03 10:16:47.314908 | controller | Cleanup SSH jumper hosts ------------------------------------------------ 0.02s
2025-10-03 10:16:47.314933 | controller | INFO     Writing /tmp/report.html report.
2025-10-03 10:16:47.604815 | controller | changed
2025-10-03 10:16:47.625303 | 
2025-10-03 10:16:47.625376 | PLAY RECAP
2025-10-03 10:16:47.625418 | controller | ok: 2 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-10-03 10:16:47.625440 | 
2025-10-03 10:16:47.706251 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-10-03 10:16:47.708361 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-03 10:16:48.297097 | 
2025-10-03 10:16:48.297203 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-10-03 10:16:48.318947 | 
2025-10-03 10:16:48.319046 | TASK [Filter out host if needed]
2025-10-03 10:16:48.327901 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-10-03 10:16:48.332620 | 
2025-10-03 10:16:48.332704 | TASK [Ensure file is present]
2025-10-03 10:16:48.670353 | controller | ok
2025-10-03 10:16:48.680282 | 
2025-10-03 10:16:48.680405 | TASK [Manage molecule report file]
2025-10-03 10:16:49.218788 | controller | changed
2025-10-03 10:16:49.224090 | 
2025-10-03 10:16:49.224172 | TASK [Check if we get ci-framework-data basedir]
2025-10-03 10:16:49.415501 | controller | ok
2025-10-03 10:16:49.421184 | 
2025-10-03 10:16:49.421271 | TASK [Create ci-framework-data log directory for zuul]
2025-10-03 10:16:49.755055 | controller | changed
2025-10-03 10:16:49.770140 | 
2025-10-03 10:16:49.770231 | TASK [Copy ci-framework interesting files]
2025-10-03 10:16:50.000696 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2025-10-03 10:16:50.321697 | controller | changed
2025-10-03 10:16:50.326805 | 
2025-10-03 10:16:50.326876 | TASK [Get SELinux listing]
2025-10-03 10:16:50.863463 | controller | changed
2025-10-03 10:16:50.869517 | 
2025-10-03 10:16:50.869589 | TASK [Generate log index]
2025-10-03 10:16:51.566710 | controller | changed
2025-10-03 10:16:51.572158 | 
2025-10-03 10:16:51.572232 | TASK [Get some env related data]
2025-10-03 10:16:52.129390 | controller | /home/zuul/.local/bin/ansible
2025-10-03 10:16:53.109969 | controller | changed
2025-10-03 10:16:53.115383 | 
2025-10-03 10:16:53.115463 | TASK [Generate list of logs to collect in home directory]
2025-10-03 10:16:53.440328 | controller | ok: All paths examined
2025-10-03 10:16:53.445620 | 
2025-10-03 10:16:53.445702 | LOOP [Copy logs from home directory]
2025-10-03 10:16:53.786114 | controller | changed:
2025-10-03 10:16:53.786226 | controller | {
2025-10-03 10:16:53.786253 | controller |   "atime": 1759486501.565562,
2025-10-03 10:16:53.786272 | controller |   "ctime": 1759486517.2886965,
2025-10-03 10:16:53.786289 | controller |   "dev": 64513,
2025-10-03 10:16:53.786304 | controller |   "gid": 1000,
2025-10-03 10:16:53.786319 | controller |   "gr_name": "zuul",
2025-10-03 10:16:53.786335 | controller |   "inode": 4450689,
2025-10-03 10:16:53.786350 | controller |   "isblk": false,
2025-10-03 10:16:53.786366 | controller |   "ischr": false,
2025-10-03 10:16:53.786387 | controller |   "isdir": false,
2025-10-03 10:16:53.786404 | controller |   "isfifo": false,
2025-10-03 10:16:53.786419 | controller |   "isgid": false,
2025-10-03 10:16:53.786433 | controller |   "islnk": false,
2025-10-03 10:16:53.786701 | controller |   "isreg": true,
2025-10-03 10:16:53.786730 | controller |   "issock": false,
2025-10-03 10:16:53.786747 | controller |   "isuid": false,
2025-10-03 10:16:53.786764 | controller |   "mode": "0644",
2025-10-03 10:16:53.786779 | controller |   "mtime": 1759486517.2886965,
2025-10-03 10:16:53.786794 | controller |   "nlink": 1,
2025-10-03 10:16:53.786809 | controller |   "path": "/home/zuul/ansible.log",
2025-10-03 10:16:53.786825 | controller |   "pw_name": "zuul",
2025-10-03 10:16:53.786840 | controller |   "rgrp": true,
2025-10-03 10:16:53.786856 | controller |   "roth": true,
2025-10-03 10:16:53.786871 | controller |   "rusr": true,
2025-10-03 10:16:53.786885 | controller |   "size": 6749,
2025-10-03 10:16:53.786899 | controller |   "uid": 1000,
2025-10-03 10:16:53.786934 | controller |   "wgrp": false,
2025-10-03 10:16:53.786951 | controller |   "woth": false,
2025-10-03 10:16:53.786969 | controller |   "wusr": true,
2025-10-03 10:16:53.786984 | controller |   "xgrp": false,
2025-10-03 10:16:53.786998 | controller |   "xoth": false,
2025-10-03 10:16:53.787011 | controller |   "xusr": false
2025-10-03 10:16:53.787025 | controller | }
2025-10-03 10:16:53.796792 | 
2025-10-03 10:16:53.796867 | TASK [Copy crio stats log file]
2025-10-03 10:16:53.821018 | controller | skipping: Conditional result was False
2025-10-03 10:16:53.826403 | 
2025-10-03 10:16:53.826484 | TASK [Get SELinux related data]
2025-10-03 10:16:54.037783 | controller | <no matches>
2025-10-03 10:16:54.354518 | controller | ERROR
2025-10-03 10:16:54.354702 | controller | {
2025-10-03 10:16:54.354737 | controller |   "delta": "0:00:00.009830",
2025-10-03 10:16:54.354760 | controller |   "end": "2025-10-03 10:16:54.038758",
2025-10-03 10:16:54.354780 | controller |   "msg": "non-zero return code",
2025-10-03 10:16:54.354798 | controller |   "rc": 1,
2025-10-03 10:16:54.354816 | controller |   "start": "2025-10-03 10:16:54.028928"
2025-10-03 10:16:54.354832 | controller | }
2025-10-03 10:16:54.354855 | controller | ERROR: Ignoring Errors
2025-10-03 10:16:54.360454 | 
2025-10-03 10:16:54.360518 | TASK [Create system configuration directory]
2025-10-03 10:16:54.541164 | controller | changed
2025-10-03 10:16:54.546530 | 
2025-10-03 10:16:54.546611 | TASK [Get some of the system configurations]
2025-10-03 10:16:55.074197 | controller | changed
2025-10-03 10:16:55.080316 | 
2025-10-03 10:16:55.080400 | TASK [Copy generated documentation if available]
2025-10-03 10:16:55.106553 | controller | skipping: Conditional result was False
2025-10-03 10:16:55.117828 | 
2025-10-03 10:16:55.117946 | TASK [Copy generated AsciiDoc documentation if available]
2025-10-03 10:16:55.142279 | controller | skipping: Conditional result was False
2025-10-03 10:16:55.148891 | 
2025-10-03 10:16:55.148992 | TASK [Compress logs bigger than 2MB]
2025-10-03 10:16:55.678503 | controller | changed
2025-10-03 10:16:55.686042 | 
2025-10-03 10:16:55.686135 | TASK [Copy files from workspace on node]
2025-10-03 10:16:55.715762 | controller | ok
2025-10-03 10:16:55.741473 | 
2025-10-03 10:16:55.741546 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-03 10:16:55.775181 | controller | skipping: Conditional result was False
2025-10-03 10:16:55.781873 | 
2025-10-03 10:16:55.781972 | TASK [fetch-output : Set log path for single node]
2025-10-03 10:16:55.811583 | controller | ok
2025-10-03 10:16:55.816400 | 
2025-10-03 10:16:55.816466 | LOOP [fetch-output : Ensure local output dirs]
2025-10-03 10:16:56.106801 | controller -> localhost | ok: "/var/lib/zuul/builds/223947a67f58454eb874644eabb7a2c2/work/logs"
2025-10-03 10:16:56.107051 | controller -> localhost | changed: All items complete
2025-10-03 10:16:56.107085 | 
2025-10-03 10:16:56.348526 | controller -> localhost | changed: "/var/lib/zuul/builds/223947a67f58454eb874644eabb7a2c2/work/artifacts"
2025-10-03 10:16:56.552985 | controller -> localhost | changed: "/var/lib/zuul/builds/223947a67f58454eb874644eabb7a2c2/work/docs"
2025-10-03 10:16:56.567981 | 
2025-10-03 10:16:56.568098 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-03 10:16:57.136106 | controller | changed:
2025-10-03 10:16:57.136278 | controller | .d..t...... ./
2025-10-03 10:16:57.136309 | controller | >f+++++++++ README.html
2025-10-03 10:16:57.136330 | controller | >f+++++++++ ansible-execution.log
2025-10-03 10:16:57.136352 | controller | >f+++++++++ ansible.log
2025-10-03 10:16:57.136371 | controller | >f+++++++++ dmesg.log
2025-10-03 10:16:57.136388 | controller | >f+++++++++ installed-pkgs.log
2025-10-03 10:16:57.136406 | controller | >f+++++++++ python.log
2025-10-03 10:16:57.136425 | controller | >f+++++++++ registries.conf
2025-10-03 10:16:57.136442 | controller | >f+++++++++ report.html
2025-10-03 10:16:57.136460 | controller | >f+++++++++ selinux-denials.log
2025-10-03 10:16:57.136478 | controller | >f+++++++++ selinux-listing.log
2025-10-03 10:16:57.136495 | controller | cd+++++++++ ci-framework-data/
2025-10-03 10:16:57.136511 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-10-03 10:16:57.136527 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-10-03 10:16:57.136543 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-10-03 10:16:57.136559 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-10-03 10:16:57.136574 | controller | cd+++++++++ ci-framework-data/logs/
2025-10-03 10:16:57.136590 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-10-03 10:16:57.136605 | controller | cd+++++++++ registries.conf.d/
2025-10-03 10:16:57.136620 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-10-03 10:16:57.136635 | controller | cd+++++++++ system-config/
2025-10-03 10:16:57.136650 | controller | cd+++++++++ system-config/libvirt/
2025-10-03 10:16:57.136665 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-10-03 10:16:57.136695 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-10-03 10:16:57.534370 | controller | changed: .d..t...... ./
2025-10-03 10:16:57.909957 | controller | changed: .d..t...... ./
2025-10-03 10:16:57.925692 | 
2025-10-03 10:16:57.925806 | TASK [Return artifact to Zuul]
2025-10-03 10:16:57.955033 | controller | ok
2025-10-03 10:16:57.974839 | 
2025-10-03 10:16:57.974930 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-10-03 10:16:57.975219 | 
2025-10-03 10:16:57.975246 | PLAY RECAP
2025-10-03 10:16:57.975281 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-10-03 10:16:57.975302 | 
2025-10-03 10:16:58.066256 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-10-03 10:16:58.068404 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 10:16:58.780381 | 
2025-10-03 10:16:58.780491 | PLAY [all]
2025-10-03 10:16:58.801298 | 
2025-10-03 10:16:58.801384 | TASK [include_role : fetch-output]
2025-10-03 10:16:58.830787 | controller | ok
2025-10-03 10:16:58.853129 | 
2025-10-03 10:16:58.853243 | TASK [fetch-output : Set log path for multiple nodes]
2025-10-03 10:16:58.907758 | controller | skipping: Conditional result was False
2025-10-03 10:16:58.914576 | 
2025-10-03 10:16:58.914664 | TASK [fetch-output : Set log path for single node]
2025-10-03 10:16:58.954578 | controller | ok
2025-10-03 10:16:58.960028 | 
2025-10-03 10:16:58.960103 | LOOP [fetch-output : Ensure local output dirs]
2025-10-03 10:16:59.380057 | controller -> localhost | ok: "/var/lib/zuul/builds/223947a67f58454eb874644eabb7a2c2/work/logs"
2025-10-03 10:16:59.591884 | controller -> localhost | ok: "/var/lib/zuul/builds/223947a67f58454eb874644eabb7a2c2/work/artifacts"
2025-10-03 10:16:59.785691 | controller -> localhost | ok: "/var/lib/zuul/builds/223947a67f58454eb874644eabb7a2c2/work/docs"
2025-10-03 10:16:59.794638 | 
2025-10-03 10:16:59.794721 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-10-03 10:17:00.375343 | controller | ok
2025-10-03 10:17:00.375533 | controller | ok: All items complete
2025-10-03 10:17:00.375573 | 
2025-10-03 10:17:00.756851 | controller | ok
2025-10-03 10:17:01.125121 | controller | ok
2025-10-03 10:17:01.146139 | 
2025-10-03 10:17:01.146273 | TASK [include_role : fetch-output-openshift]
2025-10-03 10:17:01.160093 | controller | skipping: Conditional result was False
2025-10-03 10:17:01.166583 | 
2025-10-03 10:17:01.166649 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-10-03 10:17:01.529152 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.007661
2025-10-03 10:17:01.744996 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.006920
2025-10-03 10:17:01.780116 | 
2025-10-03 10:17:01.780253 | PLAY [all]
2025-10-03 10:17:01.794731 | 
2025-10-03 10:17:01.794808 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-10-03 10:17:02.200018 | controller | changed
2025-10-03 10:17:02.222696 | 
2025-10-03 10:17:02.222768 | PLAY RECAP
2025-10-03 10:17:02.222810 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-10-03 10:17:02.222832 | 
2025-10-03 10:17:02.297478 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-10-03 10:17:02.298276 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-10-03 10:17:02.867543 | 
2025-10-03 10:17:02.867652 | PLAY [localhost]
2025-10-03 10:17:02.884960 | 
2025-10-03 10:17:02.885039 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-10-03 10:17:03.220819 | localhost | changed
2025-10-03 10:17:03.225377 | 
2025-10-03 10:17:03.225476 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-10-03 10:17:03.253896 | localhost | ok
2025-10-03 10:17:03.261988 | 
2025-10-03 10:17:03.262069 | TASK [add-fileserver : Create SSH private key tempfile]
2025-10-03 10:17:03.624495 | localhost | changed
2025-10-03 10:17:03.630718 | 
2025-10-03 10:17:03.630797 | TASK [add-fileserver : Create SSH private key from secret]
2025-10-03 10:17:04.250040 | localhost | changed
2025-10-03 10:17:04.255102 | 
2025-10-03 10:17:04.255171 | TASK [add-fileserver : Add fileserver ssh key]
2025-10-03 10:17:04.601721 | localhost | Identity added: /var/lib/zuul/builds/223947a67f58454eb874644eabb7a2c2/work/tmp/ansible.w4q12kkt (/var/lib/zuul/builds/223947a67f58454eb874644eabb7a2c2/work/tmp/ansible.w4q12kkt)
2025-10-03 10:17:04.601955 | localhost | ok: Runtime: 0:00:00.007147
2025-10-03 10:17:04.607785 | 
2025-10-03 10:17:04.607868 | TASK [add-fileserver : Remove SSH private key from disk]
2025-10-03 10:17:04.848314 | localhost | ok: Runtime: 0:00:00.004379
2025-10-03 10:17:04.854129 | 
2025-10-03 10:17:04.854217 | TASK [add-fileserver : Add fileserver to inventory]
2025-10-03 10:17:04.903451 | localhost | changed
2025-10-03 10:17:04.907764 | 
2025-10-03 10:17:04.907842 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-10-03 10:17:05.230796 | localhost | changed
2025-10-03 10:17:05.254542 | 
2025-10-03 10:17:05.254633 | PLAY [localhost]
2025-10-03 10:17:05.267405 | 
2025-10-03 10:17:05.267472 | TASK [Generate bulk log download script]
2025-10-03 10:17:05.287369 | localhost | ok
2025-10-03 10:17:05.300977 | 
2025-10-03 10:17:05.301054 | TASK [local-log-download : Check API endpoint is defined]
2025-10-03 10:17:05.341963 | localhost | ok: All assertions passed
2025-10-03 10:17:05.346611 | 
2025-10-03 10:17:05.346712 | TASK [local-log-download : Create download script]
2025-10-03 10:17:05.727189 | localhost -> localhost | changed
2025-10-03 10:17:05.736746 | 
2025-10-03 10:17:05.736830 | TASK [Register quick-download link]
2025-10-03 10:17:05.754151 | localhost | ok
2025-10-03 10:17:05.791492 | 
2025-10-03 10:17:05.791584 | PLAY [logserver.rdoproject.org]
2025-10-03 10:17:05.800885 | 
2025-10-03 10:17:05.800967 | TASK [Set zuul-log-path fact]
2025-10-03 10:17:05.816622 | logserver.rdoproject.org | ok
2025-10-03 10:17:05.825605 | 
2025-10-03 10:17:05.825695 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-10-03 10:17:05.851816 | logserver.rdoproject.org | ok
2025-10-03 10:17:05.857244 | 
2025-10-03 10:17:05.857323 | TASK [upload-logs : Create log directories]
2025-10-03 10:17:07.697012 | logserver.rdoproject.org | changed
2025-10-03 10:17:07.700188 | 
2025-10-03 10:17:07.700276 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-10-03 10:17:08.018883 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.013140
2025-10-03 10:17:08.024006 | 
2025-10-03 10:17:08.024100 | TASK [upload-logs : Upload logs to log server]
2025-10-03 10:17:09.583079 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-10-03 10:17:09.586071 | 
2025-10-03 10:17:09.586159 | LOOP [upload-logs : Compress console log and json output]
2025-10-03 10:17:09.624382 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 10:17:09.632632 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 10:17:09.643661 | 
2025-10-03 10:17:09.643762 | LOOP [upload-logs : Upload compressed console log and json output]
2025-10-03 10:17:09.681535 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 10:17:09.681791 | 
2025-10-03 10:17:09.686237 | logserver.rdoproject.org | skipping: Conditional result was False
2025-10-03 10:17:09.691453 | 
2025-10-03 10:17:09.691572 | LOOP [upload-logs : Upload console log and json output]