2025-12-05 10:26:08.838713 | Job console starting...
2025-12-05 10:26:09.054886 | Updating repositories
2025-12-05 10:26:09.814525 | Preparing job workspace
2025-12-05 10:26:16.958379 | Running Ansible setup...
2025-12-05 10:26:19.988404 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-05 10:26:20.497898 | 
2025-12-05 10:26:20.498138 | PLAY [localhost]
2025-12-05 10:26:20.506303 | 
2025-12-05 10:26:20.506369 | TASK [Gathering Facts]
2025-12-05 10:26:21.343233 | localhost | ok
2025-12-05 10:26:21.356817 | 
2025-12-05 10:26:21.356927 | TASK [log-inventory : Ensure Zuul Ansible directory exists]
2025-12-05 10:26:21.708127 | localhost -> localhost | changed
2025-12-05 10:26:21.714320 | 
2025-12-05 10:26:21.714395 | TASK [log-inventory : Copy ansible inventory to logs dir]
2025-12-05 10:26:22.429732 | localhost -> localhost | changed
2025-12-05 10:26:22.437798 | 
2025-12-05 10:26:22.437865 | TASK [Setup log path fact]
2025-12-05 10:26:22.456658 | localhost | ok
2025-12-05 10:26:22.467186 | 
2025-12-05 10:26:22.467251 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-05 10:26:22.495190 | localhost | ok
2025-12-05 10:26:22.502502 | 
2025-12-05 10:26:22.502568 | TASK [emit-job-header : Print job information]
2025-12-05 10:26:22.550098 | # Job Information
2025-12-05 10:26:22.550230 | Ansible Version: 2.15.12
2025-12-05 10:26:22.550260 | Job: cifmw-molecule-run_hook
2025-12-05 10:26:22.550282 | Pipeline: github-check
2025-12-05 10:26:22.550301 | Executor: ibm-bm4-ze.softwarefactory-project.io
2025-12-05 10:26:22.550319 | Triggered by: https://github.com/openstack-k8s-operators/ci-framework/pull/3537
2025-12-05 10:26:22.550338 | Log URL (when completed): https://logserver.rdoproject.org/56d/rdoproject.org/56d676471e324ef58163400f8888f0a1/
2025-12-05 10:26:22.550357 | Event ID: aa92ada0-d1c4-11f0-9be9-0538eab16b37
2025-12-05 10:26:22.554095 | 
2025-12-05 10:26:22.554159 | LOOP [emit-job-header : Print node information]
2025-12-05 10:26:22.645942 | localhost | ok:
2025-12-05 10:26:22.646174 | localhost | # Node Information
2025-12-05 10:26:22.646202 | localhost | Inventory Hostname: controller
2025-12-05 10:26:22.646226 | localhost | Hostname: np0005546809
2025-12-05 10:26:22.646246 | localhost | Username: zuul
2025-12-05 10:26:22.646265 | localhost | Distro: CentOS 9
2025-12-05 10:26:22.646283 | localhost | Provider: ibm-bm4-nodepool
2025-12-05 10:26:22.646301 | localhost | Region: regionOne
2025-12-05 10:26:22.646318 | localhost | Label: cloud-centos-9-stream-tripleo-ibm
2025-12-05 10:26:22.646339 | localhost | Product Name: OpenStack Compute
2025-12-05 10:26:22.646357 | localhost | Interface IP: 192.168.26.157
2025-12-05 10:26:22.668200 | 
2025-12-05 10:26:22.668312 | PLAY [all]
2025-12-05 10:26:22.675031 | 
2025-12-05 10:26:22.675099 | TASK [Gather network facts]
2025-12-05 10:26:23.030315 | controller | ok
2025-12-05 10:26:23.043120 | 
2025-12-05 10:26:23.043181 | TASK [include_role : start-zuul-console]
2025-12-05 10:26:23.062462 | controller | ok
2025-12-05 10:26:23.073080 | 
2025-12-05 10:26:23.073145 | TASK [start-zuul-console : Start zuul_console daemon.]
2025-12-05 10:26:23.386472 | controller | ok
2025-12-05 10:26:23.394472 | 
2025-12-05 10:26:23.394535 | TASK [include_role : add-build-sshkey]
2025-12-05 10:26:23.413408 | controller | ok
2025-12-05 10:26:23.425396 | 
2025-12-05 10:26:23.425462 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build]
2025-12-05 10:26:23.622116 | controller -> localhost | ok
2025-12-05 10:26:23.628069 | 
2025-12-05 10:26:23.628136 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID]
2025-12-05 10:26:23.660300 | controller | ok
2025-12-05 10:26:23.673277 | controller | included: /var/lib/zuul/builds/56d676471e324ef58163400f8888f0a1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml
2025-12-05 10:26:23.678864 | 
2025-12-05 10:26:23.678961 | TASK [add-build-sshkey : Create Temp SSH key]
2025-12-05 10:26:24.098658 | controller -> localhost | Generating public/private rsa key pair.
2025-12-05 10:26:24.098897 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/56d676471e324ef58163400f8888f0a1/work/56d676471e324ef58163400f8888f0a1_id_rsa.
2025-12-05 10:26:24.098951 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/56d676471e324ef58163400f8888f0a1/work/56d676471e324ef58163400f8888f0a1_id_rsa.pub.
2025-12-05 10:26:24.098976 | controller -> localhost | The key fingerprint is:
2025-12-05 10:26:24.098997 | controller -> localhost | SHA256:tZH6kbhUUnM00HDcdiJbmx7mPXCJr2WucDXMqB47WW0 zuul-build-sshkey
2025-12-05 10:26:24.099017 | controller -> localhost | The key's randomart image is:
2025-12-05 10:26:24.099035 | controller -> localhost | +---[RSA 3072]----+
2025-12-05 10:26:24.099052 | controller -> localhost | |          =*=.   |
2025-12-05 10:26:24.099069 | controller -> localhost | |         . =+.= .|
2025-12-05 10:26:24.099086 | controller -> localhost | |        . =  =.=.|
2025-12-05 10:26:24.099103 | controller -> localhost | |         * +.oOo |
2025-12-05 10:26:24.099119 | controller -> localhost | |        S +  ==B |
2025-12-05 10:26:24.099135 | controller -> localhost | |       . o ...+Eo|
2025-12-05 10:26:24.099151 | controller -> localhost | |        . .+o.* .|
2025-12-05 10:26:24.099170 | controller -> localhost | |          .o=. . |
2025-12-05 10:26:24.099189 | controller -> localhost | |           o...  |
2025-12-05 10:26:24.099206 | controller -> localhost | +----[SHA256]-----+
2025-12-05 10:26:24.099254 | controller -> localhost | ok: Runtime: 0:00:00.051914
2025-12-05 10:26:24.105266 | 
2025-12-05 10:26:24.105336 | TASK [add-build-sshkey : Remote setup ssh keys (linux)]
2025-12-05 10:26:24.135862 | controller | ok
2025-12-05 10:26:24.144845 | controller | included: /var/lib/zuul/builds/56d676471e324ef58163400f8888f0a1/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml
2025-12-05 10:26:24.151867 | 
2025-12-05 10:26:24.151952 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey]
2025-12-05 10:26:24.165802 | controller | skipping: Conditional result was False
2025-12-05 10:26:24.171565 | 
2025-12-05 10:26:24.171627 | TASK [add-build-sshkey : Enable access via build key on all nodes]
2025-12-05 10:26:24.532210 | controller | changed
2025-12-05 10:26:24.543953 | 
2025-12-05 10:26:24.544032 | TASK [add-build-sshkey : Make sure user has a .ssh]
2025-12-05 10:26:24.736859 | controller | ok
2025-12-05 10:26:24.741863 | 
2025-12-05 10:26:24.741947 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes]
2025-12-05 10:26:25.322244 | controller | changed
2025-12-05 10:26:25.327438 | 
2025-12-05 10:26:25.327507 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes]
2025-12-05 10:26:25.894164 | controller | changed
2025-12-05 10:26:25.899676 | 
2025-12-05 10:26:25.899755 | TASK [add-build-sshkey : Remote setup ssh keys (windows)]
2025-12-05 10:26:25.929287 | controller | skipping: Conditional result was False
2025-12-05 10:26:25.934194 | 
2025-12-05 10:26:25.934258 | TASK [remove-zuul-sshkey : Remove master key from local agent]
2025-12-05 10:26:26.272577 | controller -> localhost | changed
2025-12-05 10:26:26.283209 | 
2025-12-05 10:26:26.283298 | TASK [add-build-sshkey : Add back temp key]
2025-12-05 10:26:26.522389 | controller -> localhost | Identity added: /var/lib/zuul/builds/56d676471e324ef58163400f8888f0a1/work/56d676471e324ef58163400f8888f0a1_id_rsa (zuul-build-sshkey)
2025-12-05 10:26:26.522639 | controller -> localhost | ok: Runtime: 0:00:00.008806
2025-12-05 10:26:26.528614 | 
2025-12-05 10:26:26.528686 | TASK [add-build-sshkey : Verify we can still SSH to all nodes]
2025-12-05 10:26:26.824054 | controller | ok
2025-12-05 10:26:26.830099 | 
2025-12-05 10:26:26.830247 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)]
2025-12-05 10:26:26.859522 | controller | skipping: Conditional result was False
2025-12-05 10:26:26.869590 | 
2025-12-05 10:26:26.869656 | TASK [include_role : validate-host]
2025-12-05 10:26:26.890345 | controller | ok
2025-12-05 10:26:26.910441 | 
2025-12-05 10:26:26.910515 | TASK [validate-host : Define zuul_info_dir fact]
2025-12-05 10:26:26.940366 | controller | ok
2025-12-05 10:26:26.944898 | 
2025-12-05 10:26:26.944981 | TASK [validate-host : Ensure Zuul Ansible directory exists]
2025-12-05 10:26:27.152882 | controller -> localhost | ok
2025-12-05 10:26:27.159572 | 
2025-12-05 10:26:27.159640 | TASK [validate-host : Collect information about the host]
2025-12-05 10:26:27.746726 | controller | ok
2025-12-05 10:26:27.754523 | 
2025-12-05 10:26:27.754591 | TASK [validate-host : Sanitize hostname]
2025-12-05 10:26:27.825336 | controller | ok
2025-12-05 10:26:27.855923 | 
2025-12-05 10:26:27.856008 | TASK [validate-host : Write out all ansible variables/facts known for each host]
2025-12-05 10:26:28.225067 | controller -> localhost | changed
2025-12-05 10:26:28.230987 | 
2025-12-05 10:26:28.231052 | TASK [validate-host : Collect information about zuul worker]
2025-12-05 10:26:28.546297 | controller | ok
2025-12-05 10:26:28.550572 | 
2025-12-05 10:26:28.550639 | TASK [validate-host : Write out all zuul information for each host]
2025-12-05 10:26:28.909766 | controller -> localhost | changed
2025-12-05 10:26:28.921090 | 
2025-12-05 10:26:28.921213 | TASK [include_role : prepare-workspace-openshift]
2025-12-05 10:26:28.935168 | controller | skipping: Conditional result was False
2025-12-05 10:26:28.940983 | 
2025-12-05 10:26:28.941052 | TASK [include_role : remove-zuul-sshkey]
2025-12-05 10:26:28.954573 | controller | skipping: Conditional result was False
2025-12-05 10:26:28.959745 | 
2025-12-05 10:26:28.959815 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them]
2025-12-05 10:26:29.148556 | controller | ok: "logs"
2025-12-05 10:26:29.148843 | controller | ok: All items complete
2025-12-05 10:26:29.148874 | 
2025-12-05 10:26:29.303614 | controller | ok: "artifacts"
2025-12-05 10:26:29.457971 | controller | ok: "docs"
2025-12-05 10:26:29.466762 | 
2025-12-05 10:26:29.466880 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist]
2025-12-05 10:26:29.662203 | controller | changed: "logs"
2025-12-05 10:26:29.825815 | controller | changed: "artifacts"
2025-12-05 10:26:29.985409 | controller | changed: "docs"
2025-12-05 10:26:30.008311 | 
2025-12-05 10:26:30.008424 | PLAY RECAP
2025-12-05 10:26:30.008472 | controller | ok: 22 changed: 9 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-05 10:26:30.008498 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-05 10:26:30.008515 | 
2025-12-05 10:26:30.107218 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/pre.yaml@master]
2025-12-05 10:26:30.107972 | PRE-RUN START: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-12-05 10:26:30.704932 | 
2025-12-05 10:26:30.705094 | PLAY [all]
2025-12-05 10:26:30.723716 | 
2025-12-05 10:26:30.723793 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-12-05 10:26:30.776081 | controller | ok
2025-12-05 10:26:30.781095 | 
2025-12-05 10:26:30.781178 | TASK [mirror-info-fork : Create /etc/ci]
2025-12-05 10:26:31.127374 | controller | changed
2025-12-05 10:26:31.133532 | 
2025-12-05 10:26:31.133616 | TASK [mirror-info-fork : Install ci_mirror script]
2025-12-05 10:26:31.975473 | controller | changed
2025-12-05 10:26:31.985435 | 
2025-12-05 10:26:31.985504 | LOOP [add-authorized-keys : Enable access via build key on all nodes]
2025-12-05 10:26:32.360457 | controller | changed:
2025-12-05 10:26:32.360675 | controller | {
2025-12-05 10:26:32.360706 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAABIwAAAQEA4Z/c9osaGGtU6X8fgELwfj/yayRurfcKA0HMFfdpPxev2dbwljysMuzoVp4OZmW1gvGtyYPSNRvnzgsaabPNKNo2ym5NToCP6UM+KSe93aln4BcM/24mXChYAbXJQ5Bqq/pIzsGs/pKetQN+vwvMxLOwTvpcsCJBXaa981RKML6xj9l/UZ7IIq1HSEKMvPLxZMWdu0Ut8DkCd5F4nOw9Wgml2uYpDCj5LLCrQQ9ChdOMz8hz6SighhNlRpPkvPaet3OXxr/ytFMu7j7vv06CaEnuMMiY2aTWN1Imin9eHAylIqFHta/3gFfQSWt9jXM7owkBLKL7ATzhaAn+fjNupw== arxcruz@redhat.com"
2025-12-05 10:26:32.360734 | controller | }
2025-12-05 10:26:32.561593 | controller | changed:
2025-12-05 10:26:32.561660 | controller | {
2025-12-05 10:26:32.561688 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQDS4Fn6k4deCnIlOtLWqZJyksbepjQt04j8Ed8CGx9EKkj0fKiAxiI4TadXQYPuNHMixZy4Nevjb6aDhL5Z906TfvNHKUrjrG7G26a0k8vdc61NEQ7FmcGMWRLwwc6ReDO7lFpzYKBMk4YqfWgBuGU/K6WLKiVW2cVvwIuGIaYrE1OiiX0iVUUk7KApXlDJMXn7qjSYynfO4mF629NIp8FJal38+Kv+HA+0QkE5Y2xXnzD4Lar5+keymiCHRntPppXHeLIRzbt0gxC7v3L72hpQ3BTBEzwHpeS8KY+SX1y5lRMN45thCHfJqGmARJREDjBvWG8JXOPmVIKQtZmVcD5b mandreou@redhat.com"
2025-12-05 10:26:32.561709 | controller | }
2025-12-05 10:26:32.763929 | controller | changed:
2025-12-05 10:26:32.763983 | controller | {
2025-12-05 10:26:32.764009 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC9MiLfy30deHA7xPOAlew5qUq3UP2gmRMYJi8PtkjFB20/DKeWwWNnkZPqP9AayruRoo51SIiVg870gbZE2jYl+Ncx/FYDe56JeC3ySZsXoAVkC9bP7gkOGqOmJjirvAgPMI7bogVz8i+66Q4Ar7OKTp3762G4IuWPPEg4ce4Y7lx9qWocZapHYq4cYKMxrOZ7SEbFSATBbe2bPZAPKTw8do/Eny+Hq/LkHFhIeyra6cqTFQYShr+zPln0Cr+ro/pDX3bB+1ubFgTpjpkkkQsLhDfR6cCdCWM2lgnS3BTtYj5Ct9/JRPR5YOphqZz+uB+OEu2IL68hmU9vNTth1KeX rlandy@redhat.com"
2025-12-05 10:26:32.764029 | controller | }
2025-12-05 10:26:32.970103 | controller | changed:
2025-12-05 10:26:32.970159 | controller | {
2025-12-05 10:26:32.970186 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIFCbgz8gdERiJlk2IKOtkjQxEXejrio6ZYMJAVJYpOIp raukadah@gmail.com"
2025-12-05 10:26:32.970206 | controller | }
2025-12-05 10:26:33.160770 | controller | changed:
2025-12-05 10:26:33.160822 | controller | {
2025-12-05 10:26:33.160848 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIBqb3Q/9uDf4LmihQ7xeJ9gA/STIQUFPSfyyV0m8AoQi bshewale@redhat.com"
2025-12-05 10:26:33.160868 | controller | }
2025-12-05 10:26:33.353058 | controller | changed:
2025-12-05 10:26:33.353160 | controller | {
2025-12-05 10:26:33.353187 | controller |   "public_key": "ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQC0I8QqQx0Az2ysJt2JuffucLijhBqnsXKEIx5GyHwxVULROa8VtNFXUDH6ZKZavhiMcmfHB2+TBTda+lDP4FldYj06dGmzCY+IYGa+uDRdxHNGYjvCfLFcmLlzRK6fNbTcui+KlUFUdKe0fb9CRoGKyhlJD5GRkM1Dv+Yb6Bj+RNnmm1fVGYxzmrD2utvffYEb0SZGWxq2R9gefx1q/3wCGjeqvufEV+AskPhVGc5T7t9eyZ4qmslkLh1/nMuaIBFcr9AUACRajsvk6mXrAN1g3HlBf2gQlhi1UEyfbqIQvzzFtsbLDlSum/KmKjy818GzvWjERfQ0VkGzCd9bSLVL dviroel@redhat.com"
2025-12-05 10:26:33.353207 | controller | }
2025-12-05 10:26:33.553485 | controller | changed:
2025-12-05 10:26:33.553593 | controller | {
2025-12-05 10:26:33.553618 | 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-12-05 10:26:33.553651 | controller | }
2025-12-05 10:26:33.756859 | controller | changed:
2025-12-05 10:26:33.756986 | controller | {
2025-12-05 10:26:33.757015 | 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-12-05 10:26:33.757036 | controller | }
2025-12-05 10:26:33.960675 | controller | changed:
2025-12-05 10:26:33.960799 | controller | {
2025-12-05 10:26:33.960826 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHUnwjB20UKmsSed9X73eGNV5AOEFccQ3NYrRW776pEk cjeanner"
2025-12-05 10:26:33.960873 | controller | }
2025-12-05 10:26:34.162035 | controller | changed:
2025-12-05 10:26:34.162091 | controller | {
2025-12-05 10:26:34.162117 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDercCMGn8rW1C4P67tHgtflPdTeXlpyUJYH+6XDd2lR jgilaber@redhat.com"
2025-12-05 10:26:34.162139 | controller | }
2025-12-05 10:26:34.373675 | controller | changed:
2025-12-05 10:26:34.373727 | controller | {
2025-12-05 10:26:34.373751 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIAMI6kkg9Wg0sG7jIJmyZemEBwUn1yzNpQQd3gnulOmZ adrianfuscoarnejo@gmail.com"
2025-12-05 10:26:34.373770 | controller | }
2025-12-05 10:26:34.632215 | controller | changed:
2025-12-05 10:26:34.632343 | controller | {
2025-12-05 10:26:34.632369 | controller |   "public_key": "ecdsa-sha2-nistp256 AAAAE2VjZHNhLXNoYTItbmlzdHAyNTYAAAAIbmlzdHAyNTYAAABBBPijwpQu/3jhhhBZInXNOLEH57DrknPc3PLbsRvYyJIFzwYjX+WD4a7+nGnMYS42MuZk6TJcVqgnqofVx4isoD4= ramishra@redhat.com"
2025-12-05 10:26:34.632388 | controller | }
2025-12-05 10:26:34.811597 | controller | changed:
2025-12-05 10:26:34.811766 | controller | {
2025-12-05 10:26:34.811793 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIGpU/BepK3qX0NRf5Np+dOBDqzQEefhNrw2DCZaH3uWW rebtoor@monolith"
2025-12-05 10:26:34.811813 | controller | }
2025-12-05 10:26:35.017933 | controller | changed:
2025-12-05 10:26:35.018078 | controller | {
2025-12-05 10:26:35.018105 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDK0iKdi8jQTpQrDdLVH/AAgLVYyTXF7AQ1gjc/5uT3t ykarel@yatinkarel"
2025-12-05 10:26:35.018127 | controller | }
2025-12-05 10:26:35.230480 | controller | changed:
2025-12-05 10:26:35.230701 | controller | {
2025-12-05 10:26:35.230732 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIF/V/cLotA6LZeO32VL45Hd78skuA2lJA425Sm2LlQeZ fmount@horcrux"
2025-12-05 10:26:35.230753 | controller | }
2025-12-05 10:26:35.447531 | controller | changed:
2025-12-05 10:26:35.447671 | controller | {
2025-12-05 10:26:35.447697 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIDa7QCjuDMVmRPo1rREbGwzYeBCYVN+Ou/3WKXZEC6Sr"
2025-12-05 10:26:35.447715 | controller | }
2025-12-05 10:26:35.666088 | controller | changed:
2025-12-05 10:26:35.666226 | controller | {
2025-12-05 10:26:35.666253 | 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-12-05 10:26:35.666275 | controller | }
2025-12-05 10:26:35.884212 | controller | changed:
2025-12-05 10:26:35.884330 | controller | {
2025-12-05 10:26:35.884360 | 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-12-05 10:26:35.884389 | controller | }
2025-12-05 10:26:36.104275 | controller | changed:
2025-12-05 10:26:36.104356 | controller | {
2025-12-05 10:26:36.104383 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIOKLl0NYKwoZ/JY5KeZU8VwRAggeOxqQJeoqp3dsAaY9"
2025-12-05 10:26:36.104403 | controller | }
2025-12-05 10:26:36.314977 | controller | changed:
2025-12-05 10:26:36.315044 | controller | {
2025-12-05 10:26:36.315070 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIASASQOH2BcOyLKuuDOdWZlPi2orcjcA8q4400T73DLH evallesp@fedora"
2025-12-05 10:26:36.315090 | controller | }
2025-12-05 10:26:36.526320 | controller | changed:
2025-12-05 10:26:36.526433 | controller | {
2025-12-05 10:26:36.526458 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAILeBWlamUph+jRKV2qrx1PGU7vWuGIt5+z9k96I8WehW amsinha@amsinha-mac"
2025-12-05 10:26:36.526478 | controller | }
2025-12-05 10:26:36.735781 | controller | changed:
2025-12-05 10:26:36.735850 | controller | {
2025-12-05 10:26:36.735875 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIANvVgvJBlK3gb1yz5uef/JqIGq4HLEmY2dYA8e37swb morenod@redhat-laptop"
2025-12-05 10:26:36.735895 | controller | }
2025-12-05 10:26:36.942436 | controller | changed:
2025-12-05 10:26:36.942574 | controller | {
2025-12-05 10:26:36.942622 | 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-12-05 10:26:36.942646 | controller | }
2025-12-05 10:26:37.167523 | controller | changed:
2025-12-05 10:26:37.167638 | controller | {
2025-12-05 10:26:37.167665 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIKwedoZ0TWPJX/z/4TAbO/kKcDZOQVgRH0hAqrL5UCI1 vcastell@redhat.com"
2025-12-05 10:26:37.167684 | controller | }
2025-12-05 10:26:37.396243 | controller | changed:
2025-12-05 10:26:37.396352 | controller | {
2025-12-05 10:26:37.396383 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIEmv8sE8GCk6ZTPIqF0FQrttBdL3mq7rCm/IJy0xDFh7 michburk@redhat.com"
2025-12-05 10:26:37.396405 | controller | }
2025-12-05 10:26:37.601629 | controller | changed:
2025-12-05 10:26:37.601874 | controller | {
2025-12-05 10:26:37.601949 | controller |   "public_key": "ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAICy6GpGEtwevXEEn4mmLR5lmSLe23dGgAvzkB9DMNbkf rsafrono@rsafrono"
2025-12-05 10:26:37.601977 | controller | }
2025-12-05 10:26:37.627175 | 
2025-12-05 10:26:37.627300 | TASK [Set timezone to UTC]
2025-12-05 10:26:38.045130 | controller | changed: executed `/bin/timedatectl set-timezone UTC`
2025-12-05 10:26:38.050788 | 
2025-12-05 10:26:38.050856 | TASK [Create nodepool directory]
2025-12-05 10:26:38.272824 | controller | changed
2025-12-05 10:26:38.278379 | 
2025-12-05 10:26:38.278461 | TASK [Create nodepool sub_nodes file]
2025-12-05 10:26:38.784036 | controller | changed
2025-12-05 10:26:38.789198 | 
2025-12-05 10:26:38.789276 | TASK [Create nodepool sub_nodes_private file]
2025-12-05 10:26:39.320521 | controller | changed
2025-12-05 10:26:39.326343 | 
2025-12-05 10:26:39.326417 | LOOP [Populate nodepool sub_nodes file]
2025-12-05 10:26:39.361549 | 
2025-12-05 10:26:39.361826 | LOOP [Populate nodepool sub_nodes_private file]
2025-12-05 10:26:39.394000 | 
2025-12-05 10:26:39.394167 | TASK [Create nodepool primary file]
2025-12-05 10:26:39.419215 | controller | skipping: Conditional result was False
2025-12-05 10:26:39.426080 | 
2025-12-05 10:26:39.426179 | TASK [Create nodepool node_private for this node]
2025-12-05 10:26:40.050352 | controller | changed
2025-12-05 10:26:40.057881 | 
2025-12-05 10:26:40.057965 | LOOP [Copy ssh keys to nodepool directory]
2025-12-05 10:26:40.403902 | controller | ok: Item: id_rsa Runtime: 0:00:00.006310
2025-12-05 10:26:40.404147 | 
2025-12-05 10:26:40.577367 | controller | ok: Item: id_rsa.pub Runtime: 0:00:00.005954
2025-12-05 10:26:40.583482 | 
2025-12-05 10:26:40.583552 | TASK [Add sudoers role for zuul-sudo-grep.sh]
2025-12-05 10:26:41.190899 | controller | changed
2025-12-05 10:26:41.196382 | 
2025-12-05 10:26:41.196447 | TASK [Validate sudoers config after edits]
2025-12-05 10:26:41.421068 | controller | /etc/sudoers: parsed OK
2025-12-05 10:26:41.421147 | controller | /etc/sudoers.d/90-cloud-init-users: parsed OK
2025-12-05 10:26:41.421156 | controller | /etc/sudoers.d/zuul: parsed OK
2025-12-05 10:26:41.421163 | controller | /etc/sudoers.d/zuul-sudo-grep: parsed OK
2025-12-05 10:26:41.723291 | controller | ok: Runtime: 0:00:00.005950
2025-12-05 10:26:41.728868 | 
2025-12-05 10:26:41.728952 | TASK [Show the environment passed in to job shell scripts]
2025-12-05 10:26:41.940876 | controller | SHELL=/bin/bash
2025-12-05 10:26:41.941010 | controller | ZUUL_PROJECT=openstack-k8s-operators/ci-framework
2025-12-05 10:26:41.941025 | controller | ZUUL_SHORT_PROJECT_NAME=ci-framework
2025-12-05 10:26:41.941033 | controller | ZUUL_CHANGES=openstack-k8s-operators/ci-framework:main:refs/changes/37/3537/eb73450086809293a6f3a6959cb5d293c3a8518e
2025-12-05 10:26:41.941040 | controller | PWD=/home/zuul
2025-12-05 10:26:41.941046 | controller | ZUUL_PIPELINE=github-check
2025-12-05 10:26:41.941052 | controller | LOGNAME=zuul
2025-12-05 10:26:41.941058 | controller | XDG_SESSION_TYPE=tty
2025-12-05 10:26:41.941063 | controller | _=/usr/bin/env
2025-12-05 10:26:41.941069 | controller | MOTD_SHOWN=pam
2025-12-05 10:26:41.941074 | controller | HOME=/home/zuul
2025-12-05 10:26:41.941079 | controller | LANG=en_US.UTF-8
2025-12-05 10:26:41.941085 | controller | SSH_CONNECTION=192.168.26.12 55860 192.168.26.157 22
2025-12-05 10:26:41.941092 | 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-12-05 10:26:41.941101 | controller | ZUUL_CHANGE_IDS=3537,eb73450086809293a6f3a6959cb5d293c3a8518e
2025-12-05 10:26:41.941107 | controller | WORKSPACE=/home/zuul/workspace
2025-12-05 10:26:41.941113 | controller | XDG_SESSION_CLASS=user
2025-12-05 10:26:41.941119 | controller | SELINUX_ROLE_REQUESTED=
2025-12-05 10:26:41.941124 | controller | LESSOPEN=||/usr/bin/lesspipe.sh %s
2025-12-05 10:26:41.941130 | controller | USER=zuul
2025-12-05 10:26:41.941135 | controller | ZUUL_VOTING=True
2025-12-05 10:26:41.941141 | controller | BUILD_TIMEOUT=1800000
2025-12-05 10:26:41.941146 | controller | SELINUX_USE_CURRENT_RANGE=
2025-12-05 10:26:41.941152 | controller | SHLVL=1
2025-12-05 10:26:41.941157 | controller | ZUUL_PATCHSET=eb73450086809293a6f3a6959cb5d293c3a8518e
2025-12-05 10:26:41.941163 | controller | XDG_SESSION_ID=1
2025-12-05 10:26:41.941169 | controller | ZUUL_BRANCH=main
2025-12-05 10:26:41.941174 | controller | XDG_RUNTIME_DIR=/run/user/1000
2025-12-05 10:26:41.941180 | controller | SSH_CLIENT=192.168.26.12 55860 22
2025-12-05 10:26:41.941188 | controller | DEBUGINFOD_URLS=https://debuginfod.centos.org/
2025-12-05 10:26:41.941193 | controller | DEBUGINFOD_IMA_CERT_PATH=/etc/keys/ima:
2025-12-05 10:26:41.941199 | controller | which_declare=declare -f
2025-12-05 10:26:41.941206 | controller | PATH=/home/zuul/.local/bin:/home/zuul/bin:/usr/local/bin:/usr/bin:/usr/local/sbin:/usr/sbin
2025-12-05 10:26:41.941212 | controller | SELINUX_LEVEL_REQUESTED=
2025-12-05 10:26:41.941218 | controller | ZUUL_CHANGE=3537
2025-12-05 10:26:41.941224 | controller | DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
2025-12-05 10:26:41.941229 | controller | ZUUL_UUID=56d676471e324ef58163400f8888f0a1
2025-12-05 10:26:41.941235 | controller | BASH_FUNC_which%%=() {  ( alias;
2025-12-05 10:26:41.941241 | controller |  eval ${which_declare} ) | /usr/bin/which --tty-only --read-alias --read-functions --show-tilde --show-dot $@
2025-12-05 10:26:41.941247 | controller | }
2025-12-05 10:26:42.255282 | controller | ok: Runtime: 0:00:00.006759
2025-12-05 10:26:42.262195 | 
2025-12-05 10:26:42.262264 | TASK [Workaround hardcoded /home/zuul/workspace in zuul_legacy_vars]
2025-12-05 10:26:42.277243 | controller | skipping: Conditional result was False
2025-12-05 10:26:42.283312 | 
2025-12-05 10:26:42.283373 | TASK [Symlink /home/zuul-worker/workspace]
2025-12-05 10:26:42.807275 | controller | skipping: Conditional result was False
2025-12-05 10:26:42.817398 | 
2025-12-05 10:26:42.817528 | TASK [Ensure legacy workspace directory]
2025-12-05 10:26:43.033682 | controller | changed
2025-12-05 10:26:43.051725 | 
2025-12-05 10:26:43.051787 | PLAY RECAP
2025-12-05 10:26:43.051843 | controller | ok: 14 changed: 11 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0
2025-12-05 10:26:43.051866 | 
2025-12-05 10:26:43.140989 | PRE-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/ci-framework-rdo-base/pre.yaml@master]
2025-12-05 10:26:43.141804 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-12-05 10:26:43.648862 | 
2025-12-05 10:26:43.649040 | PLAY [Run ci/playbooks/dump_zuul_data.yml]
2025-12-05 10:26:43.668790 | 
2025-12-05 10:26:43.668861 | TASK [Create zuul-output directory]
2025-12-05 10:26:43.991732 | controller | changed
2025-12-05 10:26:43.996582 | 
2025-12-05 10:26:43.996655 | TASK [Slurp Zuul inventory test]
2025-12-05 10:26:44.274755 | controller -> localhost | ok
2025-12-05 10:26:44.281880 | 
2025-12-05 10:26:44.281964 | TASK [Save zuul inventory]
2025-12-05 10:26:45.029169 | controller | changed
2025-12-05 10:26:45.034066 | 
2025-12-05 10:26:45.034131 | TASK [Save zuul vars without the change_message]
2025-12-05 10:26:45.642593 | controller | changed
2025-12-05 10:26:45.659936 | 
2025-12-05 10:26:45.660003 | PLAY RECAP
2025-12-05 10:26:45.660056 | controller | ok: 4 changed: 3 unreachable: 0 failed: 0 skipped: 0 rescued: 0 ignored: 0
2025-12-05 10:26:45.660086 | 
2025-12-05 10:26:45.738133 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/dump_zuul_data.yml@main]
2025-12-05 10:26:45.738931 | PRE-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-12-05 10:26:46.284703 | 
2025-12-05 10:26:46.284813 | PLAY [Run ci/playbooks/molecule-prepare.yml]
2025-12-05 10:26:46.304937 | 
2025-12-05 10:26:46.305011 | TASK [Execute mirror info role to configure /etc/ci/mirror_info.sh]
2025-12-05 10:26:46.323338 | controller | ok
2025-12-05 10:26:46.339799 | 
2025-12-05 10:26:46.339879 | TASK [mirror-info-fork : Set mirror_fqdn if not defined]
2025-12-05 10:26:46.364213 | controller | skipping: Conditional result was False
2025-12-05 10:26:46.369637 | 
2025-12-05 10:26:46.369703 | TASK [mirror-info-fork : Create /etc/ci]
2025-12-05 10:26:46.702787 | controller | ok
2025-12-05 10:26:46.708366 | 
2025-12-05 10:26:46.708436 | TASK [mirror-info-fork : Install ci_mirror script]
2025-12-05 10:26:47.326471 | controller | ok
2025-12-05 10:26:47.336657 | 
2025-12-05 10:26:47.336722 | TASK [Prepare workspace]
2025-12-05 10:26:47.355864 | controller | ok
2025-12-05 10:26:47.372295 | 
2025-12-05 10:26:47.372365 | TASK [prepare-workspace : Start zuul_console daemon.]
2025-12-05 10:26:47.694726 | controller | ok
2025-12-05 10:26:47.701268 | 
2025-12-05 10:26:47.701338 | TASK [prepare-workspace : Synchronize src repos to workspace directory.]
2025-12-05 10:26:50.113561 | controller | Output suppressed because no_log was given
2025-12-05 10:26:50.122588 | 
2025-12-05 10:26:50.122653 | LOOP [Create zuul-output directory]
2025-12-05 10:26:50.313947 | controller | changed: "/home/zuul/ci-framework-data/logs"
2025-12-05 10:26:50.470161 | controller | ok: "/home/zuul/zuul-output/logs"
2025-12-05 10:26:50.477426 | 
2025-12-05 10:26:50.477559 | TASK [Install required packages]
2025-12-05 10:27:37.425755 | controller | changed
2025-12-05 10:27:37.430898 | 
2025-12-05 10:27:37.430975 | TASK [Install venv]
2025-12-05 10:28:37.241617 | controller | changed
2025-12-05 10:28:37.289589 | 
2025-12-05 10:28:37.289680 | PLAY RECAP
2025-12-05 10:28:37.289737 | controller | ok: 7 changed: 4 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-12-05 10:28:37.289763 | 
2025-12-05 10:28:37.356660 | PRE-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-prepare.yml@main]
2025-12-05 10:28:37.357598 | RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-12-05 10:28:37.882522 | 
2025-12-05 10:28:37.882634 | PLAY [Run ci/playbooks/molecule-test.yml]
2025-12-05 10:28:37.903469 | 
2025-12-05 10:28:37.903541 | TASK [Gather required facts]
2025-12-05 10:28:38.378817 | controller | ok
2025-12-05 10:28:38.384134 | 
2025-12-05 10:28:38.384211 | TASK [Load environment var if instructed to]
2025-12-05 10:28:38.408411 | controller | skipping: Conditional result was False
2025-12-05 10:28:38.413748 | 
2025-12-05 10:28:38.413825 | TASK [Ensure group_vars dir exists]
2025-12-05 10:28:38.725532 | controller | ok
2025-12-05 10:28:38.731629 | 
2025-12-05 10:28:38.731697 | TASK [Print related variables]
2025-12-05 10:28:38.760303 | controller | ok:
2025-12-05 10:28:38.760446 | controller | mol_config_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config_local.yml
2025-12-05 10:28:38.760555 | controller | roles_dir: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook
2025-12-05 10:28:38.765303 | 
2025-12-05 10:28:38.765371 | TASK [Run molecule]
2025-12-05 10:28:39.687154 | controller | INFO     Found config file /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/.config/molecule/config.yml
2025-12-05 10:28:39.765894 | controller | INFO     Running default > prepare
2025-12-05 10:28:40.403988 | controller |
2025-12-05 10:28:40.404035 | controller | PLAY [Prepare] *****************************************************************
2025-12-05 10:28:40.404174 | controller |
2025-12-05 10:28:40.404648 | controller | TASK [Gathering Facts] *********************************************************
2025-12-05 10:28:40.404730 | controller | Friday 05 December 2025  10:28:40 +0000 (0:00:00.010)       0:00:00.010 *******
2025-12-05 10:28:41.200790 | controller | ok: [instance]
2025-12-05 10:28:41.200885 | controller |
2025-12-05 10:28:41.200990 | controller | TASK [Create dummy env file] ***************************************************
2025-12-05 10:28:41.201097 | controller | Friday 05 December 2025  10:28:41 +0000 (0:00:00.797)       0:00:00.807 *******
2025-12-05 10:28:41.684799 | controller | changed: [instance]
2025-12-05 10:28:41.684888 | controller |
2025-12-05 10:28:41.684998 | controller | TASK [Create dummy playbook] ***************************************************
2025-12-05 10:28:41.685098 | controller | Friday 05 December 2025  10:28:41 +0000 (0:00:00.484)       0:00:01.291 *******
2025-12-05 10:28:43.538070 | controller | changed: [instance] => (item=dummy-1.yml)
2025-12-05 10:28:43.538146 | controller | changed: [instance] => (item=dummy-2.yml)
2025-12-05 10:28:43.538247 | controller | changed: [instance] => (item=dummy-3.yml)
2025-12-05 10:28:43.538375 | controller | changed: [instance] => (item=dummy-4.yml)
2025-12-05 10:28:43.538471 | controller | changed: [instance] => (item=dummy-5.yml)
2025-12-05 10:28:43.538561 | controller | changed: [instance] => (item=dummy-6.yml)
2025-12-05 10:28:43.538651 | controller |
2025-12-05 10:28:43.538752 | controller | TASK [Remove dummy file for retry playbook test] *******************************
2025-12-05 10:28:43.538875 | controller | Friday 05 December 2025  10:28:43 +0000 (0:00:01.853)       0:00:03.145 *******
2025-12-05 10:28:43.809689 | controller | ok: [instance]
2025-12-05 10:28:43.809785 | controller |
2025-12-05 10:28:43.809902 | controller | TASK [Create dummy retry playbook] *********************************************
2025-12-05 10:28:43.810009 | controller | Friday 05 December 2025  10:28:43 +0000 (0:00:00.271)       0:00:03.416 *******
2025-12-05 10:28:44.137159 | controller | changed: [instance]
2025-12-05 10:28:44.137278 | controller |
2025-12-05 10:28:44.137432 | controller | PLAY RECAP *********************************************************************
2025-12-05 10:28:44.137554 | controller | instance                   : ok=5    changed=3    unreachable=0    failed=0    skipped=0    rescued=0    ignored=0
2025-12-05 10:28:44.137657 | controller |
2025-12-05 10:28:44.137752 | controller | Friday 05 December 2025  10:28:44 +0000 (0:00:00.327)       0:00:03.744 *******
2025-12-05 10:28:44.137873 | controller | ===============================================================================
2025-12-05 10:28:44.137971 | controller | Create dummy playbook --------------------------------------------------- 1.85s
2025-12-05 10:28:44.138070 | controller | Gathering Facts --------------------------------------------------------- 0.80s
2025-12-05 10:28:44.138169 | controller | Create dummy env file --------------------------------------------------- 0.48s
2025-12-05 10:28:44.138291 | controller | Create dummy retry playbook --------------------------------------------- 0.33s
2025-12-05 10:28:44.138393 | controller | Remove dummy file for retry playbook test ------------------------------- 0.27s
2025-12-05 10:28:44.186379 | controller | INFO     Running default > converge
2025-12-05 10:28:44.597320 | controller |
2025-12-05 10:28:44.597689 | controller | PLAY [Converge] ****************************************************************
2025-12-05 10:28:45.367439 | controller |
2025-12-05 10:28:45.367469 | controller | TASK [Gathering Facts] *********************************************************
2025-12-05 10:28:45.367479 | controller | Friday 05 December 2025  10:28:44 +0000 (0:00:00.015)       0:00:00.015 *******
2025-12-05 10:28:45.367490 | controller | ok: [instance]
2025-12-05 10:28:45.396043 | controller |
2025-12-05 10:28:45.396068 | controller | TASK [No hook] *****************************************************************
2025-12-05 10:28:45.396077 | controller | Friday 05 December 2025  10:28:45 +0000 (0:00:00.770)       0:00:00.785 *******
2025-12-05 10:28:45.396089 | controller |
2025-12-05 10:28:45.452069 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-12-05 10:28:45.452102 | controller | Friday 05 December 2025  10:28:45 +0000 (0:00:00.028)       0:00:00.814 *******
2025-12-05 10:28:45.452114 | controller | ok: [instance]
2025-12-05 10:28:45.527077 | controller |
2025-12-05 10:28:45.527099 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-12-05 10:28:45.527106 | controller | Friday 05 December 2025  10:28:45 +0000 (0:00:00.055)       0:00:00.870 *******
2025-12-05 10:28:45.527115 | controller | ok: [instance]
2025-12-05 10:28:45.602906 | controller |
2025-12-05 10:28:45.602931 | controller | TASK [run_hook : Loop on hooks for no_hook] ************************************
2025-12-05 10:28:45.602941 | controller | Friday 05 December 2025  10:28:45 +0000 (0:00:00.074)       0:00:00.945 *******
2025-12-05 10:28:45.602952 | controller | skipping: [instance]
2025-12-05 10:28:45.624658 | controller |
2025-12-05 10:28:45.624681 | controller | TASK [Ensure we do not have ceph_uuid] *****************************************
2025-12-05 10:28:45.624697 | controller | Friday 05 December 2025  10:28:45 +0000 (0:00:00.075)       0:00:01.020 *******
2025-12-05 10:28:45.624708 | controller | ok: [instance] => changed=false
2025-12-05 10:28:45.624907 | controller |   msg: All assertions passed
2025-12-05 10:28:45.625070 | controller |
2025-12-05 10:28:45.625237 | controller | TASK [Combined hooks] **********************************************************
2025-12-05 10:28:45.625407 | controller | Friday 05 December 2025  10:28:45 +0000 (0:00:00.022)       0:00:01.043 *******
2025-12-05 10:28:45.653923 | controller |
2025-12-05 10:28:45.654120 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-12-05 10:28:45.654325 | controller | Friday 05 December 2025  10:28:45 +0000 (0:00:00.029)       0:00:01.072 *******
2025-12-05 10:28:45.709624 | controller | ok: [instance]
2025-12-05 10:28:45.709823 | controller |
2025-12-05 10:28:45.709997 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-12-05 10:28:45.710163 | controller | Friday 05 December 2025  10:28:45 +0000 (0:00:00.055)       0:00:01.128 *******
2025-12-05 10:28:45.784301 | controller | ok: [instance]
2025-12-05 10:28:45.784498 | controller |
2025-12-05 10:28:45.784644 | controller | TASK [run_hook : Loop on hooks for run_molecule] *******************************
2025-12-05 10:28:45.784787 | controller | Friday 05 December 2025  10:28:45 +0000 (0:00:00.074)       0:00:01.202 *******
2025-12-05 10:28:45.905788 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'name': '01 Default noop hook', 'source': 'noop.yml', 'type': 'playbook'})
2025-12-05 10:28:45.906011 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'name': '02 Re-run noop', 'source': 'noop.yml', 'type': 'playbook'})
2025-12-05 10:28:45.906205 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'source': '/tmp/dummy-1.yml', 'type': 'playbook', 'extra_vars': {'foo': 'bar', 'file': '/tmp/dummy-env.yml'}, 'name': '03 single hook'})
2025-12-05 10:28:45.906402 | controller |
2025-12-05 10:28:45.906584 | controller | TASK [run_hook : Set playbook path for 01 Default noop hook] *******************
2025-12-05 10:28:45.906745 | controller | Friday 05 December 2025  10:28:45 +0000 (0:00:00.121)       0:00:01.324 *******
2025-12-05 10:28:45.952063 | controller | ok: [instance]
2025-12-05 10:28:45.952243 | controller |
2025-12-05 10:28:45.952457 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-05 10:28:45.952625 | controller | Friday 05 December 2025  10:28:45 +0000 (0:00:00.046)       0:00:01.370 *******
2025-12-05 10:28:46.228343 | controller | ok: [instance]
2025-12-05 10:28:46.228575 | controller |
2025-12-05 10:28:46.228607 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-05 10:28:46.245031 | controller | Friday 05 December 2025  10:28:46 +0000 (0:00:00.275)       0:00:01.646 *******
2025-12-05 10:28:46.245059 | controller | skipping: [instance]
2025-12-05 10:28:46.517335 | controller |
2025-12-05 10:28:46.517365 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-05 10:28:46.517373 | controller | Friday 05 December 2025  10:28:46 +0000 (0:00:00.016)       0:00:01.663 *******
2025-12-05 10:28:46.517390 | controller | ok: [instance]
2025-12-05 10:28:46.517415 | controller |
2025-12-05 10:28:46.517636 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-05 10:28:46.537040 | controller | Friday 05 December 2025  10:28:46 +0000 (0:00:00.272)       0:00:01.935 *******
2025-12-05 10:28:46.537070 | controller | ok: [instance]
2025-12-05 10:28:46.818825 | controller |
2025-12-05 10:28:46.818854 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-05 10:28:46.818862 | controller | Friday 05 December 2025  10:28:46 +0000 (0:00:00.019)       0:00:01.955 *******
2025-12-05 10:28:46.818873 | controller | ok: [instance]
2025-12-05 10:28:47.010087 | controller |
2025-12-05 10:28:47.010109 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-05 10:28:47.010117 | controller | Friday 05 December 2025  10:28:46 +0000 (0:00:00.281)       0:00:02.236 *******
2025-12-05 10:28:47.010126 | controller | ok: [instance]
2025-12-05 10:28:47.586121 | controller |
2025-12-05 10:28:47.586150 | controller | TASK [run_hook : Run hook without retry - 01 Default noop hook] ****************
2025-12-05 10:28:47.586158 | controller | Friday 05 December 2025  10:28:47 +0000 (0:00:00.191)       0:00:02.428 *******
2025-12-05 10:28:47.586168 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_000_run_hook_without_retry_01.log
2025-12-05 10:28:47.613042 | controller | changed: [instance]
2025-12-05 10:28:47.613065 | controller |
2025-12-05 10:28:47.613073 | controller | TASK [run_hook : Run hook with retry - 01 Default noop hook] *******************
2025-12-05 10:28:47.613082 | controller | Friday 05 December 2025  10:28:47 +0000 (0:00:00.575)       0:00:03.004 *******
2025-12-05 10:28:47.613091 | controller | skipping: [instance]
2025-12-05 10:28:47.781580 | controller |
2025-12-05 10:28:47.781608 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-05 10:28:47.781616 | controller | Friday 05 December 2025  10:28:47 +0000 (0:00:00.027)       0:00:03.031 *******
2025-12-05 10:28:47.781626 | controller | ok: [instance]
2025-12-05 10:28:47.798495 | controller |
2025-12-05 10:28:47.798513 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-05 10:28:47.798520 | controller | Friday 05 December 2025  10:28:47 +0000 (0:00:00.168)       0:00:03.199 *******
2025-12-05 10:28:47.798529 | controller | skipping: [instance]
2025-12-05 10:28:47.844325 | controller |
2025-12-05 10:28:47.844357 | controller | TASK [run_hook : Set playbook path for 02 Re-run noop] *************************
2025-12-05 10:28:47.844365 | controller | Friday 05 December 2025  10:28:47 +0000 (0:00:00.017)       0:00:03.216 *******
2025-12-05 10:28:47.844376 | controller | ok: [instance]
2025-12-05 10:28:47.844634 | controller |
2025-12-05 10:28:48.029721 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-05 10:28:48.029760 | controller | Friday 05 December 2025  10:28:47 +0000 (0:00:00.046)       0:00:03.262 *******
2025-12-05 10:28:48.029772 | controller | ok: [instance]
2025-12-05 10:28:48.046318 | controller |
2025-12-05 10:28:48.046336 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-05 10:28:48.046344 | controller | Friday 05 December 2025  10:28:48 +0000 (0:00:00.184)       0:00:03.447 *******
2025-12-05 10:28:48.046353 | controller | skipping: [instance]
2025-12-05 10:28:48.046464 | controller |
2025-12-05 10:28:48.046482 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-05 10:28:48.046494 | controller | Friday 05 December 2025  10:28:48 +0000 (0:00:00.016)       0:00:03.464 *******
2025-12-05 10:28:48.227782 | controller | ok: [instance]
2025-12-05 10:28:48.246298 | controller |
2025-12-05 10:28:48.246322 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-05 10:28:48.246331 | controller | Friday 05 December 2025  10:28:48 +0000 (0:00:00.181)       0:00:03.645 *******
2025-12-05 10:28:48.246341 | controller | ok: [instance]
2025-12-05 10:28:48.434324 | controller |
2025-12-05 10:28:48.434355 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-05 10:28:48.434363 | controller | Friday 05 December 2025  10:28:48 +0000 (0:00:00.018)       0:00:03.664 *******
2025-12-05 10:28:48.434373 | controller | ok: [instance]
2025-12-05 10:28:48.434396 | controller |
2025-12-05 10:28:48.434412 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-05 10:28:48.434523 | controller | Friday 05 December 2025  10:28:48 +0000 (0:00:00.187)       0:00:03.852 *******
2025-12-05 10:28:48.616336 | controller | ok: [instance]
2025-12-05 10:28:48.616491 | controller |
2025-12-05 10:28:48.616504 | controller | TASK [run_hook : Run hook without retry - 02 Re-run noop] **********************
2025-12-05 10:28:48.616514 | controller | Friday 05 December 2025  10:28:48 +0000 (0:00:00.181)       0:00:04.034 *******
2025-12-05 10:28:49.186335 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_001_run_hook_without_retry_02_re.log
2025-12-05 10:28:49.186389 | controller | changed: [instance]
2025-12-05 10:28:49.186398 | controller |
2025-12-05 10:28:49.186407 | controller | TASK [run_hook : Run hook with retry - 02 Re-run noop] *************************
2025-12-05 10:28:49.186521 | controller | Friday 05 December 2025  10:28:49 +0000 (0:00:00.570)       0:00:04.604 *******
2025-12-05 10:28:49.215225 | controller | skipping: [instance]
2025-12-05 10:28:49.385362 | controller |
2025-12-05 10:28:49.385392 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-05 10:28:49.385401 | controller | Friday 05 December 2025  10:28:49 +0000 (0:00:00.029)       0:00:04.633 *******
2025-12-05 10:28:49.385411 | controller | ok: [instance]
2025-12-05 10:28:49.385433 | controller |
2025-12-05 10:28:49.385441 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-05 10:28:49.385528 | controller | Friday 05 December 2025  10:28:49 +0000 (0:00:00.170)       0:00:04.803 *******
2025-12-05 10:28:49.402885 | controller | skipping: [instance]
2025-12-05 10:28:49.449164 | controller |
2025-12-05 10:28:49.449186 | controller | TASK [run_hook : Set playbook path for 03 single hook] *************************
2025-12-05 10:28:49.449196 | controller | Friday 05 December 2025  10:28:49 +0000 (0:00:00.017)       0:00:04.821 *******
2025-12-05 10:28:49.449206 | controller | ok: [instance]
2025-12-05 10:28:49.633290 | controller |
2025-12-05 10:28:49.633320 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-05 10:28:49.633328 | controller | Friday 05 December 2025  10:28:49 +0000 (0:00:00.046)       0:00:04.867 *******
2025-12-05 10:28:49.633338 | controller | ok: [instance]
2025-12-05 10:28:49.649890 | controller |
2025-12-05 10:28:49.649906 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-05 10:28:49.649913 | controller | Friday 05 December 2025  10:28:49 +0000 (0:00:00.183)       0:00:05.051 *******
2025-12-05 10:28:49.649921 | controller | skipping: [instance]
2025-12-05 10:28:49.830790 | controller |
2025-12-05 10:28:49.830818 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-05 10:28:49.830826 | controller | Friday 05 December 2025  10:28:49 +0000 (0:00:00.016)       0:00:05.068 *******
2025-12-05 10:28:49.830836 | controller | ok: [instance]
2025-12-05 10:28:49.850305 | controller |
2025-12-05 10:28:49.850325 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-05 10:28:49.850333 | controller | Friday 05 December 2025  10:28:49 +0000 (0:00:00.180)       0:00:05.248 *******
2025-12-05 10:28:49.850342 | controller | ok: [instance]
2025-12-05 10:28:49.850368 | controller |
2025-12-05 10:28:49.850382 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-05 10:28:49.850392 | controller | Friday 05 December 2025  10:28:49 +0000 (0:00:00.019)       0:00:05.268 *******
2025-12-05 10:28:50.044415 | controller | ok: [instance]
2025-12-05 10:28:50.251192 | controller |
2025-12-05 10:28:50.251224 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-05 10:28:50.251232 | controller | Friday 05 December 2025  10:28:50 +0000 (0:00:00.193)       0:00:05.462 *******
2025-12-05 10:28:50.251243 | controller | ok: [instance]
2025-12-05 10:28:52.179011 | controller |
2025-12-05 10:28:52.179042 | controller | TASK [run_hook : Run hook without retry - 03 single hook] **********************
2025-12-05 10:28:52.179050 | controller | Friday 05 December 2025  10:28:50 +0000 (0:00:00.206)       0:00:05.669 *******
2025-12-05 10:28:52.179060 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_002_run_hook_without_retry_03.log
2025-12-05 10:28:52.209053 | controller | changed: [instance]
2025-12-05 10:28:52.209078 | controller |
2025-12-05 10:28:52.209086 | controller | TASK [run_hook : Run hook with retry - 03 single hook] *************************
2025-12-05 10:28:52.209091 | controller | Friday 05 December 2025  10:28:52 +0000 (0:00:01.927)       0:00:07.596 *******
2025-12-05 10:28:52.209100 | controller | skipping: [instance]
2025-12-05 10:28:52.397644 | controller |
2025-12-05 10:28:52.397675 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-05 10:28:52.397689 | controller | Friday 05 December 2025  10:28:52 +0000 (0:00:00.030)       0:00:07.627 *******
2025-12-05 10:28:52.397700 | controller | ok: [instance]
2025-12-05 10:28:52.424889 | controller |
2025-12-05 10:28:52.424909 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-05 10:28:52.424917 | controller | Friday 05 December 2025  10:28:52 +0000 (0:00:00.188)       0:00:07.815 *******
2025-12-05 10:28:52.424928 | controller | ok: [instance]
2025-12-05 10:28:52.449314 | controller |
2025-12-05 10:28:52.449336 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-12-05 10:28:52.449343 | controller | Friday 05 December 2025  10:28:52 +0000 (0:00:00.027)       0:00:07.842 *******
2025-12-05 10:28:52.449353 | controller | ok: [instance] => changed=false
2025-12-05 10:28:52.481383 | controller |   msg: All assertions passed
2025-12-05 10:28:52.481420 | controller |
2025-12-05 10:28:52.481431 | controller | TASK [Only listed hooks] *******************************************************
2025-12-05 10:28:52.481439 | controller | Friday 05 December 2025  10:28:52 +0000 (0:00:00.024)       0:00:07.867 *******
2025-12-05 10:28:52.481450 | controller |
2025-12-05 10:28:52.481483 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-12-05 10:28:52.481570 | controller | Friday 05 December 2025  10:28:52 +0000 (0:00:00.032)       0:00:07.899 *******
2025-12-05 10:28:52.539931 | controller | ok: [instance]
2025-12-05 10:28:52.615802 | controller |
2025-12-05 10:28:52.615834 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-12-05 10:28:52.615843 | controller | Friday 05 December 2025  10:28:52 +0000 (0:00:00.058)       0:00:07.957 *******
2025-12-05 10:28:52.615852 | controller | ok: [instance]
2025-12-05 10:28:52.726264 | controller |
2025-12-05 10:28:52.726298 | controller | TASK [run_hook : Loop on hooks for list_hooks] *********************************
2025-12-05 10:28:52.726306 | controller | Friday 05 December 2025  10:28:52 +0000 (0:00:00.075)       0:00:08.033 *******
2025-12-05 10:28:52.726317 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'name': 'Run dummy-2', 'source': '/tmp/dummy-2.yml', 'type': 'playbook', 'extra_vars': {'foo': 'bar', 'file': '/tmp/dummy-env.yml'}})
2025-12-05 10:28:52.773361 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'name': 'Run dummy-3', 'source': '/tmp/dummy-3.yml', 'type': 'playbook', 'extra_vars': {'foo': 'bar', 'file': '/tmp/dummy-env.yml'}})
2025-12-05 10:28:52.773396 | controller |
2025-12-05 10:28:52.773406 | controller | TASK [run_hook : Set playbook path for Run dummy-2] ****************************
2025-12-05 10:28:52.773415 | controller | Friday 05 December 2025  10:28:52 +0000 (0:00:00.110)       0:00:08.143 *******
2025-12-05 10:28:52.773427 | controller | ok: [instance]
2025-12-05 10:28:52.962320 | controller |
2025-12-05 10:28:52.962351 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-05 10:28:52.962359 | controller | Friday 05 December 2025  10:28:52 +0000 (0:00:00.047)       0:00:08.191 *******
2025-12-05 10:28:52.962369 | controller | ok: [instance]
2025-12-05 10:28:52.962394 | controller |
2025-12-05 10:28:52.962623 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-05 10:28:52.979952 | controller | Friday 05 December 2025  10:28:52 +0000 (0:00:00.188)       0:00:08.380 *******
2025-12-05 10:28:52.979976 | controller | skipping: [instance]
2025-12-05 10:28:53.167180 | controller |
2025-12-05 10:28:53.167212 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-05 10:28:53.167220 | controller | Friday 05 December 2025  10:28:52 +0000 (0:00:00.017)       0:00:08.398 *******
2025-12-05 10:28:53.167230 | controller | ok: [instance]
2025-12-05 10:28:53.186225 | controller |
2025-12-05 10:28:53.186246 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-05 10:28:53.186272 | controller | Friday 05 December 2025  10:28:53 +0000 (0:00:00.186)       0:00:08.584 *******
2025-12-05 10:28:53.186283 | controller | ok: [instance]
2025-12-05 10:28:53.381809 | controller |
2025-12-05 10:28:53.381840 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-05 10:28:53.381848 | controller | Friday 05 December 2025  10:28:53 +0000 (0:00:00.019)       0:00:08.604 *******
2025-12-05 10:28:53.381858 | controller | ok: [instance]
2025-12-05 10:28:53.569084 | controller |
2025-12-05 10:28:53.569115 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-05 10:28:53.569123 | controller | Friday 05 December 2025  10:28:53 +0000 (0:00:00.195)       0:00:08.799 *******
2025-12-05 10:28:53.569133 | controller | ok: [instance]
2025-12-05 10:28:55.435202 | controller |
2025-12-05 10:28:55.435232 | controller | TASK [run_hook : Run hook without retry - Run dummy-2] *************************
2025-12-05 10:28:55.435241 | controller | Friday 05 December 2025  10:28:53 +0000 (0:00:00.187)       0:00:08.987 *******
2025-12-05 10:28:55.435266 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_003_run_hook_without_retry_run.log
2025-12-05 10:28:55.463605 | controller | changed: [instance]
2025-12-05 10:28:55.463624 | controller |
2025-12-05 10:28:55.463632 | controller | TASK [run_hook : Run hook with retry - Run dummy-2] ****************************
2025-12-05 10:28:55.463638 | controller | Friday 05 December 2025  10:28:55 +0000 (0:00:01.865)       0:00:10.852 *******
2025-12-05 10:28:55.463653 | controller | skipping: [instance]
2025-12-05 10:28:55.647033 | controller |
2025-12-05 10:28:55.647062 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-05 10:28:55.647071 | controller | Friday 05 December 2025  10:28:55 +0000 (0:00:00.028)       0:00:10.881 *******
2025-12-05 10:28:55.647081 | controller | ok: [instance]
2025-12-05 10:28:55.668977 | controller |
2025-12-05 10:28:55.669001 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-05 10:28:55.669009 | controller | Friday 05 December 2025  10:28:55 +0000 (0:00:00.183)       0:00:11.065 *******
2025-12-05 10:28:55.669020 | controller | ok: [instance]
2025-12-05 10:28:55.714966 | controller |
2025-12-05 10:28:55.714992 | controller | TASK [run_hook : Set playbook path for Run dummy-3] ****************************
2025-12-05 10:28:55.715002 | controller | Friday 05 December 2025  10:28:55 +0000 (0:00:00.022)       0:00:11.087 *******
2025-12-05 10:28:55.715014 | controller | ok: [instance]
2025-12-05 10:28:55.898993 | controller |
2025-12-05 10:28:55.899023 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-05 10:28:55.899032 | controller | Friday 05 December 2025  10:28:55 +0000 (0:00:00.045)       0:00:11.133 *******
2025-12-05 10:28:55.899042 | controller | ok: [instance]
2025-12-05 10:28:55.915953 | controller |
2025-12-05 10:28:55.915974 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-05 10:28:55.915981 | controller | Friday 05 December 2025  10:28:55 +0000 (0:00:00.183)       0:00:11.317 *******
2025-12-05 10:28:55.915990 | controller | skipping: [instance]
2025-12-05 10:28:56.100177 | controller |
2025-12-05 10:28:56.100211 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-05 10:28:56.100220 | controller | Friday 05 December 2025  10:28:55 +0000 (0:00:00.017)       0:00:11.334 *******
2025-12-05 10:28:56.100230 | controller | ok: [instance]
2025-12-05 10:28:56.119839 | controller |
2025-12-05 10:28:56.119862 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-05 10:28:56.119872 | controller | Friday 05 December 2025  10:28:56 +0000 (0:00:00.183)       0:00:11.518 *******
2025-12-05 10:28:56.119883 | controller | ok: [instance]
2025-12-05 10:28:56.309817 | controller |
2025-12-05 10:28:56.309849 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-05 10:28:56.309856 | controller | Friday 05 December 2025  10:28:56 +0000 (0:00:00.019)       0:00:11.537 *******
2025-12-05 10:28:56.309867 | controller | ok: [instance]
2025-12-05 10:28:56.492176 | controller |
2025-12-05 10:28:56.492206 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-05 10:28:56.492221 | controller | Friday 05 December 2025  10:28:56 +0000 (0:00:00.189)       0:00:11.727 *******
2025-12-05 10:28:56.492231 | controller | ok: [instance]
2025-12-05 10:28:58.406351 | controller |
2025-12-05 10:28:58.406383 | controller | TASK [run_hook : Run hook without retry - Run dummy-3] *************************
2025-12-05 10:28:58.406391 | controller | Friday 05 December 2025  10:28:56 +0000 (0:00:00.182)       0:00:11.910 *******
2025-12-05 10:28:58.406401 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_004_run_hook_without_retry_run.log
2025-12-05 10:28:58.406425 | controller | changed: [instance]
2025-12-05 10:28:58.406433 | controller |
2025-12-05 10:28:58.406694 | controller | TASK [run_hook : Run hook with retry - Run dummy-3] ****************************
2025-12-05 10:28:58.437168 | controller | Friday 05 December 2025  10:28:58 +0000 (0:00:01.914)       0:00:13.824 *******
2025-12-05 10:28:58.437193 | controller | skipping: [instance]
2025-12-05 10:28:58.622227 | controller |
2025-12-05 10:28:58.622283 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-05 10:28:58.622294 | controller | Friday 05 December 2025  10:28:58 +0000 (0:00:00.030)       0:00:13.855 *******
2025-12-05 10:28:58.622305 | controller | ok: [instance]
2025-12-05 10:28:58.647410 | controller |
2025-12-05 10:28:58.647443 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-05 10:28:58.647451 | controller | Friday 05 December 2025  10:28:58 +0000 (0:00:00.185)       0:00:14.040 *******
2025-12-05 10:28:58.647462 | controller | ok: [instance]
2025-12-05 10:28:58.647519 | controller |
2025-12-05 10:28:58.647539 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-12-05 10:28:58.647551 | controller | Friday 05 December 2025  10:28:58 +0000 (0:00:00.025)       0:00:14.065 *******
2025-12-05 10:28:58.671123 | controller | ok: [instance] => changed=false
2025-12-05 10:28:58.705366 | controller |   msg: All assertions passed
2025-12-05 10:28:58.705402 | controller |
2025-12-05 10:28:58.705412 | controller | TASK [Only filtered hooks] *****************************************************
2025-12-05 10:28:58.705420 | controller | Friday 05 December 2025  10:28:58 +0000 (0:00:00.023)       0:00:14.089 *******
2025-12-05 10:28:58.705432 | controller |
2025-12-05 10:28:58.705461 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-12-05 10:28:58.705589 | controller | Friday 05 December 2025  10:28:58 +0000 (0:00:00.034)       0:00:14.123 *******
2025-12-05 10:28:58.761218 | controller | ok: [instance]
2025-12-05 10:28:58.837449 | controller |
2025-12-05 10:28:58.837466 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-12-05 10:28:58.837474 | controller | Friday 05 December 2025  10:28:58 +0000 (0:00:00.055)       0:00:14.179 *******
2025-12-05 10:28:58.837483 | controller | ok: [instance]
2025-12-05 10:28:58.932391 | controller |
2025-12-05 10:28:58.932428 | controller | TASK [run_hook : Loop on hooks for filtered_hooks] *****************************
2025-12-05 10:28:58.932439 | controller | Friday 05 December 2025  10:28:58 +0000 (0:00:00.076)       0:00:14.255 *******
2025-12-05 10:28:58.932452 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'source': '/tmp/dummy-4.yml', 'type': 'playbook', 'extra_vars': {'foo': 'bar', 'file': '/tmp/dummy-env.yml'}, 'name': '01 my hook'})
2025-12-05 10:28:58.932461 | controller |
2025-12-05 10:28:58.932468 | controller | TASK [run_hook : Set playbook path for 01 my hook] *****************************
2025-12-05 10:28:58.932478 | controller | Friday 05 December 2025  10:28:58 +0000 (0:00:00.095)       0:00:14.350 *******
2025-12-05 10:28:58.979317 | controller | ok: [instance]
2025-12-05 10:28:59.169072 | controller |
2025-12-05 10:28:59.169098 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-05 10:28:59.169105 | controller | Friday 05 December 2025  10:28:58 +0000 (0:00:00.046)       0:00:14.397 *******
2025-12-05 10:28:59.169115 | controller | ok: [instance]
2025-12-05 10:28:59.186307 | controller |
2025-12-05 10:28:59.186327 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-05 10:28:59.186336 | controller | Friday 05 December 2025  10:28:59 +0000 (0:00:00.189)       0:00:14.587 *******
2025-12-05 10:28:59.186347 | controller | skipping: [instance]
2025-12-05 10:28:59.372706 | controller |
2025-12-05 10:28:59.372730 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-05 10:28:59.372738 | controller | Friday 05 December 2025  10:28:59 +0000 (0:00:00.017)       0:00:14.604 *******
2025-12-05 10:28:59.372747 | controller | ok: [instance]
2025-12-05 10:28:59.392862 | controller |
2025-12-05 10:28:59.392881 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-05 10:28:59.392890 | controller | Friday 05 December 2025  10:28:59 +0000 (0:00:00.186)       0:00:14.790 *******
2025-12-05 10:28:59.392900 | controller | ok: [instance]
2025-12-05 10:28:59.587831 | controller |
2025-12-05 10:28:59.587858 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-05 10:28:59.587865 | controller | Friday 05 December 2025  10:28:59 +0000 (0:00:00.020)       0:00:14.811 *******
2025-12-05 10:28:59.587875 | controller | ok: [instance]
2025-12-05 10:28:59.770354 | controller |
2025-12-05 10:28:59.770384 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-05 10:28:59.770392 | controller | Friday 05 December 2025  10:28:59 +0000 (0:00:00.194)       0:00:15.005 *******
2025-12-05 10:28:59.770402 | controller | ok: [instance]
2025-12-05 10:29:01.668350 | controller |
2025-12-05 10:29:01.668379 | controller | TASK [run_hook : Run hook without retry - 01 my hook] **************************
2025-12-05 10:29:01.668387 | controller | Friday 05 December 2025  10:28:59 +0000 (0:00:00.182)       0:00:15.188 *******
2025-12-05 10:29:01.668397 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_005_run_hook_without_retry_01_my.log
2025-12-05 10:29:01.668858 | controller | changed: [instance]
2025-12-05 10:29:01.697009 | controller |
2025-12-05 10:29:01.697028 | controller | TASK [run_hook : Run hook with retry - 01 my hook] *****************************
2025-12-05 10:29:01.697037 | controller | Friday 05 December 2025  10:29:01 +0000 (0:00:01.898)       0:00:17.086 *******
2025-12-05 10:29:01.697048 | controller | skipping: [instance]
2025-12-05 10:29:01.880789 | controller |
2025-12-05 10:29:01.880814 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-05 10:29:01.880822 | controller | Friday 05 December 2025  10:29:01 +0000 (0:00:00.028)       0:00:17.115 *******
2025-12-05 10:29:01.880831 | controller | ok: [instance]
2025-12-05 10:29:01.906934 | controller |
2025-12-05 10:29:01.906958 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-05 10:29:01.906968 | controller | Friday 05 December 2025  10:29:01 +0000 (0:00:00.183)       0:00:17.298 *******
2025-12-05 10:29:01.906980 | controller | ok: [instance]
2025-12-05 10:29:01.930930 | controller |
2025-12-05 10:29:01.930946 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-12-05 10:29:01.930953 | controller | Friday 05 December 2025  10:29:01 +0000 (0:00:00.026)       0:00:17.324 *******
2025-12-05 10:29:01.930961 | controller | ok: [instance] => changed=false
2025-12-05 10:29:01.967918 | controller |   msg: All assertions passed
2025-12-05 10:29:01.967940 | controller |
2025-12-05 10:29:01.967950 | controller | TASK [Direct hooks] ************************************************************
2025-12-05 10:29:01.967958 | controller | Friday 05 December 2025  10:29:01 +0000 (0:00:00.024)       0:00:17.349 *******
2025-12-05 10:29:01.967975 | controller |
2025-12-05 10:29:02.025333 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-12-05 10:29:02.025366 | controller | Friday 05 December 2025  10:29:01 +0000 (0:00:00.036)       0:00:17.386 *******
2025-12-05 10:29:02.025378 | controller | ok: [instance]
2025-12-05 10:29:02.025403 | controller |
2025-12-05 10:29:02.025410 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-12-05 10:29:02.025417 | controller | Friday 05 December 2025  10:29:02 +0000 (0:00:00.057)       0:00:17.443 *******
2025-12-05 10:29:02.103030 | controller | ok: [instance]
2025-12-05 10:29:02.197718 | controller |
2025-12-05 10:29:02.197737 | controller | TASK [run_hook : Loop on hooks for no_hook] ************************************
2025-12-05 10:29:02.197745 | controller | Friday 05 December 2025  10:29:02 +0000 (0:00:00.077)       0:00:17.521 *******
2025-12-05 10:29:02.197754 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'name': 'Dummy-5', 'source': '/tmp/dummy-5.yml', 'type': 'playbook', 'extra_vars': {'foo': 'bar', 'file': '/tmp/dummy-env.yml'}})
2025-12-05 10:29:02.244884 | controller |
2025-12-05 10:29:02.244902 | controller | TASK [run_hook : Set playbook path for Dummy-5] ********************************
2025-12-05 10:29:02.244910 | controller | Friday 05 December 2025  10:29:02 +0000 (0:00:00.094)       0:00:17.615 *******
2025-12-05 10:29:02.244919 | controller | ok: [instance]
2025-12-05 10:29:02.428042 | controller |
2025-12-05 10:29:02.428065 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-05 10:29:02.428073 | controller | Friday 05 December 2025  10:29:02 +0000 (0:00:00.046)       0:00:17.662 *******
2025-12-05 10:29:02.428082 | controller | ok: [instance]
2025-12-05 10:29:02.445358 | controller |
2025-12-05 10:29:02.445393 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-05 10:29:02.445402 | controller | Friday 05 December 2025  10:29:02 +0000 (0:00:00.183)       0:00:17.846 *******
2025-12-05 10:29:02.445415 | controller | skipping: [instance]
2025-12-05 10:29:02.445656 | controller |
2025-12-05 10:29:02.445682 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-05 10:29:02.635134 | controller | Friday 05 December 2025  10:29:02 +0000 (0:00:00.017)       0:00:17.863 *******
2025-12-05 10:29:02.635169 | controller | ok: [instance]
2025-12-05 10:29:02.666720 | controller |
2025-12-05 10:29:02.666738 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-05 10:29:02.666746 | controller | Friday 05 December 2025  10:29:02 +0000 (0:00:00.189)       0:00:18.053 *******
2025-12-05 10:29:02.666755 | controller | ok: [instance]
2025-12-05 10:29:02.884620 | controller |
2025-12-05 10:29:02.884650 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-05 10:29:02.884657 | controller | Friday 05 December 2025  10:29:02 +0000 (0:00:00.031)       0:00:18.084 *******
2025-12-05 10:29:02.884667 | controller | ok: [instance]
2025-12-05 10:29:03.098672 | controller |
2025-12-05 10:29:03.098703 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-05 10:29:03.098711 | controller | Friday 05 December 2025  10:29:02 +0000 (0:00:00.217)       0:00:18.302 *******
2025-12-05 10:29:03.098721 | controller | ok: [instance]
2025-12-05 10:29:05.094692 | controller |
2025-12-05 10:29:05.094724 | controller | TASK [run_hook : Run hook without retry - Dummy-5] *****************************
2025-12-05 10:29:05.094732 | controller | Friday 05 December 2025  10:29:03 +0000 (0:00:00.214)       0:00:18.516 *******
2025-12-05 10:29:05.094752 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_006_run_hook_without_retry_dummy.log
2025-12-05 10:29:05.124755 | controller | changed: [instance]
2025-12-05 10:29:05.124775 | controller |
2025-12-05 10:29:05.124784 | controller | TASK [run_hook : Run hook with retry - Dummy-5] ********************************
2025-12-05 10:29:05.124791 | controller | Friday 05 December 2025  10:29:05 +0000 (0:00:01.995)       0:00:20.512 *******
2025-12-05 10:29:05.124801 | controller | skipping: [instance]
2025-12-05 10:29:05.314773 | controller |
2025-12-05 10:29:05.314803 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-05 10:29:05.314811 | controller | Friday 05 December 2025  10:29:05 +0000 (0:00:00.030)       0:00:20.542 *******
2025-12-05 10:29:05.314821 | controller | ok: [instance]
2025-12-05 10:29:05.341896 | controller |
2025-12-05 10:29:05.341916 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-05 10:29:05.341924 | controller | Friday 05 December 2025  10:29:05 +0000 (0:00:00.189)       0:00:20.732 *******
2025-12-05 10:29:05.341932 | controller | ok: [instance]
2025-12-05 10:29:05.367395 | controller |
2025-12-05 10:29:05.367431 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-12-05 10:29:05.367455 | controller | Friday 05 December 2025  10:29:05 +0000 (0:00:00.027)       0:00:20.760 *******
2025-12-05 10:29:05.367467 | controller | ok: [instance] => changed=false
2025-12-05 10:29:05.367513 | controller |   msg: All assertions passed
2025-12-05 10:29:05.367522 | controller |
2025-12-05 10:29:05.367529 | controller | TASK [Direct hooks as param] ***************************************************
2025-12-05 10:29:05.367544 | controller | Friday 05 December 2025  10:29:05 +0000 (0:00:00.025)       0:00:20.785 *******
2025-12-05 10:29:05.405158 | controller |
2025-12-05 10:29:05.465301 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-12-05 10:29:05.465323 | controller | Friday 05 December 2025  10:29:05 +0000 (0:00:00.038)       0:00:20.823 *******
2025-12-05 10:29:05.465336 | controller | ok: [instance]
2025-12-05 10:29:05.576333 | controller |
2025-12-05 10:29:05.576356 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-12-05 10:29:05.576365 | controller | Friday 05 December 2025  10:29:05 +0000 (0:00:00.059)       0:00:20.883 *******
2025-12-05 10:29:05.576376 | controller | ok: [instance]
2025-12-05 10:29:05.576563 | controller |
2025-12-05 10:29:05.576730 | controller | TASK [run_hook : Loop on hooks for no_hook] ************************************
2025-12-05 10:29:05.576888 | controller | Friday 05 December 2025  10:29:05 +0000 (0:00:00.111)       0:00:20.994 *******
2025-12-05 10:29:05.672039 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'name': 'Hook as param', 'source': '/tmp/dummy-6.yml', 'type': 'playbook', 'extra_vars': {'foo': 'bar', 'file': '/tmp/dummy-env.yml'}})
2025-12-05 10:29:05.672223 | controller |
2025-12-05 10:29:05.672406 | controller | TASK [run_hook : Set playbook path for Hook as param] **************************
2025-12-05 10:29:05.672565 | controller | Friday 05 December 2025  10:29:05 +0000 (0:00:00.095)       0:00:21.090 *******
2025-12-05 10:29:05.719654 | controller | ok: [instance]
2025-12-05 10:29:05.719801 | controller |
2025-12-05 10:29:05.719956 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-05 10:29:05.720103 | controller | Friday 05 December 2025  10:29:05 +0000 (0:00:00.047)       0:00:21.138 *******
2025-12-05 10:29:05.913349 | controller | ok: [instance]
2025-12-05 10:29:05.930945 | controller |
2025-12-05 10:29:05.930966 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-05 10:29:05.930974 | controller | Friday 05 December 2025  10:29:05 +0000 (0:00:00.193)       0:00:21.331 *******
2025-12-05 10:29:05.930983 | controller | skipping: [instance]
2025-12-05 10:29:06.121006 | controller |
2025-12-05 10:29:06.121037 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-05 10:29:06.121045 | controller | Friday 05 December 2025  10:29:05 +0000 (0:00:00.017)       0:00:21.349 *******
2025-12-05 10:29:06.121055 | controller | ok: [instance]
2025-12-05 10:29:06.140773 | controller |
2025-12-05 10:29:06.140789 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-05 10:29:06.140797 | controller | Friday 05 December 2025  10:29:06 +0000 (0:00:00.190)       0:00:21.539 *******
2025-12-05 10:29:06.140805 | controller | ok: [instance]
2025-12-05 10:29:06.335857 | controller |
2025-12-05 10:29:06.335891 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-05 10:29:06.335899 | controller | Friday 05 December 2025  10:29:06 +0000 (0:00:00.019)       0:00:21.559 *******
2025-12-05 10:29:06.335910 | controller | ok: [instance]
2025-12-05 10:29:06.523918 | controller |
2025-12-05 10:29:06.523950 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-05 10:29:06.523958 | controller | Friday 05 December 2025  10:29:06 +0000 (0:00:00.194)       0:00:21.753 *******
2025-12-05 10:29:06.523969 | controller | ok: [instance]
2025-12-05 10:29:08.432344 | controller |
2025-12-05 10:29:08.432376 | controller | TASK [run_hook : Run hook without retry - Hook as param] ***********************
2025-12-05 10:29:08.432385 | controller | Friday 05 December 2025  10:29:06 +0000 (0:00:00.188)       0:00:21.941 *******
2025-12-05 10:29:08.432395 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_007_run_hook_without_retry_hook.log
2025-12-05 10:29:08.432417 | controller | changed: [instance]
2025-12-05 10:29:08.432424 | controller |
2025-12-05 10:29:08.432430 | controller | TASK [run_hook : Run hook with retry - Hook as param] **************************
2025-12-05 10:29:08.432438 | controller | Friday 05 December 2025  10:29:08 +0000 (0:00:01.908)       0:00:23.850 *******
2025-12-05 10:29:08.463183 | controller | skipping: [instance]
2025-12-05 10:29:08.652333 | controller |
2025-12-05 10:29:08.652365 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-05 10:29:08.652380 | controller | Friday 05 December 2025  10:29:08 +0000 (0:00:00.031)       0:00:23.881 *******
2025-12-05 10:29:08.652395 | controller | ok: [instance]
2025-12-05 10:29:08.652419 | controller |
2025-12-05 10:29:08.652624 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-05 10:29:08.678779 | controller | Friday 05 December 2025  10:29:08 +0000 (0:00:00.189)       0:00:24.070 *******
2025-12-05 10:29:08.678805 | controller | ok: [instance]
2025-12-05 10:29:08.704227 | controller |
2025-12-05 10:29:08.704262 | controller | TASK [Ensure we have the ceph_uuid variable now] *******************************
2025-12-05 10:29:08.704273 | controller | Friday 05 December 2025  10:29:08 +0000 (0:00:00.026)       0:00:24.096 *******
2025-12-05 10:29:08.704305 | controller | ok: [instance] => changed=false
2025-12-05 10:29:08.740349 | controller |   msg: All assertions passed
2025-12-05 10:29:08.740373 | controller |
2025-12-05 10:29:08.740383 | controller | TASK [Ensure we have the test_list variable now] *******************************
2025-12-05 10:29:08.740391 | controller | Friday 05 December 2025  10:29:08 +0000 (0:00:00.025)       0:00:24.122 *******
2025-12-05 10:29:08.740402 | controller | ok: [instance] => changed=false
2025-12-05 10:29:08.740601 | controller |   msg: All assertions passed
2025-12-05 10:29:08.740618 | controller |
2025-12-05 10:29:08.740630 | controller | TASK [Run hook with retry] *****************************************************
2025-12-05 10:29:08.768038 | controller | Friday 05 December 2025  10:29:08 +0000 (0:00:00.036)       0:00:24.158 *******
2025-12-05 10:29:08.768058 | controller |
2025-12-05 10:29:08.824887 | controller | TASK [run_hook : Assert parameters are valid] **********************************
2025-12-05 10:29:08.824908 | controller | Friday 05 December 2025  10:29:08 +0000 (0:00:00.027)       0:00:24.186 *******
2025-12-05 10:29:08.824921 | controller | ok: [instance]
2025-12-05 10:29:08.899703 | controller |
2025-12-05 10:29:08.899731 | controller | TASK [run_hook : Assert single hooks are all mappings] *************************
2025-12-05 10:29:08.899740 | controller | Friday 05 December 2025  10:29:08 +0000 (0:00:00.056)       0:00:24.243 *******
2025-12-05 10:29:08.899750 | controller | ok: [instance]
2025-12-05 10:29:08.995413 | controller |
2025-12-05 10:29:08.995450 | controller | TASK [run_hook : Loop on hooks for retry_hook] *********************************
2025-12-05 10:29:08.995461 | controller | Friday 05 December 2025  10:29:08 +0000 (0:00:00.074)       0:00:24.317 *******
2025-12-05 10:29:08.995474 | controller | included: /home/zuul/src/github.com/openstack-k8s-operators/ci-framework/roles/run_hook/tasks/playbook.yml for instance => (item={'name': 'Run hook with retry', 'source': '/tmp/dummy-retry.yml', 'type': 'playbook', 'retry_hook': True})
2025-12-05 10:29:09.042636 | controller |
2025-12-05 10:29:09.042667 | controller | TASK [run_hook : Set playbook path for Run hook with retry] ********************
2025-12-05 10:29:09.042675 | controller | Friday 05 December 2025  10:29:08 +0000 (0:00:00.095)       0:00:24.413 *******
2025-12-05 10:29:09.042685 | controller | ok: [instance]
2025-12-05 10:29:09.231330 | controller |
2025-12-05 10:29:09.231363 | controller | TASK [run_hook : Get file stat] ************************************************
2025-12-05 10:29:09.231371 | controller | Friday 05 December 2025  10:29:09 +0000 (0:00:00.047)       0:00:24.460 *******
2025-12-05 10:29:09.231381 | controller | ok: [instance]
2025-12-05 10:29:09.231635 | controller |
2025-12-05 10:29:09.231649 | controller | TASK [run_hook : Fail if playbook doesn't exist] *******************************
2025-12-05 10:29:09.249085 | controller | Friday 05 December 2025  10:29:09 +0000 (0:00:00.188)       0:00:24.649 *******
2025-12-05 10:29:09.249106 | controller | skipping: [instance]
2025-12-05 10:29:09.433991 | controller |
2025-12-05 10:29:09.434021 | controller | TASK [run_hook : Get parameters files] *****************************************
2025-12-05 10:29:09.434029 | controller | Friday 05 December 2025  10:29:09 +0000 (0:00:00.017)       0:00:24.667 *******
2025-12-05 10:29:09.434039 | controller | ok: [instance]
2025-12-05 10:29:09.454335 | controller |
2025-12-05 10:29:09.454360 | controller | TASK [run_hook : Add parameters artifacts as extra variables] ******************
2025-12-05 10:29:09.454371 | controller | Friday 05 December 2025  10:29:09 +0000 (0:00:00.184)       0:00:24.851 *******
2025-12-05 10:29:09.454383 | controller | ok: [instance]
2025-12-05 10:29:09.454469 | controller |
2025-12-05 10:29:09.454486 | controller | TASK [run_hook : Ensure log directory exists] **********************************
2025-12-05 10:29:09.454502 | controller | Friday 05 December 2025  10:29:09 +0000 (0:00:00.020)       0:00:24.872 *******
2025-12-05 10:29:09.645759 | controller | ok: [instance]
2025-12-05 10:29:09.828612 | controller |
2025-12-05 10:29:09.828643 | controller | TASK [run_hook : Ensure artifacts directory exists] ****************************
2025-12-05 10:29:09.828651 | controller | Friday 05 December 2025  10:29:09 +0000 (0:00:00.191)       0:00:25.063 *******
2025-12-05 10:29:09.828662 | controller | ok: [instance]
2025-12-05 10:29:11.684914 | controller |
2025-12-05 10:29:11.684944 | controller | TASK [run_hook : Run hook without retry - Run hook with retry] *****************
2025-12-05 10:29:11.684952 | controller | Friday 05 December 2025  10:29:09 +0000 (0:00:00.182)       0:00:25.246 *******
2025-12-05 10:29:11.684963 | controller | Follow script's output here: /home/zuul/ci-framework-data/logs/ci_script_008_run_hook_without_retry_run.log
2025-12-05 10:29:11.717133 | controller | changed: [instance]
2025-12-05 10:29:11.717169 | controller |
2025-12-05 10:29:11.717177 | controller | TASK [run_hook : Run hook with retry - Run hook with retry] ********************
2025-12-05 10:29:11.717183 | controller | Friday 05 December 2025  10:29:11 +0000 (0:00:01.856)       0:00:27.102 *******
2025-12-05 10:29:11.717193 | controller | skipping: [instance]
2025-12-05 10:29:11.889628 | controller |
2025-12-05 10:29:11.889647 | controller | TASK [run_hook : Check if we have a file] **************************************
2025-12-05 10:29:11.889655 | controller | Friday 05 December 2025  10:29:11 +0000 (0:00:00.032)       0:00:27.134 *******
2025-12-05 10:29:11.889663 | controller | ok: [instance]
2025-12-05 10:29:11.912300 | controller |
2025-12-05 10:29:11.912318 | controller | TASK [run_hook : Load generated content in main playbook] **********************
2025-12-05 10:29:11.912331 | controller | Friday 05 December 2025  10:29:11 +0000 (0:00:00.172)       0:00:27.307 *******
2025-12-05 10:29:11.912340 | controller | skipping: [instance]
2025-12-05 10:29:12.103222 | controller |
2025-12-05 10:29:12.103264 | controller | TASK [Check if fake file exists for retry playbook] ****************************
2025-12-05 10:29:12.103275 | controller | Friday 05 December 2025  10:29:11 +0000 (0:00:00.022)       0:00:27.330 *******
2025-12-05 10:29:12.103285 | controller | ok: [instance]
2025-12-05 10:29:12.123094 | controller |
2025-12-05 10:29:12.123110 | controller | TASK [Ensure file exists and was created on retry] *****************************
2025-12-05 10:29:12.123133 | controller | Friday 05 December 2025  10:29:12 +0000 (0:00:00.190)       0:00:27.521 *******
2025-12-05 10:29:12.123142 | controller | ok: [instance] => changed=false
2025-12-05 10:29:12.313187 | controller |   msg: All assertions passed
2025-12-05 10:29:12.313211 | controller |
2025-12-05 10:29:12.313219 | controller | TASK [Remove generated file] ***************************************************
2025-12-05 10:29:12.313226 | controller | Friday 05 December 2025  10:29:12 +0000 (0:00:00.019)       0:00:27.541 *******
2025-12-05 10:29:12.313238 | controller | changed: [instance]
2025-12-05 10:29:12.370268 | controller |
2025-12-05 10:29:12.370297 | controller | PLAY RECAP *********************************************************************
2025-12-05 10:29:12.370305 | controller | instance                   : ok=112  changed=10   unreachable=0    failed=0    skipped=22   rescued=0    ignored=0
2025-12-05 10:29:12.370311 | controller |
2025-12-05 10:29:12.370317 | controller | Friday 05 December 2025  10:29:12 +0000 (0:00:00.187)       0:00:27.728 *******
2025-12-05 10:29:12.370323 | controller | ===============================================================================
2025-12-05 10:29:12.370328 | controller | run_hook : Run hook without retry - Dummy-5 ----------------------------- 2.00s
2025-12-05 10:29:12.370333 | controller | run_hook : Run hook without retry - 03 single hook ---------------------- 1.93s
2025-12-05 10:29:12.370339 | controller | run_hook : Run hook without retry - Run dummy-3 ------------------------- 1.91s
2025-12-05 10:29:12.370344 | controller | run_hook : Run hook without retry - Hook as param ----------------------- 1.91s
2025-12-05 10:29:12.370349 | controller | run_hook : Run hook without retry - 01 my hook -------------------------- 1.90s
2025-12-05 10:29:12.370355 | controller | run_hook : Run hook without retry - Run dummy-2 ------------------------- 1.87s
2025-12-05 10:29:12.370360 | controller | run_hook : Run hook without retry - Run hook with retry ----------------- 1.86s
2025-12-05 10:29:12.370365 | controller | Gathering Facts --------------------------------------------------------- 0.77s
2025-12-05 10:29:12.370375 | controller | run_hook : Run hook without retry - 01 Default noop hook ---------------- 0.58s
2025-12-05 10:29:12.370381 | controller | run_hook : Run hook without retry - 02 Re-run noop ---------------------- 0.57s
2025-12-05 10:29:12.370386 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.28s
2025-12-05 10:29:12.370392 | controller | run_hook : Get file stat ------------------------------------------------ 0.28s
2025-12-05 10:29:12.370397 | controller | run_hook : Get parameters files ----------------------------------------- 0.27s
2025-12-05 10:29:12.370402 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.22s
2025-12-05 10:29:12.370408 | controller | run_hook : Ensure artifacts directory exists ---------------------------- 0.21s
2025-12-05 10:29:12.370413 | controller | run_hook : Ensure artifacts directory exists ---------------------------- 0.21s
2025-12-05 10:29:12.370418 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.20s
2025-12-05 10:29:12.370424 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.19s
2025-12-05 10:29:12.370429 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.19s
2025-12-05 10:29:12.370434 | controller | run_hook : Ensure log directory exists ---------------------------------- 0.19s
2025-12-05 10:29:12.370444 | controller | INFO     Running default > cleanup
2025-12-05 10:29:12.370888 | controller | WARNING  Skipping, cleanup playbook not configured.
2025-12-05 10:29:12.371475 | controller | INFO     Writing /tmp/report.html report.
2025-12-05 10:29:12.828370 | controller | changed
2025-12-05 10:29:12.849663 | 
2025-12-05 10:29:12.849724 | PLAY RECAP
2025-12-05 10:29:12.849765 | controller | ok: 4 changed: 1 unreachable: 0 failed: 0 skipped: 1 rescued: 0 ignored: 0
2025-12-05 10:29:12.849787 | 
2025-12-05 10:29:12.952565 | RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/molecule-test.yml@main]
2025-12-05 10:29:12.953456 | POST-RUN START: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-12-05 10:29:13.493647 | 
2025-12-05 10:29:13.493762 | PLAY [Run ci/playbooks/collect-logs.yml]
2025-12-05 10:29:13.514190 | 
2025-12-05 10:29:13.514264 | TASK [Filter out host if needed]
2025-12-05 10:29:13.522853 | controller | skipping: end_host conditional evaluated to False, continuing execution for controller
2025-12-05 10:29:13.527240 | 
2025-12-05 10:29:13.527307 | TASK [Ensure file is present]
2025-12-05 10:29:13.830938 | controller | ok
2025-12-05 10:29:13.838066 | 
2025-12-05 10:29:13.838139 | TASK [Manage molecule report file]
2025-12-05 10:29:14.365147 | controller | changed
2025-12-05 10:29:14.371028 | 
2025-12-05 10:29:14.371305 | TASK [Check if we get ci-framework-data basedir]
2025-12-05 10:29:14.558281 | controller | ok
2025-12-05 10:29:14.564388 | 
2025-12-05 10:29:14.564458 | TASK [Create ci-framework-data log directory for zuul]
2025-12-05 10:29:14.878689 | controller | changed
2025-12-05 10:29:14.884039 | 
2025-12-05 10:29:14.884107 | TASK [Copy ci-framework interesting files]
2025-12-05 10:29:15.098629 | controller | cp: cannot stat '/home/zuul/ci-framework-data/tests': No such file or directory
2025-12-05 10:29:15.414459 | controller | changed
2025-12-05 10:29:15.420746 | 
2025-12-05 10:29:15.420819 | TASK [Get SELinux listing]
2025-12-05 10:29:15.947331 | controller | changed
2025-12-05 10:29:15.953304 | 
2025-12-05 10:29:15.953377 | TASK [Generate log index]
2025-12-05 10:29:16.604315 | controller | changed
2025-12-05 10:29:16.614060 | 
2025-12-05 10:29:16.614165 | TASK [Get some env related data]
2025-12-05 10:29:17.156775 | controller | /home/zuul/.local/bin/ansible
2025-12-05 10:29:18.143989 | controller | changed
2025-12-05 10:29:18.149350 | 
2025-12-05 10:29:18.149416 | TASK [Generate list of logs to collect in home directory]
2025-12-05 10:29:18.485070 | controller | ok: All paths examined
2025-12-05 10:29:18.490129 | 
2025-12-05 10:29:18.490197 | LOOP [Copy logs from home directory]
2025-12-05 10:29:18.806703 | controller | changed:
2025-12-05 10:29:18.806831 | controller | {
2025-12-05 10:29:18.806858 | controller |   "atime": 1764930501.157605,
2025-12-05 10:29:18.806877 | controller |   "ctime": 1764930516.8109195,
2025-12-05 10:29:18.806895 | controller |   "dev": 64513,
2025-12-05 10:29:18.806930 | controller |   "gid": 1000,
2025-12-05 10:29:18.806951 | controller |   "gr_name": "zuul",
2025-12-05 10:29:18.806969 | controller |   "inode": 4330727,
2025-12-05 10:29:18.806985 | controller |   "isblk": false,
2025-12-05 10:29:18.807000 | controller |   "ischr": false,
2025-12-05 10:29:18.807015 | controller |   "isdir": false,
2025-12-05 10:29:18.807029 | controller |   "isfifo": false,
2025-12-05 10:29:18.807043 | controller |   "isgid": false,
2025-12-05 10:29:18.807056 | controller |   "islnk": false,
2025-12-05 10:29:18.807069 | controller |   "isreg": true,
2025-12-05 10:29:18.807081 | controller |   "issock": false,
2025-12-05 10:29:18.807094 | controller |   "isuid": false,
2025-12-05 10:29:18.807107 | controller |   "mode": "0644",
2025-12-05 10:29:18.807120 | controller |   "mtime": 1764930516.8109195,
2025-12-05 10:29:18.807132 | controller |   "nlink": 1,
2025-12-05 10:29:18.807145 | controller |   "path": "/home/zuul/ansible.log",
2025-12-05 10:29:18.807160 | controller |   "pw_name": "zuul",
2025-12-05 10:29:18.807174 | controller |   "rgrp": true,
2025-12-05 10:29:18.807187 | controller |   "roth": true,
2025-12-05 10:29:18.807208 | controller |   "rusr": true,
2025-12-05 10:29:18.807223 | controller |   "size": 6749,
2025-12-05 10:29:18.807237 | controller |   "uid": 1000,
2025-12-05 10:29:18.807251 | controller |   "wgrp": false,
2025-12-05 10:29:18.807265 | controller |   "woth": false,
2025-12-05 10:29:18.807281 | controller |   "wusr": true,
2025-12-05 10:29:18.807296 | controller |   "xgrp": false,
2025-12-05 10:29:18.807310 | controller |   "xoth": false,
2025-12-05 10:29:18.807325 | controller |   "xusr": false
2025-12-05 10:29:18.807339 | controller | }
2025-12-05 10:29:18.819724 | 
2025-12-05 10:29:18.819787 | TASK [Copy crio stats log file]
2025-12-05 10:29:18.833620 | controller | skipping: Conditional result was False
2025-12-05 10:29:18.838885 | 
2025-12-05 10:29:18.838986 | TASK [Get SELinux related data]
2025-12-05 10:29:19.056035 | controller | <no matches>
2025-12-05 10:29:19.362820 | controller | ERROR
2025-12-05 10:29:19.362976 | controller | {
2025-12-05 10:29:19.363015 | controller |   "delta": "0:00:00.010858",
2025-12-05 10:29:19.363037 | controller |   "end": "2025-12-05 10:29:19.056923",
2025-12-05 10:29:19.363056 | controller |   "msg": "non-zero return code",
2025-12-05 10:29:19.363071 | controller |   "rc": 1,
2025-12-05 10:29:19.363087 | controller |   "start": "2025-12-05 10:29:19.046065"
2025-12-05 10:29:19.363102 | controller | }
2025-12-05 10:29:19.363123 | controller | ERROR: Ignoring Errors
2025-12-05 10:29:19.368410 | 
2025-12-05 10:29:19.368475 | TASK [Create system configuration directory]
2025-12-05 10:29:19.559665 | controller | changed
2025-12-05 10:29:19.564612 | 
2025-12-05 10:29:19.564686 | TASK [Get some of the system configurations]
2025-12-05 10:29:20.088964 | controller | changed
2025-12-05 10:29:20.094454 | 
2025-12-05 10:29:20.094518 | TASK [Copy generated documentation if available]
2025-12-05 10:29:20.118884 | controller | skipping: Conditional result was False
2025-12-05 10:29:20.124580 | 
2025-12-05 10:29:20.124653 | TASK [Copy generated AsciiDoc documentation if available]
2025-12-05 10:29:20.149737 | controller | skipping: Conditional result was False
2025-12-05 10:29:20.155947 | 
2025-12-05 10:29:20.156013 | TASK [Compress logs bigger than 2MB]
2025-12-05 10:29:20.684025 | controller | changed
2025-12-05 10:29:20.689614 | 
2025-12-05 10:29:20.689679 | TASK [Copy files from workspace on node]
2025-12-05 10:29:20.709032 | controller | ok
2025-12-05 10:29:20.731986 | 
2025-12-05 10:29:20.732072 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-05 10:29:20.756027 | controller | skipping: Conditional result was False
2025-12-05 10:29:20.761693 | 
2025-12-05 10:29:20.761762 | TASK [fetch-output : Set log path for single node]
2025-12-05 10:29:20.791235 | controller | ok
2025-12-05 10:29:20.796001 | 
2025-12-05 10:29:20.796064 | LOOP [fetch-output : Ensure local output dirs]
2025-12-05 10:29:21.002494 | controller -> localhost | ok: "/var/lib/zuul/builds/56d676471e324ef58163400f8888f0a1/work/logs"
2025-12-05 10:29:21.002785 | controller -> localhost | changed: All items complete
2025-12-05 10:29:21.002824 | 
2025-12-05 10:29:21.195299 | controller -> localhost | changed: "/var/lib/zuul/builds/56d676471e324ef58163400f8888f0a1/work/artifacts"
2025-12-05 10:29:21.380848 | controller -> localhost | changed: "/var/lib/zuul/builds/56d676471e324ef58163400f8888f0a1/work/docs"
2025-12-05 10:29:21.392416 | 
2025-12-05 10:29:21.392549 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-05 10:29:21.959185 | controller | changed:
2025-12-05 10:29:21.959394 | controller | .d..t...... ./
2025-12-05 10:29:21.959426 | controller | >f+++++++++ README.html
2025-12-05 10:29:21.959449 | controller | >f+++++++++ ansible-execution.log
2025-12-05 10:29:21.959471 | controller | >f+++++++++ ansible.log
2025-12-05 10:29:21.959490 | controller | >f+++++++++ dmesg.log
2025-12-05 10:29:21.959520 | controller | >f+++++++++ installed-pkgs.log
2025-12-05 10:29:21.959544 | controller | >f+++++++++ python.log
2025-12-05 10:29:21.959565 | controller | >f+++++++++ registries.conf
2025-12-05 10:29:21.959584 | controller | >f+++++++++ report.html
2025-12-05 10:29:21.959604 | controller | >f+++++++++ selinux-denials.log
2025-12-05 10:29:21.959623 | controller | >f+++++++++ selinux-listing.log
2025-12-05 10:29:21.959641 | controller | cd+++++++++ ci-framework-data/
2025-12-05 10:29:21.959659 | controller | cd+++++++++ ci-framework-data/artifacts/
2025-12-05 10:29:21.959676 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_000_run_hook_without_retry_01.sh
2025-12-05 10:29:21.959694 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_001_run_hook_without_retry_02_re.sh
2025-12-05 10:29:21.959712 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_002_run_hook_without_retry_03.sh
2025-12-05 10:29:21.959729 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_003_run_hook_without_retry_run.sh
2025-12-05 10:29:21.959750 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_004_run_hook_without_retry_run.sh
2025-12-05 10:29:21.959768 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_005_run_hook_without_retry_01_my.sh
2025-12-05 10:29:21.959785 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_006_run_hook_without_retry_dummy.sh
2025-12-05 10:29:21.959802 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_007_run_hook_without_retry_hook.sh
2025-12-05 10:29:21.959818 | controller | >f+++++++++ ci-framework-data/artifacts/ci_script_008_run_hook_without_retry_run.sh
2025-12-05 10:29:21.959836 | controller | >f+++++++++ ci-framework-data/artifacts/filtered_hooks_01_my_hook.yml
2025-12-05 10:29:21.959854 | controller | >f+++++++++ ci-framework-data/artifacts/list_hooks_run_dummy-2.yml
2025-12-05 10:29:21.959872 | controller | >f+++++++++ ci-framework-data/artifacts/list_hooks_run_dummy-3.yml
2025-12-05 10:29:21.959889 | controller | >f+++++++++ ci-framework-data/artifacts/no_hook_dummy-5.yml
2025-12-05 10:29:21.959929 | controller | >f+++++++++ ci-framework-data/artifacts/no_hook_hook_as_param.yml
2025-12-05 10:29:21.959957 | controller | >f+++++++++ ci-framework-data/artifacts/run_molecule_03_single_hook.yml
2025-12-05 10:29:21.959978 | controller | >f+++++++++ ci-framework-data/artifacts/zuul_inventory.yml
2025-12-05 10:29:21.959997 | controller | cd+++++++++ ci-framework-data/artifacts/parameters/
2025-12-05 10:29:21.960046 | controller | >f+++++++++ ci-framework-data/artifacts/parameters/zuul-params.yml
2025-12-05 10:29:21.960068 | controller | cd+++++++++ ci-framework-data/logs/
2025-12-05 10:29:21.960086 | controller | >f+++++++++ ci-framework-data/logs/ci_script_000_run_hook_without_retry_01.log
2025-12-05 10:29:21.960104 | controller | >f+++++++++ ci-framework-data/logs/ci_script_001_run_hook_without_retry_02_re.log
2025-12-05 10:29:21.960121 | controller | >f+++++++++ ci-framework-data/logs/ci_script_002_run_hook_without_retry_03.log
2025-12-05 10:29:21.960138 | controller | >f+++++++++ ci-framework-data/logs/ci_script_003_run_hook_without_retry_run.log
2025-12-05 10:29:21.960155 | controller | >f+++++++++ ci-framework-data/logs/ci_script_004_run_hook_without_retry_run.log
2025-12-05 10:29:21.960171 | controller | >f+++++++++ ci-framework-data/logs/ci_script_005_run_hook_without_retry_01_my.log
2025-12-05 10:29:21.960187 | controller | >f+++++++++ ci-framework-data/logs/ci_script_006_run_hook_without_retry_dummy.log
2025-12-05 10:29:21.960204 | controller | >f+++++++++ ci-framework-data/logs/ci_script_007_run_hook_without_retry_hook.log
2025-12-05 10:29:21.960219 | controller | >f+++++++++ ci-framework-data/logs/ci_script_008_run_hook_without_retry_run.log
2025-12-05 10:29:21.960236 | controller | >f+++++++++ ci-framework-data/logs/filtered_hooks_01_my_hook.log
2025-12-05 10:29:21.960253 | controller | >f+++++++++ ci-framework-data/logs/list_hooks_run_dummy-2.log
2025-12-05 10:29:21.960270 | controller | >f+++++++++ ci-framework-data/logs/list_hooks_run_dummy-3.log
2025-12-05 10:29:21.960286 | controller | >f+++++++++ ci-framework-data/logs/molecule-execution.log
2025-12-05 10:29:21.960303 | controller | >f+++++++++ ci-framework-data/logs/no_hook_dummy-5.log
2025-12-05 10:29:21.960320 | controller | >f+++++++++ ci-framework-data/logs/no_hook_hook_as_param.log
2025-12-05 10:29:21.960337 | controller | >f+++++++++ ci-framework-data/logs/retry_hook_run_hook_with_retry.log
2025-12-05 10:29:21.960354 | controller | >f+++++++++ ci-framework-data/logs/run_molecule_01_default_noop_hook.log
2025-12-05 10:29:21.960370 | controller | >f+++++++++ ci-framework-data/logs/run_molecule_02_re-run_noop.log
2025-12-05 10:29:21.960386 | controller | >f+++++++++ ci-framework-data/logs/run_molecule_03_single_hook.log
2025-12-05 10:29:21.960403 | controller | cd+++++++++ registries.conf.d/
2025-12-05 10:29:21.960420 | controller | >f+++++++++ registries.conf.d/000-shortnames.conf
2025-12-05 10:29:21.960440 | controller | cd+++++++++ system-config/
2025-12-05 10:29:21.960458 | controller | cd+++++++++ system-config/libvirt/
2025-12-05 10:29:21.960474 | controller | >f+++++++++ system-config/libvirt/libvirt-admin.conf
2025-12-05 10:29:21.960491 | controller | >f+++++++++ system-config/libvirt/libvirt.conf
2025-12-05 10:29:22.340037 | controller | changed: .d..t...... ./
2025-12-05 10:29:22.701951 | controller | changed: .d..t...... ./
2025-12-05 10:29:22.714359 | 
2025-12-05 10:29:22.714506 | TASK [Return artifact to Zuul]
2025-12-05 10:29:22.744766 | controller | ok
2025-12-05 10:29:22.764884 | 
2025-12-05 10:29:22.764966 | PLAY [Run ci/playbooks/collect-logs.yml on CRC host]
2025-12-05 10:29:22.765075 | 
2025-12-05 10:29:22.765102 | PLAY RECAP
2025-12-05 10:29:22.765143 | controller | ok: 18 changed: 13 unreachable: 0 failed: 0 skipped: 4 rescued: 0 ignored: 1
2025-12-05 10:29:22.765164 | 
2025-12-05 10:29:22.883478 | POST-RUN END RESULT_NORMAL: [untrusted : github.com/openstack-k8s-operators/ci-framework/ci/playbooks/collect-logs.yml@main]
2025-12-05 10:29:22.884256 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-05 10:29:23.419354 | 
2025-12-05 10:29:23.419508 | PLAY [all]
2025-12-05 10:29:23.438488 | 
2025-12-05 10:29:23.438564 | TASK [include_role : fetch-output]
2025-12-05 10:29:23.468552 | controller | ok
2025-12-05 10:29:23.487307 | 
2025-12-05 10:29:23.487400 | TASK [fetch-output : Set log path for multiple nodes]
2025-12-05 10:29:23.541807 | controller | skipping: Conditional result was False
2025-12-05 10:29:23.547595 | 
2025-12-05 10:29:23.547668 | TASK [fetch-output : Set log path for single node]
2025-12-05 10:29:23.586524 | controller | ok
2025-12-05 10:29:23.591453 | 
2025-12-05 10:29:23.591523 | LOOP [fetch-output : Ensure local output dirs]
2025-12-05 10:29:23.948493 | controller -> localhost | ok: "/var/lib/zuul/builds/56d676471e324ef58163400f8888f0a1/work/logs"
2025-12-05 10:29:24.144169 | controller -> localhost | ok: "/var/lib/zuul/builds/56d676471e324ef58163400f8888f0a1/work/artifacts"
2025-12-05 10:29:24.326785 | controller -> localhost | ok: "/var/lib/zuul/builds/56d676471e324ef58163400f8888f0a1/work/docs"
2025-12-05 10:29:24.342572 | 
2025-12-05 10:29:24.342647 | LOOP [fetch-output : Collect logs, artifacts and docs]
2025-12-05 10:29:24.868605 | controller | ok
2025-12-05 10:29:24.868852 | controller | ok: All items complete
2025-12-05 10:29:24.868881 | 
2025-12-05 10:29:25.235580 | controller | ok
2025-12-05 10:29:25.600008 | controller | ok
2025-12-05 10:29:25.613182 | 
2025-12-05 10:29:25.613250 | TASK [include_role : fetch-output-openshift]
2025-12-05 10:29:25.626316 | controller | skipping: Conditional result was False
2025-12-05 10:29:25.631773 | 
2025-12-05 10:29:25.631843 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir]
2025-12-05 10:29:25.973527 | controller -> localhost | ok: Item: artifacts Runtime: 0:00:00.006020
2025-12-05 10:29:26.164235 | controller -> localhost | ok: Item: docs Runtime: 0:00:00.005957
2025-12-05 10:29:26.197440 | 
2025-12-05 10:29:26.197544 | PLAY [all]
2025-12-05 10:29:26.211097 | 
2025-12-05 10:29:26.211165 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes]
2025-12-05 10:29:26.604374 | controller | changed
2025-12-05 10:29:26.625337 | 
2025-12-05 10:29:26.625400 | PLAY RECAP
2025-12-05 10:29:26.625510 | controller | ok: 5 changed: 2 unreachable: 0 failed: 0 skipped: 2 rescued: 0 ignored: 0
2025-12-05 10:29:26.625541 | 
2025-12-05 10:29:26.700571 | POST-RUN END RESULT_NORMAL: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-ssh.yaml@master]
2025-12-05 10:29:26.701439 | POST-RUN START: [trusted : review.rdoproject.org/config/playbooks/base-minimal/post-logs.yaml@master]
2025-12-05 10:29:27.246835 | 
2025-12-05 10:29:27.246954 | PLAY [localhost]
2025-12-05 10:29:27.264074 | 
2025-12-05 10:29:27.264149 | TASK [generate-zuul-manifest : Generate Zuul manifest]
2025-12-05 10:29:27.576317 | localhost | changed
2025-12-05 10:29:27.581430 | 
2025-12-05 10:29:27.581533 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul]
2025-12-05 10:29:27.610035 | localhost | ok
2025-12-05 10:29:27.618008 | 
2025-12-05 10:29:27.618082 | TASK [add-fileserver : Create SSH private key tempfile]
2025-12-05 10:29:27.925156 | localhost | changed
2025-12-05 10:29:27.930841 | 
2025-12-05 10:29:27.930929 | TASK [add-fileserver : Create SSH private key from secret]
2025-12-05 10:29:28.474661 | localhost | changed
2025-12-05 10:29:28.479745 | 
2025-12-05 10:29:28.479815 | TASK [add-fileserver : Add fileserver ssh key]
2025-12-05 10:29:28.811321 | localhost | Identity added: /var/lib/zuul/builds/56d676471e324ef58163400f8888f0a1/work/tmp/ansible.rjlfjgga (/var/lib/zuul/builds/56d676471e324ef58163400f8888f0a1/work/tmp/ansible.rjlfjgga)
2025-12-05 10:29:28.811512 | localhost | ok: Runtime: 0:00:00.006515
2025-12-05 10:29:28.815755 | 
2025-12-05 10:29:28.815823 | TASK [add-fileserver : Remove SSH private key from disk]
2025-12-05 10:29:29.035494 | localhost | ok: Runtime: 0:00:00.004184
2025-12-05 10:29:29.040058 | 
2025-12-05 10:29:29.040127 | TASK [add-fileserver : Add fileserver to inventory]
2025-12-05 10:29:29.087477 | localhost | changed
2025-12-05 10:29:29.092192 | 
2025-12-05 10:29:29.092257 | TASK [add-fileserver : Add fileserver server to known hosts]
2025-12-05 10:29:29.403258 | localhost | changed
2025-12-05 10:29:29.422820 | 
2025-12-05 10:29:29.422880 | PLAY [localhost]
2025-12-05 10:29:29.434329 | 
2025-12-05 10:29:29.434391 | TASK [Generate bulk log download script]
2025-12-05 10:29:29.452261 | localhost | ok
2025-12-05 10:29:29.463637 | 
2025-12-05 10:29:29.463705 | TASK [local-log-download : Check API endpoint is defined]
2025-12-05 10:29:29.490966 | localhost | ok: All assertions passed
2025-12-05 10:29:29.495347 | 
2025-12-05 10:29:29.495412 | TASK [local-log-download : Create download script]
2025-12-05 10:29:29.832657 | localhost -> localhost | changed
2025-12-05 10:29:29.841522 | 
2025-12-05 10:29:29.841599 | TASK [Register quick-download link]
2025-12-05 10:29:29.858687 | localhost | ok
2025-12-05 10:29:29.893307 | 
2025-12-05 10:29:29.893389 | PLAY [logserver.rdoproject.org]
2025-12-05 10:29:29.902324 | 
2025-12-05 10:29:29.902385 | TASK [Set zuul-log-path fact]
2025-12-05 10:29:29.917765 | logserver.rdoproject.org | ok
2025-12-05 10:29:29.926602 | 
2025-12-05 10:29:29.926666 | TASK [set-zuul-log-path-fact : Set log path for a build]
2025-12-05 10:29:29.952749 | logserver.rdoproject.org | ok
2025-12-05 10:29:29.958388 | 
2025-12-05 10:29:29.958498 | TASK [upload-logs : Create log directories]
2025-12-05 10:29:31.444324 | logserver.rdoproject.org | changed
2025-12-05 10:29:31.447338 | 
2025-12-05 10:29:31.447404 | TASK [upload-logs : Ensure logs are readable before uploading]
2025-12-05 10:29:31.663716 | logserver.rdoproject.org -> localhost | ok: Runtime: 0:00:00.004548
2025-12-05 10:29:31.668142 | 
2025-12-05 10:29:31.668206 | TASK [upload-logs : Upload logs to log server]
2025-12-05 10:29:33.114870 | logserver.rdoproject.org | Output suppressed because no_log was given
2025-12-05 10:29:33.117778 | 
2025-12-05 10:29:33.117843 | LOOP [upload-logs : Compress console log and json output]
2025-12-05 10:29:33.156695 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 10:29:33.165337 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 10:29:33.175022 | 
2025-12-05 10:29:33.175095 | LOOP [upload-logs : Upload compressed console log and json output]
2025-12-05 10:29:33.211348 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 10:29:33.211564 | 
2025-12-05 10:29:33.214855 | logserver.rdoproject.org | skipping: Conditional result was False
2025-12-05 10:29:33.222881 | 
2025-12-05 10:29:33.222979 | LOOP [upload-logs : Upload console log and json output]